Opened 12 years ago

Closed 11 years ago

#330 closed defect (fixed)

nginx crashing in ngx_http_read_client_request_body

Reported by: Proforg M Owned by:
Priority: minor Milestone:
Component: nginx-core Version: 1.3.x
Keywords: Cc:
uname -a: Debian GNU/Linux 6.0
Linux alterlit 3.2.0-0.bpo.4-amd64 #1 SMP Debian 3.2.35-2~bpo60+1 x86_64 GNU/Linux
nginx -V: nginx version: nginx/1.3.15
TLS SNI support enabled
configure arguments: --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --pid-path=/var/run/nginx.pid --lock-path=/var/lock/nginx.lock --http-log-path=/var/log/nginx/access.log --http-client-body-temp-path=/var/lib/nginx/body --http-proxy-temp-path=/var/lib/nginx/proxy --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --http-scgi-temp-path=/var/lib/nginx/scgi --with-debug --with-file-aio --with-http_stub_status_module --with-http_addition_module --with-http_random_index_module --with-http_flv_module --with-http_ssl_module --with-http_dav_module --with-http_realip_module --with-http_secure_link_module --with-http_xslt_module --with-http_addition_module --with-http_image_filter_module --with-http_mp4_module --add-module=mod_zip --add-module=nginx-upload-progress-module --with-http_geoip_module --with-http_sub_module --add-module=ngx_http_substitutions_filter_module

Description

Новые версии nginx, начиная с 1.3.11 (или 10) постоянно сегфолтятся (версии 1.3.9 при этом работает нормально)
В логах выглядит это примерно так:

2013/04/04 21:06:34 [notice] 25117#0: signal 17 (SIGCHLD) received
2013/04/04 21:06:34 [alert] 25117#0: worker process 25119 exited on signal 11 (core dumped)
2013/04/04 21:06:34 [notice] 25117#0: start worker process 21609
2013/04/04 21:06:34 [notice] 25117#0: signal 29 (SIGIO) received

В core вот такое:

