nginx/1.10.2 crashes in ngx_http_v2_write_handler

Валентин Бартенев vbart на nginx.com
Пт Ноя 25 15:09:49 UTC 2016


On Friday 25 November 2016 18:05:30 Валентин Бартенев wrote:
> 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