0

I am encountering a problem with the CommandTimeout property of my SqlCommand that I'm using to execute a stored procedure.

    using (SqlCommand command = new SqlCommand("_UpdateWorldeaseIDs", SqlC_SSuite))
    {
        command.CommandType = CommandType.StoredProcedure;
        command.CommandTimeout = 600;
        int rowsAffected = command.ExecuteNonQuery();
        logger.log($": Rows affected = {rowsAffected}.", Log4NetExtension.Level.Info);
    }

The code is fairly simple. The code used to not specify a CommandTimeout, so it would use the default of 30 seconds. It appears that this procedure can (not always) take longer than 30 seconds, so we raised it significantly to 600 seconds, presuming there was no way that wouldn't be long enough.

Strangely this morning we got another failure email that comes through automatically that said

"Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding."

I checked our log to see how much time elapsed between "Procedure begin" and "Procedure failed" logs, and it is basically 30 seconds. The image below shows that about 30 seconds after the command execution started, it failed.

Timeout image

What is happening here? I did try to read through most similar SO questions and MSDN forums, but to no avail so far.

halfer
  • 19,824
  • 17
  • 99
  • 186
Nick
  • 882
  • 2
  • 9
  • 31
  • if you can, put a wait of 300 seconds in the stored procedure, and re-test it - could the code somehow not be deployed? Or you could look at the deployed dll with ILSpy (for example). I can't see anything wrong though. The other possibility is that the stored-proc itself throws an error after 30 seconds, maybe it's checking within some sort of loop. – Cato Sep 12 '18 at 15:22
  • Perhaps you are going about this backwards? Instead of increasing the timeout you should focus on decreasing the execution time. – Sean Lange Sep 12 '18 at 15:26
  • @Cato I did use DotNetPeek to examine the .exe, and was able to confirm that the 600 second statement _is_ in place. That was my first thought. I will check with the person who wrote the procedure to see about the 300 second wait scenario, that is a good idea. – Nick Sep 12 '18 at 15:33
  • @SeanLange Fair enough, but the amount of time this procedure takes is highly variable. I'm not sure we would ever tune it to the point where we can guarantee it will take less than 30 seconds. – Nick Sep 12 '18 at 15:34
  • Understand the variance can be an issue. Your code should increase the timeout. Is it possible it is cached or maybe still executing the old code? – Sean Lange Sep 12 '18 at 15:42
  • Perhaps something besides the SqlCommand is timing out? – Tab Alleman Sep 12 '18 at 15:43
  • @SeanLange I'm pretty certain that it is not using old code. This procedure is executed at the top of every hour, via Scheduled Task. I checked the .exe that the scheduled task is hooked up to, and verified that the 600 timeout property does exist in there. So unfortunately it does look like the most recent code is there. – Nick Sep 12 '18 at 16:05
  • @TabAlleman I suppose that is a possibility, but hard for me to really determine. The log that I'm reading basically says "Procedure started" and the next logged statement is the failure, so nothing in between that for me to really go off of. I've checked with our DBA to see if he can see anything about the Procedure, Database, Connection, etc... but he's not seeing much. – Nick Sep 12 '18 at 16:07
  • To isolate the issue I would add a bunch of logging both in your code and in the procedure. Literally every other line logging something so you can find out what is going on. Logging things like the CommandTimeout property even. – Sean Lange Sep 12 '18 at 16:19
  • 1
    @SeanLange Agreed, I think that's my only hope at this point since I'm basically searching for a needle in a haystack. I'll report back if and when I figure it out. – Nick Sep 12 '18 at 16:20
  • Didn't know this myself, but... "CommandTimeout has no effect when the command is executed against a context connection (a SqlConnection opened with "context connection=true" in the connection string)." – Black Light Sep 12 '18 at 20:44

0 Answers0