Random segfaults in 7.65.1

[z1atk0]

I did this

/usr/local/bin/curl -s https://3dl.tv/feed/movies

I expected the following

a dump of the RSS feed

curl/libcurl version

curl 7.65.1 (i686-pc-linux-gnu) libcurl/7.65.1 GnuTLS/3.6.8 zlib/1.2.11 brotli/1.0.4 c-ares/1.15.0 libidn2/2.2.0 libpsl/0.20.2 (+libidn2/2.1.1) libssh2/1.8.2 nghttp2/1.20.0 librtmp/2.3
Release-Date: 2019-06-05
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtmp rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS brotli GSS-API HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz NTLM NTLM_WB PSL SPNEGO SSL TLS-SRP UnixSockets

operating system

Slackware 14.2 i686 (yes, 32bit). curl is self-compiled.

I actually get a segfault approximately once out of 5 runs. Re-compiled curl-7.65.1 and c-ares-1.15.0 with --enable-debug. Here's the backtrace:

(gdb) run
Starting program: /usr/local/bin/curl -s https://3dl.tv/feed/movies
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/libthread_db.so.1".

Program received signal SIGSEGV, Segmentation fault.
0xb7ebbdf0 in sh_delentry (entry=0x80abb64, sh=0x80a9f70, s=4) at multi.c:253
253	    dta->sh_entry = NULL;
(gdb) bt full
#0  0xb7ebbdf0 in sh_delentry (entry=0x80abb64, sh=0x80a9f70, s=4) at multi.c:253
        dta = 0x0
        list = 0x80abb64
        e = 0x809f664
#1  0xb7ebf84e in Curl_multi_closed (data=0x809f64c, s=4) at multi.c:2397
        entry = 0x80abb64
        multi = 0x80a9f04
#2  0xb7ee337f in Curl_ares_sock_state_cb (data=0x809f64c, socket_fd=4, readable=0, writable=0) at asyn-ares.c:141
        easy = 0x809f64c
        __PRETTY_FUNCTION__ = "Curl_ares_sock_state_cb"
#3  0xb7cb5f15 in ares__close_sockets (channel=0x80a0590, server=0x80a9db8) at ares__close_sockets.c:57
        sendreq = 0xb7cc3346 <ares__free_query+12>
#4  0xb7cc3323 in end_query (channel=0x80a0590, query=0x80abbe8, status=0, abuf=0xbfffc2b3 <incomplete sequence \374\205\200>, alen=108) at ares_process.c:1447
        i = 1
        __PRETTY_FUNCTION__ = "end_query"
#5  0xb7cc1e18 in process_answer (channel=0x80a0590, abuf=0xbfffc2b3 <incomplete sequence \374\205\200>, alen=108, whichserver=1, tcp=0, now=0xbfffd2f8) at ares_process.c:668
        tc = 0
        rcode = 0
        packetsz = 512
        id = 17404
        query = 0x80abbe8
        list_head = 0x80a36f8
        list_node = 0x80abbf4
#6  0xb7cc1a43 in read_udp_packets (channel=0x80a0590, read_fds=0x0, read_fd=4, now=0xbfffd2f8) at ares_process.c:532
        server = 0x80a9db8
        i = 1
        count = 108
        buf = "C\374\205\200\000\001\000\001\000\001\000\000\005proxy\006zlatk0\003net\000\000\034\000\001\300\f\000\005\000\001\000\001Q\200\000\v\bairframe\300\022\300\022\000\006\000\001\000\001Q\200\000'\003ns1\300\022\nhostmaster\300\022xI{\245\000\000*0\000\000\003\204\000\t:\200\000\001Q\200\022\300g\000\001\000\001\000\001Q\200\000\004\300\250\001\004\300U\000\001\000\001\000\001Q\200\000\004\300\250\001\003", '\000' <repeats 56 times>, "\064\064\063"...
        fromlen = 16
        from = {sa = {sa_family = 2, sa_data = "\000\065\300\250\001\003\000\000\000\000\000\000\000"}, sa4 = {sin_family = 2, sin_port = 13568, sin_addr = {s_addr = 50440384}, 
            sin_zero = "\000\000\000\000\000\000\000"}, sa6 = {sin6_family = 2, sin6_port = 13568, sin6_flowinfo = 50440384, sin6_addr = {__in6_u = {
                __u6_addr8 = "\000\000\000\000\000\000\000\000v\000\000\000\320\322\377\277", __u6_addr16 = {0, 0, 0, 0, 118, 0, 53968, 49151}, __u6_addr32 = {0, 0, 118, 3221213904}}}, sin6_scope_id = 10}}
