Skip to content

resolve: mdns: fix use-after-free#23875

Merged
bluca merged 9 commits intosystemd:mainfrom
yuwata:resolve-mdns-fix-use-after-free
Jul 27, 2022
Merged

resolve: mdns: fix use-after-free#23875
bluca merged 9 commits intosystemd:mainfrom
yuwata:resolve-mdns-fix-use-after-free

Conversation

@yuwata
Copy link
Copy Markdown
Member

@yuwata yuwata commented Jul 1, 2022

Fixes #23843.
Fixes #23873.
Fixes #23894.

@yuwata
Copy link
Copy Markdown
Member Author

yuwata commented Jul 1, 2022

cc @vchillara and @evverx.

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 1, 2022

With this patch applied it appears resolved just stops responding at some point and hits the watchdog timeout:

Jul 01 09:58:13 C systemd-resolved[193]: Received mdns UDP packet of size 42, ifindex=2, ttl=255, fragsize=0, sender=fe80::e877:11ff:fe8f:dc4b, destination=ff02::fb
Jul 01 09:58:13 C systemd-resolved[193]: Received mdns UDP packet of size 42, ifindex=2, ttl=255, fragsize=0, sender=192.168.73.29, destination=224.0.0.251
Jul 01 09:58:13 C systemd-resolved[193]: Received mdns UDP packet of size 125, ifindex=2, ttl=255, fragsize=0, sender=192.168.73.17, destination=224.0.0.251
Jul 01 09:58:13 C systemd-resolved[193]: Got mDNS reply packet
Jul 01 09:58:13 C systemd-resolved[193]: Checking for conflicts...
Jul 01 09:58:13 C systemd-resolved[193]: Processing incoming packet of size 125 on transaction 23209 (rcode=SUCCESS).
Jul 01 09:58:13 C systemd-resolved[193]: Regular transaction 23209 for <H._qotd._tcp.local IN TXT> on scope mdns on host0/INET now complete with <success> from network (unsigned; non-confidential).
Jul 01 10:00:42 C systemd[1]: systemd-resolved.service: Killing process 193 (systemd-resolve) with signal SIGABRT.

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 1, 2022

Looks like it gets stuck in dns_answer_match_key:

#0  0x00007f049aedde80 in dns_label_unescape (name=0x7f0495906040, dest=0x7f04959060c0 "_qcal", sz=61, flags=0) at ../src/shared/dns-domain.c:34
#1  0x00007f049aee18a6 in dns_name_equal (x=0x615000008a08 "_tcp.local", y=0x6040000023a2 "_qotd._tcp.local") at ../src/shared/dns-domain.c:546
#2  0x000000000058b0a3 in dns_resource_key_match_rr (key=0x604000002390, rr=0x60b000001c70, search_domain=0x0) at ../src/resolve/resolved-dns-rr.c:222
#3  0x00000000005ad7f5 in dns_answer_match_key (a=0x6020000026d0, key=0x604000002390, ret_flags=0x0) at ../src/resolve/resolved-dns-answer.c:279
#4  0x0000000000539454 in on_mdns_packet (s=0x612000002140, fd=15, revents=1, userdata=0x618000000080) at ../src/resolve/resolved-mdns.c:416
#5  0x00007f049b5b4146 in source_dispatch (s=0x612000002140) at ../src/libsystemd/sd-event/sd-event.c:3602
#6  0x00007f049b5bc9fb in sd_event_dispatch (e=0x617000000080) at ../src/libsystemd/sd-event/sd-event.c:4186
#7  0x00007f049b5bdb5f in sd_event_run (e=0x617000000080, timeout=18446744073709551615) at ../src/libsystemd/sd-event/sd-event.c:4247
#8  0x00007f049b5bdee0 in sd_event_loop (e=0x617000000080) at ../src/libsystemd/sd-event/sd-event.c:4268
#9  0x000000000055344e in run (argc=1, argv=0x7ffdaa36ff48) at ../src/resolve/resolved.c:92
#10 0x00000000005536e8 in main (argc=1, argv=0x7ffdaa36ff48) at ../src/resolve/resolved.c:99

@yuwata yuwata added the reviewed/needs-rework 🔨 PR has been reviewed and needs another round of reworks label Jul 1, 2022
@yuwata yuwata force-pushed the resolve-mdns-fix-use-after-free branch from e5be7a5 to 043f231 Compare July 1, 2022 13:16
@yuwata yuwata removed the reviewed/needs-rework 🔨 PR has been reviewed and needs another round of reworks label Jul 1, 2022
@yuwata
Copy link
Copy Markdown
Member Author

yuwata commented Jul 1, 2022

