Ok, so yesterday I had a post on how to generate a dump for a SqlException.

 

In that scenario we had an application that was throwing an exception like so:

 

Unhandled Exception: System.Data.SqlClient.SqlException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.

   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)

   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)

   at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)

   at System.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(String methodName, Boolean async)

   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe)

   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()

 

What we would like to know now is of course what SqlCommand is not returning in time and thereby causing this exception.

There may be easier ways to figure out what the SqlCommand is, but say for example that this is a deployed application (no source) and no access to SQL Server (no SQL Profiler), then this may be helpful.

This post is not intended to go into depth on how to debug .Net/ADO.Net applications, for this I would recommend my colleagues Tess blog.

 

So, first follow the steps from last post in order to create the application and dump. Found here

 

Once this is done, you should have some .dmp files in the “C:\Dumps” directory.

Now, the object of this is to figure out what SQL was executing when the application timed out. This can be done like so:

 

Download and install the debugging tools from here:

"Debugging Tools for Windows - Overview"

http://www.microsoft.com/whdc/devtools/debugging/default.mspx

 

Start the debugger (WinDbg) and go File – Open Crash Dump, select the .dmp file you are interested in (should have ‘First Chance’ in the filename)

Then you need to load what is called the symbols, so go File -> Symbol File Path, set this to:

 

srv*C:\Symbols*http://msdl.microsoft.com/download/symbols

 

Then you need to load the SOS extension. This file is found in the .Net framework directory, depending on what type of machine (x86/x64) you are running.

 

    C:\Windows\Microsoft.NET\Framework\v2.0.50727\sos.dll

    C:\Windows\Microsoft.NET\Framework64\v2.0.50727\sos.dll

 

So, in windbg, in order to load the SOS extension, type the following and hit enter:

 

.load C:\WINDOWS\Microsoft.NET\Framework64\v2.0.50727\sos.dll

 

On this is done, let us check what the CLR stack looks like at the time of the exception. Do this by running:

 

!clrstack

 

This should give an output like this:

 

0:000> !clrstack

OS Thread Id: 0x2d0 (0)

*** WARNING: Unable to verify checksum for System.Data.ni.dll

Child-SP         RetAddr          Call Site

000000000012ec90 00000642b78c50b5 System.Data.SqlClient.SqlConnection.OnError(System.Data.SqlClient.SqlException, Boolean)

000000000012ecd0 00000642b78c13fb System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(System.Data.SqlClient.TdsParserStateObject)

000000000012ed30 00000642b789a712 System.Data.SqlClient.TdsParser.Run(System.Data.SqlClient.RunBehavior, System.Data.SqlClient.SqlCommand, System.Data.SqlClient.SqlDataReader, System.Data.SqlClient.BulkCopySimpleResultSet, System.Data.SqlClient.TdsParserStateObject)

000000000012ee00 00000642b7898096 System.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(System.String, Boolean)

000000000012ee90 00000642b7897756 System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(System.Data.Common.DbAsyncResult, System.String, Boolean)

000000000012ef40 00000642801b0248 System.Data.SqlClient.SqlCommand.ExecuteNonQuery()

000000000012efb0 000006427f602672 TimeOutApp.Program.Main(System.String[])

 

This seems correct, there is an error on a SqlConnection, it all started with a call to a SqlCommand.ExecuteNonQuery.

So, let us have a look at the objects on the stack. Do this by running:

 

!dumpstackobjects

 

This should give an output like this:

 

0:000> !dumpstackobjects

OS Thread Id: 0x2d0 (0)

RSP/REG          Object           Name

000000000012e9b8 000000000207ab80 System.String

000000000012eab0 000000000205bdd0 System.Data.SqlClient.TdsParserStateObject

000000000012eab8 000000000205bb30 System.Data.SqlClient.TdsParser

000000000012eac0 000000000206ff70 System.Data.SqlClient.SqlCommand

000000000012eac8 000000000207aa50 System.Data.SqlClient.SqlException

000000000012ead0 000000000207aa50 System.Data.SqlClient.SqlException

000000000012eae0 000000000207aa50 System.Data.SqlClient.SqlException

000000000012eb00 000000000207aa50 System.Data.SqlClient.SqlException

000000000012ebd0 000000000207aa50 System.Data.SqlClient.SqlException

000000000012ebd8 000000000207aa50 System.Data.SqlClient.SqlException

000000000012ebf0 000000000206ff70 System.Data.SqlClient.SqlCommand

000000000012ebf8 000000000205bb30 System.Data.SqlClient.TdsParser

000000000012ec00 000000000205bdd0 System.Data.SqlClient.TdsParserStateObject

000000000012ec10 000000000205bb30 System.Data.SqlClient.TdsParser

000000000012ec70 0000000001ff5640 System.Data.SqlClient.SqlConnection

000000000012ec78 0000000001ff5640 System.Data.SqlClient.SqlConnection

000000000012eca0 000000000206ff70 System.Data.SqlClient.SqlCommand

000000000012eca8 000000000205bb30 System.Data.SqlClient.TdsParser

000000000012ecb0 000000000205bb30 System.Data.SqlClient.TdsParser

.. truncated ..

 

So this also seems promising, we have a SqlException and a SqlCommand, let’s check the SqlException first and see what the error message is.

This is done by passing the objects address to the !dumpobject method.

 

