Incorrect state after discard body for special response

Server NGINX
1

I see nginx get into an incorrect state after it processes a request
which has a body. In my case it is happening when posting data to
location which results in a redirect, the result is TWO responses
returned from the connection. It only occurs when nginx is handling
many connections. This problem does NOT occur if the request body
is included in a single packet or if the client closes the connection
after receiving the first response.

After switching into debug mode, I see that it tries to discard the
request body (as expected), but the socket is not ready so it sets a
keepalive handler. The problem is that it goes back into the rewrite
handler (generic phase 2) and writes the special response again to
the socket. The discard body event is not posted right away.

It seems like the event phase should be incremented or the connection
state is incorrect after setting the keepalive handler from the
special response handler.

Has anyone else seen this? I don’t know nginx well enough to know if
I can fix this there or what part of my configuration to change.

Below is a debug log of the connection:

2009/01/28 12:57:20 [debug] 19443#0: *4852 generic phase: 2
2009/01/28 12:57:20 [debug] 19443#0: 4852 http script regex: "^/(.)$"
2009/01/28 12:57:20 [debug] 19443#0: *4852 http script copy:
“http://host/”
2009/01/28 12:57:20 [debug] 19443#0: *4852 http script capture:
“http://host/uri”
2009/01/28 12:57:20 [debug] 19443#0: *4852 http script regex end
2009/01/28 12:57:20 [debug] 19443#0: *4852 http finalize request: 302,
“/uri?”
2009/01/28 12:57:20 [debug] 19443#0: *4852 http special response: 302,
“/uri”
2009/01/28 12:57:20 [debug] 19443#0: *4852 http set discard body
2009/01/28 12:57:20 [debug] 19443#0: *4852 http read discarded body
2009/01/28 12:57:20 [debug] 19443#0: *4852 recv: fd:34 -1 of 1
2009/01/28 12:57:20 [debug] 19443#0: *4852 recv() not ready (11:
Resource temporarily unavailable)

2009/01/28 12:57:20 [debug] 19443#0: *4852 writev: 462

2009/01/28 12:57:20 [debug] 19443#0: *4852 http finalize request: 0,
“/host/uri”
2009/01/28 12:57:20 [debug] 19443#0: *4852 set http keepalive handler
2009/01/28 12:57:20 [debug] 19443#0: *4852 event timer add: 34:
5000:1233176245399
2009/01/28 12:57:20 [debug] 19443#0: *4852 generic phase: 2
2009/01/28 12:57:20 [debug] 19443#0: 4852 http script regex: "^/(.)$"

<snip, same as above, until, notice TWO Location: headers below>

2009/01/28 12:57:20 [debug] 19443#0: *4852 HTTP/1.1 302 Moved
Temporarily
Server: nginx
Date: Wed, 28 Jan 2009 20:57:20 GMT
Content-Type: text/html
Content-Length: 154
Connection: keep-alive
Location: http://host/uri
Expires: Wed, 28 Jan 2009 20:57:19 GMT
Cache-Control: no-cache
Location: http://host/uri

2009/01/28 12:57:20 [debug] 19443#0: *4852 writev: 549

2

I came up with the patch below which seems to fix it. It’s meant to
prevent calling ngx_http_finalize_request again if generic phase
occurs while nginx is waiting to discard the request body. Without
this line, a second response is generated.

It seems to work in my testing, but I’m not sure if this is the
correct patch. Igor, is this the correct fix for this bug? If not,
is there another fix or workaround?

— nginx-0.6.35/src/http/ngx_http_core_module.c 2009-01-26
07:22:24.000000000 -0800
+++ nginx-0.6.35/src/http/ngx_http_core_module.c 2009-01-28
18:06:17.000000000 -0800
@@ -773,7 +773,9 @@

 /* rc == NGX_ERROR || rc == NGX_HTTP_...  */
  • ngx_http_finalize_request(r, rc);

  • if (!r->discard_body || rc == NGX_ERROR) {

  •  ngx_http_finalize_request(r, rc);

  • }

    return NGX_OK;
    }

3

On Wed, Jan 28, 2009 at 01:50:10PM -0800, Eden Li wrote:

keepalive handler. The problem is that it goes back into the rewrite

2009/01/28 12:57:20 [debug] 19443#0: *4852 http set discard body

Server: nginx

2009/01/28 12:57:20 [debug] 19443#0: *4852 writev: 549

I could not reproduce this on 0.6.35. Could you send me the whole log ?