@evverx Could you retest this??

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 1, 2022

I can't seem to trigger the heap-use-after-free anymore but resolved somehow fails to resolve services:

$ resolvectl flush-caches
$ resolvectl service C._qotd._tcp.local
Resolve call failed: 'C._qotd._tcp.local' does not have any RR of the requested type
$ ./build/resolvectl service C._qotd._tcp.local
C._qotd._tcp.local: C.local:17 [priority=0, weight=0]
                    192.168.188.77                          -- link: ve-root
                    (C/_qotd._tcp/local)

-- Information acquired via protocol mDNS/IPv4 in 8.3ms.
-- Data is authenticated: no; Data was acquired via local or encrypted transport: no
-- Data from: cache
$ resolvectl service --cache=no C._qotd._tcp.local
Resolve call failed: 'C._qotd._tcp.local' does not have any RR of the requested type

I'm not sure if it has actually ever worked though so it could be that it's a different issue.

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 1, 2022

Looks like it isn't reproducible without this PR so it's probably a regression. I'm not sure what exactly is going on though. It seems it has something to do with the cache.

@yuwata yuwata added the reviewed/needs-rework 🔨 PR has been reviewed and needs another round of reworks label Jul 1, 2022
@yuwata
Copy link
Copy Markdown
Member Author

yuwata commented Jul 1, 2022

@evverx Could you try with --service-address=no?? I'd like to know where the bus error message comes from.

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 1, 2022

With --service-address=no it doesn't seem to fail to resolve the service.

Without it it appears to always fail with --cache=no:

$ ./build/resolvectl flush-caches
$ SYSTEMD_LOG_LEVEL=debug ./build/resolvectl service  C._qotd._tcp.local
Bus n/a: changing state UNSET → OPENING
sd-bus: starting bus by connecting to /run/dbus/system_bus_socket...
Bus n/a: changing state OPENING → AUTHENTICATING
Resolving service type C._qotd._tcp.local (family *, interface *).
Bus n/a: changing state AUTHENTICATING → HELLO
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.710 path=n/a interface=n/a member=n/a cookie=4294967295 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Bus n/a: changing state HELLO → RUNNING
Sent message type=method_call sender=n/a destination=org.freedesktop.resolve1 path=/org/freedesktop/resolve1 interface=org.freedesktop.resolve1.Manager member=ResolveService cookie=2 reply_cookie=0 signature=isssit error-name=n/a error-message=n/a
Got message type=error sender=:1.703 destination=:1.710 path=n/a interface=n/a member=n/a cookie=46 reply_cookie=2 signature=s error-name=org.freedesktop.resolve1.NoSuchRR error-message='C._qotd._tcp.local' does not have any RR of the requested type
Resolve call failed: 'C._qotd._tcp.local' does not have any RR of the requested type
Bus n/a: changing state RUNNING → CLOSED
$ SYSTEMD_LOG_LEVEL=debug ./build/resolvectl service  C._qotd._tcp.local
Bus n/a: changing state UNSET → OPENING
sd-bus: starting bus by connecting to /run/dbus/system_bus_socket...
Bus n/a: changing state OPENING → AUTHENTICATING
Resolving service type C._qotd._tcp.local (family *, interface *).
Bus n/a: changing state AUTHENTICATING → HELLO
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.711 path=n/a interface=n/a member=n/a cookie=4294967295 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Bus n/a: changing state HELLO → RUNNING
Sent message type=method_call sender=n/a destination=org.freedesktop.resolve1 path=/org/freedesktop/resolve1 interface=org.freedesktop.resolve1.Manager member=ResolveService cookie=2 reply_cookie=0 signature=isssit error-name=n/a error-message=n/a
Got message type=method_return sender=:1.703 destination=:1.711 path=n/a interface=n/a member=n/a cookie=51 reply_cookie=2 signature=a(qqqsa(iiay)s)aayssst error-name=n/a error-message=n/a
C._qotd._tcp.local: C.local:17 [priority=0, weight=0]
                    192.168.123.34                          -- link: ve-root
                    (C/_qotd._tcp/local)

