Nginx 1.16.1 + Rdns Segmentation fault

[eporner]

Hi,

we have strange problem with latest nginx with Rdns module on our test platform. It randomly crashes on ngx_http_log_handler() function, but the issue is probably with be with the Rdns resolver itself.

Request is:

GET /XzT7jTAFH3M/XzT7jTAFH3M.mp4

Error log show this:

2019/09/03 21:43:07 [error] 9459#9459: *42856 open() "/usr/local/nginx/html/XzT7jTAFH3M/XzT7jTAFH3M.mp4" failed (2: No such file or directory) while connecting to upstream, client: 66.249.70.7, server: test.local, request: "GET /XzT7jTAFH3M/XzT7jTAFH3M.mp4 HTTP/1.1", upstream: "http://127.0.0.1:8282/XzT7jTAFH3M/XzT7jTAFH3M.mp4", host: "test.local"

And backtrace is:

Program terminated with signal SIGSEGV, Segmentation fault.
(gdb) bt full
#0  ngx_pnalloc (pool=0x0, size=size@entry=193) at src/core/ngx_palloc.c:139
No locals.
#1  0x000000000045764f in ngx_http_log_handler (r=0x16e54e0) at src/http/modules/ngx_http_log_module.c:362
        line = <optimized out>
        p = <optimized out>
        len = 193
        size = <optimized out>
        n = <optimized out>
        val = {len = 0, data = 0x45f763 <ngx_http_upstream_finalize_request+832> "H\203\304\030[]A\\A]A^A_\303H\211\356L\211\347\350\027\027\377\377\353\344H\213\203H\001"}
        i = <optimized out>
        l = <optimized out>
        log = <optimized out>
        op = <optimized out>
        buffer = <optimized out>
        lcf = <optimized out>
#2  0x000000000044e861 in ngx_http_log_request (r=r@entry=0x16e54e0) at src/http/ngx_http_request.c:3674
        i = <optimized out>
        n = <optimized out>
        log_handler = <optimized out>
        cmcf = <optimized out>
#3  0x000000000045003f in ngx_http_free_request (r=r@entry=0x16e54e0, rc=rc@entry=0) at src/http/ngx_http_request.c:3620
        log = 0x16f6310
        pool = <optimized out>
        linger = {l_onoff = -313370192, l_linger = 32766}
        cln = 0x0
        ctx = <optimized out>
        clcf = <optimized out>
#4  0x0000000000450908 in ngx_http_set_keepalive (r=0x16e54e0) at src/http/ngx_http_request.c:3069
        tcp_nodelay = <optimized out>
        cl = <optimized out>
        rev = 0x1621590
        b = 0x16f6438
        f = <optimized out>
        ln = <optimized out>
        wev = <optimized out>
        c = 0x15a7460
        hc = 0x16f6370
        clcf = 0x140c798
        tcp_nodelay = <optimized out>
        b = <optimized out>
        f = <optimized out>
        cl = <optimized out>
        ln = <optimized out>
        rev = <optimized out>
        wev = <optimized out>
        c = <optimized out>
        hc = <optimized out>
        clcf = <optimized out>
#5  ngx_http_finalize_connection (r=r@entry=0x16e54e0) at src/http/ngx_http_request.c:2720
        clcf = <optimized out>
#6  0x00000000004512d8 in ngx_http_finalize_request (r=r@entry=0x16e54e0, rc=<optimized out>) at src/http/ngx_http_request.c:2612
        c = 0x15a7460
        pr = <optimized out>
        clcf = <optimized out>
#7  0x0000000000450fcb in ngx_http_finalize_request (r=r@entry=0x16e54e0, rc=404) at src/http/ngx_http_request.c:2481
        c = 0x15a7460
        pr = <optimized out>
        clcf = <optimized out>
