Bug 1930415

Summary: systemd-resolved coredump malloc_consolidate(): unaligned fastbin chunk detected
Product: [Fedora] Fedora Reporter: RobbieTheK <rkudyba>
Component: systemdAssignee: systemd-maint
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 33CC: bugzilla_acct_1959, fedoraproject, filbranden, flepied, kasong, lnykryn, msekleta, ssahani, s, systemd-maint, xxjack12xx, yuwatana, zbyszek, z
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: systemd-246.13-1.fc33 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2021-03-27 01:11:00 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description RobbieTheK 2021-02-18 20:15:28 UTC
Using systemd-246.10-1.fc33.x86_64 I'm seeing several coredumps every day. I have an ABRT Analytics retrace at https://retrace.fedoraproject.org/faf/reports/72143/

sshd[2226886]: rexec line 54: Deprecated option RSAAuthentication
Feb 18 08:56:41 ourserver  systemd-resolved[2223701]: malloc(): unaligned tcache chunk detected
Feb 18 08:56:41 ourserver  systemd[1]: Started Process Core Dump (PID 2229419/UID 0).
Feb 18 08:56:41 ourserver  systemd-coredump[2229420]: Process 2223701 (systemd-resolve) of user 997 dumped core.
Stack trace of thread 2223701:
#0  0x00007fb75234a9d5 raise (libc.so.6 + 0x3d9d5)
#1  0x00007fb7523338a4 abort (libc.so.6 + 0x268a4)
#2  0x00007fb75238d177 __libc_message (libc.so.6 + 0x80177)
#3  0x00007fb752394e6c malloc_printerr (libc.so.6 + 0x87e6c)
#4  0x00007fb752399b7c malloc (libc.so.6 + 0x8cb7c)
#5  0x00007fb752a984c5 greedy_realloc (libsystemd-shared-246.so + 0x10a4c5)
#6  0x00007fb752b0c6ca bus_match_parse (libsystemd-shared-246.so + 0x17e6ca)
#7  0x00007fb752b2bcaa bus_add_match_full (libsystemd-shared-246.so + 0x19dcaa)
#8  0x00007fb752b2bf3d sd_bus_add_match_async (libsystemd-shared-246.so + 0x19df3d)
#9  0x00007fb752b2c117 sd_bus_track_add_name (libsystemd-shared-246.so + 0x19e117)
#10 0x0000565476929e22 dns_query_bus_track (systemd-resolved + 0x27e22)
#11 0x0000565476915582 bus_method_resolve_hostname (systemd-resolved + 0x13582)
#12 0x00007fb752b1ff3c object_find_and_run (libsystemd-shared-246.so + 0x191f3c)
#13 0x00007fb752b213ed bus_process_object (libsystemd-shared-246.so + 0x1933ed)
#14 0x00007fb752b2f733 bus_process_internal (libsystemd-shared-246.so + 0x1a1733)
#15 0x00007fb752b30131 io_callback (libsystemd-shared-246.so + 0x1a2131)
#16 0x00007fb752b60677 source_dispatch (libsystemd-shared-246.so + 0x1d2677)
#17 0x00007fb752b6095d sd_event_dispatch (libsystemd-shared-246.so + 0x1d295d)
#18 0x00007fb752b61c28 sd_event_run (libsystemd-shared-246.so + 0x1d3c28)
#19 0x00007fb752b61e4f sd_event_loop (libsystemd-shared-246.so + 0x1d3e4f)
#20 0x000056547691bc24 run (systemd-resolved + 0x19c24)
#21 0x000056547691061a main (systemd-resolved + 0xe61a)
#22 0x00007fb7523351e2 __libc_start_main (libc.so.6 + 0x281e2)
#23 0x00005654769106be _start (systemd-resolved + 0xe6be)


