dhcpcd crash due to double free attempt

[Sime-Zupanovic]

This is happening on dhcpcd-10.2.2 version.
What seems to happen here is expire and SIGTERM close in time.

And below is pmd full back trace.

Program terminated with signal SIGABRT, Aborted.
#0 __pthread_kill_implementation (threadid=, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
44 pthread_kill.c: No such file or directory.
(gdb) bt
#0 __pthread_kill_implementation (threadid=, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
#1 0x0000007fa5448cd8 in __pthread_kill_internal (signo=6, threadid=) at pthread_kill.c:78
#2 0x0000007fa5401ce0 in __GI_raise (sig=sig@entry=6) at /usr/src/debug/glibc/2.39+git/sysdeps/posix/raise.c:26
#3 0x0000007fa53edeb0 in __GI_abort () at abort.c:79

[**ALERT: The abort() might not be exactly invoked from the following function line.
If the trail function contains multiple abort() calls, then you should cross check by other means to get correct abort() call location.
This is due to the optimized compilation which hides the debug info for multiple abort() calls in a given function.
Refer TR HU16995 for more information]

#4 0x0000007fa543c794 in __libc_message_impl (fmt=fmt@entry=0x7fa551bf00 "%s\n") at /usr/src/debug/glibc/2.39+git/sysdeps/posix/libc_fatal.c:134
#5 0x0000007fa5452ffc in malloc_printerr (str=str@entry=0x7fa5517220 "free(): double free detected in tcache 2") at malloc.c:5772
#6 0x0000007fa54553d8 in _int_free (av=0x7fa5554a40 <main_arena>, p=p@entry=0x55a718a710, have_lock=have_lock@entry=0) at malloc.c:4541
#7 0x0000007fa5457d64 in __GI___libc_free (mem=) at malloc.c:3398
#8 0x000000558f3b55e4 in dhcp6_freedrop (ifp=ifp@entry=0x55a71a9e10, drop=drop@entry=1, reason=, reason@entry=0x558f3c2448 "EXPIRE6") at dhcp6.c:4295
--Type for more, q to quit, c to continue without paging--
#9 0x000000558f3b73a0 in dhcp6_drop (ifp=ifp@entry=0x55a71a9e10, reason=reason@entry=0x558f3c2448 "EXPIRE6") at dhcp6.c:4321
#10 0x000000558f389e10 in dhcpcd_drop_af (af=0, stop=0, ifp=0x55a71a9e10) at dhcpcd.c:408
#11 dhcpcd_drop (stop=0, ifp=0x55a71a9e10) at dhcpcd.c:437
#12 dhcpcd_handlecarrier (ifp=ifp@entry=0x55a71a9e10, carrier=-1, flags=) at dhcpcd.c:763
#13 0x000000558f39e6e0 in link_netlink (arg=, nlm=, ctx=) at if-linux.c:1158
#14 link_netlink (ctx=0x7fd455e328, arg=, nlm=0x7fd455a248) at if-linux.c:1051
#15 0x000000558f39d0e4 in if_getnetlink (ctx=ctx@entry=0x7fd455e328, iov=0x7fd455a238, iov@entry=0x7fd455e258, fd=9, flags=flags@entry=64, cb=cb@entry=0x558f39e220 <link_netlink>, cbarg=cbarg@entry=0x0) at if-linux.c:666
#16 0x000000558f39d370 in if_handlelink (ctx=ctx@entry=0x7fd455e328) at if-linux.c:1173
#17 0x000000558f38af50 in dhcpcd_handlelink (arg=0x7fd455e328, events=) at dhcpcd.c:1143
#18 0x000000558f38cb54 in eloop_run_ppoll (signals=0x7fd455e568, ts=, eloop=0x55a7198810) at eloop.c:1106
#19 eloop_start (eloop=0x55a7198810, signals=signals@entry=0x7fd455e568) at eloop.c:1228
#20 0x000000558f385a74 in main (argc=, argv=, envp=) at dhcpcd.c:2648

(gdb) bt full
#0 __pthread_kill_implementation (threadid=, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
tid = 8339
ret = 0
pd =
old_mask = {__val = {18446744069414584320}}
ret =
#1 0x0000007fa5448cd8 in __pthread_kill_internal (signo=6, threadid=) at pthread_kill.c:78
No locals.
#2 0x0000007fa5401ce0 in __GI_raise (sig=sig@entry=6) at /usr/src/debug/glibc/2.39+git/sysdeps/posix/raise.c:26
ret =
#3 0x0000007fa53edeb0 in __GI_abort () at abort.c:79
save_stage = 1
act = {__sigaction_handler = {sa_handler = 0x20, sa_sigaction = 0x20}, sa_mask = {__val = {367875731456, 549023245096, 0, 367475141376, 367875731456, 549023245096, 0, 367475303160, 549023227088, 367475306936, 549023227136, 548233529204, 549023227280, 4096, 548234764288, 549023227280}}, sa_flags = -732568792, sa_restorer = 0x0}

