Re: Followup: sloooow select, EOF-level somewhere?!?
Re: Followup: sloooow select, EOF-level somewhere?!?
- Subject: Re: Followup: sloooow select, EOF-level somewhere?!?
- From: OC <email@hidden>
- Date: Mon, 09 Mar 2015 15:26:05 +0100
Ah. Just again, I've got wrong logs from the server. Darn. Do please ignore the „problem“ quoted below -- it did _not_ happen, those SELECTs were normally generated by normal (direct action) code.
Thus, the only problem is why they took that long, and how to make them faster. There's absolutely no mystery in their occurrence or purpose (the direct action does indeed fetch that auction). Sorry for the confusing message!
On 9. 3. 2015, at 15:17, OC <email@hidden> wrote:
> Hmmm.... what's even more curious is that those SELECTs did happen _pretty long after_ appropriate request processing did finish (more precisely, after application.sleep was called). I am logging R/R loops in application awake/sleep; and the log looks like this (no occurrence of the same worker thread meantime nor later, does not seem it was re-assigned):
>
> ===
> ////// R/R loop #14 WorkerThread5 started at 11:16:48.022 9.3.
> ////// R/R loop #14 WorkerThread5 done at 11:16:48.074 took 0.053 s
> ...
> ////// R/R loop #19 WorkerThread13 started at 11:17:16.709 9.3.
> ... this is the only non-trivial R/R loop, saved some changes into the DBAuction (uid = 1000706) -- others either SELECTed or did not even that ...
> ////// R/R loop #19 WorkerThread13 done at 11:17:18.491 took 1.782 s
> ...
> ////// R/R loop #25 WorkerThread14 started at 11:25:40.688 9.3.
> ////// R/R loop #25 WorkerThread14 done at 11:25:42.835 took 2.147 s
> ...
> ////// R/R loop #28 WorkerThread8 started at 11:26:15.830 9.3.
> ////// R/R loop #28 WorkerThread8 done at 11:26:15.928 took 0.098 s
> ...
> ////// R/R loop #30 WorkerThread4 started at 11:26:26.175 9.3.
> ////// R/R loop #30 WorkerThread4 done at 11:26:26.264 took 0.089 s
> ...
> ////// R/R loop #33 WorkerThread7 started at 11:26:35.037 9.3.
> ////// R/R loop #33 WorkerThread7 done at 11:26:37.647 took 2.611 s
> ...
> 11:27:13.916 INFO "DBAuction"@2111204009 expression took 114 ms: SELECT ... FROM "T_AUCTION" t0 WHERE t0."C_UID" = 1000762 //log:er.extensions.ERXAdaptorChannelDelegate.sqlLogging [WorkerThread14]
> 11:29:10.676 INFO "DBAuction"@2111204009 expression took 188 ms: SELECT ... FROM "T_AUCTION" t0 WHERE t0."C_UID" = 1000762 //log:er.extensions.ERXAdaptorChannelDelegate.sqlLogging [WorkerThread7]
> 11:29:16.320 INFO "DBAuction"@2111204009 expression took 431 ms: SELECT ... FROM "T_AUCTION" t0 WHERE t0."C_UID" = 1000762 //log:er.extensions.ERXAdaptorChannelDelegate.sqlLogging [WorkerThread13]
> 11:38:22.783 INFO "DBAuction"@2111204009 expression took 53 ms: SELECT ... FROM "T_AUCTION" t0 WHERE t0."C_UID" = 1000762 //log:er.extensions.ERXAdaptorChannelDelegate.sqlLogging [WorkerThread8]
> 11:48:33.164 INFO "DBAuction"@2111204009 expression took 85 ms: SELECT ... FROM "T_AUCTION" t0 WHERE t0."C_UID" = 1000762 //log:er.extensions.ERXAdaptorChannelDelegate.sqlLogging [WorkerThread4]
> 11:49:03.859 INFO "DBAuction"@2111204009 expression took 65 ms: SELECT ... FROM "T_AUCTION" t0 WHERE t0."C_UID" = 1000762 //log:er.extensions.ERXAdaptorChannelDelegate.sqlLogging [WorkerThread4]
> 11:53:10.383 INFO "DBAuction"@2111204009 expression took 135 ms: SELECT ... FROM "T_AUCTION" t0 WHERE t0."C_UID" = 1000762 //log:er.extensions.ERXAdaptorChannelDelegate.sqlLogging [WorkerThread5]
> ===
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-dev mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden