Z_BUF_ERROR nginx 0.8.53

[Maxim Dounin]

Hello!

On Thu, Nov 18, 2010 at 02:45:22PM -0800, Roman Vasilyev wrote:

> I've reproduced this problem with debuging.
> Let me attach error log with debug, I'm not clearly understanding
> nginx modules chain

[...]

> 2010/11/18 14:42:23 [debug] 24622#0: *206 http upstream process non
> buffered upstream

[...]

> 2010/11/18 14:42:23 [debug] 24622#0: *206 http gunzip filter
> 2010/11/18 14:42:23 [debug] 24622#0: *206 gunzip in: 00000000055590E8
> 2010/11/18 14:42:23 [debug] 24622#0: *206 gunzip
> in_buf:0000000005559108 ni:00000000012021A0 ai:10
> 2010/11/18 14:42:23 [debug] 24622#0: *206 inflate in:
> ni:00000000012021A0 no:0000000005559940 ai:10 ao:4096 fl:2 redo:0
> 2010/11/18 14:42:23 [debug] 24622#0: *206 inflate out:
> ni:00000000012021AA no:0000000005559940 ai:0 ao:4096 rc:0
> 2010/11/18 14:42:23 [debug] 24622#0: *206 gunzip
> in_buf:0000000005559108 pos:00000000012021A0
> 2010/11/18 14:42:23 [debug] 24622#0: *206 http afbody in
> 2010/11/18 14:42:23 [debug] 24622#0: *206 http chunk size: 0
> 2010/11/18 14:42:23 [debug] 24622#0: *206 http afbody out
> 2010/11/18 14:42:23 [debug] 24622#0: *206 http postpone filter
> "/?ar=1290119308" 00000000055590D8
> 2010/11/18 14:42:23 [debug] 24622#0: *206 http gzip filter
> 2010/11/18 14:42:23 [debug] 24622#0: *206 gzip in: 00000000055590C8
> 2010/11/18 14:42:23 [debug] 24622#0: *206 gzip
> in_buf:0000000005559158 ni:0000000000000000 ai:0
> 2010/11/18 14:42:23 [debug] 24622#0: *206 deflate in:
> ni:0000000000000000 no:00000000056BDE20 ai:0 ao:8192 fl:2 redo:0
> 2010/11/18 14:42:23 [alert] 24622#0: *206 deflate() failed: 2, -5
> while reading upstream, client: 10.222.16.2, server: hss, request:
> "GET /?ar=1290119308 HTTP/1.1", upstream:
> "http://74.125.19.103:80/?ar=1290119308", host: "news.google.com",
> referrer: "http://news.google.com/"

Ah, ok, the problem is clear: due to use of proxy_buffered off; 
buffer had flush flag set.  All data from it was eaten by gunzip 
filter, and special flush buffer was passed along filter chain 
instead.

The only way to reproduce this problem without third party modules 
(i.e. gunzip filter and your local modifications to it in your 
case) seems to use $r->flush() twice from embedded perl, see test 
case here:

http://mdounin.ru/hg/nginx-tests/rev/e8546edb0267

Correct patch to the problem attached.

It basically lines up gzip filter to what is already done in 
gunzip filter - allows Z_BUF_ERROR as non-fatal and makes sure 
special flush buffer will be passed if there is no output in 
Z_SYNC_FLUSH case.

Maxim Dounin
-------------- next part --------------
# HG changeset patch
# User Maxim Dounin <mdounin at mdounin.ru>
# Date 1290136358 -10800
# Node ID 0a0e83a0001302db3436f8f57e9044800dadc8b2
# Parent  24908387c8225147cd3f328f0a38ca4a8c95dc86
Gzip filter: handle empty flush buffers.

Empty flush buffers are legitimate and may happen e.g. due to $r->flush()
calls in embedded perl.  If there are no data buffered in zlib deflate()
will return Z_BUF_ERROR (i.e. no progress possible) without adding anything
to output.  Don't treat Z_BUF_ERROR as fatal and correctly send empty flush
buffer if we have no data in output at all.

See this thread for details:

http://nginx.org/pipermail/nginx/2010-November/023693.html

diff --git a/src/http/modules/ngx_http_gzip_filter_module.c b/src/http/modules/ngx_http_gzip_filter_module.c
--- a/src/http/modules/ngx_http_gzip_filter_module.c
+++ b/src/http/modules/ngx_http_gzip_filter_module.c
@@ -758,6 +758,7 @@ static ngx_int_t
 ngx_http_gzip_filter_deflate(ngx_http_request_t *r, ngx_http_gzip_ctx_t *ctx)
 {
     int                    rc;
+    ngx_buf_t             *b;
     ngx_chain_t           *cl;
     ngx_http_gzip_conf_t  *conf;
 
@@ -769,7 +770,7 @@ ngx_http_gzip_filter_deflate(ngx_http_re
 
     rc = deflate(&ctx->zstream, ctx->flush);
 
-    if (rc != Z_OK && rc != Z_STREAM_END) {
+    if (rc != Z_OK && rc != Z_STREAM_END && rc != Z_BUF_ERROR) {
         ngx_log_error(NGX_LOG_ALERT, r->connection->log, 0,
                       "deflate() failed: %d, %d", ctx->flush, rc);
         return NGX_ERROR;
@@ -818,8 +819,6 @@ ngx_http_gzip_filter_deflate(ngx_http_re
 
     if (ctx->flush == Z_SYNC_FLUSH) {
 
-        ctx->zstream.avail_out = 0;
-        ctx->out_buf->flush = 1;
         ctx->flush = Z_NO_FLUSH;
 
         cl = ngx_alloc_chain_link(r->pool);
@@ -827,7 +826,22 @@ ngx_http_gzip_filter_deflate(ngx_http_re
             return NGX_ERROR;
         }
 
-        cl->buf = ctx->out_buf;
+        b = ctx->out_buf;
+
+        if (ngx_buf_size(b) == 0) {
+
+            b = ngx_calloc_buf(ctx->request->pool);
+            if (b == NULL) {
+                return NGX_ERROR;
+            }
+
+        } else {
+            ctx->zstream.avail_out = 0;
+        }
+
+        b->flush = 1;
+
+        cl->buf = b;
         cl->next = NULL;
         *ctx->last_out = cl;
         ctx->last_out = &cl->next;