nginx/1.10.2 crashes in ngx_http_v2_write_handler
Dmitriy M.
endo.mulo на gmail.com
Пт Ноя 25 08:31:45 UTC 2016
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?
>
> --
> Валентин Бартенев
Добрый день, Валентин
прошу прощения за задержку в ответе - проверяли разные комбинации nginx.
nginx-upload-progress-module и headers-more-nginx-module были у нас в
конфигурации скорее исторически, необходимости в них, как оказалось,
нет.
Поэтому, создали конфигурацию без сторонних модулей , с одной простой
функцией - приём SSL HTTP и проксирование:
# 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
И nginx продолжает крашится (некоторые приватные данные были заменены на ХХХ):
#0 ngx_http_v2_write_handler (wev=0x851458eb0) at src/http/v2/ngx_http_v2.c:444
444 wev = stream->request->connection->write;
[New Thread 801c16000 (LWP 100649/<unknown>)]
(gdb) bt
#0 ngx_http_v2_write_handler (wev=0x851458eb0) at src/http/v2/ngx_http_v2.c:444
#1 0x000000000048cb23 in ngx_kqueue_process_events
(cycle=0x801de9050, timer=213, flags=1) at
src/event/modules/ngx_kqueue_module.c:669
#2 0x000000000047b3fa in ngx_process_events_and_timers
(cycle=0x801de9050) at src/event/ngx_event.c:242
#3 0x0000000000489b9a in ngx_worker_process_cycle (cycle=0x801de9050,
data=0x1) at src/os/unix/ngx_process_cycle.c:753
#4 0x0000000000486cad in ngx_spawn_process (cycle=0x801de9050,
proc=0x489a90 <ngx_worker_process_cycle>, data=0x1, name=0x6a6192
"worker process", respawn=-4) at src/os/unix/ngx_process.c:198
#5 0x0000000000488890 in ngx_start_worker_processes
(cycle=0x801de9050, n=8, type=-4) at
src/os/unix/ngx_process_cycle.c:358
#6 0x0000000000488657 in ngx_master_process_cycle (cycle=0x801de9050)
at src/os/unix/ngx_process_cycle.c:243
#7 0x0000000000447672 in main (argc=1, argv=0x7fffffffebb8) at
src/core/nginx.c:367
Current language: auto; currently minimal
(gdb) i locals
rc = -2
q = (ngx_queue_t *) 0x85379ccb0
c = (ngx_connection_t *) 0x84a4c65b0
stream = (ngx_http_v2_stream_t *) 0x85379cc60
h2c = (ngx_http_v2_connection_t *) 0x85797c220
(gdb) p *q
$1 = {prev = 0x0, next = 0x0}
(gdb) p *c
$2 = {data = 0x85797c220, read = 0x84f458eb0, write = 0x851458eb0, fd
= 576, 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 = 490296, log = 0x8541a9c60, pool =
0x8541a9c00, type = 1, sockaddr = 0x8541a9c50, socklen = 16, addr_text
= {len = 13, data = 0x8541a9cb0 "46.133.156.37"}, proxy_protocol_addr
= {len = 0, data = 0x0},
ssl = 0x8541a9d20, local_sockaddr = 0x801c99d28, local_socklen = 16,
buffer = 0x0, queue = {prev = 0x0, next = 0x0}, number = 18898941,
requests = 29, 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) p stream
$3 = (ngx_http_v2_stream_t *) 0x85379cc60
(gdb) p *stream
$4 = {request = 0x85379c050, connection = 0x85797c220, node =
0x856bf0ef0, queued = 0, send_window = 6075904, recv_window = 65536,
preread = 0x0, free_frames = 0x856c6af58, free_frame_headers = 0x0,
free_bufs = 0x856c6aef8, queue = {
prev = 0x0, next = 0x0}, cookies = 0x85379cd28, header_limit = 0,
pool = 0x855eb4000, handled = 0, blocked = 0, exhausted = 0, in_closed
= 1, out_closed = 1, rst_sent = 0, no_flow_control = 0, skip_data = 0}
(gdb) p h2c
$5 = (ngx_http_v2_connection_t *) 0x85797c220
(gdb) p *h2c
$6 = {connection = 0x84a4c65b0, http_connection = 0x8541a9cc0,
processing = 1, send_window = 15146099, recv_window = 2147483003,
init_window = 6291456, frame_size = 16384, waiting = {prev =
0x85797c258, next = 0x85797c258}, state = {
sid = 57, length = 0, padding = 0, flags = 37, incomplete = 0,
keep_pool = 0, parse_name = 0, parse_value = 0, index = 0, header =
{name = {len = 10, data = 0x85798a56e "user-agent"}, value = {len =
137,
data = 0x85798a579 "Mozilla/5.0 (Linux; Android 6.0.1; Redmi
3S Build/MMB29M) AppleWebKit/537.36 (KHTML, like Gecko)
Chrome/46.0.2490.76 Mobile Safari/537.36"}}, header_limit = 15004,
field_state = 0 '\0',
field_start = 0x8543f0c6f
"/XXXXXX/XXX/XXXXXXXXXXXXXXXXXXXX/X/XXX%XXX%20XXXXXXXXXXXXXX",
field_end = 0x8543f0cac "", field_rest = 0, pool = 0x0, stream = 0x0,
buffer = 0x85797c2e0 "", buffer_used = 0,
handler = 0x500660 <ngx_http_v2_state_head>}, hpack = {entries =
0x85748f600, added = 46, deleted = 0, reused = 0, allocated = 64, size
= 4096, free = 394,
storage = 0x853d07000
"XXXXXXXXXXXXXXXXXXXXXXXXXXXXtext/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8accept-encodinggzip,
deflate, sdchaccept-languageXX-XX,XX;q=0.8,XX-XX;q=0.6,en;q=0.4cookieXXXXXXX="...,
pos = 0x853d078b6
"xscPF_QgWNtNyk0JXu2w3UcYDrgQv0fiMVXifJGNlWS0j9m37ixTHc4kFIPs8hPiLo4qEbwbg-wu88I=;
XXXXXXXXX=9d4aebb99c97d1cfd0e1685943776d38225cd062; XXXX=XXXX;
__utmb=69692428.21.10.1480053397; __utmc=69692428"},
pool = 0x8576fd000, free_frames = 0x0, free_fake_connections = 0x0,
streams_index = 0x856452220, last_out = 0x85487f648, posted = {prev =
0x85797c370, next = 0x85797c370}, dependencies = {prev = 0x859333a38,
next = 0x856452338},
closed = {prev = 0x858a64390, next = 0x856452358}, last_sid = 57,
closed_nodes = 28, settings_ack = 1, blocked = 1}
(gdb) fr
#0 ngx_http_v2_write_handler (wev=0x851458eb0) at src/http/v2/ngx_http_v2.c:444
444 wev = stream->request->connection->write;
(gdb) l
439 stream->handled = 0;
440
441 ngx_log_debug1(NGX_LOG_DEBUG_HTTP, c->log, 0,
442 "run http2 stream %ui", stream->node->id);
443
444 wev = stream->request->connection->write;
445
446 wev->active = 0;
447 wev->ready = 1;
448
(gdb) p stream->request->connection
$7 = (ngx_connection_t *) 0xa
(gdb) p stream->request
$8 = (ngx_http_request_t *) 0x85379c050
(gdb) p *stream->request
$9 = {signature = 4226631568, connection = 0xa, ctx = 0x856a11f28,
main_conf = 0x6, srv_conf = 0x856a11f33, loc_conf = 0x856a11f3a,
read_event_handler = 0x4861c3f653476b3b, write_event_handler = 0xd,
cache = 0x856a11f44,
upstream = 0x5, upstream_states = 0x856a11f52, pool = 0x856a11f58,
header_in = 0x85379cc00, headers_in = {headers = {last = 0x85379c0c0,
part = {elts = 0x8536a2020, nelts = 8, next = 0x0}, size = 48, nalloc
= 20, pool = 0x85379c000},
host = 0x8536a2020, connection = 0x0, if_modified_since = 0x0,
if_unmodified_since = 0x0, if_match = 0x0, if_none_match = 0x0,
user_agent = 0x8536a2140, referer = 0x8536a20e0, content_length = 0x0,
content_type = 0x0, range = 0x0,
if_range = 0x0, transfer_encoding = 0x0, expect = 0x0, upgrade =
0x0, accept_encoding = 0x8536a2080, via = 0x0, authorization = 0x0,
keep_alive = 0x0, x_forwarded_for = {elts = 0x0, nelts = 0, size = 0,
nalloc = 0,
pool = 0x85379c680}, x_real_ip = 0x0, user = {len = 0, data =
0x85379c1b8 ""}, passwd = {len = 0, data = 0x0}, cookies = {elts =
0x85379c6b0, nelts = 35760227744, size = 1, nalloc = 35807675712, pool
= 0x8564e6540}, server = {
len = 0, data = 0x50000000c <Address 0x50000000c out of
bounds>}, content_length_n = 164, keep_alive_n = 2380, connection_type
= 1, chunked = 1, msie = 0, msie6 = 0, opera = 1, gecko = 1, chrome =
1, safari = 0, konqueror = 0},
headers_out = {headers = {last = 0xf7370b6c, part = {elts = 0x0,
nelts = 0, next = 0x94c}, size = 35865916482, nalloc = 0, pool =
0x4d3}, status = 0, status_line = {len = 0,
data = 0x4ed2d0
"UH\211ЕH\203Л@H\211}П\211uЛ\211UХH\213}ПH\211}Ю\213UЛ\017╞UХ\211р\211вH\211}пH\213}пH\201ГЪ\001"},
server = 0x4ed470, date = 0x85379c1a0, content_length = 0x1,
content_encoding = 0x1, location = 0x0,
refresh = 0x853d2c050, last_modified = 0x61e75563aa847688,
content_range = 0x696a1394be61c396, accept_ranges =
0xb81ca0b80004753f, www_authenticate = 0x5fdf68311536ee06, expires =
0x3d260d62d0751d9a, etag = 0xb41a96a0711f744c,
override_charset = 0x2d980a62c749a8fd, content_type_len =
5361711866659580748, content_type = {len = 16111286140954451668, data
= 0xba9f34a5094abf3d <Address 0xba9f34a5094abf3d out of bounds>},
charset = {len = 8578051269243699330,
data = 0x2a83006fb498ca02 <Address 0x2a83006fb498ca02 out of
bounds>}, content_type_lowcase = 0xccdbf2c7e48d3747 <Address
0xccdbf2c7e48d3747 out of bounds>, content_type_hash =
11475120440503177658, cache_control = {
elts = 0x965161cd9a2f8500, nelts = 9138599854249686236, size =
968336868888348906, nalloc = 9872101289212144860, pool =
0x874dea215639c920}, content_length_n = -9095832714587370333,
content_offset = -8646842013157968240,
date_time = -39384271865661966, last_modified_time =
-8430598664003936891}, request_body = 0x87a8c54a6a49ea21,
lingering_time = 48371482963596688, start_sec = 1480053841, start_msec
= 396, method = 2, http_version = 2000,
request_line = {len = 0, data = 0x85379ce90 "GET
/XXXXXX/XXX/XXXXXXXXXXXXXXXXXXXX/X/XXX%XXX%20XXXXXX%20XX%20XXXXXXXXXX
HTTP/2.0"}, uri = {len = 63,
data = 0x85379cce0 "/XXXXXX/XXX/XXXXXXXXXXXXXXXXXXXX/X/XXX XXX
XXXXXX XX XXXXXXXXXX"}, args = {len = 0, data = 0x0}, exten = {len =
3, data = 0x85379cd1c "doc"}, unparsed_uri = {len = 71, data = 0x0},
method_name = {
len = 35813137368, data = 0x85379c6a0 "╠еyS\b"}, http_protocol
= {len = 5147808, data = 0x853d2cc60 "PÑŽÑ€S\b"}, out = 0xa, main =
0x85379c052, parent = 0x856a11ff9, postponed = 0x856a11ff9,
post_subrequest = 0x0,
posted_requests = 0x0, phase_handler = 35813138416, content_handler
= 0x856a11ff9, access_code = 9714584, variables = 0x0, ncaptures = 0,
captures = 0x1, captures_data = 0x85379c36f "", limit_rate =
35760227183, limit_rate_after = 0,
header_size = 0, request_length = 35760226984, err_status =
35760227183, http_connection = 0x0, stream = 0x0, log_handler = 0,
cleanup = 0x1, count = 30112, subrequests = 78, blocked = 0, aio = 0,
http_state = 0, complex_uri = 0,
quoted_uri = 0, plus_in_uri = 0, space_in_uri = 0, invalid_header =
0, add_uri_to_alias = 0, valid_location = 0, valid_unparsed_uri = 0,
uri_changed = 0, uri_changes = 0, request_body_in_single_buf = 0,
request_body_in_file_only = 0,
request_body_in_persistent_file = 0, request_body_in_clean_file = 0,
request_body_file_group_access = 0, request_body_file_log_level = 0,
request_body_no_buffering = 0, subrequest_in_memory = 0, waited = 0,
cached = 0,
gzip_tested = 0, gzip_ok = 0, gzip_vary = 0, proxy = 0, bypass_cache
= 0, no_cache = 0, limit_conn_set = 0, limit_req_set = 1, pipeline =
1, chunked = 0, header_only = 0, keepalive = 0, lingering_close = 1,
discard_body = 1,
reading_body = 0, internal = 0, error_page = 1, filter_finalize = 1,
post_action = 0, request_complete = 1, request_output = 0, header_sent
= 0, expect_tested = 1, root_tested = 0, done = 1, logged = 1,
buffered = 3,
main_filter_need_in_memory = 1, filter_need_in_memory = 0,
filter_need_temporary = 1, allow_ranges = 0, subrequest_ranges = 0,
single_range = 0, disable_not_modified = 0, stat_reading = 1,
stat_writing = 0, state = 35813137240,
header_hash = 0, lowcase_index = 0, lowcase_header = 0x85379c4d8 "",
header_name_start = 0x947020 "\022", header_name_end = 0x0,
header_start = 0x0, header_end = 0x22 <Address 0x22 out of bounds>,
uri_start = 0x0, uri_end = 0x0,
uri_ext = 0x0, args_start = 0x0, request_start = 0x4 <Address 0x4
out of bounds>, request_end = 0x0, method_end = 0x0, schema_start =
0x200 <Address 0x200 out of bounds>, schema_end = 0x853d2c000 "",
host_start = 0x0,
host_end = 0x20 <Address 0x20 out of bounds>, port_start = 0x10000
<Address 0x10000 out of bounds>, port_end = 0x93dd40 "*", http_minor =
21744, http_major = 79}
(gdb)
Core файл и исполнительный файл есть, так же записан debug.log (из
корки, через кольцевой буфер в памяти), если какие-то данных из них
понадобятся - предоставим.
Спасибо!
Подробная информация о списке рассылки nginx-ru