I have a problem with an XDataserver I can't explain. When I send a lot of changes to the database from a client using the XData REST server it sometimes happens that the server produces this error:
Status code: 500 Error Code: TObjectPool<XData.Aurelius.ConnectionPool.TDBConnectionWrapper>.EPoolAcquireException Cannot retrieve object from object pool
There seems to be no obvious reason for this problem in the code, and the data that is being sent is ok. Can you think of any reason this error is being triggered?
Sometimes, but not always, the server has an error too. Unfortunately the exception just says 'Unknown'. I'll include the server callstack from MadExcept:
main thread ($1e4c):
00f19d4e +03e LicentiebeheerServer_GUI.exe XData.Aurelius.ConnectionPool 128 +2 {Sparkle.Sys.ObjectPool}TObjectPool<XData.Aurelius.ConnectionPool.TDBConnectionWrapper>.Acquire
7fbac211 +020 user32.dll GetMessageW
004f2437 +3f7 LicentiebeheerServer_GUI.exe madExcept HandleException
004fe704 +074 LicentiebeheerServer_GUI.exe madExcept InterceptAHandleExcept
006e866f +04f LicentiebeheerServer_GUI.exe Vcl.ExtCtrls 3069 +6 TTimer.WndProc
005d9903 +023 LicentiebeheerServer_GUI.exe System.Classes 17196 +8 StdWndProc
7fbac211 +000 user32.dll DispatchMessageW
007986bf +12f LicentiebeheerServer_GUI.exe Vcl.Forms 10534 +23 TApplication.ProcessMessage
00798733 +013 LicentiebeheerServer_GUI.exe Vcl.Forms 10564 +1 TApplication.HandleMessage
00798b9f +0ef LicentiebeheerServer_GUI.exe Vcl.Forms 10702 +26 TApplication.Run
0132ab0d +0bd LicentiebeheerServer_GUI.exe LicentiebeheerServer_GUI 49 +8 initialization
7fbaaac1 +018 KERNEL32.DLL BaseThreadInitThunk
7fbae09e +01f ntdll.dll RtlUserThreadStart
thread $1e84:
00f0e955 +85 LicentiebeheerServer_GUI.exe Sparkle.HttpSys.Session 97 +7 THttpSysSession.GetContext
00f12e1f +7f LicentiebeheerServer_GUI.exe Sparkle.HttpSys.Server 165 +9 TCustomHttpSysServer.InternalStart$6$ActRec.$0$Body
005d139f +0f LicentiebeheerServer_GUI.exe System.Classes 14489 +1 TAnonymousThread.Execute
004ff234 +24 LicentiebeheerServer_GUI.exe madExcept HookedTThreadExecute
005d3730 +40 LicentiebeheerServer_GUI.exe System.Classes 14693 +18 ThreadProc
004123c8 +38 LicentiebeheerServer_GUI.exe System 23773 +6 ThreadWrapper
004ff109 +49 LicentiebeheerServer_GUI.exe madExcept ThreadExceptFrame
7fbaaac1 +18 KERNEL32.DLL BaseThreadInitThunk
7fbae09e +1f ntdll.dll RtlUserThreadStart
thread $1ff4:
7fbaaac1 +18 KERNEL32.DLL BaseThreadInitThunk
7fbae09e +1f ntdll.dll RtlUserThreadStart
thread $b7c:
7fbaa021 +000 KERNELBASE.dll WaitForMultipleObjectsEx
0066c922 +082 LicentiebeheerServer_GUI.exe System.SyncObjs 729 +13 THandleObject.WaitFor
00f19d36 +026 LicentiebeheerServer_GUI.exe XData.Aurelius.ConnectionPool 127 +1 {Sparkle.Sys.ObjectPool}TObjectPool<XData.Aurelius.ConnectionPool.TDBConnectionWrapper>.Acquire
00f194b8 +018 LicentiebeheerServer_GUI.exe XData.Aurelius.ConnectionPool 75 +2 TDBConnectionPool.GetConnection
00b25c61 +0d1 LicentiebeheerServer_GUI.exe TMSLoggingAureliusOutputHandler 79 +11 TTMSLoggerAureliusOutputHandler.LogOutput
00887368 +048 LicentiebeheerServer_GUI.exe TMSLoggingCore 3055 +6 TTMSLoggerBaseOutputHandler.Log
0087cd93 +113 LicentiebeheerServer_GUI.exe TMSLoggingCore 1442 +27 TTMSCustomLogger.LogOutputInformation
0087d7d7 +347 LicentiebeheerServer_GUI.exe TMSLoggingCore 1536 +14 TTMSCustomLogger.LogValue
0087b603 +1e3 LicentiebeheerServer_GUI.exe TMSLoggingCore 1188 +16 TTMSCustomLogger.LogInternal
00877891 +0a1 LicentiebeheerServer_GUI.exe TMSLoggingCore 674 +6 TTMSCustomLogger.Error
00877b6d +03d LicentiebeheerServer_GUI.exe TMSLoggingCore 716 +1 TTMSCustomLogger.Error
0131eefb +1eb LicentiebeheerServer_GUI.exe UnServiceImplementation 79 +4 TLicentiebeheerServerServicePart.LogNaarServer
0131f69e +59e LicentiebeheerServer_GUI.exe UnServiceImplementation 135 +40 TLicentiebeheerServerServicePart.KopieerLicentieVersie
0053d869 +069 LicentiebeheerServer_GUI.exe System.Rtti 7944 +32 RawInvoke
0053dd40 +2a0 LicentiebeheerServer_GUI.exe System.Rtti 8078 +40 Invoke
00540567 +1f7 LicentiebeheerServer_GUI.exe System.Rtti 9482 +25 TRttiIntfMethod.DispatchInvoke
0053e4c8 +058 LicentiebeheerServer_GUI.exe System.Rtti 9010 +1 TRttiMethod.Invoke
010c2c3c +56c LicentiebeheerServer_GUI.exe XData.Server.Module 842 +54 TXDataRequestHandler.ExecuteAction
01078f0d +9fd LicentiebeheerServer_GUI.exe XData.Module.Base 744 +145 TXDataBaseRequestHandler.ProcessRequest
01077205 +0a5 LicentiebeheerServer_GUI.exe XData.Module.Base 267 +13 TXDataBaseModule.ProcessRequest
00f05da3 +023 LicentiebeheerServer_GUI.exe Sparkle.HttpServer.Module 226 +0 TBaseHttpServerModule.Execute$14$ActRec.$0$Body
00f05ed3 +123 LicentiebeheerServer_GUI.exe Sparkle.HttpServer.Module 233 +8 TBaseHttpServerModule.Execute
00f13bb5 +065 LicentiebeheerServer_GUI.exe Sparkle.HttpSys.Server 317 +7 THttpSysServer.DoProcessRequest
00f1346a +0aa LicentiebeheerServer_GUI.exe Sparkle.HttpSys.Server 234 +8 TCustomHttpSysServer.WorkItemCallBack
00f0fa85 +035 LicentiebeheerServer_GUI.exe Sparkle.Sys.ThreadPool 77 +4 WorkItemFunction
004ffa79 +049 LicentiebeheerServer_GUI.exe madExcept UserWorkItemExceptFrame
7fbaaac1 +018 KERNEL32.DLL BaseThreadInitThunk
7fbae09e +01f ntdll.dll RtlUserThreadStart
wlandgraf
(Wagner Landgraf)
March 22, 2017, 12:19pm
3
This error is always server-side, the client is just informing the error that happened in the server.
It happens when the server code needs a database connection but it can't retrieve it from the pool (after a timeout which defaults to 10 seconds).
This should rarely happen indeed. But it might happen if:
1) Your code grabs a connection from the pool and holds it for too long, or does not return it to the pool.
2) You create a connection pool with a number of connections too small for your server workload (number of requests).
You can start with option 2 first. What is the size of the pool you are creating? And how many simultaneous requests your server is handling?
When this happened there was only one connection from the client. And a connection from TMSlogging. TDBConnectionPool was created with 50 connections:
const
nMaximumAantalVerbindingen: integer = 50;
...
FConnectionPool := TDBConnectionPool.Create(nMaximumAantalVerbindingen,FDBConnectionFactory);
And when is a connection being held for too long? When it happens there is indeed a very long process going. More than 10 seconds of retrieving data and sending data back.
wlandgraf
(Wagner Landgraf)
March 22, 2017, 2:24pm
5
The error should only happen in more than 50 connections are taken from the pool. The pool is indeed big. Is this easily reproducible? Does it happen when you disable the logger?
Could you provide more details, source code, etc., so we can check better what's going on (you can send to e-mail wagner at tmssoftware com)
It's very complicated to reproduce this, I'm afraid. I will disable the logger and see if it occurs then. I will see if I can distill something I can send you.
wlandgraf
(Wagner Landgraf)
March 22, 2017, 4:56pm
7
But is the server code involved small? Maybe something can be inferred from it if you could send it?
I will look into it tomorrow, maybe I can send you that code.
I have sent programs + data to your E-mailaddress
wlandgraf
(Wagner Landgraf)
March 23, 2017, 9:46pm
10
Thanks Janse, I have received it and answered you via e-mail. Basically you are destroying objects that are going to be destroyed by the manager itself, so this is causing some memory issues. Hope it helps.