[PATCH] always process short preread body
Maxim Dounin
mdounin at mdounin.ru
Thu Sep 25 13:56:16 MSD 2008
Hello!
On Thu, Sep 25, 2008 at 12:56:02AM +0100, John Fremlin wrote:
>John Fremlin <john at fremlin.org> writes:
>> We are using nginx/0.6.22 on Ubuntu hardy or intrepid, i386 or
>> amd64. nginx is in front of a mongrels rails app.
>>
>> For one particular request, the response from the rails app is received
>> by nginx, with the header and the body together in one readv(2). However
>> it waits for 60s and then sends out only the header to the client,
>> without the body, but with the correct Content-Length, as if the body
>> were included!
>>
>> This happens every time for this request but POSTs to other URLs
>> resulting in 302 work fine.
>
>The problem seems to be caused because the body gets stuck inside the
>ngx_event_pipe. This patch fixes the problem. Any comments or
>suggestions?
The patch looks wrong for me (not even mentioning that it's
whitespace damaged). It destroys buffering for no real reason,
and not only for preread body, but for ordinary reads too.
From strace in your message, it looks like the real problems are:
1. Backend, which hasn't closed connection after sending reply.
2. The fact that nginx waits for connection close before it
realizes that request was completed, even if got 'Content-Length'
header and appropriate number of body bytes.
The 1 isn't really related to nginx. The 2 should be fixed, but
a) the patch doesn't do it (or at least doesn't do it properly)
and b) it only matters with backend bug as in 1.
Could you please confirm that backend doesn't close connection?
Maxim Dounin
>
>(The patch is copyright by Cerego and released under the same license as
>nginx.)
>
>diff -u --recursive nginx-0.6.32/src/event/ngx_event_pipe.c nginx-0.6.32-clean/src/event/ngx_event_pipe.c
>--- nginx-0.6.32/src/event/ngx_event_pipe.c 2008-07-07 00:18:41.000000000 -1000
>+++ nginx-0.6.32-clean/src/event/ngx_event_pipe.c 2008-09-22 02:22:58.000000000 -1000
>@@ -298,29 +298,27 @@
> p->free_raw_bufs = NULL;
>
> while (cl && n > 0) {
>-
> ngx_event_pipe_remove_shadow_links(cl->buf);
>
> size = cl->buf->end - cl->buf->last;
>
> if (n >= size) {
> cl->buf->last = cl->buf->end;
>-
>- /* STUB */ cl->buf->num = p->num++;
>-
>- if (p->input_filter(p, cl->buf) == NGX_ERROR) {
>- return NGX_ABORT;
>- }
>-
> n -= size;
>- ln = cl;
>- cl = cl->next;
>- ngx_free_chain(p->pool, ln);
>-
>- } else {
>+ }else{
> cl->buf->last += n;
>- n = 0;
>- }
>+ n = 0;
>+ }
>+
>+ /* STUB */ cl->buf->num = p->num++;
>+
>+ if (p->input_filter(p, cl->buf) == NGX_ERROR) {
>+ return NGX_ABORT;
>+ }
>+
>+ ln = cl;
>+ cl = cl->next;
>+ ngx_free_chain(p->pool, ln);
> }
>
> if (cl) {
>
>
>
>>
>> We have quite a complex config, and possibly that might be related. Any
>> suggestions would be very much appreciated!
>>
>> Here is the strace (of nginx)
>>
>> 22:32:00.914649 write(3, "2008/09/21 22:32:00 [debug] 3432#0: epoll: fd:6 ev:0005 d:0000000000709271\n", 75) = 75 <0.000011>
>> 22:32:00.914718 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http upstream process header\n", 68) = 68 <0.000005>
>> 22:32:00.914749 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 malloc: 00000000006C7930:4096\n", 69) = 69 <0.000005>
>> 22:32:00.914778 recvfrom(6, "HTTP/1.1 302 Moved Temporarily\r\nConnection: close\r\nDate: Mon, 22 Sep 2008 08:31:57 GMT\r\nSet-Cookie: uid=884s; path=/\r\nSet-Cookie: globalize_change_user_key=; path=/\r\nSet-Cookie: language_code=en; path=/\r\nSet-Cookie: _iknow_sid=baa1d09712a041eca1edb7f6c273ea96; path=/; expires=Mon, 06 Oct 2008 06:53:39 GMT\r\nStatus: 302 Found\r\nLocation: http://localhost/list/100005/build\r\nX-Runtime: 1.55355\r\nCache-Control: no-cache\r\nServer: Mongrel 1.0.1\r\nContent-Type: text/html; charset=utf-8\r\nContent-Length: 100\r\n\r\n<html><body>You are being <a href=\"http://localhost/list/100005/build\">redirected</a>.</body></html>", 4096, 0, NULL, NULL) = 604 <0.000006>
>>
>>
>>
>>
>> 22:32:00.914845 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 recv: fd:6 604 of 4096\n", 62) = 62 <0.000005>
>> 22:32:00.914875 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy status 302 \"302 Moved Temporarily\"\n", 85) = 85 <0.000005>
>> 22:32:00.914907 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Connection: close\"\n", 78) = 78 <0.000005>
>> 22:32:00.914937 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Date: Mon, 22 Sep 2008 08:31:57 GMT\"\n", 96) = 96 <0.000019>
>> 22:32:00.914983 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Set-Cookie: uid=884s; path=/\"\n", 89) = 89 <0.000005>
>> 22:32:00.915015 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Set-Cookie: globalize_change_user_key=; path=/\"\n", 107) = 107 <0.000005>
>> 22:32:00.915047 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Set-Cookie: language_code=en; path=/\"\n", 97) = 97 <0.000005>
>> 22:32:00.915079 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Set-Cookie: _iknow_sid=baa1d09712a041eca1edb7f6c273ea96; path=/; expires=Mon, 06 Oct 2008 06:53:39 GMT\"\n", 163) = 163 <0.000005>
>> 22:32:00.915114 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Status: 302 Found\"\n", 78) = 78 <0.000005>
>> 22:32:00.915144 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Location: http://localhost/list/100005/build\"\n", 105) = 105 <0.000005>
>> 22:32:00.915176 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"X-Runtime: 1.55355\"\n", 79) = 79 <0.000005>
>> 22:32:00.915206 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Cache-Control: no-cache\"\n", 84) = 84 <0.000005>
>> 22:32:00.915236 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Server: Mongrel 1.0.1\"\n", 82) = 82 <0.000005>
>> 22:32:00.915267 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Content-Type: text/html; charset=utf-8\"\n", 99) = 99 <0.000004>
>> 22:32:00.915297 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header: \"Content-Length: 100\"\n", 80) = 80 <0.000004>
>> 22:32:00.915326 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http proxy header done\n", 62) = 62 <0.000005>
>> 22:32:00.915365 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 malloc: 0000000000763170:4096\n", 69) = 69 <0.000005>
>> 22:32:00.915396 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 HTTP/1.1 302 Moved Temporarily\r\nServer: nginx/0.6.32\r\nDate: Mon, 22 Sep 2008 08:32:00 GMT\r\nContent-Type: text/html; charset=utf-8\r\nConnection: keep-alive\r\nSet-Cookie: uid=884s; path=/\r\nSet-Cookie: globalize_change_user_key=; path=/\r\nSet-Cookie: language_code=en; path=/\r\nSet-Cookie: _iknow_sid=baa1d09712a041eca1edb7f6c273ea96; path=/; expires=Mon, 06 Oct 2008 06:53:39 GMT\r\nStatus: 302 Found\r\nLocation: http://localhost/list/100005/build\r\nX-Runtime: 1.55355\r\nCache-Control: no-cache\r\nContent-Length: 100\r\n\n\n", 547) = 547 <0.000005>
>> 22:32:00.915456 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 write new buf t:1 f:0 00000000007631B0, pos 00000000007631B0, size: 508 file: 0, size: 0\n", 128) = 128 <0.000006>
>> 22:32:00.915498 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http write filter: l:0 f:0 s:508\n", 72) = 72 <0.000005>
>> 22:32:00.915531 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http upstream process upstream\n", 70) = 70 <0.000005>
>> 22:32:00.915559 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 pipe read upstream: 1\n", 61) = 61 <0.000005>
>> 22:32:00.915587 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 pipe preread: 100\n", 57) = 57 <0.000005>
>> 22:32:00.915615 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 readv: 1:3492\n", 53) = 53 <0.000005>
>> 22:32:00.915641 readv(6, 0x7fff756d69b0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000005>
>> 22:32:00.915669 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 readv() not ready (11: Resource temporarily unavailable)\n", 96) = 96 <0.000004>
>> 22:32:00.915699 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 pipe recv chain: -2\n", 59) = 59 <0.000005>
>> 22:32:00.915727 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 pipe buf free s:0 t:1 f:0 00000000006C7930, pos 00000000006C7B28, size: 100 file: 0, size: 0\n", 132) = 132 <0.000005>
>> 22:32:00.915760 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 pipe write downstream: 1\n", 64) = 64 <0.000004>
>> 22:32:00.915787 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 pipe write busy: 0\n", 58) = 58 <0.000005>
>> 22:32:00.915815 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 pipe write: out:0000000000000000, f:0\n", 77) = 77 <0.000005>
>> 22:32:00.915843 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 pipe read upstream: 0\n", 61) = 61 <0.000005>
>> 22:32:00.915871 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 pipe buf free s:0 t:1 f:0 00000000006C7930, pos 00000000006C7B28, size: 100 file: 0, size: 0\n", 132) = 132 <0.000005>
>> 22:32:00.915904 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 event timer del: 6: 1222072377084\n", 73) = 73 <0.000005>
>> 22:32:00.915933 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 event timer add: 6: 60000:1222072380914\n", 79) = 79 <0.000005>
>> 22:32:00.915963 write(3, "2008/09/21 22:32:00 [debug] 3432#0: *4 http upstream dummy handler\n", 67) = 67 <0.000005>
>> 22:32:00.915991 write(3, "2008/09/21 22:32:00 [debug] 3432#0: timer delta: 3830\n", 54) = 54 <0.000005>
>> 22:32:00.916018 write(3, "2008/09/21 22:32:00 [debug] 3432#0: posted events 0000000000000000\n", 67) = 67 <0.000005>
>> 22:32:00.916046 write(3, "2008/09/21 22:32:00 [debug] 3432#0: worker cycle\n", 49) = 49 <0.000005>
>> 22:32:00.916073 write(3, "2008/09/21 22:32:00 [debug] 3432#0: epoll timer: 60000\n", 55) = 55 <0.000005>
>>
>>
>>
>>
>>
>> Why not respond now!?
>>
>>
>> 22:32:00.916100 epoll_wait(8, {}, 512, 60000) = 0 <59.997826>
>> 22:33:00.913995 write(3, "2008/09/21 22:33:00 [debug] 3432#0: timer delta: 59999\n", 55) = 55 <0.000010>
>> 22:33:00.914046 write(3, "2008/09/21 22:33:00 [debug] 3432#0: posted events 0000000000000000\n", 67) = 67 <0.000005>
>> 22:33:00.914076 write(3, "2008/09/21 22:33:00 [debug] 3432#0: worker cycle\n", 49) = 49 <0.000005>
>> 22:33:00.914104 write(3, "2008/09/21 22:33:00 [debug] 3432#0: epoll timer: 1\n", 51) = 51 <0.000005>
>> 22:33:00.914131 epoll_wait(8, {}, 512, 1) = 0 <0.010455>
>> 22:33:00.924637 write(3, "2008/09/21 22:33:00 [debug] 3432#0: timer delta: 11\n", 52) = 52 <0.000008>
>> 22:33:00.924693 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 event timer del: 6: 1222072380914\n", 73) = 73 <0.000005>
>> 22:33:00.924723 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http upstream process upstream\n", 70) = 70 <0.000005>
>> 22:33:00.924760 write(3, "2008/09/21 22:33:00 [error] 3432#0: *4 upstream timed out (110: Connection timed out) while reading upstream, client: 127.0.0.1, server: www.iknow.co.jp, request: \"POST /lists/new/theme HTTP/1.1\", upstream: \"http://127.0.0.1:3000/lists/new/theme\", host: \"localhost\", referrer: \"http://localhost/lists/new\"\n", 306) = 306 <0.000005>
>> 22:33:00.924806 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http upstream exit: 0000000000000000\n", 76) = 76 <0.000027>
>> 22:33:00.924858 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 finalize http upstream request: 0\n", 73) = 73 <0.000005>
>> 22:33:00.924902 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 finalize http proxy request\n", 67) = 67 <0.000005>
>> 22:33:00.924931 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 free rr peer 1 0\n", 56) = 56 <0.000005>
>> 22:33:00.924959 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 close http upstream connection: 6\n", 73) = 73 <0.000005>
>> 22:33:00.924987 close(6) = 0 <0.000034>
>> 22:33:00.925040 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http upstream temp fd: -1\n", 65) = 65 <0.000005>
>> 22:33:00.925071 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http output filter \"/lists/new/theme?\"\n", 78) = 78 <0.000005>
>> 22:33:00.925101 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 copy filter: \"/lists/new/theme?\"\n", 72) = 72 <0.000005>
>> 22:33:00.925132 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http postpone filter \"/lists/new/theme?\" 00007FFF756D6D20\n", 97) = 97 <0.000005>
>> 22:33:00.925163 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http postpone filter out \"/lists/new/theme?\"\n", 84) = 84 <0.000005>
>> 22:33:00.925195 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 write old buf t:1 f:0 00000000007631B0, pos 00000000007631B0, size: 508 file: 0, size: 0\n", 128) = 128 <0.000005>
>> 22:33:00.925229 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0\n", 126) = 126 <0.000005>
>> 22:33:00.925262 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http write filter: l:1 f:0 s:508\n", 72) = 72 <0.000005>
>> 22:33:00.925290 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http write filter limit 0\n", 65) = 65 <0.000005>
>> 22:33:00.925319 writev(10, [{"HTTP/1.1 302 Moved Temporarily\r\nServer: nginx/0.6.32\r\nDate: Mon, 22 Sep 2008 08:32:00 GMT\r\nContent-Type: text/html; charset=utf-8\r\nConnection: keep-alive\r\nSet-Cookie: uid=884s; path=/\r\nSet-Cookie: globalize_change_user_key=; path=/\r\nSet-Cookie: language_code=en; path=/\r\nSet-Cookie: _iknow_sid=baa1d09712a041eca1edb7f6c273ea96; path=/; expires=Mon, 06 Oct 2008 06:53:39 GMT\r\nStatus: 302 Found\r\nLocation: http://localhost/list/100005/build\r\nX-Runtime: 1.55355\r\nCache-Control: no-cache\r\nContent-Length: 100\r\n\r\n", 508}], 1) = 508 <0.000100>
>>
>>
>> The body is not sent!
>>
>>
>>
>> 22:33:00.925480 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 writev: 508\n", 51) = 51 <0.000004>
>> 22:33:00.925510 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http write filter 0000000000000000\n", 74) = 74 <0.000005>
>> 22:33:00.925540 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 copy filter: 0 \"/lists/new/theme?\"\n", 74) = 74 <0.000005>
>> 22:33:00.925569 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http finalize request: 0, \"/lists/new/theme?\"\n", 85) = 85 <0.000005>
>> 22:33:00.925600 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 set http keepalive handler\n", 66) = 66 <0.000005>
>> 22:33:00.925629 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http close request\n", 58) = 58 <0.000005>
>> 22:33:00.925657 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http log handler\n", 56) = 56 <0.000005>
>> 22:33:00.925690 write(4, "127.0.0.1 - - [21/Sep/2008:22:33:00 -1000] \"POST /lists/new/theme HTTP/1.1\" 302 0 \"http://localhost/lists/new\" \"Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.0.1) Gecko/2008072820 Ubuntu/8.10 (intrepid) Firefox/3.0.1\" 63.844 \"-\" \"localhost\" \"-\" [_iknow_sid=baa1d09712a041eca1edb7f6c273ea96; Navicast_SessID=j8965.5ee1aa6e647d84.www2; language_code=en; ysm_bbk1SGMN8HHSPL0MNUPLPM0FI4M7BS=13172008; uid=884s; globalize_change_user_key=]\n", 438) = 438 <0.000009>
>> 22:33:00.925749 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 free: 00000000006C7930\n", 62) = 62 <0.000005>
>> 22:33:00.925778 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 free: 00000000006C5910, unused: 0\n", 73) = 73 <0.000005>
>> 22:33:00.925807 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 free: 00000000006C6920, unused: 16\n", 74) = 74 <0.000005>
>> 22:33:00.925837 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 free: 0000000000763170, unused: 3049\n", 76) = 76 <0.000005>
>> 22:33:00.925874 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 event timer add: 10: 75000:1222072455924\n", 80) = 80 <0.000005>
>> 22:33:00.925904 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 free: 00000000006CD330\n", 62) = 62 <0.000005>
>> 22:33:00.925933 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 free: 00000000006CCD50\n", 62) = 62 <0.000005>
>> 22:33:00.925961 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 hc free: 0000000000000000 0\n", 67) = 67 <0.000005>
>> 22:33:00.925989 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 hc busy: 0000000000000000 0\n", 67) = 67 <0.000005>
>> 22:33:00.926018 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 post event 000000000072F2F0\n", 67) = 67 <0.000005>
>> 22:33:00.926047 write(3, "2008/09/21 22:33:00 [debug] 3432#0: posted events 000000000072F2F0\n", 67) = 67 <0.000004>
>> 22:33:00.926075 write(3, "2008/09/21 22:33:00 [debug] 3432#0: posted event 000000000072F2F0\n", 66) = 66 <0.000005>
>> 22:33:00.926104 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 delete posted event 000000000072F2F0\n", 76) = 76 <0.000005>
>> 22:33:00.926133 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 http keepalive handler\n", 62) = 62 <0.000005>
>> 22:33:00.926161 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 malloc: 00000000006CCD50:1024\n", 69) = 69 <0.000005>
>> 22:33:00.926191 recvfrom(10, 0x6ccd50, 1024, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable) <0.000003>
>> 22:33:00.926215 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 recv: fd:10 -1 of 1024\n", 62) = 62 <0.000005>
>> 22:33:00.926245 write(3, "2008/09/21 22:33:00 [debug] 3432#0: *4 recv() not ready (11: Resource temporarily unavailable)\n", 95) = 95 <0.000005>
>> 22:33:00.926275 write(3, "2008/09/21 22:33:00 [debug] 3432#0: posted event 0000000000000000\n", 66) = 66 <0.000005>
>> 22:33:00.926303 write(3, "2008/09/21 22:33:00 [debug] 3432#0: worker cycle\n", 49) = 49 <0.000005>
>> 22:33:00.926331 write(3, "2008/09/21 22:33:00 [debug] 3432#0: epoll timer: 75000\n", 55) = 55 <0.000005>
>> 22:33:00.926358 epoll_wait(8, {}, 512, 75000) = 0 <74.998182>
>> 22:34:15.924609 write(3, "2008/09/21 22:34:15 [debug] 3432#0: timer delta: 75000\n", 55) = 55 <0.000010>
>> 22:34:15.924661 write(3, "2008/09/21 22:34:15 [debug] 3432#0: *4 event timer del: 10: 1222072455924\n", 74) = 74 <0.000005>
>> 22:34:15.924692 write(3, "2008/09/21 22:34:15 [debug] 3432#0: *4 http keepalive handler\n", 62) = 62 <0.000005>
>> 22:34:15.924720 write(3, "2008/09/21 22:34:15 [debug] 3432#0: *4 close http connection: 10\n", 65) = 65 <0.000005>
>> 22:34:15.924749 close(10) = 0 <0.000102>
More information about the nginx
mailing list