systemd-resolved crashes: Assertion '*_head == _item' failed

[gdamjan]

Submission type

• Bug report
• Request for enhancement (RFE)

systemd version the issue has been seen with

7aa610f but I've seen the same issue in several recent versions from git

Used distribution

Arch on testing, systemd-git package from AUR that I compile several times a week.

In case of bug report: Unexpected behaviour you saw

Apr 01 18:24:40 arch-uefi-test systemd-resolved[271]: Switching to DNS server 192.168.15.1 for interface bridge0.
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: Using degraded feature set (UDP+EDNS0) for DNS server 192.168.15.1.
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: DNSSEC validation failed for question org IN SOA: failed-auxiliary
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: DNSSEC validation failed for question ntp.org IN DS: failed-auxiliary
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: DNSSEC validation failed for question ntp.org IN SOA: failed-auxiliary
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: DNSSEC validation failed for question pool.ntp.org IN DS: failed-auxiliary
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: DNSSEC validation failed for question pool.ntp.org IN SOA: failed-auxiliary
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: DNSSEC validation failed for question arch.pool.ntp.org IN SOA: failed-auxiliary
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: DNSSEC validation failed for question 2.arch.pool.ntp.org IN SOA: failed-auxiliary
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: DNSSEC validation failed for question 2.arch.pool.ntp.org IN A: failed-auxiliary
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: DNSSEC validation failed for question 2.arch.pool.ntp.org IN AAAA: failed-auxiliary
Apr 01 18:24:42 arch-uefi-test systemd-resolved[271]: Assertion '*_head == _item' failed at src/resolve/resolved-dns-transaction.c:94, function dns_transaction_free(). Aborting.
Apr 01 18:24:42 arch-uefi-test systemd[1]: systemd-resolved.service: Main process exited, code=killed, status=6/ABRT

[poettering]

Hmm, this should have left a coredump (at least if coredumpctl and stuff is enabled), any chance you can get the backtrace from that?

[gdamjan]

I don't get coredumps actually, dunno why. Tried asking on irc, noone knows either:

• systemd-coredump user exists
• sudo grep core /proc/336/limits → Max core file size unlimited unlimited bytes - 336 is systemd-resolved after it was restarted
• sysctl kernel.core_pattern → kernel.core_pattern = |/usr/lib/systemd/systemd-coredump %P %u %g %s %t %c %e - the same from /usr/lib/sysctl.d/50-coredump.conf

this is d57a7ed

[poettering]

That is certainly strange... if you can reproduce this reliably, could you maybe attach gdb to the resolved process, then reprdouce the issue and check the backtrace with gdb?

[gdamjan]

sorry for the screenshot, I had to do this in the VM before it's online

[yuwata]

I got the same issue. The snapshot I use is 4f4d6ee. I paste the outputs of systemd-resolved with "SYSTEMD_LOG_LEVEL=debug" option.

The hostname I've tested is "yitp00". On the host, run e.g. "ping yitp00" or "ssh yitp00", then resolved crash and the name resolution failed. The output of the resolved is pasted here.
In this case, systemd said

systemd[1]: systemd-resolved.service: Main process exited, code=killed, status=6/ABRT

Next, if run "ping (other host)" or "ssh (other host)", then resolved also crash, but the name resolution succeed. The output in this case is different from the previous one.
The outputs of systemd is also different.

systemd[1]: systemd-resolved.service: Main process exited, code=killed, status=11/SEGV

[yuwata]

Both cases in the above, I cannot find any coredump.

[yuwata]

Gdb backtrace for the first case above is here.

For the second case, the backtrace is here.

[yuwata]

Note that if DNSSEC=no is set then resolved seems to work fine.

[gdamjan]

with debuging enabled

May 12 16:46:33 arch-uefi-test systemd-resolved[467]: Transaction 33333 is now 61623.
May 12 16:46:33 arch-uefi-test systemd-resolved[467]: Transaction 61623 for <org IN DS> scope dns on bridge0/*.
May 12 16:46:33 arch-uefi-test systemd-resolved[467]: Transaction 61623 for <org IN DS> on scope dns on bridge0/* now complete with <rr-type-unsupported> from none (unsigned).
May 12 16:46:33 arch-uefi-test systemd-resolved[467]: Freeing transaction 61623.
May 12 16:46:33 arch-uefi-test systemd-resolved[467]: Transaction 61623 for <. CLASS21989 TYPE21989> on scope (null) on /* now complete with <success> from none (unsigned).
May 12 16:46:33 arch-uefi-test systemd-resolved[467]: Freeing transaction 61623.
May 12 16:46:33 arch-uefi-test systemd-resolved[467]: Assertion 'p->n_ref > 0' failed at src/resolve/resolved-dns-packet.c:184, function dns_packet_unref(). Aborting.

[gdamjan]

Seems to be fixed as of 6f270e6, I wonder if 0e3e1ae did it. I'll run some more tests, and report back.

[gdamjan]

spoke too soon, it just needed more time :/