[**ALERT: The abort() might not be exactly invoked from the following function line.
If the trail function contains multiple abort() calls, then you should cross check by other means to get correct abort() call location.
This is due to the optimized compilation which hides the debug info for multiple abort() calls in a given function.
Refer TR HU16995 for more information]

#4 0x0000007fa543c794 in __libc_message_impl (fmt=fmt@entry=0x7fa551bf00 "%s\n") at /usr/src/debug/glibc/2.39+git/sysdeps/posix/libc_fatal.c:134
ap = {__stack = 0x7fd4559e20, __gr_top = 0x7fd4559e20, __vr_top = 0x7fd4559de0, __gr_offs = -48, __vr_offs = 0}
fd = 2
iov = {{iov_base = 0x7fa5517220, iov_len = 40}, {iov_base = 0x7fa551bf02, iov_len = 1}, {iov_base = 0x30, iov_len = 88}, {iov_base = 0x7fa555a000 <__pthread_keys+14928>, iov_len = 548234702848}, {iov_base = 0x7fa556c5c0, iov_len = 548234676800}, {iov_base = 0x72b1, iov_len = 367875837264}, {iov_base = 0x7fd4559e40, iov_len = 367475065384}}
iovcnt =
--Type for more, q to quit, c to continue without paging--
total =
cp =
#5 0x0000007fa5452ffc in malloc_printerr (str=str@entry=0x7fa5517220 "free(): double free detected in tcache 2") at malloc.c:5772
No locals.
#6 0x0000007fa54553d8 in _int_free (av=0x7fa5554a40 <main_arena>, p=p@entry=0x55a718a710, have_lock=have_lock@entry=0) at malloc.c:4541
tmp =
cnt =
e = 0x55a718a720
tc_idx = 10
size = 192
fb =
#7 0x0000007fa5457d64 in __GI___libc_free (mem=) at malloc.c:3398
ar_ptr =
p = 0x55a718a710
err =
#8 0x000000558f3b55e4 in dhcp6_freedrop (ifp=ifp@entry=0x55a71a9e10, drop=drop@entry=1, reason=, reason@entry=0x558f3c2448 "EXPIRE6") at dhcp6.c:4295
state = 0x55a7187f70
ctx =
options =
#9 0x000000558f3b73a0 in dhcp6_drop (ifp=ifp@entry=0x55a71a9e10, reason=reason@entry=0x558f3c2448 "EXPIRE6") at dhcp6.c:4321
No locals.
#10 0x000000558f389e10 in dhcpcd_drop_af (af=0, stop=0, ifp=0x55a71a9e10) at dhcpcd.c:408
No locals.
#11 dhcpcd_drop (stop=0, ifp=0x55a71a9e10) at dhcpcd.c:437
No locals.
#12 dhcpcd_handlecarrier (ifp=ifp@entry=0x55a71a9e10, carrier=-1, flags=) at dhcpcd.c:763
was_link_up = true
was_roaming = false
func = "dhcpcd_handlecarrier"
#13 0x000000558f39e6e0 in link_netlink (arg=, nlm=, ctx=) at if-linux.c:1158
ifp = 0x55a71a9e10
len = 0
rta =
hwaddr =
ifn = "port0\000\000\000\000\000\000", <incomplete sequence \360>
r =
mtu =
ifi = 0x7fd455a258
ifp =
r =
len =
--Type for more, q to quit, c to continue without paging--
rta =
hwaddr =
mtu =
ifi =
ifn = { <repeats 17 times>}
hwa =
hwl =
#14 link_netlink (ctx=0x7fd455e328, arg=, nlm=0x7fd455a248) at if-linux.c:1051
ifp =
r =
len =
rta =
hwaddr =
mtu =
ifi =
ifn = { <repeats 17 times>}
hwa =
hwl =
#15 0x000000558f39d0e4 in if_getnetlink (ctx=ctx@entry=0x7fd455e328, iov=0x7fd455a238, iov@entry=0x7fd455e258, fd=9, flags=flags@entry=64, cb=cb@entry=0x558f39e220 <link_netlink>, cbarg=cbarg@entry=0x0) at if-linux.c:666
nladdr = {nl_family = 16, nl_pad = 0, nl_pid = 0, nl_groups = 1}
msg = {msg_name = 0x7fd455a180, msg_namelen = 12, msg_iov = 0x7fd455a238, msg_iovlen = 1, msg_control = 0x0, msg_controllen = 0, msg_flags = 0}
len = 1844
nlm = 0x7fd455a248
r = 0
again =
terminated = false
func = "if_getnetlink"
#16 0x000000558f39d370 in if_handlelink (ctx=ctx@entry=0x7fd455e328) at if-linux.c:1173
buf = "4\a\000\000\020", '\000' <repeats 13 times>, "\001\000\063\000\000\000C\020\000\000\000\000\000\000\016\000\003\000port0\000\000\000\b\000\r\000\350\003\000\000\005\000\020\000\006\000\000\000\005\000\021\000\000\000\000\000\b\000\004\000\334\005\000\000\b\000\062\000D\000\000\000\b\000\063\000\377\377\000\000\b\000\033\000\000\000\000\000\b\000\036\000\000\000\000\000\b\000=\000\000\000\000\000\b\000\037\000\001\000\000\000\b\000(\000\377\377\000\000\b\000)\000\000\000\001\000\b\000:\000\000\000\001\000\b\000;\000\000\000\001\000\b\000<\000\377\377\000\000\b\000 \000\001\000\000\000\005\000!\000\000\000\000\000\f\000\006\000noqueue\000\b\000#\000"...
iov = {iov_base = 0x7fd455a248, iov_len = 16384}
#17 0x000000558f38af50 in dhcpcd_handlelink (arg=0x7fd455e328, events=) at dhcpcd.c:1143
ctx = 0x7fd455e328
func = "dhcpcd_handlelink"
#18 0x000000558f38cb54 in eloop_run_ppoll (signals=0x7fd455e568, ts=, eloop=0x55a7198810) at eloop.c:1106
nn = 0
e = 0x55a71a45b0
n =
--Type for more, q to quit, c to continue without paging--
pfd =
events =
n =
nn =
e =
pfd =
events =
#19 eloop_start (eloop=0x55a7198810, signals=signals@entry=0x7fd455e568) at eloop.c:1228
error =
t =
ts = {tv_sec = 18, tv_nsec = 97269450}
tsp =
PRETTY_FUNCTION = "eloop_start"
#20 0x000000558f385a74 in main (argc=, argv=, envp=) at dhcpcd.c:2648
ctx = {pidfile = "/run/dhcpcd/port0.pid", '\000' <repeats 13 times>, vendor = "dhcpcd-10.2.2:Linux-6.1.118-manual-02438-gba80a67ead18:aarch64:AArch64", '\000' <repeats 185 times>, fork_fd = -1, cffile = 0x55a7183340 "/etc/pnc-dhcpcd.conf", options = 310344232912607245, logfile = 0x0, argc = 5, argv = 0x7fd455e978, ifac = 0, ifav = 0x0, ifdc = 0, ifdv = 0x0, ifc = 1, ifv = 0x7fd455e998, ifcc = 1, ifcv = 0x55a71985e0, duid_type = 0 '\000', duid = 0x55a71a26d0 "", duid_len = 16, ifaces = 0x55a71a45f0, ctl_buf = 0x0, ctl_buflen = 0, ctl_bufpos = 0, ctl_extra = 0, routes = {rbt_root = 0x0, rbt_ops = 0x558f3d94c0 <rt_compare_os_ops>, rbt_minmax = {0x7fd455e500, 0x7fd455e500}}, froutes = {rbt_root = 0x55a7187618, rbt_ops = 0x558f3d94e0 <rt_compare_free_ops>, rbt_minmax = {0x55a7184968, 0x55a71a66f8}}, rt_order = 1, pf_inet_fd = 15, priv = 0x55a71a30d0, link_fd = 9, link_rcvbuf = 0, seq = 176, sseq = 0, sigset = {__val = {0 <repeats 16 times>}}, eloop = 0x55a7198810, script = 0x558f3c31b8 "/usr/libexec/dhcpcd-run-hooks", script_fp = 0x55a719c410, script_buf = 0x55a71a4650 "PATH=/usr/bin:/usr/sbin:/bin:/sbin", script_buflen = 269, script_env = 0x55a7189e60, script_envlen = 83, control_fd = -1, control_unpriv_fd = -1, control_fds = {tqh_first = 0x55a71a3000, tqh_last = 0x55a71a3000}, control_sock = "/run/dhcpcd/port0.sock", '\000' <repeats 14 times>, control_sock_unpriv = "/run/dhcpcd/port0.unpriv.sock", '\000' <repeats 14 times>, control_group = 0, vivso = 0x0, vivso_len = 0, randomstate = 0x0, ps_user = 0x7fa5561668 , ps_processes = {tqh_first = 0x55a71a3f50, tqh_last = 0x55a71a4350}, ps_root = 0x55a71a3f50, ps_inet = 0x55a71a4130, ps_ctl = 0x55a71a4350, ps_data_fd = 8, ps_log_fd = -1, ps_log_root_fd = -1, ps_eloop = 0x55a71a3eb0, ps_control = 0x55a71a3000, ps_control_client = 0x0, dhcp_opts = 0x55a7194da0, dhcp_opts_len = 157, udp_rfd = -1, udp_wfd = -1, opt_buffer = 0x0, opt_buffer_len = 0, secret = 0x0, secret_len = 0, nd_fd = -1, ra_routers = 0x55a71bb1b0, nd_opts = 0x55a71979d0, nd_opts_len = 7, dhcp6_rfd = -1, dhcp6_wfd = -1, dhcp6_opts = 0x55a71a0940, dhcp6_opts_len = 84, dev_load = 0x0, dev_fd = -1, dev = 0x0, dev_handle = 0x0}
ifaddrs = 0x0
ifo = 0x0
ifp =
family = 0
opt =
oi = 4
i = 1
logopts =
t =
len =
pid =
fork_fd = {5, 6}
sig =
siga = 0x0
si = 1
func = "main"
--Type for more, q to quit, c to continue without paging--

