I would really appreciate any suggestions, no matter how simple or complex, to help me get this issue isolated and resolved.
I have a bit of code that generates small report files. For each file in the collection, a stored proc is executed to get the data via XML reader (its a pretty big result set). When I created all this, and stepped through it, all is well. Files are generated, no errors.
This library is called via remoting, and is hosted via IIS. When I deploy the compiled library and call it, its able to generate some of the reports, but then throws a Thread Abort Exception. If I attach the debugger to the asp worker process, and step through the code, I have no problems.
Seeing as this failure is pretty consistent, I looked for similarities and found that the failure happens on different reports, but seems to happen at about the same chronological point.
This lead me to think that it was a timeout setting that the debugger is overriding, I did some rough timings of the overall process (not the single piece of failing code) and it seems to fail at just after about 200 seconds. The web.config executionTimeout is set for 600 minutes (plenty high enough). There are other parts to this server application that require COM+ transactions (2 minute timeout), but this is not one of them. I am at a loss as to what timeout it could be hitting (at about the 200 second mark).
The SQL Connection timeout is left at default (the connection opens successfully), the command timeout is 300 seconds (it takes only 12-15 to exec the command).
I ran SQL profiler, and it shows that the result is returned correctly (all statements and RPC completed - no errors). Executing the code via SSMS provides perfect results.
Using reflector, I drilled into the SNINativeMethodWrapper, and its a wrapper for unmanaged code and I cant see what its trying to actually do. I can only assume (perhaps wrongly) that the code has received the TDS from the SQL server and the wrapper is trying to get the connection associated with the packet and it cannot.
I tried using different methods (ExecScalar, DataAdapter), but they all use ExecuteReader internally.
I tried disabling connection pooling and forcing the client to use the same packet size as the server.
Private Function GetDataAsXmlDoc(ByVal cmd As SqlClient.SqlCommand) As XmlDocument
Dim _xmlDoc As XmlDocument
Using _connection As New SqlClient.SqlConnection(GetConnectionString())
Logging.DebugEvent.Raise(Me.GetType.Namespace, Reflection.MethodBase.GetCurrentMethod().Name, _
"No cached data found or used. Getting data for report from the database using SQL connection.")
Dim _xmlReader As XmlReader
'DataAdapter,ExecuteScalar, ExecuteXmlReader all use ExecuteReader internally and suffer the same problem.'
'If you dont believe me, reflect it or look at one of the blowed up stack traces. '
'_connection.ConnectionString += ";Pooling=false;"' 'This has no effect on the ThreadAbort.'
cmd.Connection = _connection
cmd.CommandTimeout = 300
_connection.Open()
Logging.DebugEvent.Log(String.Format("Connection opened, using packet size of {0}.", _connection.PacketSize))
_xmlReader = cmd.ExecuteXmlReader() 'Thread aborts in here'
Logging.DebugEvent.Raise(Me.GetType.Namespace, Reflection.MethodBase.GetCurrentMethod().Name, _
"Report data recieved from database")
_xmlDoc = New XmlDocument()
_xmlDoc.Load(_xmlReader)
_xmlReader.Close()
End Using
Return _xmlDoc
End Function
Exception String - System.Threading.ThreadAbortException: Thread was being aborted.
at SNINativeMethodWrapper.SNIPacketGetConnection(IntPtr packet)
at System.Data.SqlClient.TdsParserStateObject.ProcessSniPacket(IntPtr packet, UInt32 error)
at System.Data.SqlClient.TdsParserStateObject.ReadSni(DbAsyncResult asyncResult, TdsParserStateObject stateObj)
at System.Data.SqlClient.TdsParserStateObject.ReadNetworkPacket()
at System.Data.SqlClient.TdsParserStateObject.ReadBuffer()
at System.Data.SqlClient.TdsParserStateObject.ReadByte()
at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at System.Data.SqlClient.SqlDataReader.ConsumeMetaData()
at System.Data.SqlClient.SqlDataReader.get_MetaData()
at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
at System.Data.SqlClient.SqlCommand.ExecuteXmlReader()...
I believe I have resolved the problem. The offending line of code in the example above was the statement...
Logging.DebugEvent.Raise(Me.GetType.Namespace, Reflection.MethodBase.GetCurrentMethod().Name, _
"Report data recieved from database")
This is a call to a Application Block (MS enterprise library) for logging events to flat files (in this case) or event logs.
This one, in between the ExecuteXMLReader() and the actual usage of the reader in the XML document, was sometimes failing harshly, causing the whole thread to abort. I moved the line to after the _xmlReader.Close()
and it took care of the problem.