search

apache / incubator-pagespeed-ngx

Automatic PageSpeed optimization module for Nginx
http://ngxpagespeed.com/
Apache License 2.0
4.36k stars 363 forks source link

nginx worker crash with ngx_pagespeed #1357

Open Hujinyong opened 7 years ago

Hujinyong commented 7 years ago

I have built nginx-1.10.2 with ngx_pagespeed-latest-beta, but nginx will crash sometimes, following is the callstack.

nginx coredump by signal 11 (SIGSEGV) nginx: worker process[0x5701cc] /lib64/libpthread.so.0[0x367f40f7e0] nginx: worker process(ngx_palloc+0x14)[0x491461] nginx: worker process(ngx_http_lua_rebase_path+0x2b)[0x5900fa] nginx: worker process(ngx_http_lua_log_handler_file+0x73)[0x5ade89] nginx: worker process(ngx_http_lua_log_handler+0x108)[0x5add63] nginx: worker process[0x4ed37f] nginx: worker process(ngx_http_free_request+0x172)[0x4ed1ec] nginx: worker process[0x4ebe3f] nginx: worker process[0x4eb2c1] nginx: worker process(ngx_http_finalize_request+0x76b)[0x4eaee7] nginx: worker process(_ZN12net_instaweb12NgxBaseFetch12ReadCallbackERKNS_13ps_event_dataE+0x37e)[0x5c958a] nginx: worker process(_ZN12net_instaweb18NgxEventConnection13ReadAndNotifyEi+0x77)[0x5ca869] nginx: worker process(_ZN12net_instaweb18NgxEventConnection16ReadEventHandlerEP11ngx_event_s+0xfd)[0x5ca773] nginx: worker process[0x4cac8a] nginx: worker process(ngx_process_events_and_timers+0xd3)[0x4bacc9] nginx: worker process[0x4c87d3] nginx: worker process(ngx_spawn_process+0x6bb)[0x4c50cf] nginx: worker process[0x4c827f] nginx: worker process(ngx_master_process_cycle+0x506)[0x4c6e9c] nginx: worker process(main+0x53d)[0x48d5b9]

[root]# addr2line -f 0x5c958a -e /nginx/bin/nginx _ZN12net_instaweb12NgxBaseFetch12ReadCallbackERKNS_13ps_event_dataE /root/nginx-new/nginx/../ext/ngx_pagespeed-latest-beta/src/ngx_base_fetch.cc:198 [root]# addr2line -f 0x5ca869 -e /nginx/bin/nginx _ZN12net_instaweb18NgxEventConnection13ReadAndNotifyEi /root/nginx-new/nginx/../ext/ngx_pagespeed-latest-beta/src/ngx_event_connection.cc:123 [root]# addr2line -f 0x4cac8a -e /nginx/bin/nginx

Below is ngx_pagespeed.conf:

pagespeed on; pagespeed FileCachePath /nginx/ngx_pagespeed_cache; pagespeed RewriteLevel OptimizeForBandwidth; pagespeed XHeaderValue "Powered By ngx_pagespeed";

pagespeed DisableFilters rewrite_css; pagespeed DisableFilters rewrite_javascript;

pagespeed EnableFilters extend_cache; pagespeed EnableFilters rewrite_images; pagespeed EnableFilters convert_jpeg_to_webp; pagespeed EnableFilters convert_to_webp_animated; pagespeed EnableFilters recompress_images; pagespeed EnableFilters resize_images;

pagespeed StatisticsPath /ngx_pagespeed_statistics; pagespeed MessagesPath /ngx_pagespeed_message; pagespeed ConsolePath /ngx_pagespeed_console; pagespeed AdminPath /ngx_pagespeed_admin;

pagespeed Statistics on; pagespeed StatisticsLogging on; pagespeed LogDir /var/log/pagespeed;

oschaaf commented 7 years ago 
_ZN12net_instaweb12NgxBaseFetch12ReadCallbackERKNS_13ps_event_dataE
/root/nginx-new/nginx/../ext/ngx_pagespeed-latest-beta/src/ngx_base_fetch.cc:198