#8  0x000000000044cb52 in ngx_http_core_content_phase (r=0x16e54e0, ph=0x1599df0) at src/http/ngx_http_core_module.c:1179
        root = 4504347
        rc = <optimized out>
        path = {len = 21028144, data = 0x16e6248 "crawl-66-249-70-7.googlebot.com\221"}
#9  0x0000000000447772 in ngx_http_core_run_phases (r=r@entry=0x16e54e0) at src/http/ngx_http_core_module.c:858
        rc = <optimized out>
        ph = 0x1599c40
        cmcf = <optimized out>
#10 0x0000000000450f57 in ngx_http_finalize_request (r=r@entry=0x16e54e0, rc=rc@entry=-5) at src/http/ngx_http_request.c:2437
--Type <RET> for more, q to quit, c to continue without paging--
        c = 0x15a7460
        pr = <optimized out>
        clcf = <optimized out>
#11 0x00000000004f387a in resolver_handler_finalize (r=r@entry=0x16e54e0, ctx=ctx@entry=0x16e6228) at ../nginx-http-rdns/ngx_http_rdns_module.c:825
No locals.
#12 0x00000000004f3a50 in rdns_handler (rctx=0x1525d30) at ../nginx-http-rdns/ngx_http_rdns_module.c:675
        hostname = {len = 31, data = 0x172a1b8 "crawl-66-249-70-7.googlebot.com/usr/local/nginx/html/XzT7jTAFH3M/XzT7jTAFH3M.mp4"}
        r = 0x16e54e0
        ctx = 0x16e6228
        loc_cf = 0x140dd30
        cconf = <optimized out>
#13 0x000000000042de71 in ngx_resolver_process_ptr (nan=<optimized out>, code=<optimized out>, ident=<optimized out>, n=<optimized out>, buf=0x7ffeed525b70 "", r=<optimized out>) at src/core/ngx_resolver.c:3340
        start = <optimized out>
        expire_queue = 0x13f7780
        an = <optimized out>
        digit = <optimized out>
        addr6 = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}
        tree = <optimized out>
        next = 0x0
        rn = 0x16bb430
        addr = <optimized out>
        a = <optimized out>
        ctx = <optimized out>
        type = <optimized out>
        qident = <optimized out>
        i = 54
        name = {len = 31, data = 0x1689020 "crawl-66-249-70-7.googlebot.com"}
        hash = <optimized out>
        mask = <optimized out>
        class = <optimized out>
        err = <optimized out>
        len = <optimized out>
        ttl = <optimized out>
        octet = <optimized out>
        err = <optimized out>
        len = <optimized out>
        addr = <optimized out>
        ttl = <optimized out>
        octet = <optimized out>
        name = <optimized out>
        mask = <optimized out>
        type = <optimized out>
        class = <optimized out>
        qident = <optimized out>
        a = <optimized out>
        i = <optimized out>
        start = <optimized out>
        expire_queue = <optimized out>
        tree = <optimized out>
        an = <optimized out>
        ctx = <optimized out>
        next = <optimized out>
        rn = <optimized out>
        hash = <optimized out>
        digit = <optimized out>
        addr6 = <optimized out>
#14 ngx_resolver_process_response (r=<optimized out>, buf=buf@entry=0x7ffeed525c20 "\355\067\201\200", n=<optimized out>, tcp=tcp@entry=0) at src/core/ngx_resolver.c:1842
        err = <optimized out>
        i = <optimized out>
        times = <optimized out>
        ident = <optimized out>
        qident = <optimized out>
        flags = <optimized out>
        code = <optimized out>
        nqs = <optimized out>
        nan = <optimized out>
        trunc = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        qtype = <optimized out>
        qclass = <optimized out>
        qident6 = <optimized out>
        q = <optimized out>
        qs = <optimized out>
        response = 0x7ffeed525c20
        rn = <optimized out>
