Hi. After update from 1.0.14 to 1.2.3, strange alerts starts to appears in error.log: 2012/10/08 23:44:07 [alert] 25551#0: *79037 zero size buf in output t:0 r:0 f:0 000000000D31F3F0 000000000D31F3F0-000000000D3273F0 0000000000000000 0-0 while sending to client, client: 91.138.121.71, server: www.example.ru, request: "HEAD /images/one/video_player.swf?file=http://www.example.ru/test/generate_xml%3fpid=51559%26one=22 HTTP/1.1", upstream: "http://10.23.23.15:6644/images/one/video_player.sw..., host: "www.example.ru" We can't reproduce it in test environment(without real load). It appears on different servers with different CentOS versions on it. In most cases error appears after HEAD requests(by google bot, for example). We uses proxy_cache requests, config: proxy_cache_key "$request_method|$host|$uri?$args"; proxy_cache_path /var/nginx/cache/html levels=1:2 keys_zone=html-cache:18m max_size=5g inactive=60m; proxy_cache html-cache; proxy_cache_valid 200 302 301 10m; proxy_cache_valid 304 10m; proxy_cache_valid 404 1m; proxy_cache_use_stale updating timeout error http_502 http_503 http_500; So, when there's no file in cache path, and we made, for example, a HEAD request, in some cases it generates an error. Example with full debug in attachment. # uname -a Linux fe1 2.6.18-194.17.1.el5 #1 SMP Wed Sep 29 12:50:31 EDT 2010 x86_64 x86_64 x86_64 GNU/Linux # nginx -V nginx version: nginx/1.2.3 TLS SNI support disabled configure arguments: --prefix=/var/nginx/ --sbin-path=/usr/sbin/nginx --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/nginx/logs/error.log --http-log-path=/var/nginx/logs/access.log --pid-path=/var/run/nginx.pid --lock-path=/var/run/nginx.lock --http-client-body-temp-path=/var/nginx/tmp/client_body --http-proxy-temp-path=/var/nginx/tmp/proxy_temp --http-fastcgi-temp-path=/var/nginx/tmp/fastcgi_temp --http-uwsgi-temp-path=/var/nginx/tmp/uwsgi_temp --http-scgi-temp-path=/var/nginx/tmp/scgi_temp --user=_nginx --group=_nginx --with-http_ssl_module --with-http_realip_module --with-http_addition_module --with-http_sub_module --with-http_dav_module --with-http_flv_module --with-http_mp4_module --with-http_gzip_static_module --with-http_random_index_module --with-http_secure_link_module --with-http_stub_status_module --with-file-aio --with-ipv6 --add-module=nginx_upstream_hash-0.3.1 --with-cc-opt='-O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic'
on 2012-10-09 16:52
on 2012-10-09 21:37
Hello! On Tue, Oct 09, 2012 at 06:51:21PM +0400, Andrey Feldman wrote: > host: "www.example.ru" > proxy_cache_valid 200 302 301 10m; > proxy_cache_valid 304 10m; > proxy_cache_valid 404 1m; > proxy_cache_use_stale updating timeout error http_502 http_503 http_500; > > So, when there's no file in cache path, and we made, for example, a > HEAD request, in some cases it generates an error. > Example with full debug in attachment. Thank you for report. From debug log it's more or less clear what goes on here, it indeed affects HEAD (as well as other header only) requests while loading cache entry. I'm able to reproduce it here with the following config: location = /proxy { proxy_pass http://127.0.0.1:8080/10m; proxy_cache one; proxy_cache_valid any 5s; sendfile off; output_buffers 1 1024; } It's more or less harmless (i.e. no bad things happen, worst one is log entry). Quick fix would be to do something like this: --- a/src/http/ngx_http_upstream.c +++ b/src/http/ngx_http_upstream.c @@ -2075,6 +2075,8 @@ ngx_http_upstream_send_response(ngx_http r->write_event_handler = ngx_http_request_empty_handler; c->error = 1; + u->pipe->downstream_error = 1; + } else { ngx_http_upstream_finalize_request(r, u, rc); return; Though it probably needs more attention. I'll take a look as time permits. -- Maxim Dounin http://nginx.com/support.html
on 2012-10-10 00:08
Tried your patch, but after few minutes workers starts crashing.
GDB:
Core was generated by `nginx: worker process '.
Program terminated with signal 11, Segmentation fault.
#0 0x000000000040ab19 in ngx_vslprintf (buf=0x7fff9e5f2785 <Address
0x7fff9e5f2785 out of bounds>,
last=0x7fff9e5f2f50 <Address 0x7fff9e5f2f50 out of bounds>,
fmt=<value optimized out>, args=0x7fff9e5f2730) at
src/core/ngx_string.c:178
178 while (*fmt >= '0' && *fmt <= '9') {
on 2012-10-10 13:01
Hello! On Wed, Oct 10, 2012 at 02:07:43AM +0400, Andrey Feldman wrote: > 178 while (*fmt >= '0' && *fmt <= '9') { Strange. What's in backtrace? > > > > > > } else { > http://mailman.nginx.org/mailman/listinfo/nginx -- Maxim Dounin http://nginx.com/support.html
on 2012-10-10 15:44
On Wed, Oct 10, 2012 at 3:01 PM, Maxim Dounin <mdounin@mdounin.ru> wrote: >> 0x7fff9e5f2785 out of bounds>, >> last=0x7fff9e5f2f50 <Address 0x7fff9e5f2f50 out of bounds>, >> fmt=<value optimized out>, args=0x7fff9e5f2730) at >> src/core/ngx_string.c:178 >> 178 while (*fmt >= '0' && *fmt <= '9') { > > Strange. What's in backtrace? Backtrace in attach.
on 2012-10-10 18:51
Hello! On Wed, Oct 10, 2012 at 05:43:20PM +0400, Andrey Feldman wrote: > >> #0 0x000000000040ab19 in ngx_vslprintf (buf=0x7fff9e5f2785 <Address > >> 0x7fff9e5f2785 out of bounds>, > >> last=0x7fff9e5f2f50 <Address 0x7fff9e5f2f50 out of bounds>, > >> fmt=<value optimized out>, args=0x7fff9e5f2730) at > >> src/core/ngx_string.c:178 > >> 178 while (*fmt >= '0' && *fmt <= '9') { > > > > Strange. What's in backtrace? > > Backtrace in attach. Unfortunately, backtrace is completely unreadable. Not sure if it's a result of memory corruption, a result of optimization used, or just a core vs. binary mismatch. -- Maxim Dounin http://nginx.com/support.html
on 2012-10-10 20:07
2012/10/10 Maxim Dounin <mdounin@mdounin.ru>: > Hello! > > Unfortunately, backtrace is completely unreadable. GooglePlus shows the following as attachment: Core was generated by `nginx: worker process '. Program terminated with signal 11, Segmentation fault. #0 0x000000000040ab19 in ngx_vslprintf (buf=0x7fffefda6605 "", last=0x7fffefda6dd0 "\020", fmt=<value optimized out>, args=0x7fffefda65b0) at src/core/ngx_string.c:178 178 while (*fmt >= '0' && *fmt <= '9') { (gdb) bt #0 0x000000000040ab19 in ngx_vslprintf (buf=0x7fffefda6605 "", last=0x7fffefda6dd0 "\020", fmt=<value optimized out>, args=0x7fffefda65b0) at src/core/ngx_string.c:178 #1 0x000000000040692e in ngx_log_error_core (level=3, log=0x14143930, err=14, fmt=0x473e4a "\307", <incomplete sequence \320>) at src/core/ngx_log.c:108 #2 0x000000000040dfb2 in ngx_conf_set_path_slot (cf=0x14224fe8, cmd=<value optimized out>, conf=<value optimized out>) at src/core/ngx_file.c:267 #3 0x00000000141439b8 in ?? () #4 0x0000000014225850 in ?? () #5 0x00002b87720e8250 in ?? () #6 0x0000000014154770 in ?? () #7 0x0000000000449e6f in ngx_http_upstream_send_response (r=0x0, u=0x1) at src/http/ngx_http_upstream.c:2124 #8 ngx_http_upstream_process_header (r=0x0, u=0x1) at src/http/ngx_http_upstream.c:1644 #9 0x00000000141439b8 in ?? () #10 0x0000000000000078 in ?? () #11 0x4a8da000006b3500 in ?? () #12 0x0000000050757962 in ?? () #13 0x00000000141439b8 in ?? () #14 0x00000000141439b8 in ?? () #15 0xfffffffffffffffe in ?? () #16 0x0000000000000078 in ?? () #17 0x00000000141d7828 in ?? () #18 0x0000000050757962 in ?? () #19 0x000000000045106a in ngx_http_file_cache_exists (cache=0x4742a1, c=0x40aa1c) at src/http/ngx_http_file_cache.c:690 #20 0x0000000300000010 in ?? () #21 0x0000000014143930 in ?? () #22 0x000000000068c2c0 in ?? () #23 0x00000000141439b8 in ?? () #24 0x0000000014224c80 in ?? () #25 0x00000000141439b8 in ?? () #26 0x0000000014224a00 in ?? () #27 0x00002b87720e8250 in ?? () #28 0x00000000141d6798 in ?? () #29 0x0000000000000001 in ?? () #30 0x00000000004409d6 in ngx_http_variable_sent_keep_alive (r=<value optimized out>, v=0x78, data=<value optimized out>) at src/http/ngx_http_variables.c:1654 #31 0x000000000000012e in ?? () #32 0x0000000014224c80 in ?? () #33 0x0000000014224c80 in ?? () #34 0x00000000141439b8 in ?? () #35 0x00000000141439b8 in ?? () #36 0x00002b87720e8250 in ?? () #37 0x00000000141d6798 in ?? () #38 0x0000000014224a00 in ?? () #39 0x0000000014224c80 in ?? () #40 0x00000000141439b8 in ?? () #41 0x00002b87720e8250 in ?? () #42 0x00000000141d6798 in ?? () #43 0x000000000044321c in ngx_http_script_regex_start_code (e=0x1) at src/http/ngx_http_script.c:974 #44 0x00000000140610d0 in ?? () #45 0x00000000004762c9 in ngx_http_modern_browser (cf=0x7fffefda6605, cmd=0x0, conf=0x7fffefda6e00) at src/http/modules/ngx_http_browser_module.c:553 #46 0x0000000000000089 in ?? () ---Type <return> to continue, or q <return> to quit--- #47 0x00000000000019b0 in ?? () #48 0xfffffffffffffffc in ?? () #49 0x000000000041fee0 in ngx_event_pipe_read_upstream (p=0x0, do_write=<value optimized out>) at src/event/ngx_event_pipe.c:382 #50 ngx_event_pipe (p=0x0, do_write=<value optimized out>) at src/event/ngx_event_pipe.c:49 #51 0x0000000000001260 in ?? () #52 0x0000000000000062 in ?? () #53 0x00000000004220e9 in ngx_signal_handler (signo=25593) at src/os/unix/ngx_process.c:316 #54 0x0000000000000000 in ?? () Not unreadable, but a little bit confusing to me. Andre Jaenisch
on 2012-10-10 20:28
Hello! On Wed, Oct 10, 2012 at 08:07:27PM +0200, Andre Jaenisch wrote: > #0 0x000000000040ab19 in ngx_vslprintf (buf=0x7fffefda6605 "", > err=14, fmt=0x473e4a "\307", <incomplete sequence \320>) > at src/core/ngx_log.c:108 > #2 0x000000000040dfb2 in ngx_conf_set_path_slot (cf=0x14224fe8, > cmd=<value optimized out>, conf=<value optimized out>) > at src/core/ngx_file.c:267 > #3 0x00000000141439b8 in ?? () > #4 0x0000000014225850 in ?? () > #5 0x00002b87720e8250 in ?? () > #6 0x0000000014154770 in ?? () [...] > Not unreadable, but a little bit confusing to me. I can see gdb output in the attachment, thank you. :) But it's not something I can read (and understand). Obviously backtrace is invalid/corrupted, and I already named several possible reasons. -- Maxim Dounin http://nginx.com/support.html
on 2012-10-10 20:29
On Wednesday 10 October 2012 22:07:27 Andre Jaenisch wrote: > 2012/10/10 Maxim Dounin <mdounin@mdounin.ru>: > > Hello! > > > > Unfortunately, backtrace is completely unreadable. > > GooglePlus shows the following as attachment: > [...] I believe Maxim meant in terms of informativity. The backtrace looks broken. wbr, Valentin V. Bartenev -- http://nginx.com/support.html
on 2012-10-10 20:31
On 10/10/2012 10:27 PM, Maxim Dounin wrote: > But it's not something I can read (and understand). Obviously > backtrace is invalid/corrupted, and I already named several > possible reasons. I made a new build, will try it now and give you normal bt, i hope:)
on 2012-10-10 23:17
Hello! On Wed, Oct 10, 2012 at 11:05:13PM +0400, Andrey Feldman wrote: > >I made a new build, will try it now and give you normal bt, i hope:) > > > #2 0x000000000040e562 in ngx_ext_rename_file (src=0x1bdb2540, to=0x1bdb1c98, ext=0x7fffce909330) at src/core/ngx_file.c:557 > #3 0x000000000045153a in ngx_http_file_cache_update (r=0x1bcbf9e8, tf=0x1bdb2538) at src/http/ngx_http_file_cache.c:938 > #4 0x0000000000446ed6 in ngx_http_upstream_process_request (r=0x1bcbf9e8) at src/http/ngx_http_upstream.c:2686 Ok, thanx, I see what goes on. The patch is indeed wrong, it broke small HEAD requests. Disregard it. -- Maxim Dounin http://nginx.com/support.html
Enable email notification
Enable multi-page viewPlease log in before posting. Registration is free and takes only a minute.
Existing account
(Switch to SSL-encrypted connection)
NEW: Do you have a Google/GoogleMail or Yahoo account? No registration required!
Log in with Google account | Log in with Yahoo account
Log in with Google account | Log in with Yahoo account
No account? Register here.