Extended Events: using ATTENTION Event to log external apps timeouts.

  • The purpose I created the attached Session and one of the queries to view data and periodically reload it to the table WAS BECAUSE

    once in a couple of weeks we have had this nasty bottleneck in our environment when instead of an average of 40 or 50 timeouts (from ASP web pages/IIS) per day we would suddenly see 500 AppTimeouts/minute. And this coincides with the entire SQL Server being very slow, CPU maxed, users panicking and complaining of freezing latencies on their screen,  CIO joining the troubleshooting team, etc..

    Needless to say that during such time neither DMVs /sp_whoisactive NOR Traces capture SPIDS or details for such timeouts. So we decided to create an XE Session intercepting/logging ALL App timeouts 24/7.

    NOW, MY QUESTION What baffles us: in IIS/web apps the Timeout for query execution is set the same for all: 30 seconds.

    It is understandable why some queries are timed out after a longer wait, 50 seconds or 60 or 200 seconds. That is explicable. However, it is not clear/known (to us at least..) WHY some calls would be timing out within microseconds, which is way below even a second. Or in 10 or 15 seconds, which is till below the set time out = 30 seconds. I am attaching a screenshot of such records.

    Should we even care about such short-living query exec requests? and rather filter those  out that are <  3000000 microsec in duration? OR should we log them all for review purposes anyway, and do they  even contribute significantly  to the latencies/overall bottleneck?

    But the main question is WHY they exist? What reasons make those requests that are shorter than 3o seconds timeout much earlier than after 30 seconds?

    NOTE: Also, it appears that the Duration is in MILLIseconds not in MICROseconds as the MS Documentation says.

     

    THANK YOU VERY MUCH

    FOR YOUR POSSIBLE CLARIFICATION AND GUIDANCE in this matter!

    Attachments:
    You must be logged in to view attached files.

    Likes to play Chess

  • Have you checked the SQL Server logs for deadlocks?  And I'm pretty sure that the MS documentation is correct about MicroSeconds.

    --Jeff Moden


    RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
    First step towards the paradigm shift of writing Set Based code:
    ________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.

    Change is inevitable... Change for the better is not.


    Helpful Links:
    How to post code problems
    How to Post Performance Problems
    Create a Tally Function (fnTally)

  • Jeff, why do you think deadlocks could be an issue? in any case, we almost never have them in our environment.

    for example, between a month ago and today there are only 25 deadlocks, which is nothing.

    Re: Duration - Microseconds? How could it then be possible for IIS query timeout to happen in 25 microseconds only? see my screenshots. Lots of 2 and 3 digit durations. How is it possible and why?

     

    Likes to play Chess

  • VoldemarG wrote:

    Jeff, why do you think deadlocks could be an issue?

    It was a suggestion based on previous experience that was meant to prompt you into checking for them.  That worked.  Heh... and you say "only 25 deadlocks, which is nothing" but that means that there were 25 losers that got cut off at the knees.

    VoldemarG wrote:

    Re: Duration - Microseconds? How could it then be possible for IIS query timeout to happen in 25 microseconds only? see my screenshots. Lots of 2 and 3 digit durations. How is it possible and why?

    Ok.. let me ask then.. do you think your having timeouts of 749 seconds like the first entry in your screen shot would indicate if it were millisonds?

    And I heard the Developers on the team I work with complain of things timing out "nearly instantaneously" (their words, not mine).  I never did ask them if they were able to fix them or what the issue was and, not having worked the front-end in nearly 2 decades and except for the deadlock suggestion, I haven't a clue as to what else it might be unless there simply aren't enough connections available.  It would be interesting to see what the connection code/configuration looked like.  I might not even be able to to help with that but it might pop and idea or two into someone else's head.

    • This reply was modified 2 years, 2 months ago by  Jeff Moden.

    --Jeff Moden


    RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
    First step towards the paradigm shift of writing Set Based code:
    ________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.

    Change is inevitable... Change for the better is not.


    Helpful Links:
    How to post code problems
    How to Post Performance Problems
    Create a Tally Function (fnTally)

Viewing 4 posts - 1 through 3 (of 3 total)

You must be logged in to reply to this topic. Login to reply