(gdb) thread apply all bt

Thread 1 (LWP 8339):
#0 __pthread_kill_implementation (threadid=, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
#1 0x0000007fa5448cd8 in __pthread_kill_internal (signo=6, threadid=) at pthread_kill.c:78
#2 0x0000007fa5401ce0 in __GI_raise (sig=sig@entry=6) at /usr/src/debug/glibc/2.39+git/sysdeps/posix/raise.c:26
#3 0x0000007fa53edeb0 in __GI_abort () at abort.c:79

Fault seems to be on dhcp6.c:line 4295 on attempt of freeing free(state->send);.

         free(state->old);
         state->old = state->new;
         state->old_len = state->new_len;
         state->new = NULL;
         state->new_len = 0;
         if (drop && state->old &&
             (options & DHCPCD_NODROP) != DHCPCD_NODROP)
         {
                if (reason == NULL)
                       reason = "STOP6";
                script_runreason(ifp, reason);
         }
         free(state->old);
         **free(state->send); ---this seems to be line 4295 where it breaks**
         free(state->recv);
         free(state);
         ifp->if_data[IF_DATA_DHCP6] = NULL;

I suspect this is happening:
Expire6 event fires -> Callback 1 runs and eventually calls dhcp6_freedrop() -> triggers netlink through call dhcp6_freedrop_addrs() -> Callback 2 runs and eventually calls dhcp6_freedrop() -> nested dhcp6_freedrop()!