-- Information acquired via protocol mDNS/IPv6 in 181.8ms.
-- Data is authenticated: no; Data was acquired via local or encrypted transport: no
-- Data from: cache
Bus n/a: changing state RUNNING → CLOSED
D-Bus cache flush request from client PID 153135 (resolvectl) with UID 1000
Flushed all caches.
Sent message type=method_return sender=n/a destination=:1.709 path=n/a interface=n/a member=n/a cookie=42 reply_cookie=2 signature=n/a error-name=n/a error-message=n/a
Got message type=method_call sender=:1.710 destination=org.freedesktop.resolve1 path=/org/freedesktop/resolve1 interface=org.freedesktop.resolve1.Manager member=ResolveService cookie=2 reply_cookie=0 signature=isssit error-name=n/a error-message=n/a
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixProcessID cookie=43 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.703 path=n/a interface=n/a member=n/a cookie=4294967295 reply_cookie=43 signature=u error-name=n/a error-message=n/a
D-Bus service resolution request from client PID 153137 (resolvectl) with UID 1000
Looking up RR for C._qotd._tcp.local IN SRV.
Looking up RR for C._qotd._tcp.local IN TXT.
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=AddMatch cookie=44 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetNameOwner cookie=45 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.703 path=n/a interface=n/a member=n/a cookie=4294967295 reply_cookie=45 signature=s error-name=n/a error-message=n/a
Cache miss for C._qotd._tcp.local IN SRV
Firing regular transaction 64853 for <C._qotd._tcp.local IN SRV> scope mdns on ve-root/INET6 (validate=yes).
Delaying mdns transaction 64853 for 41495us.
Cache miss for C._qotd._tcp.local IN TXT
Firing regular transaction 10967 for <C._qotd._tcp.local IN TXT> scope mdns on ve-root/INET6 (validate=yes).
Delaying mdns transaction 10967 for 45482us.
Cache miss for C._qotd._tcp.local IN SRV
Firing regular transaction 31402 for <C._qotd._tcp.local IN SRV> scope mdns on ve-root/INET (validate=yes).
Delaying mdns transaction 31402 for 40710us.
Cache miss for C._qotd._tcp.local IN TXT
Firing regular transaction 46130 for <C._qotd._tcp.local IN TXT> scope mdns on ve-root/INET (validate=yes).
Delaying mdns transaction 46130 for 110474us.
Got message type=method_return sender=org.freedesktop.DBus destination=:1.703 path=n/a interface=n/a member=n/a cookie=4294967295 reply_cookie=44 signature= error-name=n/a error-message=n/a
Match type='signal',sender='org.freedesktop.DBus',path='/org/freedesktop/DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',arg0=':1.710' successfully installed.
Initial jitter phase for transaction 31402 elapsed.
Retrying transaction 31402.
Cache miss for C._qotd._tcp.local IN SRV
Firing regular transaction 31402 for <C._qotd._tcp.local IN SRV> scope mdns on ve-root/INET (validate=yes).
Cache miss for C._qotd._tcp.local IN TXT
Sending query packet with id 0 on interface 8/AF_INET of size 42.
Initial jitter phase for transaction 10967 elapsed.
Retrying transaction 10967.
Cache miss for C._qotd._tcp.local IN TXT
Firing regular transaction 10967 for <C._qotd._tcp.local IN TXT> scope mdns on ve-root/INET6 (validate=yes).
Cache miss for C._qotd._tcp.local IN SRV
Sending query packet with id 0 on interface 8/AF_INET6 of size 42.
Received mdns UDP packet of size 42, ifindex=8, ttl=255, fragsize=0, sender=169.254.184.15, destination=224.0.0.251
Received mdns UDP packet of size 42, ifindex=8, ttl=255, fragsize=0, sender=fe80::8c8f:67ff:fe3c:2c4e, destination=ff02::fb
Received mdns UDP packet of size 70, ifindex=8, ttl=255, fragsize=0, sender=192.168.123.34, destination=224.0.0.251
Got mDNS reply packet
Checking for conflicts...
Processing incoming packet of size 70 on transaction 46130 (rcode=SUCCESS).
Regular transaction 46130 for <C._qotd._tcp.local IN TXT> on scope mdns on ve-root/INET now complete with <success> from network (unsigned; non-confidential).
Processing incoming packet of size 70 on transaction 31402 (rcode=SUCCESS).
Regular transaction 31402 for <C._qotd._tcp.local IN SRV> on scope mdns on ve-root/INET now complete with <success> from network (unsigned; non-confidential).
Freeing transaction 64853.
Freeing transaction 10967.
Freeing transaction 46130.
Looking up RR for C.local IN A.
Looking up RR for C.local IN AAAA.
Cache miss for C.local IN AAAA
Firing regular transaction 23150 for <C.local IN AAAA> scope mdns on ve-root/INET6 (validate=yes).
Delaying mdns transaction 23150 for 119410us.
Cache miss for C.local IN A
Firing regular transaction 53071 for <C.local IN A> scope mdns on ve-root/INET (validate=yes).
Delaying mdns transaction 53071 for 108865us.
Freeing transaction 31402.
Processing incoming packet of size 70 on transaction 53071 (rcode=SUCCESS).
Regular transaction 53071 for <C.local IN A> on scope mdns on ve-root/INET now complete with <success> from network (unsigned; non-confidential).
Freeing transaction 23150.
Sent message type=error sender=n/a destination=:1.710 path=n/a interface=n/a member=n/a cookie=46 reply_cookie=2 signature=s error-name=org.freedesktop.resolve1.NoSuchRR error-message='C._qotd._tcp.local' does not have any RR of the requested type
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=RemoveMatch cookie=47 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Freeing transaction 53071.
Added positive unauthenticated non-confidential cache entry for C._qotd._tcp.local IN SRV 120s on ve-root/INET/192.168.123.34
Added positive unauthenticated non-confidential cache entry for C._qotd._tcp.local IN TXT 120s on ve-root/INET/192.168.123.34
Received mdns UDP packet of size 70, ifindex=8, ttl=255, fragsize=0, sender=fe80::e877:11ff:fe8f:dc4b, destination=ff02::fb
Got mDNS reply packet
Checking for conflicts...
Added positive unauthenticated non-confidential cache entry for C._qotd._tcp.local IN TXT 120s on ve-root/INET6/fe80::e877:11ff:fe8f:dc4b
Added positive unauthenticated non-confidential cache entry for C._qotd._tcp.local IN SRV 120s on ve-root/INET6/fe80::e877:11ff:fe8f:dc4b
Got message type=method_call sender=:1.711 destination=org.freedesktop.resolve1 path=/org/freedesktop/resolve1 interface=org.freedesktop.resolve1.Manager member=ResolveService cookie=2 reply_cookie=0 signature=isssit error-name=n/a error-message=n/a
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixProcessID cookie=48 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.703 path=n/a interface=n/a member=n/a cookie=4294967295 reply_cookie=48 signature=u error-name=n/a error-message=n/a
D-Bus service resolution request from client PID 153139 (resolvectl) with UID 1000
Looking up RR for C._qotd._tcp.local IN SRV.
Looking up RR for C._qotd._tcp.local IN TXT.
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=AddMatch cookie=49 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetNameOwner cookie=50 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.703 path=n/a interface=n/a member=n/a cookie=4294967295 reply_cookie=50 signature=s error-name=n/a error-message=n/a
Positive cache hit for C._qotd._tcp.local IN TXT
Regular transaction 35972 for <C._qotd._tcp.local IN TXT> on scope mdns on ve-root/INET6 now complete with <success> from cache (unsigned; non-confidential).
Positive cache hit for C._qotd._tcp.local IN SRV
Regular transaction 61962 for <C._qotd._tcp.local IN SRV> on scope mdns on ve-root/INET6 now complete with <success> from cache (unsigned; non-confidential).
Positive cache hit for C._qotd._tcp.local IN TXT
Regular transaction 30411 for <C._qotd._tcp.local IN TXT> on scope mdns on ve-root/INET now complete with <success> from cache (unsigned; non-confidential).
Positive cache hit for C._qotd._tcp.local IN SRV
Regular transaction 47064 for <C._qotd._tcp.local IN SRV> on scope mdns on ve-root/INET now complete with <success> from cache (unsigned; non-confidential).
Freeing transaction 35972.
Freeing transaction 61962.
Freeing transaction 30411.
Freeing transaction 47064.
Looking up RR for C.local IN A.
Looking up RR for C.local IN AAAA.
Cache miss for C.local IN AAAA
Firing regular transaction 31916 for <C.local IN AAAA> scope mdns on ve-root/INET6 (validate=yes).
Delaying mdns transaction 31916 for 100856us.
Cache miss for C.local IN A
Firing regular transaction 18366 for <C.local IN A> scope mdns on ve-root/INET (validate=yes).
Delaying mdns transaction 18366 for 62318us.
Got message type=method_return sender=org.freedesktop.DBus destination=:1.703 path=n/a interface=n/a member=n/a cookie=4294967295 reply_cookie=49 signature= error-name=n/a error-message=n/a
Match type='signal',sender='org.freedesktop.DBus',path='/org/freedesktop/DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',arg0=':1.711' successfully installed.
Initial jitter phase for transaction 18366 elapsed.
Retrying transaction 18366.
Cache miss for C.local IN A
Firing regular transaction 18366 for <C.local IN A> scope mdns on ve-root/INET (validate=yes).
Sending query packet with id 0 on interface 8/AF_INET of size 25.
Initial jitter phase for transaction 31916 elapsed.
Retrying transaction 31916.
Cache miss for C.local IN AAAA
Firing regular transaction 31916 for <C.local IN AAAA> scope mdns on ve-root/INET6 (validate=yes).
Sending query packet with id 0 on interface 8/AF_INET6 of size 25.
Received mdns UDP packet of size 25, ifindex=8, ttl=255, fragsize=0, sender=169.254.184.15, destination=224.0.0.251
Received mdns UDP packet of size 25, ifindex=8, ttl=255, fragsize=0, sender=fe80::8c8f:67ff:fe3c:2c4e, destination=ff02::fb
Received mdns UDP packet of size 35, ifindex=8, ttl=255, fragsize=0, sender=192.168.123.34, destination=224.0.0.251
Got mDNS reply packet
Checking for conflicts...
Processing incoming packet of size 35 on transaction 18366 (rcode=SUCCESS).
Regular transaction 18366 for <C.local IN A> on scope mdns on ve-root/INET now complete with <success> from network (unsigned; non-confidential).
Freeing transaction 31916.
Sent message type=method_return sender=n/a destination=:1.711 path=n/a interface=n/a member=n/a cookie=51 reply_cookie=2 signature=a(qqqsa(iiay)s)aayssst error-name=n/a error-message=n/a
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=RemoveMatch cookie=52 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Freeing transaction 18366.
Added positive unauthenticated non-confidential cache entry for C.local IN A 120s on ve-root/INET/192.168.123.34
Received mdns UDP packet of size 47, ifindex=8, ttl=255, fragsize=0, sender=fe80::e877:11ff:fe8f:dc4b, destination=ff02::fb
Got mDNS reply packet
Checking for conflicts...
Added positive unauthenticated non-confidential cache entry for C.local IN AAAA 120s on ve-root/INET6/fe80::e877:11ff:fe8f:dc4b

