Opened 11 years ago

Closed 6 years ago

#274 closed defect (fixed)

error_page 400 =444 /; утекают сокеты

Reported by: naikoto Owned by:
Priority: minor Milestone:
Component: nginx-core Version: 1.3.x
Keywords: Cc:
uname -a: Linux 3.2.0-0.bpo.4-amd64 #1 SMP Debian 3.2.32-1~bpo60+1 x86_64 GNU/Linux
nginx -V: nginx version: nginx/1.3.11
configure arguments: --with-debug --prefix=/usr --sbin-path=/usr/sbin/nginx --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --pid-path=/var/run/nginx/nginx.pid --lock-path=/var/lock/nginx.lock --http-log-path=/var/log/nginx/access.log --http-client-body-temp-path=/tmp/body --http-proxy-temp-path=/tmp/proxy --without-http_auth_basic_module --without-http_browser_module --without-http_empty_gif_module --without-http_fastcgi_module --without-http_geo_module --without-http_gzip_module --without-http_limit_req_module --without-http_limit_conn_module --without-http_map_module --without-http_memcached_module --without-http_proxy_module --without-http_scgi_module --without-http_split_clients_module --without-http_ssi_module --without-http_upstream_ip_hash_module --without-http_userid_module --without-http_uwsgi_module

Description

Конфигурация для игнорирования неизвестных доменов.
При некорректном запросе соединение не закрывается и остаётся в CLOSE_WAIT.
Запрос должен быть с другого хоста.

echo -e '\x04\x01\x00P>\xECl\xC80\x00'|nc server 8000

conf

worker_processes  1;
worker_rlimit_core  500M;
working_directory   /tmp/core/;
debug_points abort;
pid        /tmp/nginx.pid;
events { worker_connections  1024; }
error_log /tmp/err debug;
http {
 types { text/html html; }
 access_log off;
 server {
  server_name _;
  return 444;
  error_page 400 =444 /;
 }
}

error.log:

2013/01/06 13:59:37 [debug] 16876#0: *1 malloc: 083BFC68:656
2013/01/06 13:59:37 [debug] 16876#0: *1 malloc: 083C5E00:1024
2013/01/06 13:59:37 [debug] 16876#0: *1 posix_memalign: 083C6220:4096 @16
2013/01/06 13:59:37 [debug] 16876#0: *1 http process request line
2013/01/06 13:59:37 [debug] 16876#0: *1 recv: fd:5 11 of 1024
2013/01/06 13:59:37 [info] 16876#0: *1 client sent invalid method while reading client request line, client: 1.0.0.8, server: _, request: "^D^A^@P><EC>l<C8>0^@"
2013/01/06 13:59:37 [debug] 16876#0: *1 http finalize request: 400, "?" a:1, c:1
2013/01/06 13:59:37 [debug] 16876#0: *1 event timer del: 5: 256771487
2013/01/06 13:59:37 [debug] 16876#0: *1 http special response: 400, "?"
2013/01/06 13:59:37 [debug] 16876#0: *1 internal redirect: "/?"
2013/01/06 13:59:37 [debug] 16876#0: *1 rewrite phase: 0
2013/01/06 13:59:37 [debug] 16876#0: *1 http finalize request: 444, "/?" a:1, c:2
2013/01/06 13:59:37 [debug] 16876#0: *1 http terminate request count:2
2013/01/06 13:59:37 [debug] 16876#0: *1 http terminate cleanup count:2 blk:0
2013/01/06 13:59:37 [debug] 16876#0: *1 http finalize request: -4, "/?" a:1, c:2
2013/01/06 13:59:37 [debug] 16876#0: *1 http request count:2 blk:0
...
2013/01/06 14:00:23 [alert] 16876#0: open socket #5 left in connection 2
2013/01/06 14:00:23 [alert] 16876#0: aborting
2013/01/06 14:00:23 [notice] 16875#0: signal 17 (SIGCHLD) received
2013/01/06 14:00:23 [alert] 16875#0: worker process 16876 exited on signal 6 (core dumped)

gdb

