Hello,
I have a situation that occurs at some user’s locations more often than at others in which the server suddenly stops replying to any clients, thus leading to timeout exceptions.
Here are the existing threads call stacks, as reported by madExcept:
exception class : EROSuperHTTPChannelException
exception message : Timeout.
thread $3d90 (THealthMonitorThread):
01074f39 +121 ASMServer.exe uROBaseSuperHttpChannel 513 +13 TROBaseSuperHTTPChannel.IntDispatch
00e3e199 +195 ASMServer.exe uROTransportChannel 530 +36 TROTransportChannel.Dispatch
00e3eb93 +12f ASMServer.exe uROTransportChannel 854 +31 TROTransportChannel.Dispatch
00ecf895 +085 ASMServer.exe AAW.ROService_Intf 1173 +8 TAAWSessionManagerService_Proxy.StartSession
0118ccdd +14d ASMServer.exe fServerDataModule 377 +23 TServerDataModule.ReloadNetworkParameters$ActRec.$0$Body
00efe044 +0e4 ASMServer.exe AAW.ROService.Utils 152 +20 THealthMonitorThread.Execute
00efe1fe +29e ASMServer.exe AAW.ROService.Utils 194 +62 THealthMonitorThread.Execute
00efe242 +2e2 ASMServer.exe AAW.ROService.Utils 196 +64 THealthMonitorThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by main thread ($4808) at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
main thread ($4808):
00d29e9d +149 ASMServer.exe Vcl.Forms TApplication.Idle
00d28e6f +017 ASMServer.exe Vcl.Forms TApplication.HandleMessage
00d37ce8 +180 ASMServer.exe Vcl.SvcMgr TServiceApplication.Run
00d37d7c +214 ASMServer.exe Vcl.SvcMgr TServiceApplication.Run
00d37da9 +241 ASMServer.exe Vcl.SvcMgr TServiceApplication.Run
00d387cb +007 ASMServer.exe uROComboService 264 +0 TROService.Run
01301be2 +0ca ASMServer.exe ASMServer 70 +7 initialization
01301c4c +134 ASMServer.exe ASMServer 78 +15 initialization
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
thread $88 (TSystemLevelRefresherThread):
76bfc94d +12d KERNELBASE.dll WaitForMultipleObjectsEx
00b7045d +019 ASMServer.exe madExcept InterceptClassDestroy
00c55663 +023 ASMServer.exe System.Win.Registry TRegistry.Destroy
00abaf1c +008 ASMServer.exe System 268 +0 TObject.Free
00ddd077 +357 ASMServer.exe uCoreTools 428 +57 LoadRegistryKeyX
00ddd973 +08b ASMServer.exe uCoreTools 558 +3 LoadRegistryKeyHKCUFailOver
00c72d76 +056 ASMServer.exe System.SyncObjs THandleObject.WaitFor
00efd3eb +037 ASMServer.exe LogUtils 335 +4 TSystemLevelRefresherThread.Execute
00efd42a +076 ASMServer.exe LogUtils 339 +8 TSystemLevelRefresherThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by main thread ($4808) at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
thread $3700 (TASMEnvironmentsCleanerThread):
76bfc94d +12d KERNELBASE.dll WaitForMultipleObjectsEx
00c72d76 +056 ASMServer.exe System.SyncObjs THandleObject.WaitFor
0112ff1b +02b ASMServer.exe EnvironmentClasses 779 +4 TASMEnvironmentsCleanerThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by main thread ($4808) at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
thread $3670 (TASMConfig.TSerialChangeCheckerThread):
76c00325 +45 KERNELBASE.dll SleepEx
76c002ca +0a KERNELBASE.dll Sleep
00c031b1 +01 ASMServer.exe System.Classes TThread.Sleep
0117159c +2c ASMServer.exe ConfigClasses 594 +12 TASMConfig.TSerialChangeCheckerThread.Execute
00b707a3 +2b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +96 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +49 ASMServer.exe System.Classes ThreadProc
00c022c0 +ac ASMServer.exe System.Classes ThreadProc
00abccac +28 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +0d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +32 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +17 KERNEL32.DLL BaseThreadInitThunk
>> created by main thread ($4808) at:
00c02324 +18 ASMServer.exe System.Classes TThread.Create
thread $3fc (TASMLicenseActiveUsersCleanerThread):
76c00325 +045 KERNELBASE.dll SleepEx
0116139b +4f3 ASMServer.exe CompanyClasses 1193 +43 TASMLicenseActiveUsersCleanerThread.Execute
011613cd +525 ASMServer.exe CompanyClasses 1196 +46 TASMLicenseActiveUsersCleanerThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by main thread ($4808) at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
thread $d74 (TROThreadTimer):
76bfc94d +12d KERNELBASE.dll WaitForMultipleObjectsEx
00ac2370 +010 ASMServer.exe System 268 +0 @IntfClear
00b7045d +019 ASMServer.exe madExcept InterceptClassDestroy
0100a083 +077 ASMServer.exe uROBaseSuperHttpServer 42 +0 {System.Generics.Collections}TThreadList<uROBaseSuperHttpServer.TROSuperHTTPWaitingConnection>.Destroy
00abaf1c +008 ASMServer.exe System 268 +0 TObject.Free
01004eb1 +089 ASMServer.exe uROBaseSuperHttpServer 303 +12 TROSuperHTTPServerConnection.DisposeData
00b7045d +019 ASMServer.exe madExcept InterceptClassDestroy
01004f48 +02c ASMServer.exe uROBaseSuperHttpServer 320 +4 TROSuperHTTPServerConnection.Destroy
00ac37c5 +039 ASMServer.exe System 268 +0 TInterfacedObject._Release
00ac2370 +010 ASMServer.exe System 268 +0 @IntfClear
010075aa +1be ASMServer.exe uROBaseSuperHttpServer 1014 +39 TROBaseSuperHTTPServer.cbCleanup
00c72d76 +056 ASMServer.exe System.SyncObjs THandleObject.WaitFor
00e39df7 +027 ASMServer.exe uROThreadTimer 117 +4 TROThreadTimer.IntExecute
00e3740f +07f ASMServer.exe uROInitializedThread 58 +7 TROInitializedThread.Execute
00e3742e +09e ASMServer.exe uROInitializedThread 61 +10 TROInitializedThread.Execute
00e37452 +0c2 ASMServer.exe uROInitializedThread 64 +13 TROInitializedThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by main thread ($4808) at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
thread $4228 (TIPSocketWorkerThread):
777b546c +0bc ws2_32.dll select
0100ff12 +25a ASMServer.exe uIPAsyncSocket 965 +50 TIPSocketWorkerThread.IntExecute
00e3740f +07f ASMServer.exe uROInitializedThread 58 +7 TROInitializedThread.Execute
00e3742e +09e ASMServer.exe uROInitializedThread 61 +10 TROInitializedThread.Execute
00e37452 +0c2 ASMServer.exe uROInitializedThread 64 +13 TROInitializedThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by main thread ($4808) at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
thread $340c (TServiceStartThread):
76bfa383 +93 KERNELBASE.dll WaitForSingleObjectEx
76bfa2dd +0d KERNELBASE.dll WaitForSingleObject
75e24091 +61 sechost.dll StartServiceCtrlDispatcherW
00d37b4b +07 ASMServer.exe Vcl.SvcMgr TServiceStartThread.Execute
00b707a3 +2b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +96 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +49 ASMServer.exe System.Classes ThreadProc
00c022c0 +ac ASMServer.exe System.Classes ThreadProc
00abccac +28 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +0d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +32 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +17 KERNEL32.DLL BaseThreadInitThunk
>> created by main thread ($4808) at:
00c02324 +18 ASMServer.exe System.Classes TThread.Create
thread $55d8:
76bfa383 +093 KERNELBASE.dll WaitForSingleObjectEx
76bfa2dd +00d KERNELBASE.dll WaitForSingleObject
00c03324 +09c ASMServer.exe System.Classes TThread.WaitFor
00d36def +077 ASMServer.exe Vcl.SvcMgr TService.DoStart
00d36e28 +0b0 ASMServer.exe Vcl.SvcMgr TService.DoStart
00d36ece +156 ASMServer.exe Vcl.SvcMgr TService.DoStart
00d36d1d +095 ASMServer.exe Vcl.SvcMgr TService.Main
00d37233 +083 ASMServer.exe Vcl.SvcMgr TServiceApplication.DispatchServiceMain
00d3703a +00e ASMServer.exe Vcl.SvcMgr ServiceMain
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by thread $340c (TServiceStartThread) at:
75e2ac92 +000 sechost.dll
thread $9f4 (TServiceThread):
753d424a +02a USER32.dll GetMessageW
00d364f0 +048 ASMServer.exe Vcl.SvcMgr TServiceThread.ProcessRequests
00d36369 +0f1 ASMServer.exe Vcl.SvcMgr TServiceThread.Execute
00d36495 +21d ASMServer.exe Vcl.SvcMgr TServiceThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by thread $55d8 at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
thread $427c (TROPooledThread):
76bfc94d +12d KERNELBASE.dll WaitForMultipleObjectsEx
0100e9bd +0d9 ASMServer.exe uIPAsyncSocket 465 +16 TIPBaseAsyncSocket.BeginSend
00ac2370 +010 ASMServer.exe System 268 +0 @IntfClear
00abed34 +174 ASMServer.exe System 268 +0 @FinalizeRecord
00ac2370 +010 ASMServer.exe System 268 +0 @IntfClear
010066ad +1f5 ASMServer.exe uROBaseSuperHttpServer 648 +32 TQueueItem.SuperHttpCallback
00c72d76 +056 ASMServer.exe System.SyncObjs THandleObject.WaitFor
010000f2 +03a ASMServer.exe uROThreadPool 136 +5 TROPooledThread.IntExecute
01000213 +15b ASMServer.exe uROThreadPool 164 +33 TROPooledThread.IntExecute
00e3740f +07f ASMServer.exe uROInitializedThread 58 +7 TROInitializedThread.Execute
00e3742e +09e ASMServer.exe uROInitializedThread 61 +10 TROInitializedThread.Execute
00e37452 +0c2 ASMServer.exe uROInitializedThread 64 +13 TROInitializedThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by thread $4228 (TIPSocketWorkerThread) at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
thread $3be0 (TROThreadTimer):
76bfc94d +12d KERNELBASE.dll WaitForMultipleObjectsEx
00ebc3bf +02b ASMServer.exe uROSessions 1025 +1 TROCustomSessionManager.DoNotifySessionsChangesListener
00ebbc28 +11c ASMServer.exe uROSessions 818 +22 TROCustomSessionManager.DeleteSession
00ebc7e1 +061 ASMServer.exe uROSessions 1220 +3 TROInMemorySessionManager.DoClearSessions
00ebb76b +093 ASMServer.exe uROSessions 713 +10 TROCustomSessionManager.ClearSessions
00c72d76 +056 ASMServer.exe System.SyncObjs THandleObject.WaitFor
00e39df7 +027 ASMServer.exe uROThreadTimer 117 +4 TROThreadTimer.IntExecute
00e3740f +07f ASMServer.exe uROInitializedThread 58 +7 TROInitializedThread.Execute
00e3742e +09e ASMServer.exe uROInitializedThread 61 +10 TROInitializedThread.Execute
00e37452 +0c2 ASMServer.exe uROInitializedThread 64 +13 TROInitializedThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by thread $427c (TROPooledThread) at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
thread $3a20 (TROPooledThread):
76bfc94d +12d KERNELBASE.dll WaitForMultipleObjectsEx
00ac2370 +010 ASMServer.exe System 268 +0 @IntfClear
010066ad +1f5 ASMServer.exe uROBaseSuperHttpServer 648 +32 TQueueItem.SuperHttpCallback
00c72d76 +056 ASMServer.exe System.SyncObjs THandleObject.WaitFor
010000f2 +03a ASMServer.exe uROThreadPool 136 +5 TROPooledThread.IntExecute
01000213 +15b ASMServer.exe uROThreadPool 164 +33 TROPooledThread.IntExecute
00e3740f +07f ASMServer.exe uROInitializedThread 58 +7 TROInitializedThread.Execute
00e3742e +09e ASMServer.exe uROInitializedThread 61 +10 TROInitializedThread.Execute
00e37452 +0c2 ASMServer.exe uROInitializedThread 64 +13 TROInitializedThread.Execute
00b707a3 +02b ASMServer.exe madExcept HookedTThreadExecute
00b7080e +096 ASMServer.exe madExcept HookedTThreadExecute
00c0225d +049 ASMServer.exe System.Classes ThreadProc
00c022c0 +0ac ASMServer.exe System.Classes ThreadProc
00abccac +028 ASMServer.exe System 268 +0 ThreadWrapper
00b70689 +00d ASMServer.exe madExcept CallThreadProcSafe
00b706ee +032 ASMServer.exe madExcept ThreadExceptFrame
00b70764 +0a8 ASMServer.exe madExcept ThreadExceptFrame
773d05c7 +017 KERNEL32.DLL BaseThreadInitThunk
>> created by thread $4228 (TIPSocketWorkerThread) at:
00c02324 +018 ASMServer.exe System.Classes TThread.Create
thread $12c8:
773d05c7 +17 KERNEL32.DLL BaseThreadInitThunk
thread $51b0:
773d05c7 +17 KERNEL32.DLL BaseThreadInitThunk
The THealthMonitorThread is a thread internal to the server itself that behaves like a client, basically doing a healthcheck on a regular basis.
When it times out as in the trace above, no other real clients from remote computers can communicate either.
An analysis of the call stacks leads me to believe there is a deadlock between two threads inside the server, which might be induced by my users’ “security suites” that introduce some artificial delay in the way sockets are dealt with.
I must admit this is very speculative and so would like your opinion on what I believe is a case of “lock A, wait for lock B” while another thread has done “lock B, wait for lock A” happening because of this sequence:
- A pool thread finishes
DispatchMessage(StartSession/GetVersionalready ran) and entersSendAsyncResponse. It locksWaitingConnectionsand callsSendResponse/BeginSend. BeginSendwaits onfMyCs, or the send otherwise does not complete quickly (security suite impact most likely).- The 30 s cleanup timer fires, takes
fConnections, then triesWaitingConnections.LockListon the same connection → blocks. - From this point every
GetConnectionblocks onfConnections. External clients hang. The health probe’sIntDispatchwaitsRequestTimeout(60 s) and raisesTimeout. - Incoming TCP accepts still succeed (
selectis still running); the HTTP request is read; SuperHTTP then stalls inGetConnection. Clients see a connected socket that never answers.
This seems to fit with the above dump:
| Thread | Stack | Meaning |
|---|---|---|
$3d90 THealthMonitorThread |
IntDispatch +13 |
Client waited 60 s for the wait-socket reply |
$427c TROPooledThread |
SuperHttpCallback +32 → BeginSend |
Server already dispatched the RPC; stuck sending the reply |
$3a20 TROPooledThread |
SuperHttpCallback +32 |
Second worker in the same send path |
$d74 TROThreadTimer |
cbCleanup → DisposeData → TThreadList.Destroy → connection Destroy / _Release |
Cleanup tearing down wait sockets (and dropping the last interface ref) while the global lock is held |
$3be0 TROThreadTimer |
ClearSessions → DeleteSession → DoNotifySessionsChangesListener |
Session teardown notifying SuperHTTP listeners; created by $427c |
$4228 TIPSocketWorkerThread |
select |
Accept loop not dead |
To avoid this deadlock, I suggest to modify SendAsyncResponse, DisposeData and cbCleanup so that they identify the items to work on while in the locked section, but work on those items outisde the locked section itself while ensuring no other thread can use those identified items.
The following zip contains suggested diffs:
ro superserver deadlock.zip (3.1 KB)
Once again, I must insist that this is all very speculative, based on observations at users’ locations which makes it hard for me to assess the validity of the suggested fixes.
It would thus be nice if you could give me your honest opinion on this, and maybe try the fix on your entire test suite to see if it doesn’t break anything.
Regards
Olivier