@yuwata yuwata force-pushed the resolve-mdns-fix-use-after-free branch 2 times, most recently from db50a3b to 00fd5b5 Compare July 3, 2022 21:18
@yuwata
Copy link
Copy Markdown
Member Author

yuwata commented Jul 3, 2022

@evverx Please test again. At least, now it works fine for me.

@yuwata
Copy link
Copy Markdown
Member Author

yuwata commented Jul 3, 2022

(The first commit needs to be backported to stable branch)

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 3, 2022

@yuwata it seems all the issues are gone. I still can trigger various "assertions" like

Jul 03 22:13:40 C systemd-resolved[783]: Assertion '(dns_question_size(p->question) > 0)' failed at src/resolve/resolved-mdns.c:259, function mdns_scope_process_query(). Ignoring.
Jul 03 22:13:40 C systemd-resolved[783]: Assertion '(dns_question_size(p->question) > 0)' failed at src/resolve/resolved-mdns.c:259, function mdns_scope_process_query(). Ignoring.
Jul 03 22:13:42 C systemd-resolved[783]: Assertion '(dns_question_size(p->question) > 0)' failed at src/resolve/resolved-mdns.c:259, function mdns_scope_process_query(). Ignoring.
Jul 03 22:13:46 C systemd-resolved[783]: Assertion '(dns_question_size(p->question) > 0)' failed at src/resolve/resolved-mdns.c:259, function mdns_scope_process_query(). Ignoring.
Jul 03 22:13:47 C systemd-resolved[783]: Assertion '(dns_question_size(p->question) > 0)' failed at src/resolve/resolved-mdns.c:259, function mdns_scope_process_query(). Ignoring.
Jul 03 22:13:49 C systemd-resolved[783]: Assertion '(dns_question_size(p->question) > 0)' failed at src/resolve/resolved-mdns.c:259, function mdns_scope_process_query(). Ignoring.
Jul 03 23:05:34 C systemd-resolved[25298]: Assertion 'e->state != SD_EVENT_FINISHED' failed at src/libsystemd/sd-event/sd-event.c:1248, function sd_event_add_time(). Ignoring.
Jul 03 23:05:34 C systemd-resolved[25298]: Assertion 'e->state != SD_EVENT_FINISHED' failed at src/libsystemd/sd-event/sd-event.c:1248, function sd_event_add_time(). Ignoring.
Jul 03 23:42:23 C systemd-resolved[38836]: Assertion 'r > 0' failed at src/resolve/resolved-mdns.c:180, function mdns_do_tiebreak(). Aborting.
Jul 03 23:43:00 C systemd-resolved[38866]: Assertion 'r > 0' failed at src/resolve/resolved-mdns.c:180, function mdns_do_tiebreak(). Aborting.

