SQLServer Transport QueuePeeker stops after timeout exception

[Steve James]

Hi, I am running some tests with a message handler that calls a stored procedure that could potentially take a considerable amount of time to execute, therefore the sp is set to take over 5 mins.

I sometimes get an exception where the QueuePeeker has a timeout exception, this seems to occur around 30 seconds after the message handler is invoked.

It doesn't seem to recover from this and so no further messages are read from the queue table until I restart my endpoint.

Stack Trace:

2016-05-24 13:16:18.6841 Failed to peek TestEndpoint2@[dbo] System.Data.SqlClient.SqlException (0x80131904): Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out

   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)

   at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)

   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)

   at System.Data.SqlClient.SqlCommand.InternalEndExecuteReader(IAsyncResult asyncResult, String endMethod)

   at System.Data.SqlClient.SqlCommand.EndExecuteReaderInternal(IAsyncResult asyncResult)

   at System.Data.SqlClient.SqlCommand.EndExecuteReaderAsync(IAsyncResult asyncResult)

   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)

--- End of stack trace from previous location where exception was thrown ---

   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()

   at NServiceBus.Transports.SQLServer.TableBasedQueue.<TryPeek>d__3.MoveNext() in C:\Build\src\NServiceBus.SqlServer\Queuing\TableBasedQueue.cs:line 26

--- End of stack trace from previous location where exception was thrown ---

   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()

   at NServiceBus.Transports.SQLServer.QueuePeeker.<Peek>d__1.MoveNext() in C:\Build\src\NServiceBus.SqlServer\Receiving\QueuePeeker.cs:line 23

ClientConnectionId:1edc62b8-acfb-47ef-b4d6-03243af70e3c

Error Number:-2,State:0,Class:11

Product name: NServiceBus 6.0.0 beta 0002, NServiceBus.SqlServer 3.0.0 beta 00002

[ramon...@particular.net]

Hi Steve,

How are you hosting the endpoint? Are you self hosting the endpoint instance?

Are there more log statements that this which mention errors?

if you are self-hosting then the instance can stop processing messages when it internally activates a circuit breaker.

http://docs.particular.net/nservicebus/hosting/critical-errors#raising-critical-error

Please watch the log for related errors and implement this callback. In the callback you can terminate the process to that your process can be restarted.

Let me know if this is what is happening.

Regards,

Ramon

[tomasz.m...@particular.net]

Hi Steve,

I was able to reproduce the problem with NServiceBus.SqlServer 3.0.0-beta0003. I've discovered a bug in the input queue peeking logic (see: https://github.com/Particular/NServiceBus.SqlServer/issues/248) that we will fix. I'll let you know once it's released on Nuget.

Additionally when dealing with long running handlers please make sure that transaction timeout is set to large enough value. Here is documentation page that describes relevant api calls.

Please let me know if you have any further questions.

Regards,

Tomasz

On Tuesday, May 24, 2016 at 2:31:34 PM UTC+2, Steve James wrote:

[Steve James]

Thanks Tomasz