May 20, 2014 at 10:08 am
Hi folks, advice is needed.
I have a situation.
Call center agents are using an .NET application to get order related info from the database.
Application is calling a stored procedure which executes in less than a second (in average).
Procedure is called approximately 3500 times a day.
I log each execution (start and duration)
The application throws a timeout ~ 15 times a day without any specific time pattern.
The problem: the time out is being logged in to the error log table 40 seconds before the procedure actually logs it's start time.
The server is not under any stress. 80~100 sessions open. 200~300 transactions per second.
And, since same application is able to log the timeout in to the database, I assume there is no connectivity issue.
Any ideas where to dig?
Thanks!
May 20, 2014 at 12:30 pm
I am going to guess that the logging logic is toward the end of the stored procedure. When a client times out (command timeout expired), the client gives up, but the command on SQL Server does not know it, and continues on. You can try this out, by making a procedure that consists of a WAITFOR DELAY of more than 30 seconds, and a couple calls to getdate().
As for why a procedure that normally takes 1 second would suddenly go to over 30 seconds (default command timeout value), I would suspect you have some locking contention going on in the database. Check in the output of sp_who2, or run
select session_id, blocking_session_id
from sys.dm_exec_requests
where blocking_session_id > 0and see what you come up with.
May 20, 2014 at 12:39 pm
Additionally you might want to check the datetime settings on your servers. I assume you are logging the error from your .NET application which is likely running on a different server than your database server. This means that DateTime.Now get the value of the .NET server and GETDATE() gets the value from the SQL Server. 😛
_______________________________________________________________
Need help? Help us help you.
Read the article at http://www.sqlservercentral.com/articles/Best+Practices/61537/ for best practices on asking questions.
Need to split a string? Try Jeff Modens splitter http://www.sqlservercentral.com/articles/Tally+Table/72993/.
Cross Tabs and Pivots, Part 1 – Converting Rows to Columns - http://www.sqlservercentral.com/articles/T-SQL/63681/
Cross Tabs and Pivots, Part 2 - Dynamic Cross Tabs - http://www.sqlservercentral.com/articles/Crosstab/65048/
Understanding and Using APPLY (Part 1) - http://www.sqlservercentral.com/articles/APPLY/69953/
Understanding and Using APPLY (Part 2) - http://www.sqlservercentral.com/articles/APPLY/69954/
May 20, 2014 at 1:12 pm
Hi, thanks for the replies.
The procedure logs "start time" before it does anything else.
example: Procedure started at 06:03:34.077, duration :127 ms.
Application logged timeout at 06:02:37.210. Minus 20 seconds for timeout delay gives me 06:02:17
The 'date' column is has a default GETDATE() in both tables, so the time difference is not the issue.
Another fact.
I did a stress test using SQLQueryStress with 200 connections, 10 iterations each. No problems found.
Viewing 4 posts - 1 through 3 (of 3 total)
You must be logged in to reply to this topic. Login to reply