post_action crash

Thu Dec 11 11:50:11 MSK 2008

Совсем забыл:

web01:/opt/nginx-global/sbin# ./nginx -V
nginx version: nginx/0.6.32
built by gcc 4.1.2 20061115 (prerelease) (Debian 4.1.1-21)
configure arguments: --with-debug --prefix=/opt/nginx-global
--with-http_ssl_module --with-http_stub_status_module
--add-module=/root/build/nginx/scribd_module
--add-module=/root/build/nginx/upload_module

web01:/opt/nginx-global/sbin# uname -a
Linux web01.scribd.com 2.6.18-6-amd64 #1 SMP Fri Jun 6 05:24:08 UTC
2008 x86_64 GNU/Linux

On Thu, Dec 11, 2008 at 3:49 AM, Alexey Kovyrin <alexey at kovyrin.net> wrote:
> Решил тут заюзать post_action, чтобы после отдачи страницы документа
> юзеру дергать наш сервер аналитики (раньше дергал с бекенда, но щас
> приделали squid перед ним - не выходит, так как 90% запросов отдаются
> из кеша).
>
> Сделал вот так:
>
>    location = @analytics_docview {
>        internal;
>
>        proxy_set_header  X-Analytics-page_type 'document';
>        proxy_set_header  X-Analytics-docview_uri $docview_uri;
>        proxy_set_header  X-Analytics-referer $http_referer;
>        proxy_set_header  X-Analytics-user_agent $http_user_agent;
>        proxy_set_header  X-Analytics-user_ip $remote_addr;
>
>        proxy_connect_timeout 5;
>        proxy_read_timeout 5;
>        proxy_send_timeout 5;
>
>        access_log logs/analytics-api.log main;
>        error_log logs/analytics-api.error.log debug;
>
>        proxy_pass http://XXXXXXX:4000/collector/register_hit;
>    }
>
>    # Distribute queries among different mongrel packs
>    # DOCVIEW page - with caching
>    location /doc/ {
>        access_log logs/scribd.analytics.log analytics;
>        add_header X-Served-By backend;
>
>        set $docview_uri $uri;
>        post_action @analytics_docview;
>        ..........................................
>        ... много всего, в основном
>        ... proxy_pass'ы всякие
>        ..........................................
>    }
>
>
>
> Результат оказался странным:
>
> 1) В еррор логе:
>
> 2008/12/11 02:20:38 [error] 7402#0: *36 could not find named location
> "@analytics_docview" while sending to client, client: 66.249.90.136, s
> erver: *.scribd.com, request: "GET
> /doc/10536/PAN-F49A?query2=WWW.tininfo%40nsdl.co.in HTTP/1.0",
> upstream: "http://10.10.170.18:8080/doc/10
> 536/PAN-F49A?query2=WWW.tininfo%40nsdl.co.in", host: "www.scribd.com"
>
> 2) проверял на трафике в 50+ QPS и за 10-15 секунд получил десяток
> core-файлов :-/
>
> Core was generated by `nginx: worker process       '.
> Program terminated with signal 11, Segmentation fault.
> #0  0x0000000000409e3c in ngx_vsnprintf (buf=0x7fff5291f12c "?*",
> max=<value optimized out>, fmt=<value optimized out>,
>    args=0x7fff5291f030) at src/core/ngx_string.c:426
> 426                         *--p = (u_char) (ui32 % 10 + '0');
> (gdb) bt
> #0  0x0000000000409e3c in ngx_vsnprintf (buf=0x7fff5291f12c "?*",
> max=<value optimized out>, fmt=<value optimized out>,
>    args=0x7fff5291f030) at src/core/ngx_string.c:426
> #1  0x000000000040a219 in ngx_snprintf (buf=0x7fff5291f12c "?*",
> max=140734578683891, fmt=0x2ff <Address 0x2ff out of bounds>)
>    at src/core/ngx_string.c:100
> #2  0x0000000000406353 in ngx_log_error_core (level=4, log=0x7d2f00,
> err=0, fmt=0x45e090 "could not find named location \"%V\"")
>    at src/core/ngx_log.c:98
> #3  0x000000000042901b in ngx_http_named_location (r=0x700640,
> name=0x671d40) at src/http/ngx_http_core_module.c:1934
> #4  0x000000000042b560 in ngx_http_post_action (r=0x700640) at
> src/http/ngx_http_request.c:2560
> #5  0x000000000042cd35 in ngx_http_finalize_request (r=0x700640,
> rc=500) at src/http/ngx_http_request.c:1706
> #6  0x0000000000429028 in ngx_http_named_location (r=0x700640,
> name=0x671d40) at src/http/ngx_http_core_module.c:1937
> #7  0x000000000042b560 in ngx_http_post_action (r=0x700640) at
> src/http/ngx_http_request.c:2560
> #8  0x000000000042cd35 in ngx_http_finalize_request (r=0x700640,
> rc=500) at src/http/ngx_http_request.c:1706
> #9  0x0000000000429028 in ngx_http_named_location (r=0x700640,
> name=0x671d40) at src/http/ngx_http_core_module.c:1937
> #10 0x000000000042b560 in ngx_http_post_action (r=0x700640) at
> src/http/ngx_http_request.c:2560
> #11 0x000000000042cd35 in ngx_http_finalize_request (r=0x700640,
> rc=500) at src/http/ngx_http_request.c:1706
> #12 0x0000000000429028 in ngx_http_named_location (r=0x700640,
> name=0x671d40) at src/http/ngx_http_core_module.c:1937
> #13 0x000000000042b560 in ngx_http_post_action (r=0x700640) at
> src/http/ngx_http_request.c:2560
> #14 0x000000000042cd35 in ngx_http_finalize_request (r=0x700640,
> rc=500) at src/http/ngx_http_request.c:1706
> #15 0x0000000000429028 in ngx_http_named_location (r=0x700640,
> name=0x671d40) at src/http/ngx_http_core_module.c:1937
> #16 0x000000000042b560 in ngx_http_post_action (r=0x700640) at
> src/http/ngx_http_request.c:2560
> #17 0x000000000042cd35 in ngx_http_finalize_request (r=0x700640,
> rc=500) at src/http/ngx_http_request.c:1706
> #18 0x0000000000429028 in ngx_http_named_location (r=0x700640,
> name=0x671d40) at src/http/ngx_http_core_module.c:1937
> #19 0x000000000042b560 in ngx_http_post_action (r=0x700640) at
> src/http/ngx_http_request.c:2560
> .............
> ............тут очень много одинаковых блоков вызовов (злобная такая рекурсия)
> ............
> #39500 0x000000000042cd35 in ngx_http_finalize_request (r=0x700640,
> rc=500) at src/http/ngx_http_request.c:1706
> #39501 0x0000000000429028 in ngx_http_named_location (r=0x700640,
> name=0x671d40) at src/http/ngx_http_core_module.c:1937
> #39502 0x000000000042b560 in ngx_http_post_action (r=0x700640) at
> src/http/ngx_http_request.c:2560
> #39503 0x000000000042cd35 in ngx_http_finalize_request (r=0x700640,
> rc=500) at src/http/ngx_http_request.c:1706
> ---Type <return> to continue, or q <return> to quit---
>
> Дальше мне надоело жать ентер :-)
>
> Внимание, вопрос: что делать? :-(
>
> --
> Alexey Kovyrin
> http://kovyrin.info/
>

-- 
Alexey Kovyrin
http://kovyrin.info/