That seems like a bit of an odd line, maybe I'm not looking at the correct version.. could you let me know what ngx_pagespeed version is mentioned in the logs? Is it 1.12.34.2-beta ?

Hujinyong commented 7 years ago

Yes, ngx_pagespeed 1.12.34.2-beta vesion.

(gdb) bt

0 0x0000000000491461 in ngx_palloc (pool=0x0, size=31) at src/core/ngx_palloc.c:126

1 0x00000000005900fa in ngx_http_lua_rebase_path (pool=0x0, src=0x7f5fd31fa076 "/nginx/conf/global/lua/log.lua", len=30) at ../ext/ngx_http_lua_module-v0.10.6/src/ngx_http_lua_util.c:377

2 0x00000000005ade89 in ngx_http_lua_log_handler_file (r=0x7f5f3b16f3b0) at ../ext/ngx_http_lua_module-v0.10.6/src/ngx_http_lua_logby.c:144

3 0x00000000005add63 in ngx_http_lua_log_handler (r=0x7f5f3b16f3b0) at ../ext/ngx_http_lua_module-v0.10.6/src/ngx_http_lua_logby.c:98

4 0x00000000004ed37f in ngx_http_log_request (r=0x7f5f3b16f3b0) at src/http/ngx_http_request.c:3511

5 0x00000000004ed1ec in ngx_http_free_request (r=0x7f5f3b16f3b0, rc=0) at src/http/ngx_http_request.c:3458

6 0x00000000004ebe3f in ngx_http_set_keepalive (r=0x7f5f3b16f3b0) at src/http/ngx_http_request.c:2896

7 0x00000000004eb2c1 in ngx_http_finalize_connection (r=0x7f5f3b16f3b0) at src/http/ngx_http_request.c:2545

8 0x00000000004eaee7 in ngx_http_finalize_request (r=0x7f5f3b16f3b0, rc=0) at src/http/ngx_http_request.c:2441

9 0x00000000005c958a in net_instaweb::NgxBaseFetch::ReadCallback (data=...) at ../ext/ngx_pagespeed-latest-beta/src/ngx_base_fetch.cc:196

10 0x00000000005ca869 in net_instaweb::NgxEventConnection::ReadAndNotify (fd=51) at ../ext/ngx_pagespeed-latest-beta/src/ngx_event_connection.cc:122

11 0x00000000005ca773 in net_instaweb::NgxEventConnection::ReadEventHandler (ev=0x7f5f544c77f0) at ../ext/ngx_pagespeed-latest-beta/src/ngx_event_connection.cc:83

12 0x00000000004bd36d in ngx_event_process_posted (cycle=0x17e0d30, posted=0x15b9680 ) at src/event/ngx_event_posted.c:33

13 0x00000000004bad5c in ngx_process_events_and_timers (cycle=0x17e0d30) at src/event/ngx_event.c:259

14 0x00000000004c87d3 in ngx_worker_process_cycle (cycle=0x17e0d30, data=0x7) at src/os/unix/ngx_process_cycle.c:753

15 0x00000000004c50cf in ngx_spawn_process (cycle=0x17e0d30, proc=0x4c86de , data=0x7, name=0xdd456b "worker process", respawn=-3)

at src/os/unix/ngx_process.c:198

16 0x00000000004c760f in ngx_start_worker_processes (cycle=0x17e0d30, n=8, type=-3) at src/os/unix/ngx_process_cycle.c:358

17 0x00000000004c6c2c in ngx_master_process_cycle (cycle=0x17e0d30) at src/os/unix/ngx_process_cycle.c:130

18 0x000000000048d5b9 in main (argc=3, argv=0x7ffcafc6ff28) at src/core/nginx.c:367

(gdb) frame 2

2 0x00000000005ade89 in ngx_http_lua_log_handler_file (r=0x7f5f3b16f3b0) at ../ext/ngx_http_lua_module-v0.10.6/src/ngx_http_lua_logby.c:144

