Project

General

Profile

Actions

Bug #3207

closed

Segfaults after upgrade to version 1.4.70

Added by ultimator 9 months ago. Updated 9 months ago.

Status:
Fixed
Priority:
Normal
Category:
mod_accesslog
Target version:
ASK QUESTIONS IN Forums:
No

Description

Since the upgrade to version 1.4.70, the server crashes from time to time with SIGSEGV.
Backtrace

0x0000007ff7d72218 in memcpy () from /lib64/libc.so.6
(gdb) bt full
#0  0x0000007ff7d72218 in memcpy () from /lib64/libc.so.6
No symbol table info available.
#1  0x0000005555563a0c in buffer_append_string_len (b=0x55556ab198, s=0x0, len=1055) at ../lighttpd-1.4.70/src/buffer.c:194
No locals.
#2  0x0000007ff73a12d8 in buffer_append_buffer (b=0x55556ab198, src=0x55556f26c8) at ../lighttpd-1.4.70/src/buffer.h:304
No locals.
#3  0x0000007ff73a3d48 in log_access_record (r=0x5555756a90, b=0x55556ab198, parsed_format=0x55556834e0, esc=0x55555652ec <buffer_append_bs_escaped>) at ../lighttpd-1.4.70/src/mod_accesslog.c:943
        f = 0x55556834f8
        vb = 0x55556a0f60
        ts = {tv_sec = 0, tv_nsec = 0}
        flush = 0
#4  0x0000007ff73a407c in log_access_write (r=0x5555756a90, p_d=0x55556a0f60) at ../lighttpd-1.4.70/src/mod_accesslog.c:1008
        p = 0x55556a0f60
        fdlog = 0x55556ab190
        b = 0x55556ab198
        esc_fn = 0x55555652ec <buffer_append_bs_escaped>
        flush = 127
#5  0x00000055555855a8 in plugins_call_fn_req_data (r=0x5555756a90, e=5) at ../lighttpd-1.4.70/src/plugin.c:284
        plugin_slots = 0x55556a1090
        offset = 384
        plfd = 0x55556a1210
        rc = HANDLER_GO_ON
#6  0x000000555558585c in plugins_call_handle_request_done (r=0x5555756a90) at ../lighttpd-1.4.70/src/plugin.c:339
No locals.
#7  0x000000555559fef8 in h2_release_stream (r=0x5555756a90, con=0x55556c1c60) at ../lighttpd-1.4.70/src/h2.c:2894
No locals.
#8  0x00000055555a0028 in h2_retire_stream (r=0x5555756a90, con=0x55556c1c60) at ../lighttpd-1.4.70/src/h2.c:2929
        h2c = 0x555572ab60
        ar = 0x555572ab60
        i = 0
        rused = 0
#9  0x00000055555a09c4 in h2_process_streams (con=0x55556c1c60, http_response_loop=0x55555ab958 <http_response_handler>, connection_handle_write=0x5555596aa4 <connection_handle_write>) at ../lighttpd-1.4.70/src/h2.c:3292
        alive = 0
        r = 0x5555756a90
        i = 0
        max_bytes = 261755
        cqlen = 0
        h2c = 0x555572ab60
        resched = 0
        h2r = 0x200000002000
#10 0x0000005555597d0c in connection_state_machine (con=0x55556c1c60) at ../lighttpd-1.4.70/src/connections.c:863
        rc = 127
        r = 0x55555ac13c <server_monotonic_secs+44>
#11 0x00000055555afe20 in server_run_con_queue (joblist=0x55556c1c60, sentinel=0x55555f0c40 <log_con_jqueue>) at ../lighttpd-1.4.70/src/server.c:2148
        con = 0x55556c1c60
        jqnext = 0x55555f0c40 <log_con_jqueue>
#12 0x00000055555affb0 in server_main_loop (srv=0x55555f2520) at ../lighttpd-1.4.70/src/server.c:2204
        mono_ts = 7413790
        sentinel = 0x55555f0c40 <log_con_jqueue>
        joblist = 0x55556c1c60
        last_active_ts = 7413790
#13 0x00000055555b01d8 in main (argc=4, argv=0x7fffffec58) at ../lighttpd-1.4.70/src/server.c:2296
        srv = 0x55555f2520
        rc = 1

OS: Gentoo Linux
Arch: arm64
USE: brotli lua nettle pcre ssl system-xxhash xattr zlib
CFLAGS: -march=armv8-a+crc+simd -mtune=cortex-a72 -ftree-vectorize -O2 -pipe -fomit-frame-pointer


Files

lighttpd.conf (29.1 KB) lighttpd.conf ultimator, 2023-05-20 08:39

