Opened 3 months ago

Last modified 3 months ago

#1832 new defect

Occasionally get "...zero size buf in writer..."

Reported by: carlbom.hakan@… Owned by:
Priority: major Milestone:
Component: other Version: 1.17.x
Keywords: Cc:
uname -a: Linux Rehappen-env-nginx-2 4.18.0-1025-azure #27~18.04.1-Ubuntu SMP Thu Jul 4 20:49:16 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
nginx -V: nginx version: nginx/1.17.2 (Ubuntu) built by gcc 7.4.0 (Ubuntu 7.4.0-1ubuntu1~18.04.1) built with OpenSSL 1.1.1c 28 May 2019 TLS SNI support enabled configure arguments: --prefix=/etc/nginx --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib/nginx/modules --conf-path=/etc/nginx/nginx.conf --error-log-path\ =/var/log/nginx/error.log --pid-path=/var/run/nginx.pid --lock-path=/var/run/nginx.lock --user=nginx --group=nginx --build=Ubuntu --builddir=nginx-1.17.2 --w\ ith-select_module --with-poll_module --with-threads --with-file-aio --with-http_ssl_module --with-http_v2_module --with-http_realip_module --with-http_additi\ on_module --with-http_xslt_module=dynamic --with-http_image_filter_module=dynamic --with-http_geoip_module=dynamic --with-http_sub_module --with-http_dav_mod\ ule --with-http_flv_module --with-http_mp4_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_auth_request_module --with-http_random\ _index_module --with-http_secure_link_module --with-http_degradation_module --with-http_slice_module --with-http_stub_status_module --with-http_perl_module=d\ ynamic --with-perl_modules_path=/usr/share/perl/5.26.1 --with-perl=/usr/bin/perl --http-log-path=/var/log/nginx/access.log --http-client-body-temp-path=/var/\ cache/nginx/client_temp --http-proxy-temp-path=/var/cache/nginx/proxy_temp --http-fastcgi-temp-path=/var/cache/nginx/fastcgi_temp --http-uwsgi-temp-path=/var\ /cache/nginx/uwsgi_temp --http-scgi-temp-path=/var/cache/nginx/scgi_temp --with-mail=dynamic --with-mail_ssl_module --with-stream=dynamic --with-stream_ssl_m\ odule --with-stream_realip_module --with-stream_geoip_module=dynamic --with-stream_ssl_preread_module --with-compat --with-pcre=../pcre-8.43 --with-pcre-jit \ --with-zlib=../zlib-1.2.11 --with-openssl=../openssl-1.1.1c --with-openssl-opt=no-nextprotoneg --with-debug

Description

My system loads a text file into a MongoDB database , due to the way MongoDB handle _id fields the sizes of the json objects becomes different.

I have configured nginx as a reverse proxy in front of the express server.

After one of the loads of the text into the MongoDB accessing one specific record triggered the "zero size buf in writer" when the reverse proxy shall return the response to the client (browser). The string "zero size buf in writer" is found in four location of the source code (in two different files)

Downloading the the 1.17.2 source code of nginx, adding the text (adding HACA:1, HACA:2, HACA:3 and HACA:4) to the log printout (yes this could have been made in smarter ways) I locate it to be the second location the the file "ngx_http_write_filter_module.c", my version of the source:

if (ngx_buf_size(cl->buf) == 0 && !ngx_buf_special(cl->buf)) {

ngx_log_error(NGX_LOG_ALERT, c->log, 0,

"zero size buf in writer (HACA:2) "
"temporary:%d recycled:%d in_file:%d start:%p pos:%p-last:%p file:%p file_pos:%O-file_last:%O",
cl->buf->temporary,
cl->buf->recycled,
cl->buf->in_file,
cl->buf->start,
cl->buf->pos,
cl->buf->last,
cl->buf->file,
cl->buf->file_pos,
cl->buf->file_last);

ngx_debug_point();
return NGX_ERROR;

}

and the error.log part:

2019/08/13 16:43:40 [alert] 12069#12069: *142 zero size buf in writer (HACA:2) temporary:1 recycled:1 in_file:0 start:000055EF566FD010 pos:000055EF566FD010-last:000055EF566FD010 file:0000000000000000 file_pos:0-file_last:0 while sending to client, client: ...

Analyzing the marcos:

  • temporary == 1 gives that ngx_buf_in_memory is true
  • for an in memory buf and pos == last gives that ngx_buf_size is deemed == 0
  • ngx_buf_special is false (since ngx_buf_in_memory is true)

Running my application it works great for accessing all my database MongoDB records (i.e. the reverse proxy passes them through as intended) but this very specific record triggers the above issue, As I reloaded the same text file into a new MongoDB database, the added records gets other new _id and this case the above reported error does not happen (in the second database the json string becomes 7 characters longer due to different _id fields).

To me this seem to be a case of some specific length of the response that statistically happens very seldom, but when it does it triggers the behaviour. If it in general nginx was wrongly configured I assume that reloading into a new MongoDB database should also fail (but it does not trigger this behaviour).

I hope someone with better insight into how the rest of nginx works in total can spot why this rare case happens and can fix it...

Change History (1)

comment:1 Changed 3 months ago by mdounin

As long as you have gzipping enabled, try switching it off and/or upgrade to nginx 1.17.3, which has a fix for a bug in gzip filter which can cause "zero size buf" alerts on certain response sizes. Quoting CHANGES:

    *) Bugfix: "zero size buf" alerts might appear in logs when using
       gzipping; the bug had appeared in 1.17.2.

See #1826 for some additional details.

Note: See TracTickets for help on using tickets.