5

I have a strange problem. A process gets frozen/stuck while reading data using System.Data.SqlClient.SqlDataReader on GetValue() function. I am analyzing the process dump using WinDbg. I used SOS commands like !dlk, !SyncBlk, !analyze -v -hang etc. but none of them indicate any deadlocks.

The last call on callstack is 

000000001a98e8a8 0000000076febd7a [InlinedCallFrame: 000000001a98e8a8] .**SNIReadSyncOverAsync**(SNI_ConnWrapper*, SNI_Packet**, Int32)
000000001a98e8a8 000007fee9e8bca1 [InlinedCallFrame: 000000001a98e8a8] .SNIReadSyncOverAsync(SNI_ConnWrapper*, SNI_Packet**, Int32)
000000001a98e880 000007fee9e8bca1 DomainBoundILStubClass.IL_STUB_PInvoke(SNI_ConnWrapper*, SNI_Packet**, Int32)
000000001a98e950 000007fee9e7254f SNINativeMethodWrapper.SNIReadSyncOverAsync(System.Runtime.InteropServices.SafeHandle, IntPtr ByRef, Int32)
000000001a98e9c0 000007fee9e7226e System.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()
000000001a98ea70 000007fee9e72180 System.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()
000000001a98eab0 000007fee9e72950 System.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()
000000001a98eae0 000007fee9e728d8 System.Data.SqlClient.TdsParserStateObject.TryReadByteArray(Byte[], Int32, Int32, Int32 ByRef)
000000001a98eb50 000007feea4c0adc System.Data.SqlClient.TdsParser.TryReadSqlValue(System.Data.SqlClient.SqlBuffer, System.Data.SqlClient.SqlMetaDataPriv, Int32, System.Data.SqlClient.TdsParserStateObject)
000000001a98ec10 000007fee9e85cb5 System.Data.SqlClient.SqlDataReader.TryReadColumnInternal(Int32, Boolean)
000000001a98ecb0 000007fee9e85af0 System.Data.SqlClient.SqlDataReader.TryReadColumn(Int32, Boolean, Boolean)
000000001a98ed20 000007fee9e85a0b System.Data.SqlClient.SqlDataReader.GetValueInternal(Int32)
000000001a98ed60 000007fee9e859b7 System.Data.SqlClient.SqlDataReader.GetValue(Int32)

What are other avenues for further debugging here? Did someone face the same issue with SqlDataReader?

I recently found out when this kind of stack trace is found, there is always a Win32 error in dump like this.

0:009> !gle LastErrorValue: (Win32) 0x3e5 (997) - Overlapped I/O operation is in progress. LastStatusValue: (NTSTATUS) 0xc0000034 - Object Name not found.

Does this mean it is blocked due to some underlying IO operation?

murtazat
  • 399
  • 3
  • 12
  • It seems to read a byte[]. How many bytes do you expect? – Thomas Weller May 11 '17 at 11:17
  • 1
    !dlk supports only a small subset of sychronization objects. I would try analyzing the dump with DebugDiag – Thomas Weller May 11 '17 at 16:58
  • @ThomasWeller, am not sure the exact number of bytes. Basically, it is reading a single column value. I am a newbie to windbg so cannot exactly tell which particular column index it is in stack. I think this line System.Data.SqlClient.SqlDataReader.GetValue(Int32) gets column index as parameter but I am not suer how to retieve that parameter and get the value at address. – murtazat May 11 '17 at 21:49
  • Perhaps `!clrstack -a` can help for the parameter. – Thomas Weller May 11 '17 at 21:56
  • I tried that but did not get parameter details. I read in this post (https://blogs.msdn.microsoft.com/dau-blog/2012/01/13/how-to-read-managed-function-parameter-values-from-call-stack-when-they-read-no-data-in-windbg/) that parameter details are removed in release DLLs (something to do with JIT optimizaton). I have a post mortem dump from production. – murtazat May 11 '17 at 22:20
  • 0:009> !gle **LastErrorValue: (Win32) 0x3e5 (997) - Overlapped I/O operation is in progress.** LastStatusValue: (NTSTATUS) 0xc0000034 - Object Name not found. – murtazat May 18 '17 at 21:52
  • I think you'd have a stack like this when the client is waiting for SQL Server to send more data. If you perform the exact same query in SSMS, does it take a long time between result sets or perhaps is SQL Server itself waiting for locks? These won't show up as locks in the client application. Also, the win32 error suggests that the `SNIReadSyncOverAsync()` might be doing a busy poll loop instead of using a blocking `read()` or wait handle. – binki Jan 06 '18 at 05:53
  • I see pretty much same issue when calling ExecuteNonQuery method for SQLCommand. It executes a simple UPDATE query (nothing complicated). The issue is not constantly reproducible, it happened for some users and I was lucky to get the issue in Debug mode and find dump files, which shows very similar stack trace to this. We are using .NET Framework 4.6.1. – Chuck Norris Oct 16 '20 at 16:43
  • P.S. Also can see this LastErrorValue somewhere in dump file, but LastStatusValue is different. Not sure if it's related to the SQL call which hungs the process... – Chuck Norris Oct 16 '20 at 16:44
  • Similar questions 1. https://stackoverflow.com/questions/45987876/sqldatareader-getvalue-hangs 2. https://stackoverflow.com/questions/12109869/ado-net-sqlcommand-executereader-slows-down-or-hangs 3. https://stackoverflow.com/questions/42016075/sqldatareader-hangs-on-getvalue-method-and-snireadsyncoverasync – Chuck Norris Oct 16 '20 at 16:48
  • One more note - we set CommandTimeout = 0, so it just hungs, no timeouts (it can happen like once a week, therefore it's not an issue which happens constantly). – Chuck Norris Oct 16 '20 at 16:59
  • Does it deadlock or is it just slow? What does the SQL Server query profiler (part of SSMS SQL Server Management Studio) tell you? Has SQL Server high disk/CPU when your query has become stuck? – Alois Kraus Oct 21 '20 at 21:21

0 Answers0