but I don't think it has anything to do with this PR.

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 4, 2022

Looks like

Jul 03 23:42:23 C systemd-resolved[38836]: Assertion 'r > 0' failed at src/resolve/resolved-mdns.c:180, function mdns_do_tiebreak(). Aborting.

isn't as harmless as the others in the sense that apparently resolved can be actually crashed on receiving query packets. I'm not sure how to reproduce it reliably yet though.

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 4, 2022

There seems to be another crash:

Got a goodbye packet
Got a goodbye packet
Got a goodbye packet
Got a goodbye packet
Got a goodbye packet
Got a goodbye packet
Added positive unauthenticated non-confidential shared cache entry for _services._dns-sd._udp.local IN PTR 1s on ve-root/INET/192.168.60.119
Added positive unauthenticated non-confidential cache entry for 119.60.168.192.in-addr.arpa IN PTR 1s on ve-root/INET/192.168.60.119
Added positive unauthenticated non-confidential cache entry for C.local IN A 1s on ve-root/INET/192.168.60.119
Added positive unauthenticated non-confidential cache entry for C._qotd._tcp.local IN TXT 1s on ve-root/INET/192.168.60.119
Added positive unauthenticated non-confidential shared cache entry for _qotd._tcp.local IN PTR 1s on ve-root/INET/192.168.60.119
Added positive unauthenticated non-confidential cache entry for C._qotd._tcp.local IN SRV 1s on ve-root/INET/192.168.60.119
Added positive unauthenticated non-confidential shared cache entry for _services._dns-sd._udp.local IN PTR 120s on ve-root/INET/192.168.60.119
Received mdns UDP packet of size 251, ifindex=21, ttl=255, fragsize=0, sender=fe80::e877:11ff:fe8f:dc4b, destination=ff02::fb
Got mDNS reply packet
Checking for conflicts...
Got a goodbye packet
Got a goodbye packet
Got a goodbye packet
Got a goodbye packet
Got a goodbye packet
Got a goodbye packet
Assertion 'key' failed at src/resolve/resolved-dns-answer.c:276, function dns_answer_match_key(). Aborting.
Aborted

