nginx/1.10.2 crashes in ngx_http_v2_write_handler

Dmitriy M. endo.mulo на gmail.com
Пт Ноя 25 08:56:45 UTC 2016


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