#7  0xb7cc0ee1 in processfds (channel=0x80a0590, read_fds=0x0, read_fd=4, write_fds=0x0, write_fd=-1) at ares_process.c:131
        now = {tv_sec = 172534, tv_usec = 913729}
#8  0xb7cc0f5e in ares_process_fd (channel=0x80a0590, read_fd=4, write_fd=-1) at ares_process.c:152
No locals.
#9  0xb7ee37df in waitperform (conn=0x80ab65c, timeout_ms=0) at asyn-ares.c:333
        data = 0x809f64c
        nfds = 1
        bitmask = 3
        socks = {3, 4, -1208125064, -1073753096, 3691283, 1847318074, 3564640, 1, 1, -1209667584, -1209667584, -1073752984, -1210235750, 1, -1073753016, 172539}
        pfd = {{fd = 3, events = 65, revents = 0}, {fd = 4, events = 65, revents = 65}, {fd = 3690123, events = 0, revents = 0}, {fd = 3564640, events = 1, revents = 0}, {fd = 1, events = -4096, 
            revents = -18459}, {fd = -1209667584, events = -11288, revents = -16385}, {fd = -1210235750, events = -28971, revents = -18452}, {fd = -1073753144, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = -1209291294, events = -11288, revents = -16385}, {fd = -1209269472, events = 780, revents = 2058}, {fd = 134873980, events = 0, revents = 0}, {fd = -1073753192, 
            events = -11368, revents = -16385}, {fd = -1073753112, events = -27707, revents = -18452}, {fd = 172539, events = -3836, revents = 13}, {fd = -1208125722, events = 29508, revents = -18435}}
        i = 1
        num = 2
#10 0xb7ee383e in Curl_resolver_is_resolved (conn=0x80ab65c, dns=0xbfffd4d8) at asyn-ares.c:360
        data = 0x809f64c
        res = 0x80abf34
---Type <return> to continue, or q <return> to quit---
        result = CURLE_OK
        __PRETTY_FUNCTION__ = "Curl_resolver_is_resolved"
#11 0xb7e87deb in Curl_resolv_check (conn=0x80ab65c, dns=0xbfffd4d8) at hostip.c:1026
No locals.
#12 0xb7ebdcff in multi_runsingle (multi=0x80a9f04, now=..., data=0x809f64c) at multi.c:1436
        dns = 0x0
        conn = 0x80ab65c
        hostname = 0x80ab57c "proxy"
        stream_error = false
        msg = 0x0
        connected = 229
        async = 240
        protocol_connect = false
        dophase_done = false
        done = false
        rc = CURLM_OK
        result = CURLE_OK
        timeout_ms = 300000
        recv_timeout_ms = 5000
        send_timeout_ms = -1073752840
        control = 1
        __PRETTY_FUNCTION__ = "multi_runsingle"
#13 0xb7ebf04e in curl_multi_perform (multi=0x80a9f04, running_handles=0xbfffd5ac) at multi.c:2080
        result = -1208643584
        data = 0x809f64c
        returncode = CURLM_OK
        t = 0x0
        now = {tv_sec = 172534, tv_usec = 913725}
#14 0xb7eb26ad in easy_transfer (multi=0x80a9f04) at easy.c:624
        still_running = 0
        gotsocket = true
        done = false
        mcode = CURLM_OK
        result = CURLE_OK
#15 0xb7eb2876 in easy_perform (data=0x809f64c, events=false) at easy.c:718
        multi = 0x80a9f04
        mcode = CURLM_OK
        result = CURLE_OK
#16 0xb7eb28b2 in curl_easy_perform (data=0x809f64c) at easy.c:737
No locals.
#17 0x0805c156 in operate_do (global=0xbfffd9bc, config=0x809d344) at tool_operate.c:1599
        retry_sleep = 1000
        this_url = 0x80b1544 "https://3dl.tv/feed/movies"
        metalink_next_res = 0
        outfile = 0x0
        retrystart = {tv_sec = 172534, tv_usec = 913054}
        retry_sleep_default = 1000
        infd = 0
        infdopen = false
        outs = {filename = 0x0, alloc_filename = false, is_cd_filename = false, s_isreg = false, fopened = false, stream = 0xb7e5fd60 <_IO_2_1_stdout_>, config = 0x809d344, bytes = 0, init = 0}
        input = {fd = 0, config = 0x809d344}
        uploadfilesize = -1