As usual for some reason

Coredump entry has no core attached (neither internally in the journal nor externally on disk).

I'll redirect coredumps to something that can actually collect them and attach the backtrace if it's triggered again.

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 4, 2022

Got DNS stub UDP query packet for id 12849
Got request with recursion disabled, refusing.
Sending response packet with id 12849 on interface 1/AF_INET of size 47.
Received mdns UDP packet of size 180, ifindex=22, ttl=255, fragsize=0, sender=192.168.31.125, destination=224.0.0.251
Got mDNS reply packet
Checking for conflicts...
Assertion 'key' failed at src/resolve/resolved-dns-answer.c:276, function dns_answer_match_key(). Aborting.
#0  0x00007ffff40a1aec in __pthread_kill_implementation () from /lib64/libc.so.6
#1  0x00007ffff40552a6 in raise () from /lib64/libc.so.6
#2  0x00007ffff40287f3 in abort () from /lib64/libc.so.6
#3  0x00007ffff62178b6 in log_assert_failed (text=0x6497c0 "key", file=0x649323 "src/resolve/resolved-dns-answer.c", line=276, func=0x64a2c0 <__PRETTY_FUNCTION__.17> "dns_answer_match_key")
    at ../src/basic/log.c:856
#4  0x00000000005acc8c in dns_answer_match_key (a=0x6020001125b0, key=0x0, ret_flags=0x0) at ../src/resolve/resolved-dns-answer.c:276
#5  0x0000000000538c36 in on_mdns_packet (s=0x612000017ec0, fd=13, revents=1, userdata=0x618000000080) at ../src/resolve/resolved-mdns.c:419
#6  0x00007ffff65b4bb0 in source_dispatch (s=0x612000017ec0) at ../src/libsystemd/sd-event/sd-event.c:3602
#7  0x00007ffff65bd465 in sd_event_dispatch (e=0x617000007080) at ../src/libsystemd/sd-event/sd-event.c:4186
#8  0x00007ffff65be5c9 in sd_event_run (e=0x617000007080, timeout=18446744073709551615) at ../src/libsystemd/sd-event/sd-event.c:4247
#9  0x00007ffff65be94a in sd_event_loop (e=0x617000007080) at ../src/libsystemd/sd-event/sd-event.c:4268
#10 0x0000000000552c38 in run (argc=1, argv=0x7fffffffe518) at ../src/resolve/resolved.c:92
#11 0x0000000000552ed2 in main (argc=1, argv=0x7fffffffe518) at ../src/resolve/resolved.c:99

@yuwata yuwata force-pushed the resolve-mdns-fix-use-after-free branch from 00fd5b5 to d4e101d Compare July 4, 2022 02:45
@yuwata
Copy link
Copy Markdown
Member Author

yuwata commented Jul 4, 2022

@evverx Thanks. Hopefully fixed assertions except for one in sd_event_add_time(). Another try please!

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 4, 2022