gdb backtrace:
Core was generated by `/usr/lib/systemd/systemd-resolved'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:49
49        return ret;
(gdb) bt full
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:49
        set = {__val = {17179888130, 8, 140432087934947, 140432079538518, 140432087934947, 94363142312384,
            140432087934947, 140432079538986, 32, 140432079542985, 140432079541504, 140432079542295,
            140432079541504, 14877651963795832576, 0, 94363142312384}}
        pid = <optimized out>
        tid = <optimized out>
        ret = <optimized out>
#1  0x00007fb8e43188a4 in __GI_abort () at abort.c:79
        save_stage = 1
        act = {__sigaction_handler = {sa_handler = 0x6d616864726f66, sa_sigaction = 0x6d616864726f66},
          sa_mask = {__val = {140432086520734, 140729076474240, 94363147741621, 30787871773647872,
              14877651963795832576, 140729076474277, 140432087242139, 140729076474032,
              14877651963795832576, 94363147741618, 140729076474032, 94363147877312, 94363147741618,
              94363147877296, 94363141710200, 112}}, sa_flags = -1616169179, sa_restorer = 0x7ffe0a9cdfe0}
        sigs = {__val = {32, 140729076473568, 140729076473632, 140432086521313, 140729076474240,
            140729076473552, 0, 94363147877330, 140728906114048, 140428250710016, 140729076474000,
            140729076473664, 3, 140432087075718, 140729076473664, 3}}
#2  0x00007fb8e4372177 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7fb8e44843a7 "%s\n")
    at ../sysdeps/posix/libc_fatal.c:155
        ap = {{gp_offset = 24, fp_offset = 0, overflow_arg_area = 0x7ffe0a9ce0e0,
            reg_save_area = 0x7ffe0a9ce070}}
        fd = <optimized out>
        list = <optimized out>
        nlist = <optimized out>
        cp = <optimized out>
#3  0x00007fb8e4379e6c in malloc_printerr (
    str=str@entry=0x7fb8e44866e0 "malloc_consolidate(): unaligned fastbin chunk detected") at malloc.c:5389
No locals.
#4  0x00007fb8e437af14 in malloc_consolidate (av=av@entry=0x7fb8e44b6a00 <main_arena>) at malloc.c:4509
--Type <RET> for more, q to quit, c to continue without paging--
        idx = <optimized out>
        fb = 0x7fb8e44b6a28 <main_arena+40>
        maxfb = 0x7fb8e44b6a58 <main_arena+88>
        p = 0x1
        nextp = <optimized out>
        unsorted_bin = 0x7fb8e44b6a60 <main_arena+96>
        first_unsorted = <optimized out>
        nextchunk = <optimized out>
        size = <optimized out>
        nextsize = <optimized out>
        prevsize = <optimized out>
        nextinuse = <optimized out>
#5  0x00007fb8e437cdc3 in _int_malloc (av=av@entry=0x7fb8e44b6a00 <main_arena>, bytes=bytes@entry=4096)
    at malloc.c:3727
        nb = 4112
        idx = 99
        bin = <optimized out>
        victim = <optimized out>
        size = <optimized out>
        victim_index = <optimized out>
        remainder = <optimized out>
        remainder_size = <optimized out>
        block = <optimized out>
        bit = <optimized out>
        map = <optimized out>
        fwd = <optimized out>
        bck = <optimized out>
        tcache_unsorted_count = <optimized out>
        tcache_nb = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        tc_idx = <optimized out>
        return_cached = <optimized out>
        __PRETTY_FUNCTION__ = "_int_malloc"
#6  0x00007fb8e437f6c5 in __libc_calloc (n=n@entry=1, elem_size=elem_size@entry=4096) at malloc.c:3448
        av = <optimized out>
        oldtop = 0x55d2a1ea38f0
        p = <optimized out>
        sz = 4096
        csz = <optimized out>
        oldtopsize = 18192
        mem = <optimized out>
        clearsize = <optimized out>
        nclears = <optimized out>
        d = <optimized out>
        bytes = 4096
        hook = <optimized out>
        __PRETTY_FUNCTION__ = "__libc_calloc"
#7  0x000055d29faaf686 in dns_packet_new (ret=0x7ffe0a9ce270, protocol=DNS_PROTOCOL_DNS,
    min_alloc_dsize=<optimized out>, max_size=65535) at ../src/resolve/resolved-dns-packet.c:74
        p = <optimized out>
        a = 3928
        __func__ = "dns_packet_new"
        __PRETTY_FUNCTION__ = {<optimized out> <repeats 15 times>}
#8  0x000055d29fab9e7e in dns_packet_new_query.constprop.0 (ret=0x7ffe0a9ce2d0, protocol=<optimized out>,
    dnssec_checking_disabled=<optimized out>, min_alloc_dsize=0) at ../src/resolve/resolved-dns-packet.c:146
        p = 0x55d2a193e910
        r = <optimized out>
        __PRETTY_FUNCTION__ = {<optimized out> <repeats 21 times>}
#9  0x000055d29fa9aba0 in dns_transaction_make_packet (t=0x55d2a193e910)
--Type <RET> for more, q to quit, c to continue without paging--
    at ../src/resolve/resolved-dns-transaction.c:1624
        p = 0x0
        r = <optimized out>
        p = <optimized out>
        r = <optimized out>
        __PRETTY_FUNCTION__ = {<optimized out> <repeats 28 times>}
        _ptr_ = <optimized out>
#10 dns_transaction_go (t=0x55d2a193e910) at ../src/resolve/resolved-dns-transaction.c:1711
        ts = 767040262109
        r = <optimized out>
        key_str = "\360\237\212\241\322U\000\000\376U\252\344\270\177\000\000\060\343\234\n\376\177\000\000\000\177\361ɢ\tx\316\375\071\237\034˿\242]\fO\252\344\270\177", '\000' <repeats 18 times>, "\377\000\000\000\000\000\000\000\002\000\000\000\000\000\000\000\360\343\234\n\376\177\000\000 \000\000\000\000\000\000\000\230\240\212\241\322U\000\000\376U\252\344\270\177\000\000\220\343\234\n\376\177\000\000\000\177\361ɢ\tx\316q\\\246\261\270\016\265\215\230\240\212\241\322U\000\000\002\000\000\000\000\000\000\000\360\343\234\n\376\177\000\000\220\251\346\241\322U\000\000\060䕡\322U\000\000\001\000\000\000\000\000\000\000\315\\\252\344\270\177\000\000\020\017\351\241\322U\000\000\230\240\212\241\322U\000\000"...
        __PRETTY_FUNCTION__ = "dns_transaction_go"
        __func__ = "dns_transaction_go"
        _found = <optimized out>
        __assert_in_set = {<optimized out>, <optimized out>}
#11 0x000055d29fa97854 in dns_query_candidate_go (c=0x55d2a19656d0)
    at ../src/resolve/resolved-dns-query.c:149
        keep_c = 0x55d2a19656d0
        t = 0x55d2a193e910
        i = {idx = 4294967295, next_key = 0x0}
        r = <optimized out>
        n = 0
        __PRETTY_FUNCTION__ = "dns_query_candidate_go"
--Type <RET> for more, q to quit, c to continue without paging--
#12 0x000055d29fa98569 in dns_query_go (q=0x55d2a1e6a880) at ../src/resolve/resolved-dns-query.c:712
        found = 5
        s = <optimized out>
        first = <optimized out>
        c = 0x55d2a19656d0
        r = <optimized out>
        __PRETTY_FUNCTION__ = {<optimized out> <repeats 13 times>}
        __func__ = {<optimized out> <repeats 13 times>}
#13 0x000055d29fa835a7 in dns_query_go (q=<optimized out>) at ../src/resolve/resolved-dns-query.c:625
        s = <optimized out>
        c = <optimized out>
        fail = <optimized out>
        found = DNS_SCOPE_NO
        first = 0x0
        r = <optimized out>
        found = <optimized out>
        s = <optimized out>
        first = <optimized out>
        c = <optimized out>
        r = <optimized out>
        __PRETTY_FUNCTION__ = {<optimized out> <repeats 13 times>}
        __func__ = {<optimized out> <repeats 13 times>}
        fail = <optimized out>
        match = <optimized out>
        name = <optimized out>
        _level = <optimized out>
        _e = <optimized out>
        _realm = <optimized out>
        state = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        match = <optimized out>
        name = <optimized out>
        _level = <optimized out>
        _e = <optimized out>
        _realm = <optimized out>
#14 bus_method_resolve_hostname (message=0x55d2a1e9b330, userdata=0x55d2a18a9210, error=0x7ffe0a9ce670)
    at ../src/resolve/resolved-bus.c:363
        question_idna = 0x0
        question_utf8 = 0x55d2a195e430
        m = 0x55d2a18a9210
        hostname = 0x55d2a1e704a0 "storm.cis.fordham.edu"
        family = 10
        ifindex = 0
        flags = 31
        q = 0x55d2a1e6a880
        r = 0
        __PRETTY_FUNCTION__ = "bus_method_resolve_hostname"
#15 0x00007fb8e4b04f3c in method_callbacks_run (found_object=0x7ffe0a9ce737, require_fallback=false,
    c=0x55d2a1955640, m=0x55d2a1e9b330, bus=0x55d2a1e79870) at ../src/libsystemd/sd-bus/bus-objects.c:415
        slot = 0x55d2a1e6f060
        error = {name = 0x0, message = 0x0, _need_free = 0}
        signature = <optimized out>
        u = 0x55d2a18a9210
        r = <optimized out>
        error = {name = <optimized out>, message = <optimized out>, _need_free = <optimized out>}
        signature = <optimized out>
        u = <optimized out>
        r = <optimized out>
        __PRETTY_FUNCTION__ = {<optimized out> <repeats 21 times>}
--Type <RET> for more, q to quit, c to continue without paging--
        slot = <optimized out>
        __unique_prefix_A4 = <optimized out>
#16 object_find_and_run (bus=0x55d2a1e79870, m=0x55d2a1e9b330,
    p=0x55d2a1e703e8 "/org/freedesktop/resolve1", require_fallback=false, found_object=0x7ffe0a9ce737)
    at ../src/libsystemd/sd-bus/bus-objects.c:1325
        n = 0x55d2a19eba30
        vtable_key = {path = 0x55d2a1e703e8 "/org/freedesktop/resolve1",
          interface = 0x55d2a1e70428 "org.freedesktop.resolve1.Manager",
          member = 0x55d2a1e70410 "ResolveHostname", parent = 0xce7809a2c9f17f00, last_iteration = 0,
          vtable = 0x55d2a1e798f8}
        v = 0x55d2a1955640
        r = <optimized out>
        __PRETTY_FUNCTION__ = "object_find_and_run"
#17 0x00007fb8e4b063ed in bus_process_object (bus=0x55d2a1e79870, m=0x55d2a1e9b330)
    at ../src/libsystemd/sd-bus/bus-objects.c:1445
        prefix = 0x55d2a1e7bc10 "\313E\234\374\327U"
        r = <optimized out>
        pl = <optimized out>
        found_object = true
        __PRETTY_FUNCTION__ = "bus_process_object"
#18 0x00007fb8e4b14733 in process_message (m=0x55d2a1e9b330, bus=0x55d2a1e79870)
    at ../src/libsystemd/sd-bus/sd-bus.c:2777
        r = <optimized out>
        r = <optimized out>
        __PRETTY_FUNCTION__ = {<optimized out> <repeats 16 times>}
        __func__ = {<optimized out> <repeats 16 times>}
        finish = <optimized out>
        _mm = <optimized out>
        _level = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        _e = <optimized out>
        _realm = <optimized out>
#19 process_running (ret=0x0, bus=<optimized out>) at ../src/libsystemd/sd-bus/sd-bus.c:2819
        m = 0x55d2a1e9b330
        r = 1
        null_message = <optimized out>
        m = <optimized out>
        r = <optimized out>
        __PRETTY_FUNCTION__ = {<optimized out> <repeats 16 times>}
        null_message = <optimized out>
        __func__ = {<optimized out> <repeats 16 times>}
        _found = <optimized out>
        __assert_in_set = {<optimized out>, <optimized out>}
        _ptr_ = <optimized out>
        _level = <optimized out>
        _e = <optimized out>
        _realm = <optimized out>
#20 bus_process_internal (bus=<optimized out>, ret=0x0) at ../src/libsystemd/sd-bus/sd-bus.c:3039
        r = <optimized out>
        _dont_destroy_bus = 0x55d2a1e79870
        __PRETTY_FUNCTION__ = "bus_process_internal"
#21 0x00007fb8e4b15131 in io_callback (s=<optimized out>, fd=<optimized out>, revents=<optimized out>,
    userdata=0x55d2a1e79870) at ../src/libsystemd/sd-bus/sd-bus.c:3425
        bus = 0x55d2a1e79870
        r = <optimized out>
        __PRETTY_FUNCTION__ = "io_callback"
        __func__ = "io_callback"
#22 0x00007fb8e4b45677 in source_dispatch (s=s@entry=0x55d2a1e8d930)
    at ../src/libsystemd/sd-event/sd-event.c:3181
--Type <RET> for more, q to quit, c to continue without paging--
        saved_type = SOURCE_IO
        r = <optimized out>
        __PRETTY_FUNCTION__ = "source_dispatch"
        __func__ = "source_dispatch"
#23 0x00007fb8e4b4595d in sd_event_dispatch (e=0x55d2a1e94350) at ../src/libsystemd/sd-event/sd-event.c:3620
        ref = 0x55d2a1e94350
        p = 0x55d2a1e8d930
        r = <optimized out>
        __PRETTY_FUNCTION__ = "sd_event_dispatch"
#24 0x00007fb8e4b46c28 in sd_event_run (e=e@entry=0x55d2a1e94350,
    timeout=timeout@entry=18446744073709551615) at ../src/libsystemd/sd-event/sd-event.c:3678
        r = 1
        __PRETTY_FUNCTION__ = "sd_event_run"
#25 0x00007fb8e4b46e4f in sd_event_loop (e=0x55d2a1e94350) at ../src/libsystemd/sd-event/sd-event.c:3700
        ref = <optimized out>
        r = <optimized out>
        __PRETTY_FUNCTION__ = "sd_event_loop"
#26 0x000055d29fa89c24 in run (argc=<optimized out>, argv=<optimized out>) at ../src/resolve/resolved.c:92
        m = <optimized out>
        notify_stop = 0x55d29fac2668 "STOPPING=1\nSTATUS=Shutting down..."
        r = 0
        __func__ = "run"
        __PRETTY_FUNCTION__ = "run"
#27 0x000055d29fa7e61a in main (argc=<optimized out>, argv=<optimized out>) at ../src/resolve/resolved.c:99
        r = <optimized out>

Comment 1 Zbigniew Jędrzejewski-Szmek 2021-03-25 11:49:41 UTC
Can you please check if this still occurs with systemd-246.12-1.fc33 (currently in updates-testing)?

Comment 2 RobbieTheK 2021-03-25 13:43:55 UTC
(In reply to Zbigniew Jędrzejewski-Szmek from comment #1)
> Can you please check if this still occurs with systemd-246.12-1.fc33
> (currently in updates-testing)?

I see systemd-246.13-1.fc33.x86_64 and have installed it. So far no coredumps after an hour

Comment 3 Zbigniew Jędrzejewski-Szmek 2021-03-26 17:05:30 UTC
OK, let's assume it is fixed.

Comment 4 Fedora Update System 2021-03-26 17:06:49 UTC
FEDORA-2021-1c1a870ceb has been submitted as an update to Fedora 33. https://bodhi.fedoraproject.org/updates/FEDORA-2021-1c1a870ceb

Comment 5 Fedora Update System 2021-03-27 01:11:00 UTC
FEDORA-2021-1c1a870ceb has been pushed to the Fedora 33 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 6 Jack 2021-03-31 01:23:27 UTC
After upgrading to systemd-libs-246.13-1.fc33.x86_64, I'm now getting this instead of Mar 30 06:07:10 systemd-resolved[1558340]: malloc(): unaligned tcache chunk detected



Mar 30 14:32:51 systemd-resolved[207182]: malloc(): unaligned fastbin chunk detected 3
Mar 30 14:32:51 systemd[1]: systemd-resolved.service: Main process exited, code=killed, status=6/ABRT
Mar 30 14:32:51 systemd[1]: systemd-resolved.service: Failed with result 'signal'.
Mar 30 14:32:51 systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 2.
Mar 30 14:32:51 systemd[1]: Stopped Network Name Resolution.
Mar 30 14:32:51 systemd[1]: Starting Network Name Resolution...
Mar 30 14:32:51 systemd-resolved[207227]: Positive Trust Anchors:
Mar 30 14:32:51 systemd-resolved[207227]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
Mar 30 14:32:51 systemd-resolved[207227]: Negative trust anchors: 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa corp home internal intranet lan local private test
Mar 30 14:32:51 systemd-resolved[207227]: Using system hostname 'redacted'.
Mar 30 14:32:51 systemd[1]: Started Network Name Resolution.
Mar 30 14:32:53 kernel: traps: systemd-resolve[207227] general protection fault ip:7f1c974f82d7 sp:7ffc0947b9a0 error:0 in libsystemd-shared-246.so[7f1c97424000+1a8000]
Mar 30 14:32:53 systemd[1]: systemd-resolved.service: Main process exited, code=killed, status=11/SEGV
Mar 30 14:32:53 systemd[1]: systemd-resolved.service: Failed with result 'signal'.
Mar 30 14:32:53 systemd[1]: systemd-resolved.service: Scheduled restart job, restart counter is at 3.
Mar 30 14:32:53 systemd[1]: Stopped Network Name Resolution.
Mar 30 14:32:53 systemd[1]: Starting Network Name Resolution...

Comment 7 Zbigniew Jędrzejewski-Szmek 2021-03-31 07:39:25 UTC
Jack: please open a new bug, with the core file or at least a full backtrace.

Comment 8 Jack 2021-04-05 08:16:50 UTC
Created a new bug report at https://bugzilla.redhat.com/show_bug.cgi?id=1945413