---Type <return> to continue, or q <return> to quit---
        retry_numretries = 0
        uploadfile = 0x0
        separator = 0
        urls = 0x80b09fc
        urlnum = 1
        infilenum = 1
        mlres = 0x0
        up = 0
        infiles = 0x0
        outfiles = 0x0
        inglob = 0x0
        metalink = 0
        mlfile = 0x0
        errorbuffer = "\000~\353\267'", '\000' <repeats 11 times>, "\266v\353\267\350\327\377\277\000\220\365\267\350\327\377\277Jy\353\267\320N\361\267[W\006\b[\003\000\000\320\335\377\277\033\000\000\000\234\t\v\b\033\000\000\000\227x\353\267\000\000\000\000 \332\377\277\234\t\v\b\033\000\000\000\206@\006\b \332\377\277\b\331\377\277c\025\005\b\320\335\377\277[\003\000\000[W\006\bn\000\000\000\000\000\000\000w\000\000\000\000\000\000\000|\000\000\000UTF-8//\000\200\367\345\267\330\066\t\b \000\000\000k>\341\267\000\360巀\367\345\267\004\000\000\000\030\000\000\000\000\000\000\000бԷ\000\360\345\267\f\000\000\000\v\000\000\000\220\265Է\000\000\000\000\360\327\377\277\020"...
        progressbar = {calls = 0, prev = 0, prevtime = {tv_sec = 0, tv_usec = 0}, width = 206, out = 0xb7e5fcc0 <_IO_2_1_stderr_>, initial_size = 0, tick = 150, bar = 0, barmove = 1}
        urlnode = 0x80b06cc
        hdrcbdata = {global = 0xbfffd9bc, config = 0x809d344, outs = 0xbfffd650, heads = 0xbfffd728, honor_cd_filename = false}
        heads = {filename = 0x0, alloc_filename = false, is_cd_filename = false, s_isreg = false, fopened = false, stream = 0xb7e5fd60 <_IO_2_1_stdout_>, config = 0x809d344, bytes = 0, init = 0}
        mlfile_last = 0x0
        curl = 0x809f64c
        httpgetfields = 0x0
        result = CURLE_OK
        li = 0
        capath_from_env = false
        orig_noprogress = true
        orig_isatty = false
        __PRETTY_FUNCTION__ = "operate_do"
#18 0x0805d330 in operate (config=0xbfffd9bc, argc=3, argv=0xbfffdab4) at tool_operate.c:2093
        count = 1
        operation = 0x0
        res = PARAM_OK
        result = CURLE_OK
#19 0x08056d3a in main (argc=3, argv=0xbfffdab4) at tool_main.c:326
        result = CURLE_OK
        global = {easy = 0x809f64c, showerror = 0, mute = true, noprogress = true, isatty = true, errors = 0xb7e5fcc0 <_IO_2_1_stderr_>, errors_fopened = false, trace_dump = 0x0, trace_stream = 0x0, 
          trace_fopened = false, tracetype = TRACE_NONE, tracetime = false, progressmode = 0, libcurl = 0x0, fail_early = false, styled_output = true, first = 0x809d344, current = 0x809d344, 
          last = 0x809d344}
(gdb) 

curl-7.65.0 didn't have this problem. Given that it always segfaults in sh_delentry & taking into consideration the Changelog, it's probably related to 5f73e0c:

- multi: track users of a socket better

  They need to be removed from the socket hash linked list with more care.
  
  When sh_delentry() is called to remove a sockethash entry, remove all
  individual transfers from the list first. To enable this, each Curl_easy struct
  now stores a pointer to the sockethash entry to know how to remove itself.
                            
  Reported-by: Tom van der Woerdt and Kunal Ekawde

  Fixes #3952
  Fixes #3904
  Closes #3953

If you need any more info/data just let me know.

Thanks,
Thomas

[jay]

Ref: 8581e19#commitcomment-33840706
Ref: #3961

/cc @gvanem

[bagder]

I think this looks very similar to the #3986 problem

[jreynojustin]

I also started receiving segmentation faults from curl when upgrading to 7.65.1 and a rollback to 7.65.0 fixed the issue. Probably same root cause it seems, can work to gather the trace if you need additional info beyond what z1atk0 reported.

[jeroen]

I started seeing immediate segfaults in MacOS on Travis for the R bindings with homebrew libcurl 7.65.1, but only for the curl-openssl flavor (which uses nghttp2 and c-ares). The crashes do not appear with the regular curl (darwinssl) flavor.

Interestingly I cannot reproduce this locally on my mac with same curl-openssl. So it must be a side effect of the Travis environment, which could be related to DNS.

[bagder]

It's more likely to happen with c-ares (or HTTP/2 multiplexing) and it's timing sensitive. #3997 is my initial take at a fix.

[z1atk0]

Yes, this seems to fix the problem for me. 1000 calls of the command line in my initial report without a single segfault. Yay! 😃

[bagder]

Awesome, thanks for confirming!

[jeroen]

Once this is merged in master I can easily check if this also resolves my travis problem.