==859107==ERROR: AddressSanitizer: heap-use-after-free on address 0x612000567728 at pc 0x0000004bb2a2 bp 0x7ffc0b4f6b70 sp 0x7ffc0b4f6b68
READ of size 8 at 0x612000567728 thread T0
    #0 0x4bb2a1 in dns_transaction_make_packet_mdns ../src/resolve/resolved-dns-transaction.c:1826
    #1 0x4bbdc7 in dns_transaction_make_packet ../src/resolve/resolved-dns-transaction.c:1909
    #2 0x4bd7b1 in dns_transaction_go ../src/resolve/resolved-dns-transaction.c:2008
    #3 0x4abb93 in dns_transaction_retry ../src/resolve/resolved-dns-transaction.c:521
    #4 0x4b807c in on_transaction_timeout ../src/resolve/resolved-dns-transaction.c:1548
    #5 0x7f429fbb4d82  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11b4d82)
    #6 0x7f429fbbd464  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11bd464)
    #7 0x7f429fbbe5c8  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11be5c8)
    #8 0x7f429fbbe949  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11be949)
    #9 0x553063 in run ../src/resolve/resolved.c:92
    #10 0x5532fd in main ../src/resolve/resolved.c:99
    #11 0x7f429d64043f in __libc_start_call_main (/lib64/libc.so.6+0x4043f)
    #12 0x7f429d6404ef in __libc_start_main@@GLIBC_2.34 (/lib64/libc.so.6+0x404ef)
    #13 0x40c094 in _start (/home/vagrant/systemd/build/systemd-resolved+0x40c094)

0x612000567728 is located 232 bytes inside of 280-byte region [0x612000567640,0x612000567758)
freed by thread T0 here:
    #0 0x7f42a0aae627 in free (/lib64/libasan.so.6+0xae627)
    #1 0x4a3edc in dns_transaction_free ../src/resolve/resolved-dns-transaction.c:161
    #2 0x4a443a in dns_transaction_gc ../src/resolve/resolved-dns-transaction.c:180
    #3 0x43a93f in dns_query_candidate_stop ../src/resolve/resolved-dns-query.c:56
    #4 0x43eafb in dns_query_stop ../src/resolve/resolved-dns-query.c:354
    #5 0x4438a9 in dns_query_complete ../src/resolve/resolved-dns-query.c:588
    #6 0x448bdb in dns_query_accept ../src/resolve/resolved-dns-query.c:925
    #7 0x44904b in dns_query_ready ../src/resolve/resolved-dns-query.c:978
    #8 0x43e7ea in dns_query_candidate_notify ../src/resolve/resolved-dns-query.c:340
    #9 0x4a991a in dns_transaction_complete ../src/resolve/resolved-dns-transaction.c:436
    #10 0x4b8f84 in dns_transaction_prepare ../src/resolve/resolved-dns-transaction.c:1663
    #11 0x4bb06f in dns_transaction_make_packet_mdns ../src/resolve/resolved-dns-transaction.c:1853
    #12 0x4bbdc7 in dns_transaction_make_packet ../src/resolve/resolved-dns-transaction.c:1909
    #13 0x4bd7b1 in dns_transaction_go ../src/resolve/resolved-dns-transaction.c:2008
    #14 0x4abb93 in dns_transaction_retry ../src/resolve/resolved-dns-transaction.c:521
    #15 0x4b807c in on_transaction_timeout ../src/resolve/resolved-dns-transaction.c:1548
    #16 0x7f429fbb4d82  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11b4d82)
    #17 0x7f429fbbd464  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11bd464)
    #18 0x7f429fbbe5c8  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11be5c8)
    #19 0x7f429fbbe949  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11be949)
    #20 0x553063 in run ../src/resolve/resolved.c:92
    #21 0x5532fd in main ../src/resolve/resolved.c:99
    #22 0x7f429d64043f in __libc_start_call_main (/lib64/libc.so.6+0x4043f)