gdb) set $c = &ngx_cycle->connections[2]
(gdb) p $c->log->connection
$1 = 1
(gdb) p *$c
$2 = {data = 0x83bfc68, read = 0x83e5748, write = 0x83f2750, fd = 5, recv = 0x806e4d0 <ngx_unix_recv>, 
  send = 0x806ea14 <ngx_unix_send>, recv_chain = 0x806e650 <ngx_readv_chain>, send_chain = 0x8074a54 <ngx_linux_sendfile_chain>, 
  listening = 0x83c0924, sent = 0, log = 0x83bfb98, pool = 0x83bfb60, sockaddr = 0x83bfb88, socklen = 16, addr_text = {len = 7, 
    data = 0x83bfbb0 "1.0.0.8"}, local_sockaddr = 0x83cb5d4, buffer = 0x83bfbec, queue = {prev = 0x0, next = 0x0}, number = 1, 
  requests = 1, buffered = 0, log_error = 2, single_connection = 1, unexpected_eof = 0, timedout = 0, error = 0, destroyed = 0, 
  idle = 0, reusable = 0, close = 0, sendfile = 0, sndlowat = 0, tcp_nodelay = 0, tcp_nopush = 2}
(gdb) set $r = (ngx_http_request_t *) $c->data
(gdb) p *$r
$3 = {signature = 1347703880, connection = 0x83cd798, ctx = 0x83c6428, main_conf = 0x83c1080, srv_conf = 0x83c9a40, 
  loc_conf = 0x83c9a90, read_event_handler = 0x8085893 <ngx_http_block_reading>, 
  write_event_handler = 0x80851bb <ngx_http_terminate_handler>, cache = 0x0, upstream = 0x0, upstream_states = 0x0, 
  pool = 0x83c6220, header_in = 0x83bfbec, headers_in = {headers = {last = 0x0, part = {elts = 0x0, nelts = 0, next = 0x0}, 
      size = 0, nalloc = 0, pool = 0x0}, host = 0x0, connection = 0x0, if_modified_since = 0x0, if_unmodified_since = 0x0, 
    if_match = 0x0, if_none_match = 0x0, user_agent = 0x0, referer = 0x0, content_length = 0x0, content_type = 0x0, range = 0x0, 
    if_range = 0x0, transfer_encoding = 0x0, expect = 0x0, authorization = 0x0, keep_alive = 0x0, user = {len = 0, data = 0x0}, 
    passwd = {len = 0, data = 0x0}, cookies = {elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0}, server = {len = 0, 
      data = 0x0}, content_length_n = -1, keep_alive_n = -1, connection_type = 0, chunked = 0, msie = 0, msie6 = 0, opera = 0, 
    gecko = 0, chrome = 0, safari = 0, konqueror = 0}, headers_out = {headers = {last = 0x83bfd38, part = {elts = 0x83c6248, 
        nelts = 0, next = 0x0}, size = 24, nalloc = 20, pool = 0x83c6220}, status = 444, 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 = 0x0, lingering_time = 0, start_sec = 1357466377, start_msec = 23, 
  method = 2, http_version = 0, request_line = {len = 10, data = 0x83c5e00 "\004\001"}, uri = {len = 1, data = 0x83c9e47 "/"}, 
  args = {len = 0, data = 0x0}, exten = {len = 0, data = 0x0}, unparsed_uri = {len = 0, data = 0x0}, method_name = {len = 3, 
    data = 0x80b8cf8 "GET "}, http_protocol = {len = 0, data = 0x0}, out = 0x0, main = 0x83bfc68, parent = 0x0, postponed = 0x0, 
  post_subrequest = 0x0, posted_requests = 0x83bfec0, virtual_names = 0x0, phase_handler = 0, content_handler = 0, 
  access_code = 0, variables = 0x83c6478, ncaptures = 0, captures = 0x0, captures_data = 0x0, limit_rate = 0, header_size = 0, 
  request_length = 0, err_status = 444, http_connection = 0x83bfbcc, log_handler = 0x8086fef <ngx_http_log_error_handler>, 
  cleanup = 0x0, subrequests = 201, count = 1, blocked = 0, aio = 0, http_state = 1, 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, proxy = 0, bypass_cache = 0, no_cache = 0, 
  limit_conn_set = 0, limit_req_set = 0, pipeline = 0, plain_http = 0, chunked = 0, header_only = 0, keepalive = 0, 
  lingering_close = 0, discard_body = 0, internal = 1, error_page = 1, 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, 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 = 0x83bfc68 "HTTP\230\327<\b(d<\b\200\020<\b@\232<\b\220\232<\b\223X\b\b\273Q\b\b", uri_end = 0x0, uri_ext = 0x0, 
  args_start = 0x0, request_start = 0x83c5e00 "\004\001", 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}

Change History (5)

comment:1 by naikoto, 11 years ago

При замене на именованный location

  error_page 400 @drop;
  location @drop { }

процесс падает

2013/01/06 14:51:15 [debug] 17128#0: *1 http process request line
2013/01/06 14:51:15 [debug] 17128#0: *1 recv: fd:5 11 of 1024
2013/01/06 14:51:15 [info] 17128#0: *1 client sent invalid method while reading client request line, client: 1.0.0.8, server: _, request: "^D^A^@P><EC>l<C8>0^@"
2013/01/06 14:51:15 [debug] 17128#0: *1 http finalize request: 400, "?" a:1, c:1
2013/01/06 14:51:15 [debug] 17128#0: *1 event timer del: 5: 259870381
2013/01/06 14:51:15 [debug] 17128#0: *1 http special response: 400, "?"
2013/01/06 14:51:15 [debug] 17128#0: *1 test location: "@drop"
2013/01/06 14:51:15 [debug] 17128#0: *1 using location: @drop "?"
2013/01/06 14:51:15 [debug] 17128#0: *1 rewrite phase: 2
2013/01/06 14:51:15 [debug] 17128#0: *1 post rewrite phase: 3
2013/01/06 14:51:15 [debug] 17128#0: *1 access phase: 4
2013/01/06 14:51:15 [debug] 17128#0: *1 post access phase: 5
2013/01/06 14:51:15 [debug] 17128#0: *1 content phase: 6
2013/01/06 14:51:15 [notice] 17127#0: signal 17 (SIGCHLD) received
2013/01/06 14:51:15 [alert] 17127#0: worker process 17128 exited on signal 11 (core dumped)

gdb

Program terminated with signal 11, Segmentation fault.
#0  0x080a1b06 in ngx_http_index_handler (r=0x972bc68) at src/http/modules/ngx_http_index_module.c:112
112	    if (r->uri.data[r->uri.len - 1] != '/') {
(gdb) bt
#0  0x080a1b06 in ngx_http_index_handler (r=0x972bc68) at src/http/modules/ngx_http_index_module.c:112
#1  0x0807a39b in ngx_http_core_content_phase (r=0x972bc68, ph=0x97377f0) at src/http/ngx_http_core_module.c:1412
#2  0x0807913e in ngx_http_core_run_phases (r=0x972bc68) at src/http/ngx_http_core_module.c:885
#3  0x0807c232 in ngx_http_named_location (r=0x972bc68, name=0xff99f1ec) at src/http/ngx_http_core_module.c:2649
#4  0x08081211 in ngx_http_send_error_page (r=0x972bc68, err_page=0x9735e5c) at src/http/ngx_http_special_response.c:574
#5  0x08080e71 in ngx_http_special_response_handler (r=0x972bc68, error=400) at src/http/ngx_http_special_response.c:416
#6  0x08084ba7 in ngx_http_finalize_request (r=0x972bc68, rc=400) at src/http/ngx_http_request.c:2014
#7  0x08082b98 in ngx_http_process_request_line (rev=0x9751748) at src/http/ngx_http_request.c:952
#8  0x080823b4 in ngx_http_init_request (rev=0x9751748) at src/http/ngx_http_request.c:527
#9  0x0807481e in ngx_epoll_process_events (cycle=0x972c618, timer=60000, flags=1) at src/event/modules/ngx_epoll_module.c:683
#10 0x080673ff in ngx_process_events_and_timers (cycle=0x972c618) at src/event/ngx_event.c:247
#11 0x08072b3b in ngx_worker_process_cycle (cycle=0x972c618, data=0x0) at src/os/unix/ngx_process_cycle.c:807
#12 0x0806fcac in ngx_spawn_process (cycle=0x972c618, proc=0x80729c7 <ngx_worker_process_cycle>, data=0x0, 
    name=0x80b727b "worker process", respawn=-3) at src/os/unix/ngx_process.c:198
#13 0x08071cbe in ngx_start_worker_processes (cycle=0x972c618, n=1, type=-3) at src/os/unix/ngx_process_cycle.c:362
#14 0x0807145b in ngx_master_process_cycle (cycle=0x972c618) at src/os/unix/ngx_process_cycle.c:136
#15 0x0804aa18 in main (argc=3, argv=0xff99f764) at src/core/nginx.c:412

#0  0x080a1b06 in ngx_http_index_handler (r=0x972bc68) at src/http/modules/ngx_http_index_module.c:112
        p = 0x7c9d4d95 <Address 0x7c9d4d95 out of bounds>
        name = 0x972bbb6 "8"
        len = 8
        root = 4151233432
        reserve = 0
        allocated = 0
        rc = 1
        path = {len = 21, data = 0xf7721f24 "\024\016"}
        uri = {len = 4288278760, data = 0xf76ec268 "libcrypto.so.0.9.8"}
        i = 284
        dir_tested = 2
        index = 0xf7740858
        of = {fd = -143324960, uniq = 17831417647083065177, mtime = -143269900, size = 8446413988, fs_size = -615670427878297316, 
          directio = -615677690667994916, read_ahead = 4148558199, err = 134517923, failed = 0x0, valid = 134516939, 
          min_uses = 4151233672, disable_symlinks_from = 4151446884, disable_symlinks = 0, test_dir = 0, test_only = 1, log = 1, 
          errors = 0, events = 1, is_dir = 0, is_file = 1, is_link = 1, is_exec = 0, is_directio = 1}
        code = 0xff99f130
        e = {ip = 0xf756fc29 "%hu%n:%hu%n:%hu%n", pos = 0xf7721f24 "\024\016", sp = 0xd696910, buf = {len = 4288278684, 
            data = 0xf774ac66 "\213M\340\205\300u3\211\360\213]\364\213u\370\213}\374\211\354]Ít&"}, line = {len = 4151456853, 
            data = 0x804948d "GLIBC_2.0"}, args = 0x972bb54 "4", flushed = 1, skip = 0, quote = 0, is_args = 1, log = 1, 
          status = -143733784, request = 0xff990002}
        clcf = 0xff99e939
        ilcf = 0xff99f100
        lcode = 0xff99e928
#1  0x0807a39b in ngx_http_core_content_phase (r=0x972bc68, ph=0x97377f0) at src/http/ngx_http_core_module.c:1412
        root = 4294967291
        rc = 0
        path = {len = 0, data = 0x1 <Address 0x1 out of bounds>}
#2  0x0807913e in ngx_http_core_run_phases (r=0x972bc68) at src/http/ngx_http_core_module.c:885
        rc = -2
        ph = 0x97377a8
        cmcf = 0x972d170
#3  0x0807c232 in ngx_http_named_location (r=0x972bc68, name=0xff99f1ec) at src/http/ngx_http_core_module.c:2649
        cscf = 0x9735ae0
        clcfp = 0x9736770
        cmcf = 0x972d170
#4  0x08081211 in ngx_http_send_error_page (r=0x972bc68, err_page=0x9735e5c) at src/http/ngx_http_special_response.c:574
        overwrite = -1
        uri = {len = 5, data = 0x9735e41 "@drop"}
        args = {len = 1, data = 0x1 <Address 0x1 out of bounds>}
        location = 0xff99f1f0
        clcf = 0xff99ea18

WORKAROUND Работает нормально при такой конфигурации:

  error_page 400 @drop;
  location @drop { return 0; }

comment:2 by Maxim Dounin, 11 years ago

Status: newaccepted

It's bad idea to set error_page for 400 Bad Request, and it's known to cause various problems due to lack of otherwise required request properties. It worth making it a bit better though.

comment:3 by Maxim Dounin, 9 years ago

See also #695.

comment:4 by Maxim Dounin <mdounin@…>, 6 years ago

In 7354:1812f1d79d84/nginx:

Fixed socket leak with "return 444" in error_page (ticket #274).

Socket leak was observed in the following configuration:

error_page 400 = /close;

location = /close {

return 444;

}

The problem is that "return 444" triggers termination of the request,
and due to error_page termination thinks that it needs to use a posted
request to clear stack. But at the early request processing where 400
errors are generated there are no ngx_http_run_posted_requests() calls,
so the request is only terminated after an external event.

Variants of the problem include "error_page 497" instead (ticket #695)
and various other errors generated during early request processing
(405, 414, 421, 494, 495, 496, 501, 505).

The same problem can be also triggered with "return 499" and "return 408"
as both codes trigger ngx_http_terminate_request(), much like "return 444".

To fix this, the patch adds ngx_http_run_posted_requests() calls to
ngx_http_process_request_line() and ngx_http_process_request_headers()
functions, and to ngx_http_v2_run_request() and ngx_http_v2_push_stream()
functions in HTTP/2.

Since the ngx_http_process_request() function is now only called via
other functions which call ngx_http_run_posted_requests(), the call
there is no longer needed and was removed.

comment:5 by Maxim Dounin, 6 years ago

Resolution: fixed
Status: acceptedclosed

Fix committed, thanks for reporting this.

Note: See TracTickets for help on using tickets.