From gdb we can see old and new pointers are set to NULL

(gdb) p *state
$2 = {state = 89730220, started = {tv_sec = 8817249710939041503, tv_nsec = 854369100}, IMD = 0, RTC = 1, IRT = 1, MRC = 10, MRT = 30, MRCcallback = 0x557b37b540 <dhcp6_failrequest>, sol_max_rt = 3600, inf_max_rt = 3600,
RT = 2020, send = 0x5592caff60, send_len = 176, recv = 0x0, recv_len = 0, new = 0x0, new_len = 0, old = 0x0, old_len = 0, acquired = {tv_sec = 358, tv_nsec = 857515240}, renew = 60, rebind = 120, expire = 4000, unicast = {
__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, addrs = {tqh_first = 0x0, tqh_last = 0x5592cacfd8}, lowpl = 3000,
leasefile = "/var/lib/dhcpcd/port0.lease6", '\000' <repeats 142 times>, reason = 0x557b38ce88 "BOUND6", lerror = 0, has_no_binding = false, failed = false, new_start = false, auth = {replay = 0, token = 0x0,
reconf = 0x0}}

suspicion is that dhcp6_freedrop_addrs() triggers netlink call due to address free and we get Callback 2 triggered before we reached ifp->if_data[IF_DATA_DHCP6] = NULL; :

Callback 2 - dhcpcd_handlelink():
/* Start handling kernel messages for interfaces, addresses and
* routes. */
if (eloop_event_add(ctx.eloop, ctx.link_fd, ELE_READ,
dhcpcd_handlelink, &ctx) == -1)
logerr("%s: eloop_event_add", func);

there is also interesting comment in dhcp6_freedrop() pointing on possible function re-entering

   state = D6_STATE(ifp);
   if (state) {
          _**/* Failure to send the release may cause this function to
         * re-enter */**_
         if (state->state == DH6S_RELEASE) {
                dhcp6_finishrelease(ifp);
                return;
         }