previously allocated by thread T0 here:
    #0 0x7f42a0aae91f in __interceptor_malloc (/lib64/libasan.so.6+0xae91f)
    #1 0x49ea27 in malloc_multiply ../src/basic/alloc-util.h:104
    #2 0x4a5370 in dns_transaction_new ../src/resolve/resolved-dns-transaction.c:271
    #3 0x43c6ea in dns_query_candidate_add_transaction ../src/resolve/resolved-dns-query.c:137
    #4 0x43e29c in dns_query_candidate_setup_transactions ../src/resolve/resolved-dns-query.c:286
    #5 0x443d19 in dns_query_add_candidate ../src/resolve/resolved-dns-query.c:624
    #6 0x445b3c in dns_query_go ../src/resolve/resolved-dns-query.c:771
    #7 0x41c7bf in bus_method_resolve_service ../src/resolve/resolved-bus.c:1377
    #8 0x7f429f98b914  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0xf8b914)
    #9 0x7f429f995114  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0xf95114)
    #10 0x7f429f9967d6  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0xf967d6)
    #11 0x7f429f9f5b6d  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0xff5b6d)
    #12 0x7f429f9f6084  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0xff6084)
    #13 0x7f429f9f8ee5  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0xff8ee5)
    #14 0x7f429f9f907f  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0xff907f)
    #15 0x7f429f9fc780  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0xffc780)
    #16 0x7f429fbb4baf  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11b4baf)
    #17 0x7f429fbbd464  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11bd464)
    #18 0x7f429fbbe5c8  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11be5c8)
    #19 0x7f429fbbe949  (/home/vagrant/systemd/build/src/shared/libsystemd-shared-251.so+0x11be949)
    #20 0x553063 in run ../src/resolve/resolved.c:92
    #21 0x5532fd in main ../src/resolve/resolved.c:99
    #22 0x7f429d64043f in __libc_start_call_main (/lib64/libc.so.6+0x4043f)

SUMMARY: AddressSanitizer: heap-use-after-free ../src/resolve/resolved-dns-transaction.c:1826 in dns_transaction_make_packet_mdns
Shadow bytes around the buggy address:
  0x0c24800a4e90: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c24800a4ea0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c24800a4eb0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c24800a4ec0: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
  0x0c24800a4ed0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c24800a4ee0: fd fd fd fd fd[fd]fd fd fd fd fd fa fa fa fa fa
  0x0c24800a4ef0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c24800a4f00: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c24800a4f10: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c24800a4f20: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
  0x0c24800a4f30: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==859107==ABORTING

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 4, 2022

That heap-use-after-free is reproducible without this PR: #23894

@yuwata yuwata force-pushed the resolve-mdns-fix-use-after-free branch from 5ec1f76 to df57225 Compare July 4, 2022 13:18
@yuwata yuwata removed the reviewed/needs-rework 🔨 PR has been reviewed and needs another round of reworks label Jul 4, 2022
@yuwata
Copy link
Copy Markdown
Member Author

yuwata commented Jul 4, 2022

@evverx Thank you for the report. PTAL!

@evverx

This comment was marked as outdated.

@yuwata yuwata force-pushed the resolve-mdns-fix-use-after-free branch from df57225 to 3f907f6 Compare July 6, 2022 05:48
@yuwata
Copy link
Copy Markdown
Member Author

yuwata commented Jul 6, 2022

@evverx Updated. PTAL.

@evverx

This comment was marked as resolved.

@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 6, 2022

Looks like the LLMNR stuff no longer works:

Never mind. Looks like it got blocked by firewalld. I installed it to report firewalld/firewalld#985. I'll block it and try again.

yuwata added 9 commits July 9, 2022 05:20
This reverts commit 127b26f.

The commit made mDNS queries quite unstable.
Note that, RFC 6762 does not explicitly prohibit to send a request
multiple times.
Also, this makes mDNS regular queries sent without delay (except for
one caused by the default accuracy of sd-event).

Note, RFC 6762 Section 5.2 is about continuous mDNS query, which is not
implemented yet.
This also fixes timeout in dns_transaction_make_packet_mdns(), which was
incremented multiple times.
Fixes the following assertion:
---
Assertion 'r > 0' failed at src/resolve/resolved-mdns.c:180, function mdns_do_tiebreak(). Aborting.
---
…authorities

Otherwise, if we have many cached entries or pending transactions with
TYPE_ANY, then dns_transaction_make_packet_mdns() fails with -EMSGSIZE.

This also fixes use-after-free.

Fixes systemd#23894.
@bluca bluca merged commit bffb318 into systemd:main Jul 27, 2022
@evverx
Copy link
Copy Markdown
Contributor

evverx commented Jul 27, 2022

FWIW I haven't tested the latest version of this PR. I'll unleash the fuzz targets on resolved once I've gotten round to it (and open new issues if there are any).

@yuwata yuwata deleted the resolve-mdns-fix-use-after-free branch July 28, 2022 03:28
@keszybz
Copy link
Copy Markdown
Member

keszybz commented Aug 8, 2022

I'm backporting this now. I needed to pull in some older commits to avoid conflicts. @yuwata please double-check when this is pushed to v251-stable (a bit later today).

@yuwata
Copy link
Copy Markdown
Member Author

yuwata commented Aug 8, 2022

Sure, thank you.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

4 participants