144 script_path = ngx_http_lua_rebase_path(r->pool, eval_src.data, (gdb) p r->pool $1 = (ngx_pool_t *) 0x0 (gdb) frame 8

8 0x00000000004eaee7 in ngx_http_finalize_request (r=0x7f5f3b16f3b0, rc=0) at src/http/ngx_http_request.c:2441

2441 ngx_http_finalize_connection(r); (gdb) p r->pool $2 = (ngx_pool_t *) 0x0 (gdb) frame 8

8 0x00000000004eaee7 in ngx_http_finalize_request (r=0x7f5f3b16f3b0, rc=0) at src/http/ngx_http_request.c:2441

2441 ngx_http_finalize_connection(r); (gdb) p r->pool $3 = (ngx_pool_t *) 0x0 (gdb) p r->pool

The reason is member variable "pool" of r is a NULL pointer.

jmarantz commented 7 years ago

The obvious question given that stack, is whether you might be running out of memory.

And if you are, his much is being consumed by PageSpeed, Lua, or something else.

What do you Lua scripts do? What is your PageSpeed cache configuration? Do you have other in memory caches configured? Is there something else consuming memory on your machine?

Josh

On Jan 12, 2017 2:31 AM, "Hujinyong" notifications@github.com wrote:

(gdb) bt

0 0x0000000000491461 in ngx_palloc (pool=0x0, size=31) at

src/core/ngx_palloc.c:126

1 https://github.com/pagespeed/ngx_pagespeed/issues/1 0x00000000005900fa

in ngx_http_lua_rebase_path (pool=0x0, src=0x7f5fd31fa076 "/nginx/conf/global/lua/log.lua", len=30) at ../ext/ngx_http_lua_module-v0. 10.6/src/ngx_http_lua_util.c:377

2 https://github.com/pagespeed/ngx_pagespeed/pull/2 0x00000000005ade89

in ngx_http_lua_log_handler_file (r=0x7f5f3b16f3b0) at ../ext/ngx_http_lua_module-v0.10.6/src/ngx_http_lua_logby.c:144

3 https://github.com/pagespeed/ngx_pagespeed/issues/3 0x00000000005add63

in ngx_http_lua_log_handler (r=0x7f5f3b16f3b0) at ../ext/ngx_http_lua_module-v0.10.6/src/ngx_http_lua_logby.c:98

4 https://github.com/pagespeed/ngx_pagespeed/pull/4 0x00000000004ed37f

in ngx_http_log_request (r=0x7f5f3b16f3b0) at src/http/ngx_http_request.c: 3511

5 https://github.com/pagespeed/ngx_pagespeed/pull/5 0x00000000004ed1ec

in ngx_http_free_request (r=0x7f5f3b16f3b0, rc=0) at src/http/ngx_http_request.c:3458

6 https://github.com/pagespeed/ngx_pagespeed/issues/6 0x00000000004ebe3f

in ngx_http_set_keepalive (r=0x7f5f3b16f3b0) at src/http/ngx_http_request.c: 2896

7 https://github.com/pagespeed/ngx_pagespeed/pull/7 0x00000000004eb2c1

in ngx_http_finalize_connection (r=0x7f5f3b16f3b0) at src/http/ngx_http_request.c:2545

8 https://github.com/pagespeed/ngx_pagespeed/pull/8 0x00000000004eaee7

in ngx_http_finalize_request (r=0x7f5f3b16f3b0, rc=0) at src/http/ngx_http_request.c:2441

9 https://github.com/pagespeed/ngx_pagespeed/pull/9 0x00000000005c958a

in net_instaweb::NgxBaseFetch::ReadCallback (data=...) at ../ext/ngx_pagespeed-latest-beta/src/ngx_base_fetch.cc:196

10 https://github.com/pagespeed/ngx_pagespeed/pull/10 0x00000000005ca869

in net_instaweb::NgxEventConnection::ReadAndNotify (fd=51) at ../ext/ngx_pagespeed-latest-beta/src/ngx_event_connection.cc:122

11 https://github.com/pagespeed/ngx_pagespeed/pull/11 0x00000000005ca773

in net_instaweb::NgxEventConnection::ReadEventHandler (ev=0x7f5f544c77f0) at ../ext/ngx_pagespeed-latest-beta/src/ngx_event_connection.cc:83

12 https://github.com/pagespeed/ngx_pagespeed/issues/12

0x00000000004bd36d in ngx_event_process_posted (cycle=0x17e0d30, posted=0x15b9680 ) at src/event/ngx_event_posted.c:33

13 https://github.com/pagespeed/ngx_pagespeed/pull/13 0x00000000004bad5c

in ngx_process_events_and_timers (cycle=0x17e0d30) at src/event/ngx_event.c:259

14 https://github.com/pagespeed/ngx_pagespeed/issues/14

0x00000000004c87d3 in ngx_worker_process_cycle (cycle=0x17e0d30, data=0x7) at src/os/unix/ngx_process_cycle.c:753

15 https://github.com/pagespeed/ngx_pagespeed/pull/15 0x00000000004c50cf

in ngx_spawn_process (cycle=0x17e0d30, proc=0x4c86de

, data=0x7, name=0xdd456b "worker process", respawn=-3) at src/os/unix/ngx_process.c:198 #16 0x00000000004c760f in ngx_start_worker_processes (cycle=0x17e0d30, n=8, type=-3) at src/os/unix/ngx_process_cycle.c:358 #17 0x00000000004c6c2c in ngx_master_process_cycle (cycle=0x17e0d30) at src/os/unix/ngx_process_cycle.c:130 #18 0x000000000048d5b9 in main (argc=3, argv=0x7ffcafc6ff28) at src/core/nginx.c:367 (gdb) frame 2 #2 0x00000000005ade89 in ngx_http_lua_log_handler_file (r=0x7f5f3b16f3b0) at ../ext/ngx_http_lua_module-v0.10.6/src/ngx_http_lua_logby.c:144 144 script_path = ngx_http_lua_rebase_path(r->pool, eval_src.data, (gdb) p r->pool $1 = (ngx_pool_t *) 0x0 (gdb) frame 8 #8 0x00000000004eaee7 in ngx_http_finalize_request (r=0x7f5f3b16f3b0, rc=0) at src/http/ngx_http_request.c:2441 2441 ngx_http_finalize_connection(r); (gdb) p r->pool $2 = (ngx_pool_t *) 0x0 (gdb) frame 8 #8 0x00000000004eaee7 in ngx_http_finalize_request (r=0x7f5f3b16f3b0, rc=0) at src/http/ngx_http_request.c:2441 2441 ngx_http_finalize_connection(r); (gdb) p r->pool $3 = (ngx_pool_t *) 0x0 (gdb) p r->pool The reason is member variable "pool" or r is a NULL pointer. — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub , or mute the thread .
Hujinyong commented 7 years ago

Lua script only logs some nginx variables, I disabled the nginx-lua-module, the crash still occurs. Nginx server has 96G memory.

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 27571 nobody 20 0 2476m 83m 44m D 52.6 0.1 0:11.47 nginx 25822 nobody 20 0 2570m 235m 175m D 12.6 0.2 1:57.46 nginx 27026 nobody 20 0 2557m 155m 104m D 11.9 0.2 0:36.97 nginx 27635 nobody 20 0 2474m 65m 36m D 10.2 0.1 0:03.07 nginx 24664 nobody 20 0 2566m 264m 200m D 9.9 0.3 3:05.04 nginx 27215 nobody 20 0 2555m 128m 87m D 9.3 0.1 0:20.03 nginx 24170 nobody 20 0 2574m 304m 225m D 7.6 0.3 3:41.82 nginx 27609 nobody 20 0 2494m 114m 66m D 6.6 0.1 0:06.10 nginx

Following is all of my ngx_pagespeed config:

pagespeed on; pagespeed FileCachePath /nginx/ngx_pagespeed_cache; pagespeed RewriteLevel OptimizeForBandwidth; pagespeed XHeaderValue "Powered By ngx_pagespeed";

pagespeed DisableFilters rewrite_css; pagespeed DisableFilters rewrite_javascript;

pagespeed EnableFilters extend_cache; pagespeed EnableFilters rewrite_images; pagespeed EnableFilters convert_jpeg_to_webp; pagespeed EnableFilters convert_to_webp_animated; pagespeed EnableFilters recompress_images; pagespeed EnableFilters resize_images;

pagespeed StatisticsPath /ngx_pagespeed_statistics; pagespeed MessagesPath /ngx_pagespeed_message; pagespeed ConsolePath /ngx_pagespeed_console; pagespeed AdminPath /ngx_pagespeed_admin;

pagespeed Statistics on; pagespeed StatisticsLogging on; pagespeed LogDir /var/log/pagespeed;

oschaaf commented 7 years ago

Could you post a backtrace of the crash with with the lua module taken out of the equation? Seeing the contents of error.log leading up to the crash (with the log level set to debug) would also be very helpful.

Hujinyong commented 7 years ago

2017/01/13 11:26:05 [debug] 19963#0: posix_memalign: 00007F137E998310:512 @16 2017/01/13 11:26:05 [debug] 19963#0: 1023909 accept: 106.115.34.193:20803 fd:241 2017/01/13 11:26:05 [debug] 19963#0: 1023909 event timer add: 241: 10000:1484277975473 2017/01/13 11:26:05 [debug] 19963#0: 1023909 reusable connection: 1 2017/01/13 11:26:05 [debug] 19963#0: 1023909 epoll add event: fd:241 op:1 ev:80002001 2017/01/13 11:26:05 [debug] 19963#0: accept() not ready (11: Resource temporarily unavailable) 2017/01/13 11:26:05 [debug] 19963#0: posted event 00007F1394C91A90 2017/01/13 11:26:05 [debug] 19963#0: delete posted event 00007F1394C91A90 2017/01/13 11:26:05 [debug] 19963#0: pagespeed [00007F137F08BEE0] event: D. bf:00007F137EE29790 (html transform) - refcnt:0 - det: Y 2017/01/13 11:26:05 [debug] 19963#0: worker cycle 2017/01/13 11:26:05 [debug] 19963#0: accept mutex locked 2017/01/13 11:26:05 [debug] 19963#0: epoll timer: 196 2017/01/13 11:26:05 [debug] 19963#0: epoll: fd:74 ev:0001 d:00007F1394E7E091 2017/01/13 11:26:05 [debug] 19963#0: 1023907 post event 00007F1394C96290 2017/01/13 11:26:05 [debug] 19963#0: timer delta: 1 2017/01/13 11:26:05 [debug] 19963#0: posted event 00007F1394C96290 2017/01/13 11:26:05 [debug] 19963#0: 1023907 delete posted event 00007F1394C96290 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http wait request handler 2017/01/13 11:26:05 [debug] 19963#0: 1023907 malloc: 00007F137E53DCF0:1024 2017/01/13 11:26:05 [debug] 19963#0: 1023907 recv: fd:74 261 of 1024 2017/01/13 11:26:05 [debug] 19963#0: 1023907 reusable connection: 0 2017/01/13 11:26:05 [debug] 19963#0: 1023907 posix_memalign: 00007F137E50D360:4096 @16 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http process request line 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http request line: "GET /zhnews408/img/wm_20.gif HTTP/1.1" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http uri: "/zhnews408/img/wm_20.gif" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http args: "" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http exten: "gif" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 posix_memalign: 00007F137F4E5E70:4096 @16 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http process request header line 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http header: "Host: www.zhxww.net" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http header: "Referer: http://www.zhxww.net/zhnews408/" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http header: "If-None-Match: "b41582ff4f3ac91:beda"" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http header: "If-Modified-Since: Thu, 30 Oct 2008 05:26:02 GMT" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http header: "PageSpeed: off" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http header: "User-Agent: Serf/1.3.8 (mod_pagespeed/1.12.34.2-0)" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http header done 2017/01/13 11:26:05 [debug] 19963#0: 1023907 event timer del: 74: 1484277975473 2017/01/13 11:26:05 [debug] 19963#0: 1023907 rewrite phase: 0 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: "/" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: "yundun_domains_key" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: "yundun_redis_keys" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: "yundun_ssl_config" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: "yundun_system_monitor" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ "/(yundun_get_verify_pic)$" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ "/(yundun_chk_captcha)$" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ "/yundun_setcookies(/.)" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ "/yundun_cache_purge(/.)" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ "/yundun_cache_static(/.)" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ ".pagespeed.([a-z].)?[a-z]{2}.[^.]{10}.[^.]+" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ "^/ngx_pagespeed_static/" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ "^/ngx_pagespeed_beacon$" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ "^/ngx_pagespeed_global_admin" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 test location: ~ "^/ngx_pagespeed_admin" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 using configuration "/" 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http cl:-1 max:104857600 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http cleanup add: 00007F137F4E6280 2017/01/13 11:26:05 [debug] 19963#0: shmtx lock 2017/01/13 11:26:05 [debug] 19963#0: shmtx unlock 2017/01/13 11:26:05 [debug] 19963#0: shmtx lock 2017/01/13 11:26:05 [debug] 19963#0: shmtx unlock 2017/01/13 11:26:05 [debug] 19963#0: shmtx lock 2017/01/13 11:26:05 [debug] 19963#0: shmtx unlock 2017/01/13 11:26:05 [debug] 19963#0: shmtx lock 2017/01/13 11:26:05 [debug] 19963#0: shmtx unlock 2017/01/13 11:26:05 [debug] 19963#0: 1023907 add cleanup: 00007F137F4E62A8 2017/01/13 11:26:05 [debug] 19963#0: 1023907 post rewrite phase: 4 2017/01/13 11:26:05 [debug] 19963#0: 1023907 generic phase: 5 2017/01/13 11:26:05 [debug] 19963#0: 1023907 generic phase: 6 2017/01/13 11:26:05 [debug] 19963#0: 1023907 access phase: 7 2017/01/13 11:26:05 [debug] 19963#0: 1023907 access phase: 8 2017/01/13 11:26:05 [debug] 19963#0: 1023907 access phase: 9 2017/01/13 11:26:05 [debug] 19963#0: shmtx lock 2017/01/13 11:26:05 [debug] 19963#0: shmtx unlock 2017/01/13 11:26:05 [debug] 19963#0: 1023907 post access phase: 10 2017/01/13 11:26:05 [debug] 19963#0: 1023907 pagespeed phase: 11 2017/01/13 11:26:05 [debug] 19963#0: 1023907 http pagespeed handler "/zhnews408/img/wm_20.gif" 2017/01/13 11:26:07 [debug] 19963#0: 1023909 write old buf t:1 f:0 00007F137E743070, pos 00007F137E743070, size: 376 file: 0, size: 0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 write new buf t:1 f:0 00007F137E743370, pos 00007F137E743370, size: 4 file: 0, size: 0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 write new buf t:1 f:0 00007F137E743238, pos 00007F137E743238, size: 183 file: 0, size: 0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 posix_memalign: 00007F137EFEFD30:4096 @16 2017/01/13 11:26:07 [debug] 19963#0: 1023909 write new buf t:0 f:0 0000000000000000, pos 0000000000DDCBDD, size: 7 file: 0, size: 0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http write filter: l:1 f:1 s:570 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http write filter limit 0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 writev: 570 of 570 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http write filter 0000000000000000 2017/01/13 11:26:07 [debug] 19963#0: pagespeed [00007F138C5BBB20] ps_base_fetch_handler() returned 0 for H 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http finalize request: 0, "/facebox/loading.gif?" a:1, c:1 2017/01/13 11:26:07 [debug] 19963#0: 1023909 set http keepalive handler 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http close request 2017/01/13 11:26:07 [debug] 19963#0: 1023909 cleanup http upstream request: "/facebox/loading.gif" 2017/01/13 11:26:07 [debug] 19963#0: 1023909 finalize http upstream request: -4 2017/01/13 11:26:07 [debug] 19963#0: 1023909 finalize http proxy request 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free keepalive peer 2017/01/13 11:26:07 [debug] 19963#0: 1023909 close http upstream connection: 739 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F137F314200, unused: 48 2017/01/13 11:26:07 [debug] 19963#0: 1023909 event timer del: 739: 1484278027303 2017/01/13 11:26:07 [debug] 19963#0: 1023909 reusable connection: 0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http upstream temp fd: -1 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http finalize request: -4, "/facebox/loading.gif?" a:1, c:1 2017/01/13 11:26:07 [debug] 19963#0: 1023909 event timer add: 241: 5000:1484277972509 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http lingering close handler 2017/01/13 11:26:07 [debug] 19963#0: 1023909 recv: fd:241 0 of 4096 2017/01/13 11:26:07 [debug] 19963#0: 1023909 lingering read: 0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http request count:1 blk:0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http close request 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http log handler 2017/01/13 11:26:07 [debug] 19963#0: 1023909 run cleanup: 00007F137EAC9850 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F137E891710 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F138C376EA0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F138C5BBAD0, unused: 0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F137EAC9400, unused: 2 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F137E742410, unused: 8 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F137EFEFD30, unused: 4009 2017/01/13 11:26:07 [debug] 19963#0: 1023909 close http connection: 241 2017/01/13 11:26:07 [debug] 19963#0: 1023909 event timer del: 241: 1484277972509 2017/01/13 11:26:07 [debug] 19963#0: 1023909 reusable connection: 0 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F138D29B090 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F137E998310, unused: 112 2017/01/13 11:26:07 [debug] 19963#0: 1023909 http log handler 2017/01/13 11:26:07 [debug] 19963#0: 1023909 epoll add event: fd:-1 op:1 ev:80002001 2017/01/13 11:26:07 [debug] 19963#0: 1023909 close http connection: -1 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F138D29B090 2017/01/13 11:26:07 [debug] 19963#0: 1023909 free: 00007F137E998310, unused: 18446604585822793976

The following stack shows nginx worker crashed in function ngx_destroy_pool.

nginx: worker process(ngx_destroy_pool+0x1b2)[0x49135f] nginx: worker process(ngx_http_close_connection+0xca)[0x4ed466] nginx: worker process[0x4ebe78] nginx: worker process[0x4eb2cd] nginx: worker process(ngx_http_finalize_request+0x76b)[0x4eaef3] nginx: worker process(_ZN12net_instaweb12NgxBaseFetch12ReadCallbackERKNS_13ps_event_dataE+0x449)[0x5c9679] nginx: worker process(_ZN12net_instaweb18NgxEventConnection13ReadAndNotifyEi+0x77)[0x5ca959] nginx: worker process(_ZN12net_instaweb18NgxEventConnection16ReadEventHandlerEP11ngx_event_s+0xfd)[0x5ca863] nginx: worker process(ngx_event_process_posted+0x109)[0x4bd379] nginx: worker process(ngx_process_events_and_timers+0x166)[0x4bad68] nginx: worker process[0x4c87df] nginx: worker process(ngx_spawn_process+0x6bb)[0x4c50db] nginx: worker process[0x4c761b] nginx: worker process(ngx_master_process_cycle+0x296)[0x4c6c38] nginx: worker process(main+0x53d)[0x48d5b9] /lib64/libc.so.6(__libc_start_main+0xfd)[0x367f01ed1d] nginx: worker process[0x48ce41]

oschaaf commented 7 years ago

Thanks. Unfortunately, I'm not sure yet what leads up to the attempt to double free, and I can't force something similar to happen on my dev machine given just the nginx/ngx_pagespeed version.

What does nginx -V show? And would it be possible to transfer your complete configuration and maybe the crash dump + nginx binary to me so I can inspect that more closely? My email is oschaaf@we-amp.com

karlisk commented 7 years ago

When did the problems start appearing? Was it after an upgrade of NGINX or Pagespeed... or did it just randomly started happening out of the blue?