nginx/1.10.2 crashes in ngx_http_v2_write_handler
Валентин Бартенев
vbart на nginx.com
Пт Ноя 25 15:05:30 UTC 2016
On Friday 25 November 2016 10:56:45 Dmitriy M. wrote:
> 25 ноября 2016 г., 10:31 пользователь Dmitriy M. <endo.mulo на gmail.com> написал:
> > 20 ноября 2016 г., 18:22 пользователь Валентин Бартенев
> > <vbart на nginx.com> написал:
> >> On Sunday 20 November 2016 19:17:12 Валентин Бартенев wrote:
> >>> On Sunday 20 November 2016 17:58:45 Dmitriy M. wrote:
> >>> [..]
> >>> >
> >>> > К сожалению, это практически невозможно. Сервису необходимы
> >>> > перечисленные при сборке модули, без них возможности проверки под
> >>> > нагрузкой нет. Способа воспроизведения нет, они происходят
> >>> > неконтролируемо и очень редко (1-2 краша в сутки на ряде разных
> >>> > клонированных сетапов).
> >>> >
> >>> > Могу дополнить, что эти же модули (набор модулей, но да
> >>> > headers-more-nginx-module-84241e4 и libressl были обновлены) были
> >>> > вкомпилены в nginx-1.9.12 , с которым на протяжении более полугода
> >>> > крашей небыло, конфигурация nginx.conf существенно не менялась.
> >>> >
> >>> > Попробую собрать с предыдущими версиями модулей
> >>> > (openresty-headers-more-nginx-module-0c6e05d и libressl-2.3.6) и без
> >>> > оптимизаций кода для дебаггинга.
> >>> > https://www.nginx.com/resources/wiki/start/topics/tutorials/debugging/
> >>>
> >>> То, что модули раньше работали - абсолютно не показатель. Многие сторонние
> >>> модули славятся тем, что лезут во внутренние структуры nginx, используя их
> >>> не по назначению. Как результат, такие модули могут поломать nginx при любых
> >>> изменениях в его внутренних механизмах.
> >>>
> >>> Между версией 1.10.1 и 1.10.2 произошли существенные изменения в обработке
> >>> тела запроса в модуле http/2.
> >>>
> >>> Бектрейс, который вы привели - не содержит какой-либо полезной информации
> >>> для дебага. Ошибка, послужившая причиной падения, произошла в другом месте,
> >>> на другой итерации цикла обработки событий. А то, что видно на бэктрейсе -
> >>> лишь следствие.
> >>>
> >>> Можно попытаться получить debug-лог перед падением:
> >>> http://nginx.org/ru/docs/debugging_log.html#memory
> >>>
> >>> Смотрите раздел про запись его в буфер в памяти.
> >>>
> >> [..]
> >>
> >> И в дополнение к предыдущему письму, а вы уверены, что у вас
> >> nginx-upload-progress-module вообще с HTTP/2 корректно работает?
> >>
> >> Судя по тому же тикету на github, он и не должен:
> >> https://github.com/masterzen/nginx-upload-progress-module/issues/45
> >>
> >> Интересно также, что вы делаете с помощью headers-more-nginx-module,
> >> что не получается сделать стандартными средствами nginx?
> >>
> >> --
> >> Валентин Бартенев
> >
> > Добрый день, Валентин
> >
>
> и вдогонку прошлому письму, core номер два, тоже на сетапе без сторонних модулей
> nginx -V
> nginx version: nginx/1.10.2
> built with LibreSSL 2.4.4
> TLS SNI support enabled
> configure arguments: --prefix=/usr/local/etc/nginx --with-cc-opt='-I
> /usr/local/include' --with-ld-opt='-L /usr/local/lib -lrt'
> --conf-path=/usr/local/etc/nginx/nginx.conf
> --sbin-path=/usr/local/sbin/nginx --pid-path=/var/run/nginx.pid
> --error-log-path=/var/log/nginx/error.log --user=www --group=www
> --modules-path=/usr/local/libexec/nginx
> --http-client-body-temp-path=/var/tmp/nginx/client_body_temp
> --http-fastcgi-temp-path=/var/tmp/nginx/fastcgi_temp
> --http-proxy-temp-path=/var/tmp/nginx/proxy_temp
> --http-scgi-temp-path=/var/tmp/nginx/scgi_temp
> --http-uwsgi-temp-path=/var/tmp/nginx/uwsgi_temp
> --http-log-path=/var/log/nginx/access.log --with-http_realip_module
> --with-http_stub_status_module --with-pcre --with-threads
> --with-http_ssl_module --with-http_v2_module
> --with-openssl=./libressl-2.4.4 --with-debug
>
>
> #0 0x00000000004fd0da in ngx_http_v2_write_handler (wev=0x85144f380)
> at src/http/v2/ngx_http_v2.c:435
> 435 ngx_queue_remove(q);
> [New Thread 801c16000 (LWP 100771/<unknown>)]
> (gdb) i locals
> rc = -2
> q = (ngx_queue_t *) 0x85d2bdcb0
> c = (ngx_connection_t *) 0x84a4b0b80
> stream = (ngx_http_v2_stream_t *) 0x85144f380
> h2c = (ngx_http_v2_connection_t *) 0x853bf7a20
> Current language: auto; currently minimal
> (gdb) p q
> $1 = (ngx_queue_t *) 0x85d2bdcb0
> (gdb) p *q
> $2 = {prev = 0x3938386138313962, next = 0x85e7d7cb0}
> (gdb) p c
> $3 = (ngx_connection_t *) 0x84a4b0b80
> (gdb) p *c
> $4 = {data = 0x853bf7a20, read = 0x84f44f380, write = 0x85144f380, fd
> = 6509, recv = 0x491af0 <ngx_ssl_recv>, send = 0x491db0
> <ngx_ssl_write>, recv_chain = 0x492240 <ngx_ssl_recv_chain>,
> send_chain = 0x4923b0 <ngx_ssl_send_chain>,
> listening = 0x801de93d0, sent = 2319718, log = 0x8562a2460, pool =
> 0x8562a2400, type = 1, sockaddr = 0x8562a2450, socklen = 16, addr_text
> = {len = 12, data = 0x8562a24b0 "92.60.186.11\b"}, proxy_protocol_addr
> = {len = 0, data = 0x0},
> ssl = 0x8562a2520, local_sockaddr = 0x801c99d28, local_socklen = 16,
> buffer = 0x0, queue = {prev = 0x0, next = 0x0}, number = 25442656,
> requests = 202, buffered = 1, log_error = 2, unexpected_eof = 1,
> timedout = 0, error = 0,
> destroyed = 0, idle = 0, reusable = 0, close = 0, shared = 0,
> sendfile = 0, sndlowat = 0, tcp_nodelay = 1, tcp_nopush = 0,
> need_last_buf = 0, sendfile_task = 0x0}
> (gdb) fr
> #0 0x00000000004fd0da in ngx_http_v2_write_handler (wev=0x85144f380)
> at src/http/v2/ngx_http_v2.c:435
> 435 ngx_queue_remove(q);
> (gdb) l
> 430 }
> 431
> 432 while (!ngx_queue_empty(&h2c->posted)) {
> 433 q = ngx_queue_head(&h2c->posted);
> 434
> 435 ngx_queue_remove(q);
> 436
> 437 stream = ngx_queue_data(q, ngx_http_v2_stream_t, queue);
> 438
> 439 stream->handled = 0;
> (gdb) p h2c
> $5 = (ngx_http_v2_connection_t *) 0x853bf7a20
> (gdb) p *h2c
> $6 = {connection = 0x84a4b0b80, http_connection = 0x8562a24c0,
> processing = 3, send_window = 10055604, recv_window = 2147445557,
> init_window = 131072, frame_size = 16384, waiting = {prev =
> 0x853bf7a58, next = 0x853bf7a58}, state = {
> sid = 415, length = 4, padding = 0, flags = 0, incomplete = 0,
> keep_pool = 0, parse_name = 0, parse_value = 0, index = 0, header =
> {name = {len = 25, data = 0x85df80ccb "upgrade-insecure-requests"},
> value = {len = 1,
> data = 0x85dd4e7fb "1"}}, header_limit = 14373, field_state =
> 0 '\0', field_start = 0x85dd4e7fb "1", field_end = 0x85dd4e7fc "",
> field_rest = 0, pool = 0x0, stream = 0x0, buffer = 0x853bf7ae0 "",
> buffer_used = 0,
> handler = 0x500660 <ngx_http_v2_state_head>}, hpack = {entries =
> 0x85eb43e00, added = 360, deleted = 311, reused = 307, allocated = 64,
> size = 4096, free = 10,
> storage = 0x85abfc000
> "etracknew=1442820681065738.1480063024.205cookieloginhesh=68224ef0f0f562b069105a5a84d3bf43bb4f4beacookietracknew=1442820681065738.1480063033.205cookie__utmb=69692428.27.9.1480062955667refererhttps://ma"...,
> pos = 0x85abfc30f
> "(organic)|utmcmd=organic|utmctr=ukrcookie__utmv=183793058.|1=Users=Registered=1^2=Gender=f=1^3=Age=41=1^4=ID=40d191c1723959071990c7556fae5c92=1cookieuid=1CpM/FfSfoQYenDjBEOlAg==cookietrackss=147496897"...},
> pool = 0x860d2b000, free_frames = 0x860d2b490, free_fake_connections
> = 0x0, streams_index = 0x853d22820, last_out = 0x857066188, posted =
> {prev = 0x85e7d7cb0, next = 0x85d2bdcb0}, dependencies = {prev =
> 0x8575e6bb0,
> next = 0x853d229a0}, closed = {prev = 0x855bffb80, next =
> 0x858b1f900}, last_sid = 415, closed_nodes = 31, settings_ack = 1,
> blocked = 1}
> (gdb) p h2c->posted
> $7 = {prev = 0x85e7d7cb0, next = 0x85d2bdcb0}
> (gdb) p h2c->posted.next
> $8 = (ngx_queue_t *) 0x85d2bdcb0
> (gdb) p *h2c->posted.next
> $9 = {prev = 0x3938386138313962, next = 0x85e7d7cb0}
>
>
> core файл и исполнительный тоже есть, debug log был включен, если
> нужны дополнительные данные - попробуем извлечь.
Дебаг-лог и хотелось бы увидеть. Поскольку ошибка происходит на самом деле
не там, где оно падает, то нужен лог событий, а бэктрейс просто не содержит
необходимой информации.
--
Валентин Бартенев
Подробная информация о списке рассылки nginx-ru