#15 0x000000000042e413 in ngx_resolver_udp_read (rev=0x1620cf0) at src/core/ngx_resolver.c:1569
        n = <optimized out>
        c = 0x15a5e18
        rec = 0x13f7898
        buf = "\355\067\201\200\000\001\000\001\000\004\000\b\001\067\002\067\060\003\062\064\071\002\066\066\ain-addr\004arpa\000\000\f\000\001\300\f\000\f\000\001\000\001QR\000!\021crawl-66-249-70-7\tgooglebot\003cm\000\300\016\000\002\000\001\000\001H\300\000\r\003ns4\006google\300R\300\016\000\002\000\001\000\001H\300\000\006\003ns3\300g\300\016\000\002\000\001\000\001H\300\000\006\003ns1\300g\300\016\000\002\000\001\000\001\300\000\006\003ns2\300g\300\216\000\001\000\001\000\002\231\324\000\004\330\357 \n\300|\000\001\000\001\000\002\231\324\000\004\330\357$\n\300\240"...
#16 0x000000000043af1d in ngx_epoll_process_events (cycle=<optimized out>, timer=<optimized out>, flags=<optimized out>) at src/event/modules/ngx_epoll_module.c:902
        events = 1
        revents = 1
        instance = 1
        i = 0
        level = <optimized out>
        err = <optimized out>
        rev = <optimized out>
        wev = <optimized out>
        queue = <optimized out>
        c = 0x15a5e18
#17 0x0000000000431fed in ngx_process_events_and_timers (cycle=cycle@entry=0x13dff20) at src/event/ngx_event.c:242
        flags = 1
        timer = 5000
        delta = 2927870
#18 0x0000000000439677 in ngx_worker_process_cycle (cycle=0x13dff20, data=<optimized out>) at src/os/unix/ngx_process_cycle.c:750
        worker = <optimized out>
#19 0x0000000000437d71 in ngx_spawn_process (cycle=cycle@entry=0x13dff20, proc=proc@entry=0x439587 <ngx_worker_process_cycle>, data=data@entry=0x3, name=name@entry=0x4f8855 "worker process", respawn=respawn@entry=-3)
    at src/os/unix/ngx_process.c:199
        on = 1
        pid = 0
        s = 3
#20 0x0000000000438873 in ngx_start_worker_processes (cycle=cycle@entry=0x13dff20, n=6, type=type@entry=-3) at src/os/unix/ngx_process_cycle.c:359
        i = 3
        ch = {command = 1, pid = 5484, slot = 2, fd = 38}
#21 0x0000000000439cd8 in ngx_master_process_cycle (cycle=cycle@entry=0x13dff20) at src/os/unix/ngx_process_cycle.c:131
        title = 0x159cca4 "master process /usr/local/nginx/sbin/nginx"
        p = <optimized out>
        size = <optimized out>
        i = <optimized out>
        n = <optimized out>
        sigio = <optimized out>
        set = {__val = {0 <repeats 16 times>}}
        itv = {it_interval = {tv_sec = 0, tv_usec = 0}, it_value = {tv_sec = 0, tv_usec = 0}}
        live = <optimized out>
        delay = <optimized out>
        ls = <optimized out>
        ccf = 0x13e1e18
