Thanks mate. I'll give it a go... On 22 June 2012 18:16, Rob LaRubbio <[email protected]> wrote:
> I did it by recompiling with NDEBUG undefined. > > -Rob > > > On 6/22/12 10:08 AM, Matt Hoyle wrote: > > How do I go about enabling debug logging in Mongrel then? > > There doesn't appear to be any mention of it in the docco. There is a > post on the mail list abour USR1 logging? > > > > On 13 June 2012 19:39, Matt Hoyle <[email protected]> wrote: > >> Hello, >> >> I've messing about with Plack::Handler::Mongrel2 plugged into a Dancer >> application and obviously Mongrel2. >> >> Under JMeter load testing hitting the same URL repeatedly I am getting >> into a situation where the front end requests start receiving a >> "java.net.SocketTimeoutException: Read timed out" error. The tests are >> doing a repeated request "GET >> http://localhost:6767/app/polamaolaolaolaoaloalaoalaoalaoalaoalaoalaaoalaoaalaoalaoalaoa?j=8&t=1 >> " >> >> >> >> Mongrel will always produce the following error for a failed request: >> >> [INFO] (src/mongrel2.c:343) Starting Mongrel2/1.7.5. Copyright (C) Zed >> A. Shaw. Licensed BSD. >> [INFO] (src/server.c:272) Starting server on port 6767 >> [INFO] (src/task/fd.c:151) MAX limits.fdtask_stack=102400 >> [INFO] (src/superpoll.c:102) Allowing for 256 hot and 768 idle file >> descriptors (dividend was 4) >> [INFO] (src/handler.c:209) MAX allowing limits.handler_targets=128 >> [INFO] (src/handler.c:285) Binding handler PUSH socket tcp:// >> 127.0.0.1:9998 with identity: E80576A8-AC0B-11DF-A841-3D4975AD5E34 >> [INFO] (src/handler.c:311) Binding listener SUB socket tcp:// >> 127.0.0.1:9999 subscribed to: D807E984-AC0B-11DF-979C-3C4975AD5E34 >> [INFO] (src/control.c:401) Setting up control socket in at >> ipc://run/control >> *[ERROR] (src/register.c:214: errno: Resource temporarily unavailable) >> Nothing registered under id 0.* >> *[ERROR] (src/register.c:199: errno: None) Invalid FD given for exists >> check* >> * >> * >> >> Mongrel finish's the tcp connection to the http client after the zmq >> message is sent to the Plank back end: >> >> http client -> Mongrel 6767 >> Mongrel -> plank 9998 >> *This is when the problem occurs and client http connection is finished* >> Plank -> Mongrel 9999 >> Mongrel -> Client 'high port' >> >> >> sudo tcpdump -n -i lo -s 158 -p tcp port 6767 or tcp port 9999 or tcp >> port 9998 >> >> 18:11:11.991287 IP 127.0.0.1.52686 > 127.0.0.1.6767: Flags [P.], seq >> 30808:31037, ack 79381, win 384, options [nop,nop,TS val 41369964 ecr >> 41369963], length 229 >> 18:11:11.991470 IP 127.0.0.1.9998 > 127.0.0.1.55744: Flags [P.], seq >> 17675:18211, ack 3, win 256, options [nop,nop,TS val 41369964 ecr >> 41369955], length 536 >> 18:11:11.991480 IP 127.0.0.1.55744 > 127.0.0.1.9998: Flags [.], ack >> 18211, win 384, options [nop,nop,TS val 41369964 ecr 41369959], length 0 >> 18:11:12.001689 IP 127.0.0.1.52686 > 127.0.0.1.6767: Flags *[F.]*, seq >> 31037, ack 79381, win 384, options [nop,nop,TS val 41369966 ecr 41369963], >> length 0 >> 18:11:12.001759 IP 127.0.0.1.6767 > 127.0.0.1.52686: Flags *[F.]*, seq >> 79381, ack 31038, win 384, options [nop,nop,TS val 41369966 ecr 41369964], >> length 0 >> 18:11:12.001772 IP 127.0.0.1.52686 > 127.0.0.1.6767: Flags [.], ack >> 79382, win 384, options [nop,nop,TS val 41369966 ecr 41369966], length 0 >> 18:11:12.010615 IP 127.0.0.1.50171 > 127.0.0.1.9999: Flags [P.], seq >> 21123:21763, ack 3, win 257, options [nop,nop,TS val 41369968 ecr >> 41369956], length 640 >> 18:11:12.010655 IP 127.0.0.1.9999 > 127.0.0.1.50171: Flags [.], ack >> 21763, win 384, options [nop,nop,TS val 41369968 ecr 41369960], length 0 >> >> >> Whereas it normally looks like this: >> >> 18:11:11.968949 IP 127.0.0.1.52686 > 127.0.0.1.6767: Flags [P.], seq >> 29663:29892, ack 76441, win 384, options [nop,nop,TS val 41369958 ecr >> 41369958], length 229 >> 18:11:11.969095 IP 127.0.0.1.9998 > 127.0.0.1.55742: Flags [P.], seq >> 17137:17673, ack 3, win 256, options [nop,nop,TS val 41369958 ecr >> 41369954], length 536 >> 18:11:11.971890 IP 127.0.0.1.50169 > 127.0.0.1.9999: Flags [P.], seq >> 20483:21123, ack 3, win 257, options [nop,nop,TS val 41369959 ecr >> 41369955], length 640 >> 18:11:11.972006 IP 127.0.0.1.6767 > 127.0.0.1.52686: Flags [P.], seq >> 76441:77029, ack 29892, win 384, options [nop,nop,TS val 41369959 ecr >> 41369958], length 588 >> 18:11:11.973493 IP 127.0.0.1.52686 > 127.0.0.1.6767: Flags [P.], seq >> 29892:30121, ack 77029, win 384, options [nop,nop,TS val 41369959 ecr >> 41369959], length 229 >> >> >> The only thing of note I found in Plack::Handler::Mongrel2 at the same >> time as the errors were undefined variable errors, but they were all >> related to the METHOD=JSON disconnect message being sent out after this >> issue has occured. >> >> I can increase the the frequency of the errors by increasing the debug >> logging on the Perl/Plack side of things so I believe it's something in the >> back end but I'm at a loss at the moment as to what could be causing it. >> It happens with or without multiple threads or a single thread at each >> http client and plack levels. >> >> Any ideas on where to look next would be appreciated. >> >> Cheers, >> Matt >> >> > > >
