Deadlock issue with multiple clients

Tim_Mayer · June 21, 2021, 7:04pm

Hi,

I created a fairly simple API, and when running locally (localhost), everything seems to work fine. However, when I started running it on a local VM, and then connected using the IP address of that VM (virtual ethernet adapter), the server ends up in a deadlock situation (reproduceable).

The result it the client starts reporting a timeout waiting for an API response, and when I examined the server I saw the following threads:

16884 Worker Thread
RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.CleanupTimerCallback
[Waiting on lock owned by Thread 12524, double-click or press enter to switch to thread]
[External Code]

12524 Worker Thread
RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.GetConnection
[Waiting on lock owned by Thread 16884, double-click or press enter to switch to thread]
[External Code]

I’ve attached the complete thread dump below, but I believe these are the two above are the important ones.

Other properties:

Need to restart the server to get it working again. Never recovers.
.NET Core 3.1
Remoting SDK for .NET 10.0.0.1495
Uses JsonMessage instead of binMessage
100 simultaneous clients each making multiple API calls.

One last observation is that an equivalent API is also implemented as an ASP.NET Core 3.1 API and it doesn’t seem to exhibit this same issue (actually ported the ASP.NET Core 31 API to RemObjects).

Have you ever seen this before?

Thanks,

Tim

RemObjects Thread Dump.txt (25.7 KB)

Tim_Mayer · June 21, 2021, 7:23pm

FWIW, I just tried using bin (BinMessage) instead of JSON (JsonMessage), and the result is the same.

mh · June 21, 2021, 7:31pm

very strange. theres quite a few threads waiting on these two ones that are deadlocked with each other. What surprises me that there’s no further callstacks. are you accidentally debugging Native instead of Managed? or can you try disabling “Just My Code” in the Debugger options?

Not Flagged		16884	4	Worker Thread	Worker Thread	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.CleanupTimerCallback
 	 	 	 	 	 	[Waiting on lock owned by Thread 12524, double-click or press enter to switch to thread]
 	 	 	 	 	 	[External Code]

Not Flagged		12524	6	Worker Thread	Worker Thread	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.GetConnection
 	 	 	 	 	 	[Waiting on lock owned by Thread 16884, double-click or press enter to switch to thread]
 	 	 	 	 	 	[External Code]

Tim_Mayer · June 21, 2021, 8:08pm

Thanks for the quick reply Marc.

I disabled “Just My Code” and it gives more detailed now (attached).

RemObjects Thread Dump - Details.txt (95.5 KB)

I also removed all significant code from this specific API method just as a test, and it didn’t make a difference. So effectively the API method is called with a single string parameter, which is ignored, and it returns a single string result. Almost all logic has been removed.

This is part of a test to see how my service handles a significant # of clients and API calls.

Tim

mh · June 21, 2021, 8:11pm

Not Flagged		5348	47	Worker Thread	Worker Thread	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.GetConnection
 	 	 	 	 	 	[Waiting on lock owned by Thread 16792, double-click or press enter to switch to thread]
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.GetConnection(System.Guid connectionId) Line 208
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.ProcessServiceRequest(RemObjects.SDK.Server.IServerChannelInfo context, RemObjects.SDK.Http.HttpHeaders request, RemObjects.SDK.Server.MessageDispatcher dispatcher, byte[] data, System.Net.Sockets.Socket socket) Line 530
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.ProcessRequest(RemObjects.SDK.Server.IServerChannelInfo context, RemObjects.SDK.Http.HttpHeaders requestHeaders, string path, byte[] data, System.Net.Sockets.Socket socket) Line 729
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.IpSuperHttpServerChannel.Server_OnHttpRequest(object sender, RemObjects.SDK.Server.AsyncHttpRequestEventArgs e) Line 186
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.AsyncHttpServerWorker.WantBodyCallback(System.IAsyncResult ar) Line 281
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.BeginRead(byte[] buffer, int offset, int count, System.AsyncCallback callback, object state) Line 1266
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.AsyncHttpServerWorker.HeaderLinesCallback(System.IAsyncResult ar) Line 186
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.BeginReadLine(System.AsyncCallback callback, object state) Line 1047
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.AsyncHttpServerWorker.HeaderFirstLineCallback(System.IAsyncResult ar) Line 110
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.IntReadLineCallback(System.IAsyncResult ar) Line 1185
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.LazyAsyncResult.Complete(System.IntPtr userToken)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.ContextAwareResult.CaptureOrComplete(ref System.Threading.ExecutionContext cachedContext, bool returnContext)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.ContextAwareResult.FinishPostingAsyncOp(ref System.Net.CallbackClosure closure)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.Sockets.Socket.BeginReceive(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags, out System.Net.Sockets.SocketError errorCode, System.AsyncCallback callback, object state)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.Sockets.Socket.BeginReceive(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags, System.AsyncCallback callback, object state)
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.IntBeginRead(byte[] buffer, int offset, int count, System.AsyncCallback callback, object state) Line 976
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.BeginReadLine(System.AsyncCallback callback, object state) Line 1062
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.AsyncHttpServerWorker.ResponseBodyCallback(System.IAsyncResult ar) Line 489
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.LazyAsyncResult.Complete(System.IntPtr userToken)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.ContextAwareResult.CaptureOrComplete(ref System.Threading.ExecutionContext cachedContext, bool returnContext)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.ContextAwareResult.FinishPostingAsyncOp(ref System.Net.CallbackClosure closure)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.Sockets.Socket.BeginSend(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags, out System.Net.Sockets.SocketError errorCode, System.AsyncCallback callback, object state)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.Sockets.Socket.BeginSend(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags, System.AsyncCallback callback, object state)
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.IntBeginWrite(byte[] buffer, int offset, int count, System.AsyncCallback callback, object state) Line 991
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.BeginWrite(byte[] buffer, int offset, int count, System.AsyncCallback callback, object state) Line 1375
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.AsyncHttpServerWorker.SendResponse() Line 394
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.AddWaitingRequest(RemObjects.SDK.Server.IServerChannelInfo context, RemObjects.SDK.Server.SuperHttpServerConnection connection) Line 883
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.ProcessServiceRequest(RemObjects.SDK.Server.IServerChannelInfo context, RemObjects.SDK.Http.HttpHeaders request, RemObjects.SDK.Server.MessageDispatcher dispatcher, byte[] data, System.Net.Sockets.Socket socket) Line 539
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.ProcessRequest(RemObjects.SDK.Server.IServerChannelInfo context, RemObjects.SDK.Http.HttpHeaders requestHeaders, string path, byte[] data, System.Net.Sockets.Socket socket) Line 729
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.IpSuperHttpServerChannel.Server_OnHttpRequest(object sender, RemObjects.SDK.Server.AsyncHttpRequestEventArgs e) Line 186
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.AsyncHttpServerWorker.WantBodyCallback(System.IAsyncResult ar) Line 281
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.BeginRead(byte[] buffer, int offset, int count, System.AsyncCallback callback, object state) Line 1266
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.AsyncHttpServerWorker.HeaderLinesCallback(System.IAsyncResult ar) Line 186
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.BeginReadLine(System.AsyncCallback callback, object state) Line 1047
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.AsyncHttpServerWorker.HeaderFirstLineCallback(System.IAsyncResult ar) Line 110
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.IntReadLineCallback(System.IAsyncResult ar) Line 1185
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.LazyAsyncResult.Complete(System.IntPtr userToken)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.ContextAwareResult.CaptureOrComplete(ref System.Threading.ExecutionContext cachedContext, bool returnContext)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.ContextAwareResult.FinishPostingAsyncOp(ref System.Net.CallbackClosure closure)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.Sockets.Socket.BeginReceive(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags, out System.Net.Sockets.SocketError errorCode, System.AsyncCallback callback, object state)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.Sockets.Socket.BeginReceive(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags, System.AsyncCallback callback, object state)
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.IntBeginRead(byte[] buffer, int offset, int count, System.AsyncCallback callback, object state) Line 976
 	 	 	 	 	 	RemObjects.SDK.dll!RemObjects.SDK.Connection.IntReadLineCallback(System.IAsyncResult ar) Line 1203
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.LazyAsyncResult.Complete(System.IntPtr userToken)
 	 	 	 	 	 	System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.ContextAwareResult.Complete(System.IntPtr userToken)
 	 	 	 	 	 	System.Net.Sockets.dll!System.Net.Sockets.BaseOverlappedAsyncResult.CompletionPortCallback(uint errorCode, uint numBytes, System.Threading.NativeOverlapped* nativeOverlapped)
 	 	 	 	 	 	System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state)
 	 	 	 	 	 	System.Private.CoreLib.dll!System.Threading._IOCompletionCallback.PerformIOCompletionCallback(uint errorCode, uint numBytes, System.Threading.NativeOverlapped* pNativeOverlapped)