0:000> !dumpobj 000000000207aa50

Name: System.Data.SqlClient.SqlException

MethodTable: 00000642b7a2e978

EEClass: 00000642b73c5aa8

Size: 144(0x90) bytes

 (C:\WINDOWS\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)

Fields:

              MT    Field   Offset                 Type VT     Attr            Value Name

00000642784365e8  40000b5        8        System.String  0 instance 0000000000000000 _className

0000064278434990  40000b6       10 ...ection.MethodBase  0 instance 0000000000000000 _exceptionMethod

00000642784365e8  40000b7       18        System.String  0 instance 0000000000000000 _exceptionMethodString

00000642784365e8  40000b8       20        System.String  0 instance 000000000207a950 _message

000006427842dc08  40000b9       28 ...tions.IDictionary  0 instance 000000000207aae0 _data

00000642784368b0  40000ba       30     System.Exception  0 instance 0000000000000000 _innerException

00000642784365e8  40000bb       38        System.String  0 instance 0000000000000000 _helpURL

0000064278435ed8  40000bc       40        System.Object  0 instance 0000000000000000 _stackTrace

00000642784365e8  40000bd       48        System.String  0 instance 0000000000000000 _stackTraceString

.. truncated ..

 

It makes sense that the message is in the _message variable, so let’s check the value of that, again using !dumpobject and the address.

 

0:000> !dumpobj 000000000207a950

Name: System.String

MethodTable: 00000642784365e8

EEClass: 000006427803e4f0

Size: 254(0xfe) bytes

 (C:\WINDOWS\assembly\GAC_64\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)

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

Fields:

              MT    Field   Offset                 Type VT     Attr            Value Name

000006427843d858  4000096        8         System.Int32  1 instance              115 m_arrayLength

000006427843d858  4000097        c         System.Int32  1 instance              114 m_stringLength

0000064278438030  4000098       10          System.Char  1 instance               54 m_firstChar

.. truncated ..

 

So this is clearly the same error that we got from the application, promising. Let’s then examine the SqlCommand that we got by running !dumpstackobjects earlier.

Again, this is done by passing the SqlCommand object address to the !dumpobj method.

 

0:000> !dumpobj 000000000206ff70

Name: System.Data.SqlClient.SqlCommand

MethodTable: 00000642b7a2f240

EEClass: 00000642b73c5fe8

Size: 224(0xe0) bytes

 (C:\WINDOWS\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)

Fields:

              MT    Field   Offset                 Type VT     Attr            Value Name

0000064278435ed8  400018a        8        System.Object  0 instance 0000000000000000 __identity

0000064274b3d5b0  40008c3       10 ...ponentModel.ISite  0 instance 0000000000000000 site

0000064274b6cec8  40008c4       18 ....EventHandlerList  0 instance 0000000000000000 events

0000064278435ed8  40008c2      210        System.Object  0   static 0000000001ff9120 EventDisposed

000006427843d858  40016f2       b0         System.Int32  1 instance                1 ObjectID

00000642784365e8  40016f3       20        System.String  0 instance 0000000001ff3e90 _commandText

00000642b79ee2c0  40016f4       b4         System.Int32  1 instance                0 _commandType

000006427843d858  40016f5       b8         System.Int32  1 instance               10 _commandTimeout

00000642b79f0ab0  40016f6       bc         System.Int32  1 instance                3 _updatedRowSource

00000642784357b8  40016f7       d0       System.Boolean  1 instance                0 _designTimeInvisible

00000642b7a31e90  40016f8       28 ...ent.SqlDependency  0 instance 0000000000000000 _sqlDep

00000642784357b8  40016f9       d1       System.Boolean  1 instance                0 _inPrepare

000006427843d858  40016fa       c0         System.Int32  1 instance               -1 _prepareHandle

00000642784357b8  40016fb       d2       System.Boolean  1 instance                0 _hiddenPrepare

00000642b7a2fbe0  40016fc       30 ...rameterCollection  0 instance 0000000000000000 _parameters

.. truncated ..

 

So now naturally we’ll just dump out the value for the commandText variable:

 

0:000> !dumpobj 0000000001ff3e90

Name: System.String

MethodTable: 00000642784365e8

EEClass: 000006427803e4f0

Size: 76(0x4c) bytes

 (C:\WINDOWS\assembly\GAC_64\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)

String: waitfor delay '00:00:20';

Fields:

              MT    Field   Offset                 Type VT     Attr            Value Name

000006427843d858  4000096        8         System.Int32  1 instance               26 m_arrayLength

000006427843d858  4000097        c         System.Int32  1 instance               25 m_stringLength

0000064278438030  4000098       10          System.Char  1 instance               77 m_firstChar

.. truncated ..

 

This gives us the command that was executing when the application was throwing the exception.

In this case we have forcefully made the command to wait for 20 seconds. In your scenario you should take what you found here and

try to execute it from outside the application, for example from SQL Server Management Studio. If it runs slowly from there, we can rule out the client side as the cause of the error.

 

But as mentioned, this was just a very short introduction on how to find out what SqlCommand.CommandText was executing when getting a timeout.

For more info on SOS, have a look here:

 

".NET Framework Tools - SOS Debugging Extension (SOS.dll)"

http://msdn.microsoft.com/en-us/library/bb190764.aspx