#22 0x0000000000413ce6 in main (argc=1, argv=<optimized out>) at src/core/nginx.c:382
        b = <optimized out>
        log = 0x5a74c0 <ngx_log>
        i = <optimized out>
        cycle = 0x13dff20
        init_cycle = {conf_ctx = 0x0, pool = 0x13c32c0, log = 0x5a74c0 <ngx_log>, new_log = {log_level = 0, file = 0x0, connection = 0, disk_full_time = 0, handler = 0x0, data = 0x0, writer = 0x0, wdata = 0x0,
            action = 0x0, next = 0x0}, log_use_stderr = 0, files = 0x0, free_connections = 0x0, free_connection_n = 0, modules = 0x0, modules_n = 0, modules_used = 0, reusable_connections_queue = {prev = 0x0,
            next = 0x0}, reusable_connections_n = 0, listening = {elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0}, paths = {elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0}, config_dump = {
            elts = 0x0, nelts = 0, size = 0, nalloc = 0, pool = 0x0}, config_dump_rbtree = {root = 0x0, sentinel = 0x0, insert = 0x0}, config_dump_sentinel = {key = 0, left = 0x0, right = 0x0, parent = 0x0,
            color = 0 '\000', data = 0 '\000'}, open_files = {last = 0x0, part = {elts = 0x0, nelts = 0, next = 0x0}, size = 0, nalloc = 0, pool = 0x0}, shared_memory = {last = 0x0, part = {elts = 0x0, nelts = 0,
              next = 0x0}, size = 0, nalloc = 0, pool = 0x0}, connection_n = 0, files_n = 0, connections = 0x0, read_events = 0x0, write_events = 0x0, old_cycle = 0x0, conf_file = {len = 32,
            data = 0x13c3310 "14 (linux-gnu)"}, conf_param = {len = 0, data = 0x0}, conf_prefix = {len = 22, data = 0x13c3310 "14 (linux-gnu)"}, prefix = {len = 17, data = 0x4f41cb "/usr/local/nginx/"}, lock_file = {
            len = 0, data = 0x0}, hostname = {len = 0, data = 0x0}}
        cd = <optimized out>
        ccf = <optimized out>

As you can see in frame 13 we got successful resolved name to crawl-66-249-70-7.googlebot.com

But then in frame 12 we got:
hostname = {len = 31, data = 0x172a1b8 "crawl-66-249-70-7.googlebot.com/usr/local/nginx/html/e5rTPCqK8ds/e5rTPCqK8ds.mp4"}

hostname.len is okay, but for some reason hostname.data has attached local path /usr/local/nginx/html and $uri which is /e5rTPCqK8ds/e5rTPCqK8ds.mp4.

1. how it is possible ? In ngx_http_rdns_module.c:645 there is code:

        hostname.data = ngx_pcalloc(r->pool, rctx->name.len * sizeof(u_char));
        ngx_memcpy(hostname.data, rctx->name.data, rctx->name.len);

so it should just copy name.data from ngx_resolver_process_ptr to hostname.data, but for some reason it add path and $uri to this ?

2. Why error log show open() "/usr/local/nginx/html/XzT7jTAFH3M/XzT7jTAFH3M.mp4" failed (2: No such file or directory) while connecting to upstream ? It should connect to upstream due to
   proxy_pass ​https://www.eporner.com/; directive. It is trying to connect to upstream but opening local file from $uri insted ? It looks like Rdns code is doing some overwriting with variables used by proxy/upstream modules.

3. I guess that segmentation fault in ngx_http_log_handler is due to missmatch between data and length in hostname/uri in previous frames caused by Rdns.

Test nginx.conf:

    server {

        listen :443 ssl http2;
        server_name test.local;
        ssl_certificate /etc/test.local/fullchain.pem;
        ssl_certificate_key /etc/test.local/privkey.pem;
        proxy_buffering off;

        rdns on;
        rdns_allow (.*google\.com|.*googlebot\.com);
        rdns_deny .*;

        location / {

            proxy_pass ​http://127.0.0.1:8282/;

        }

        }

    server {

        listen 127.0.0.1:8282;
        proxy_buffering off;

        location / {

            proxy_pass ​https://www.eporner.com/;
            proxy_intercept_errors on;
            recursive_error_pages on;
            error_page 301 302 307 = @handle_redirect;

        }

        location @handle_redirect {

            set $saved_redirect_location '$upstream_http_location';
            proxy_pass $saved_redirect_location;
            proxy_intercept_errors on;
            recursive_error_pages on;
            error_page 301 302 307 = @handle_redirect;

        }

}

We are using latest Rdns from: ​https://github.com/flant/nginx-http-rdns