Core was generated by `nginx: worker pr'.
Program terminated with signal 11, Segmentation fault.
#0  0x000000000046660e in ngx_http_read_client_request_body (r=0x1d832f0, post_handler=0x471855 <ngx_http_upstream_init>) at src/http/ngx_http_request_body.c:88
88          preread = r->header_in->last - r->header_in->pos;
(gdb) bt
#0  0x000000000046660e in ngx_http_read_client_request_body (r=0x1d832f0, post_handler=0x471855 <ngx_http_upstream_init>) at src/http/ngx_http_request_body.c:88
#1  0x00000000004b7da3 in ngx_http_fastcgi_handler (r=0x1d832f0) at src/http/modules/ngx_http_fastcgi_module.c:636
#2  0x000000000044c2c2 in ngx_http_core_content_phase (r=0x1d832f0, ph=0x1ca5370) at src/http/ngx_http_core_module.c:1408
#3  0x000000000044ae0c in ngx_http_core_run_phases (r=0x1d832f0) at src/http/ngx_http_core_module.c:888
#4  0x000000000044ad83 in ngx_http_handler (r=0x1d832f0) at src/http/ngx_http_core_module.c:871
#5  0x000000000045a4c5 in ngx_http_run_posted_requests (c=0x7f74d91e4750) at src/http/ngx_http_request.c:2170
#6  0x0000000000459bf3 in ngx_http_process_request (r=0x1d2b7a0) at src/http/ngx_http_request.c:1853
#7  0x00000000004584e5 in ngx_http_process_request_headers (rev=0x7f74d8ea16a8) at src/http/ngx_http_request.c:1282
#8  0x000000000045785f in ngx_http_process_request_line (rev=0x7f74d8ea16a8) at src/http/ngx_http_request.c:963
#9  0x000000000045677a in ngx_http_wait_request_handler (rev=0x7f74d8ea16a8) at src/http/ngx_http_request.c:486
#10 0x000000000042ee01 in ngx_event_process_posted (cycle=0x1c1bcf0, posted=0x71a520) at src/event/ngx_event_posted.c:40
#11 0x000000000042ca4c in ngx_process_events_and_timers (cycle=0x1c1bcf0) at src/event/ngx_event.c:276
#12 0x000000000043a08d in ngx_worker_process_cycle (cycle=0x1c1bcf0, data=0x1) at src/os/unix/ngx_process_cycle.c:807
#13 0x000000000043699a in ngx_spawn_process (cycle=0x1c1bcf0, proc=0x439ec7 <ngx_worker_process_cycle>, data=0x1, name=0x4e26eb "worker process", respawn=-3)
    at src/os/unix/ngx_process.c:198
#14 0x0000000000438ed3 in ngx_start_worker_processes (cycle=0x1c1bcf0, n=2, type=-3) at src/os/unix/ngx_process_cycle.c:362
#15 0x0000000000438528 in ngx_master_process_cycle (cycle=0x1c1bcf0) at src/os/unix/ngx_process_cycle.c:136
#16 0x00000000004082e6 in main (argc=1, argv=0x7fffff3ac518) at src/core/nginx.c:412

Повторяется на 3х разных серверах, с разным типом нагрузки
Попробовать версию без сторонних модулей, к сожалению, не могу - они все используются в работе :(

Change History (6)

comment:1 by Maxim Dounin, 12 years ago

Что показывает

fr 0
p *r
p *r->main
p *r->connection

в gdb?

comment:2 by Proforg M, 12 years ago 

(gdb) fr 0
#0  0x000000000046660e in ngx_http_read_client_request_body (r=0x18a7690, post_handler=0x471855 <ngx_http_upstream_init>) at src/http/ngx_http_request_body.c:88
88          preread = r->header_in->last - r->header_in->pos;

(gdb) p *r
$1 = {signature = 1347703880, connection = 0x7f1168eec750, ctx = 0x18bfc70, main_conf = 0x179e0b0, srv_conf = 0x17b5ef0, loc_conf = 0x17d9348,
  read_event_handler = 0x45c9ee <ngx_http_request_empty_handler>, write_event_handler = 0x45c9ee <ngx_http_request_empty_handler>, cache = 0x0, upstream = 0x18a7f90,
  upstream_states = 0x0, pool = 0x18b1a20, header_in = 0x0, headers_in = {headers = {last = 0x18b1ae0, part = {elts = 0x18bf090, nelts = 4, next = 0x0}, size = 48,
      nalloc = 20, pool = 0x18b1a20}, host = 0x18bf090, connection = 0x0, if_modified_since = 0x0, if_unmodified_since = 0x0, if_match = 0x0, if_none_match = 0x0,
    user_agent = 0x18bf0c0, referer = 0x0, content_length = 0x18bf0f0, content_type = 0x0, range = 0x0, if_range = 0x0, transfer_encoding = 0x0, expect = 0x0,
    upgrade = 0x0, accept_encoding = 0x0, via = 0x0, authorization = 0x0, keep_alive = 0x0, x_forwarded_for = {elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0},
    x_real_ip = 0x0, depth = 0x0, destination = 0x0, overwrite = 0x0, date = 0x0, user = {len = 0, data = 0x0}, passwd = {len = 0, data = 0x0}, cookies = {elts = 0x0,
      nelts = 0, size = 0, nalloc = 0, pool = 0x0}, server = {len = 9, data = 0x18bad66 "udaff.com"}, content_length_n = 0, keep_alive_n = -1, connection_type = 1,
    chunked = 0, msie = 0, msie6 = 0, opera = 0, gecko = 0, chrome = 0, safari = 0, konqueror = 0}, headers_out = {headers = {last = 0x18a7890, part = {elts = 0x18a7bd0,
        nelts = 0, next = 0x0}, size = 48, nalloc = 20, pool = 0x18b1a20}, status = 0, status_line = {len = 0, data = 0x0}, server = 0x0, date = 0x0, content_length = 0x0,
    content_encoding = 0x0, location = 0x0, refresh = 0x0, last_modified = 0x0, content_range = 0x0, accept_ranges = 0x0, www_authenticate = 0x0, expires = 0x0,
    etag = 0x0, override_charset = 0x0, content_type_len = 0, content_type = {len = 0, data = 0x0}, charset = {len = 0, data = 0x0}, content_type_lowcase = 0x0,
    content_type_hash = 0, cache_control = {elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0}, content_length_n = -1, date_time = 0, last_modified_time = -1},
  request_body = 0x18bffb8, lingering_time = 0, start_sec = 1365133433, start_msec = 751, method = 2, http_version = 1001, request_line = {len = 14,
    data = 0x18bad50 "GET / HTTP/1.1\r\nHost"}, uri = {len = 9, data = 0x18bfc40 "/mmc.fcgi"}, args = {len = 0, data = 0x0}, exten = {len = 4, data = 0x18bfc45 "fcgi"},
  unparsed_uri = {len = 1, data = 0x18bad54 "/ HTTP/1.1\r\nHost"}, method_name = {len = 3, data = 0x4e47e7 "GET "}, http_protocol = {len = 8,
    data = 0x18bad56 "HTTP/1.1\r\nHost"}, out = 0x0, main = 0x18b1a70, parent = 0x18b1a70, postponed = 0x0, post_subrequest = 0x0, posted_requests = 0x0,
  phase_handler = 12, content_handler = 0x4b7b46 <ngx_http_fastcgi_handler>, access_code = 0, variables = 0x18b2520, ncaptures = 0, captures = 0x18bff40,
  captures_data = 0x0, limit_rate = 0, header_size = 0, request_length = 0, err_status = 0, http_connection = 0x0, log_handler = 0x45d2a7 <ngx_http_log_error_handler>,
  cleanup = 0x0, subrequests = 0, count = 0, 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 = 1, valid_unparsed_uri = 0, uri_changed = 0, uri_changes = 11, request_body_in_single_buf = 0, request_body_in_file_only = 1,
  request_body_in_persistent_file = 1, request_body_in_clean_file = 1, request_body_file_group_access = 0, request_body_file_log_level = 6, subrequest_in_memory = 0,
  waited = 1, 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 = 0, pipeline = 0,
  chunked = 0, header_only = 0, keepalive = 0, lingering_close = 0, discard_body = 0, internal = 1, error_page = 0, ignore_content_encoding = 0, filter_finalize = 0,
  post_action = 0, request_complete = 0, request_output = 0, header_sent = 0, expect_tested = 1, root_tested = 0, done = 0, logged = 0, buffered = 0,
  main_filter_need_in_memory = 0, filter_need_in_memory = 0, filter_need_temporary = 0, allow_ranges = 0, stat_reading = 0, stat_writing = 0, state = 0, header_hash = 0,
  lowcase_index = 0, lowcase_header = '\000' <repeats 31 times>, header_name_start = 0x0, header_name_end = 0x0, header_start = 0x0, header_end = 0x0, uri_start = 0x0,
  uri_end = 0x0, uri_ext = 0x0, args_start = 0x0, request_start = 0x0, request_end = 0x0, method_end = 0x0, schema_start = 0x0, schema_end = 0x0, host_start = 0x0,
  host_end = 0x0, port_start = 0x0, port_end = 0x0, http_minor = 0, http_major = 0}

(gdb) p *r->main
$2 = {signature = 1347703880, connection = 0x7f1168eec750, ctx = 0x18b2370, main_conf = 0x179e0b0, srv_conf = 0x17b5ef0, loc_conf = 0x17ce988,
  read_event_handler = 0x45b73c <ngx_http_test_reading>, write_event_handler = 0x45b22c <ngx_http_writer>, cache = 0x0, upstream = 0x0, upstream_states = 0x0,
  pool = 0x18b1a20, header_in = 0x17a49f0, headers_in = {headers = {last = 0x18b1ae0, part = {elts = 0x18bf090, nelts = 4, next = 0x0}, size = 48, nalloc = 20,
      pool = 0x18b1a20}, host = 0x18bf090, connection = 0x0, if_modified_since = 0x0, if_unmodified_since = 0x0, if_match = 0x0, if_none_match = 0x0,
    user_agent = 0x18bf0c0, referer = 0x0, content_length = 0x18bf0f0, content_type = 0x0, range = 0x0, if_range = 0x0, transfer_encoding = 0x0, expect = 0x0,
    upgrade = 0x0, accept_encoding = 0x0, via = 0x0, authorization = 0x0, keep_alive = 0x0, x_forwarded_for = {elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0},
    x_real_ip = 0x0, depth = 0x0, destination = 0x0, overwrite = 0x0, date = 0x0, user = {len = 0, data = 0x0}, passwd = {len = 0, data = 0x0}, cookies = {elts = 0x0,
      nelts = 0, size = 0, nalloc = 0, pool = 0x0}, server = {len = 9, data = 0x18bad66 "udaff.com"}, content_length_n = 0, keep_alive_n = -1, connection_type = 1,
    chunked = 0, msie = 0, msie6 = 0, opera = 0, gecko = 0, chrome = 0, safari = 0, konqueror = 0}, headers_out = {headers = {last = 0x18b1c70, part = {elts = 0x18b1fb0,
        nelts = 1, next = 0x0}, size = 48, nalloc = 20, pool = 0x18b1a20}, status = 200, status_line = {len = 0, data = 0x0}, server = 0x0, date = 0x0,
    content_length = 0x0, content_encoding = 0x0, location = 0x0, refresh = 0x0, last_modified = 0x0, content_range = 0x0, accept_ranges = 0x0, www_authenticate = 0x0,
    expires = 0x0, etag = 0x0, override_charset = 0x0, content_type_len = 9, content_type = {len = 24,
      data = 0x18bfa92 "text/html; charset=utf-8\r\nTransfer-Encoding: chunked\r\nConnection: close\r\n\r\n"}, charset = {len = 5, data = 0x17b77d6 "utf-8"},
    content_type_lowcase = 0x18bf7f0 "text/html", content_type_hash = 101824002410317, cache_control = {elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0},
    content_length_n = -1, date_time = 0, last_modified_time = -1}, request_body = 0x0, lingering_time = 0, start_sec = 1365133433, start_msec = 751, method = 2,
  http_version = 1001, request_line = {len = 14, data = 0x18bad50 "GET / HTTP/1.1\r\nHost"}, uri = {len = 11, data = 0x18b29b4 "/index.html"}, args = {len = 0,
    data = 0x0}, exten = {len = 4, data = 0x18b29bb "html"}, unparsed_uri = {len = 1, data = 0x18bad54 "/ HTTP/1.1\r\nHost"}, method_name = {len = 3,
    data = 0x18bad50 "GET / HTTP/1.1\r\nHost"}, http_protocol = {len = 8, data = 0x18bad56 "HTTP/1.1\r\nHost"}, out = 0x18bfae0, main = 0x18b1a70, parent = 0x0,
  postponed = 0x18bfe20, post_subrequest = 0x0, posted_requests = 0x0, phase_handler = 16, content_handler = 0, access_code = 0, variables = 0x18b2520, ncaptures = 0,
  captures = 0x18b2850, captures_data = 0x18b29b4 "/index.html", limit_rate = 0, header_size = 165, request_length = 202, err_status = 0, http_connection = 0x17a2ac0,
  log_handler = 0x45d2a7 <ngx_http_log_error_handler>, cleanup = 0x0, subrequests = 200, count = 3, blocked = 0, aio = 0, http_state = 6, complex_uri = 0, quoted_uri = 0,
  plus_in_uri = 0, space_in_uri = 0, invalid_header = 0, add_uri_to_alias = 0, valid_location = 1, valid_unparsed_uri = 0, uri_changed = 0, uri_changes = 10,
  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 = 5, subrequest_in_memory = 0, waited = 0, cached = 0, gzip_tested = 1, gzip_ok = 0, gzip_vary = 0, proxy = 0, bypass_cache = 0,
  no_cache = 0, limit_conn_set = 0, limit_req_set = 0, pipeline = 0, chunked = 1, header_only = 0, keepalive = 0, lingering_close = 0, discard_body = 0, internal = 1,
  error_page = 0, ignore_content_encoding = 0, filter_finalize = 0, post_action = 0, request_complete = 0, request_output = 1, header_sent = 1, expect_tested = 0,
  root_tested = 1, done = 0, logged = 0, buffered = 5, main_filter_need_in_memory = 0, filter_need_in_memory = 1, filter_need_temporary = 0, allow_ranges = 0,
  stat_reading = 0, stat_writing = 1, state = 0, header_hash = 2715320498552542, lowcase_index = 10, lowcase_header = "connectionngth", '\000' <repeats 17 times>,
  header_name_start = 0x18bae18 "\r\nGMT", header_name_end = 0x18bae0f "", header_start = 0x18bae11 "close", header_end = 0x18bae18 "\r\nGMT",
  uri_start = 0x18bad54 "/ HTTP/1.1\r\nHost", uri_end = 0x18bad55 " HTTP/1.1\r\nHost", uri_ext = 0x0, args_start = 0x0, request_start = 0x18bad50 "GET / HTTP/1.1\r\nHost",
  request_end = 0x18bad5e "\r\nHost", method_end = 0x18bad52 "T / HTTP/1.1\r\nHost", schema_start = 0x0, schema_end = 0x0, host_start = 0x0, host_end = 0x0,
  port_start = 0x0, port_end = 0x0, http_minor = 1, http_major = 1}

(gdb) p *r->connection
$4 = {data = 0x18a7690, read = 0x7f1168ba80a8, write = 0x7f11688670a8, fd = 28, recv = 0x434e38 <ngx_unix_recv>, send = 0x435468 <ngx_unix_send>,
  recv_chain = 0x434fdc <ngx_readv_chain>, send_chain = 0x43cc8c <ngx_linux_sendfile_chain>, listening = 0x179d260, sent = 0, log = 0x17a2a80, pool = 0x17a2a20,
  sockaddr = 0x17a2a70, socklen = 16, addr_text = {len = 13, data = 0x17a2ab0 "85.26.184.138"}, ssl = 0x0, local_sockaddr = 0x1826480, buffer = 0x17a49f0, queue = {
    prev = 0x0, next = 0x0}, number = 229641, requests = 1, buffered = 0, log_error = 2, unexpected_eof = 0, timedout = 0, error = 0, destroyed = 0, idle = 0,
  reusable = 0, close = 0, sendfile = 1, sndlowat = 0, tcp_nodelay = 0, tcp_nopush = 2}

comment:3 by Maxim Dounin, 12 years ago

Патч.

# HG changeset patch
# User Maxim Dounin <mdounin@mdounin.ru>
# Date 1365110202 -14400
# Node ID de151056e90a4f9d6bb6e1adef69e95c09840a8f
# Parent  726de506d7684d9bf6c11f7452155854a5125907
Request body: only read body in main request.

In subrequest this will cause segfault if body wasn't already read.

diff --git a/src/http/ngx_http_request_body.c b/src/http/ngx_http_request_body.c
--- a/src/http/ngx_http_request_body.c
+++ b/src/http/ngx_http_request_body.c
@@ -49,7 +49,7 @@ ngx_http_read_client_request_body(ngx_ht
     }
 #endif
 
-    if (r->request_body || r->discard_body) {
+    if (r != r->main || r->request_body || r->discard_body) {
         post_handler(r);
         return NGX_OK;
     }

comment:4 by Proforg M, 12 years ago

Спасибо, проблема решена!

comment:5 by Maxim Dounin, 12 years ago

In 5175/nginx:

Request body: only read body in main request (ticket #330).

Before 1.3.9 an attempt to read body in a subrequest only caused problems
if body wasn't already read or discarded in a main request. Starting with
1.3.9 it might also cause problems if body was discarded by a main request
before subrequest start.

Fix is to just ignore attempts to read request body in a subrequest, which
looks like right thing to do anyway.

comment:6 by Maxim Dounin, 11 years ago

Resolution: → fixed
Status: new → closed

The problem was fixed by [f458156fd46a].

Note: See TracTickets for help on using tickets.