and

Not Flagged		16792	5	Worker Thread	Worker Thread	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.CleanupTimerCallback
 	 	 	 	 	 	[Waiting on lock owned by Thread 5348, double-click or press enter to switch to thread]
 	 	 	 	 	 	RemObjects.SDK.Server.dll!RemObjects.SDK.Server.SuperHttpServerChannel.CleanupTimerCallback(object state) Line 120
 	 	 	 	 	 	System.Private.CoreLib.dll!System.Threading.TimerQueueTimer..cctor.AnonymousMethod__23_0(object state)
 	 	 	 	 	 	System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state)
 	 	 	 	 	 	System.Private.CoreLib.dll!System.Threading.TimerQueueTimer.CallCallback(bool isThreadPool)
 	 	 	 	 	 	System.Private.CoreLib.dll!System.Threading.TimerQueueTimer.Fire(bool isThreadPool)
 	 	 	 	 	 	System.Private.CoreLib.dll!System.Threading.TimerQueue.FireNextTimers()
 	 	 	 	 	 	System.Private.CoreLib.dll!System.Threading.TimerQueue.AppDomainTimerCallback(int id)

curious. I’ll have to ;eave that form my colleague tomorrow, as I’m not familiar with what SuperHttpServerChannel.CleanupTimerCallback does, but the does indeed sound like a bug.

Tim_Mayer · June 21, 2021, 8:18pm

Thanks Marc.

RemObjectsSoftware · June 21, 2021, 8:21pm

Logged as bugs://D19097.

mohamedkoker · June 22, 2021, 12:59am

Hi Marc,

I have uploaded the server and client projects Tim is using to the following link since this might help Anton in reproducing/resolving this issue:

https://personal.filesanywhere.com/fs/v.aspx?v=8e6b6b885c5e75b0af67

Regards

-Mohamed

mh · June 22, 2021, 1:01am

Thanks!

antonk · June 22, 2021, 7:34am

Thanks for the testcase. Reproduced it.
I’ll give it the highest priority possible.
It is the internal SuperHTTP Garbage Collector that locks up.

It will some time to resolve this issue (multithreading-related issues and race conditions are quite hard to debug)

RemObjectsSoftware · July 6, 2021, 2:51pm

bugs://D19097 was closed as fixed.

mohamedkoker · July 8, 2021, 1:16pm

Hi Anton,

I understand from Tim that this issue has been resolved.

Would it be possible to obtain a Nuget package that contains this fix?

Regards

-Mohamed

antonk · July 8, 2021, 1:21pm

Hello

Sure. I have sent them already (one of the last messages in the thread “RemObjects SDK cyber-security”)

If needed please send a mail to support and I’ll resend these packages

Regards

mohamedkoker · July 8, 2021, 1:35pm

Hi Anton,

Are you saying the Nuget package you sent me earlier already contains this fix?

Regards

-Mohamed

antonk · July 8, 2021, 1:49pm

Yes.

Message 2 days ago:
…
These packages contain the deadlock issue fix: REDACTED
I have run like 4,000,000 requests in 200 threads (your testcase, run the “200 threads x 200 requests” test 100 times in a loop) without deadlocks.
…

Anyway, just drop a mail to support@ and I’ll resend it.

mohamedkoker · July 8, 2021, 2:31pm

Thanks Anton,

Can you please confirm that build 10.0.0.1510 contains this fix?

Regards

-Mohamed

antonk · July 8, 2021, 2:49pm

Unfortunately 10.0.0.1510 is a family of interim builds between releases. So only the latest of .1510 builds contain this fix.

mohamedkoker · July 8, 2021, 3:02pm

Hi Anton,

In that case, I would be grateful if you can send me a new package.

Regards

-Mohamed

mh · July 8, 2021, 6:46pm

I believe the now public build .1511 should have this fix, as well. FTR.

mohamedkoker · July 8, 2021, 7:04pm

Thanks Marc!