Related issues 1 (0 open1 closed)

Has duplicate Bug #3210: Unexpected 403 after multiple reloads in lighttpd 1.4.70DuplicateActions
Actions #1

Updated by gstrauss 9 months ago

  • Target version changed from 1.4.xx to 1.4.71

buffer_append_string_len (b=0x55556ab198, s=0x0, len=1055)

Looks like a NULL pointer dereference. :( I'll dig in later and tomorrow to see if I can find scenarios where r->dst_addr_buf points to an invalid (buffer *)

What was the previous version of lighttpd you were running (which did not crash)? Was it lighttpd 1.4.69?

mod_accesslog logs at the end of request handling, but if your server is not too busy, and requests generally complete quickly, then debug.log-request-header = "enable" will log request headers in the error log and might help to identify which types of requests cause the crash.

Actions #2

Updated by gstrauss 9 months ago

Is a periodic scanner on your network triggering the crashes?
If you temporarily disable mod_sockproxy and then run the scanner, do the crash still happen?


Asides:

I do not think that "^remote" will match anything, since the url-path begins with "/"

    $HTTP["host"] == "nextcloud.pygos.space" {
        url.rewrite-once           = (
            "^remote\/[^\?]*\?(.*)$"          => "remote.php&$1",
            ...

You should use Let's Encrypt /path/to/fullchain.pem in ssl.pemfile and then remove ssl.verifyclient.ca-file. ssl.verifyclient.ca-file is for TLS client certificate verification and the name of that directive (ssl.verifyclient.ca-file) was changed to reflect that. It is a historical misfeature of openssl to re-use that to attempt to complete certificate chains that are incomplete elsewhere, e.g. for the server certificate, which may be issued from a different Certificate Authority than the Certificate Authority which issued your client certificates (if you issue client certificates).

        ssl.pemfile              = "/etc/letsencrypt/live/pygos.space/fullchain.pem" 
        ssl.privkey              = "/etc/letsencrypt/live/pygos.space/privkey.pem" 

Actions #3

Updated by ultimator 9 months ago

What was the previous version of lighttpd you were running (which did not crash)? Was it lighttpd 1.4.69?

Yes. 1.4.69 had no crash.

debug.log-request-header = "enable" will log request headers

I will try this.

Is a periodic scanner on your network triggering the crashes?

The crashes happen quite randomly. Sometimes after a few minutes but sometimes I have no crash in 20 hours. I have a scanner running that checks every 10 minutes or so so that should not be the (only) culprit.

Asides: ...

Thanks.

Actions #4

Updated by ultimator 9 months ago

Some gdb info

(gdb) select-frame 3

(gdb) print /s *r

$11 = {state = CON_STATE_RESPONSE_END, http_status = 200, x = {h2 = {state = 6, id = 41, rwin = 65536, swin = 4194087, rwin_fudge = 0, prio = 7 '\a'}, h1 = {bytes_written_ckpt = 176093659142, bytes_read_ckpt = 18013466501644288, te_chunked = 458752}}, 
  http_method = HTTP_METHOD_GET, http_version = HTTP_VERSION_2, handler_module = 0x55555f8f90, plugin_ctx = 0x55556bffd0, con = 0x55556c4d50, conditional_is_valid = 4294967295, cond_cache = 0x55556c2e20, cond_match = 0x0, cond_match_data = 0x0, conf = {errh = 0x55556a0400, 
    http_parseopts = 9567, max_request_field_size = 8192, mimetypes = 0x5555608420, document_root = 0x55555fabc0, server_name = 0x0, server_tag = 0x0, max_request_size = 0, max_keep_alive_requests = 1000, max_keep_alive_idle = 5, max_read_idle = 60, max_write_idle = 360, 
    stream_request_body = 32768, stream_response_body = 3, high_precision_timestamps = 0, allow_http11 = 1, range_requests = 1, follow_symlink = 1, etag_flags = 7, use_xattr = 0, force_lowercase_filenames = 0, error_intercept = 0, h2proto = 2, log_request_handling = 1, 
    log_state_handling = 0, log_condition_handling = 0, log_response_header = 1, log_request_header = 1, log_request_header_on_error = 1, log_file_not_found = 0, log_timeouts = 0, bytes_per_second = 0, global_bytes_per_second = 0, global_bytes_per_second_cnt_ptr = 0x0, 
    error_handler = 0x0, error_handler_404 = 0x0, errorfile_prefix = 0x0, serrh = 0x0}, rqst_header_len = 307, rqst_htags = 220676381942481925, rqst_headers = {data = 0x55556a9af0, sorted = 0x55556b80a0, used = 9, size = 16}, uri = {scheme = {ptr = 0x55556c3410 "https", used = 6, 
      size = 65}, authority = {ptr = 0x55556c3540 "matrix.pygos.space", used = 19, size = 65}, path = {ptr = 0x55556c34b0 "/_matrix/client/r0/sync", used = 24, size = 129}, query = {
      ptr = 0x55556db810 "filter=0&since=s313153_7767597_318_95484_113430_55_2437_179219_0_2&timeout=30000", used = 81, size = 129}}, physical = {path = {ptr = 0x55556c3a60 "/var/www/servers/matrix.pygos.space/htdocs/_matrix/client/r0/sync", used = 66, size = 257}, basedir = {
      ptr = 0x55556c3a10 "/var/www/servers/matrix.pygos.space/htdocs/", used = 44, size = 65}, doc_root = {ptr = 0x55556c3930 "/var/www/servers/matrix.pygos.space/htdocs/", used = 44, size = 65}, rel_path = {ptr = 0x55556c3980 "/_matrix/client/r0/sync", used = 24, size = 129}}, 
  env = {data = 0x0, sorted = 0x0, used = 0, size = 0}, reqbody_length = 0, resp_body_scratchpad = -1, http_host = 0x55556b8150, server_name = 0x55556c2ce8, target = {
    ptr = 0x5555608eb0 "/_matrix/client/r0/sync?filter=0&since=s313153_7767597_318_95484_113430_55_2437_179219_0_2&timeout=30000", used = 105, size = 257}, target_orig = {
    ptr = 0x555568aac0 "/_matrix/client/r0/sync?filter=0&since=s313153_7767597_318_95484_113430_55_2437_179219_0_2&timeout=30000", used = 105, size = 257}, pathinfo = {ptr = 0x0, used = 0, size = 0}, server_name_buf = {ptr = 0x55556c38e0 "matrix.pygos.space", used = 19, 
    size = 65}, dst_addr = 0x55556aa9a8, dst_addr_buf = 0x55556aaa18, resp_header_len = 510, resp_htags = 158329675728945, resp_headers = {data = 0x55556be160, sorted = 0x55556be1f0, used = 11, size = 16}, resp_body_finished = 1 '\001', resp_body_started = 1 '\001', 
  resp_send_chunked = 0 '\000', resp_decode_chunked = 1 '\001', resp_header_repeated = 0 '\000', loops_per_request = 0 '\000', keep_alive = 0 '\000', async_callback = 0 '\000', tmp_buf = 0x55555f26d0, gw_dechunk = 0x55556f62d0, start_hp = {tv_sec = 1684664878, tv_nsec = 0}, 
  error_handler_saved_status = 0, error_handler_saved_method = HTTP_METHOD_GET, write_queue = {first = 0x0, last = 0x0, bytes_in = 727, bytes_out = 727, tempdirs = 0x55555f31b0, upload_temp_file_size = 1048576, tempdir_idx = 0}, read_queue = {first = 0x0, last = 0x0, 
    bytes_in = 307, bytes_out = 307, tempdirs = 0x55555f31b0, upload_temp_file_size = 1048576, tempdir_idx = 0}, reqbody_queue = {first = 0x0, last = 0x0, bytes_in = 0, bytes_out = 0, tempdirs = 0x55555f31b0, upload_temp_file_size = 1048576, tempdir_idx = 0}, tmp_sce = 0x0, 
  cond_captures = 0, h2_connect_ext = 0}

(gdb) print /s *(r->dst_addr_buf)

$12 = {ptr = 0x0, used = 1056, size = 0}

Actions #5

Updated by gstrauss 9 months ago

  • Status changed from New to Patch Pending

Can you test with this patch?

--- a/src/reqpool.c
+++ b/src/reqpool.c
@@ -305,6 +305,8 @@ request_acquire (connection * const con)
     }

     r->con = con;
+    r->dst_addr = &con->dst_addr;
+    r->dst_addr_buf = &con->dst_addr_buf;
     r->tmp_buf = con->srv->tmp_buf;
     return r;
 }

Actions #6

Updated by ultimator 9 months ago

gstrauss wrote in #note-5:

Can you test with this patch?
[...]

I applied the patch.
No crash in the last 24h so far.

Actions #7

Updated by gstrauss 9 months ago

  • Status changed from Patch Pending to Fixed
Actions #8

Updated by ultimator 9 months ago

Still no crash. Looks like this indeed fixes the issue. Thanks for investigating.

Actions #9

Updated by gstrauss 9 months ago

  • Has duplicate Bug #3210: Unexpected 403 after multiple reloads in lighttpd 1.4.70 added
Actions

Also available in: Atom