Bug 2006393 - [DNS over TLS] following connection to a wifi AP, internet is not available for ~30s
Summary: [DNS over TLS] following connection to a wifi AP, internet is not available f...
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: systemd
Version: 36
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: systemd-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: 1889901
TreeView+ depends on / blocked
 
Reported: 2021-09-21 16:17 UTC by Chris Murphy
Modified: 2023-05-25 19:31 UTC (History)
19 users (show)

Fixed In Version: systemd-249.4-2.fc35
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2023-05-25 19:31:59 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
journal log monotonic (642.92 KB, text/plain)
2021-09-21 16:22 UTC, Chris Murphy
no flags Details
journal, resolved debug, monotonic (808.81 KB, text/plain)
2021-09-21 17:03 UTC, Chris Murphy
no flags Details
journal with systemd-250.3-3.fc36 (7.55 MB, text/plain)
2022-02-08 01:26 UTC, Chris Murphy
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Github systemd systemd issues 20801 0 None closed DNS over TLS: following connection to a wifi AP, internet is not available for ~30s 2022-08-26 14:16:12 UTC

Description Chris Murphy 2021-09-21 16:17:11 UTC
Description of problem:

When switching between AP's (Xfinity provided APs in each case), or when waking from sleep, there is a 30-45 second delay routing to the internet. This appears in GNOME Shell as wifi icon with ? in it, instead of signal strength.


Version-Release number of selected component (if applicable):
NetworkManager-1.32.10-2.fc35.x86_64
systemd-249.4-1.fc35.x86_64


How reproducible:
Always

Steps to Reproduce:
1. wake from sleep or switch wifi APs
2.
3.

Actual results:

30-45s delay connecting to internet

Expected results:

Internet should be routable within seconds of wifi connection to AP

Additional info:

This is a regression. It doesn't happen with Fedora Workstation 34.

I've disabled NetworkManager-wait-online.service since a long time because it can cause excessive boot times on some hardware.

Loaded: loaded (/usr/lib/systemd/system/NetworkManager-wait-online.service; disabled; vendor preset: enabled)

Comment 1 Chris Murphy 2021-09-21 16:17:52 UTC
The icon name is 'network-wireless-no-route'

Comment 2 Chris Murphy 2021-09-21 16:22:02 UTC
Created attachment 1824989 [details]
journal log monotonic

Complete journal attached. Decoder ring example of the problem:

[ 5136.002078] fovo.local NetworkManager[904]: <warn>  [1632240328.3719] device (wlp0s20f3): Activation: (wifi) association took too long, failing activation

This is shortly after wake from suspend to RAM. The previous AP is distant/weak, and doesn't connect (alphadriver) and instead it connects to a stronger AP (altitude) which is expected. But for the next ~30 seconds, internet is non-routable. The wireless icon switches from the no route icon to the normal one at the same time this message appears:

[ 5169.255496] fovo.local systemd-resolved[778]: Using degraded feature set UDP+EDNS0 instead of TLS+EDNS0 for DNS server 75.75.75.75.

Comment 3 Chris Murphy 2021-09-21 16:31:57 UTC
I'm wondering if it's related to this feature: https://fedoraproject.org/wiki/Changes/DNS_Over_TLS

If I go to Settings -> Wi-Fi -> $apname -> gear icon -> IPv4, and disable automatic DNS and enter 1.1.1.1,8.8.8., click apply - now changes to/from such a configured AP entry is instant - there's no "no-rout" icon, and no delay getting to the internet.

Comment 4 Chris Murphy 2021-09-21 17:03:16 UTC
Created attachment 1824996 [details]
journal, resolved debug, monotonic

Comment 5 Michael Catanzaro 2021-09-21 17:12:52 UTC
(In reply to Chris Murphy from comment #3)
> I'm wondering if it's related to this feature:
> https://fedoraproject.org/wiki/Changes/DNS_Over_TLS

I think this is our first bug report regarding DoT. This looks like a good guess, but to find out for sure, please create a config file /etc/systemd/resolved.conf.d/50-dot.conf with contents:

[Resolve]
DNSOverTLS=no

Comment 6 Michael Catanzaro 2021-09-21 17:13:50 UTC
And then after creating the new config:

$ systemctl restart systemd-resolved.service\

to apply it.

Comment 7 Fedora Blocker Bugs Application 2021-09-21 17:18:22 UTC
Proposed as a Blocker for 35-final by Fedora user chrismurphy using the blocker tracking app because:

 This is a stretch ...

*All system services present after installation with one of the release-blocking package sets must start properly ... *

While systemd-resolved daemon itself starts, a consistent 30+ second delay connecting to the internet seems so suboptimal as to be improper; plus it's a regression from 34.

Comment 8 Chris Murphy 2021-09-21 17:22:31 UTC
(In reply to Michael Catanzaro from comment #5)
> I think this is our first bug report regarding DoT. This looks like a good
> guess, but to find out for sure, please create a config file
> /etc/systemd/resolved.conf.d/50-dot.conf with contents:
> 
> [Resolve]
> DNSOverTLS=no

This also fixes the problem.

Comment 9 Zbigniew Jędrzejewski-Szmek 2021-09-21 18:31:49 UTC
Yep, the problem is that resolved tries the protocol, and doesn't get an answer, most likely because the router is of questionable quality.
If it just got an error, it would immediately switch to the next attempt, but since it doesn't get any answer, it just waits:

[   23.591792] systemd-resolved[773]: Cache miss for fedoraproject.org IN A
[   23.591877] systemd-resolved[773]: Firing regular transaction 36180 for <fedoraproject.org IN A> scope dns on wlp0s20f3/* (validate=yes).
[   23.591933] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 36180.
[   23.591991] systemd-resolved[773]: Using DNS server 75.75.75.75 for transaction 36180.
[   23.592070] systemd-resolved[773]: Sending query via TCP since UDP isn't supported or DNS-over-TLS is selected.
[   23.592123] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 36180.
[   23.592193] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
...
[   33.841985] systemd-resolved[773]: Connection failure for DNS TCP stream: Connection timed out
[   33.842046] systemd-resolved[773]: Retrying transaction 51563, after switching servers.
[   33.842093] systemd-resolved[773]: Switching to DNS server 75.75.76.76 for interface wlp0s20f3.
[   33.842139] systemd-resolved[773]: Cache miss for accounts.google.com IN A
[   33.842185] systemd-resolved[773]: Firing regular transaction 51563 for <accounts.google.com IN A> scope dns on wlp0s20f3/* (validate=yes).
[   33.842265] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 51563.
[   33.842319] systemd-resolved[773]: Using DNS server 75.75.76.76 for transaction 51563.
[   33.842431] systemd-resolved[773]: Sending query via TCP since UDP isn't supported or DNS-over-TLS is selected.
[   33.842502] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 51563.
[   33.842564] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
[   33.842615] systemd-resolved[773]: Retrying transaction 46999, after switching servers.
[   33.842767] systemd-resolved[773]: Cache miss for accounts.google.com IN AAAA
[   33.842850] systemd-resolved[773]: Firing regular transaction 46999 for <accounts.google.com IN AAAA> scope dns on wlp0s20f3/* (validate=yes).
[   33.842901] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 46999.
[   33.842950] systemd-resolved[773]: Using DNS server 75.75.76.76 for transaction 46999.
[   33.842999] systemd-resolved[773]: Sending query via TCP since UDP isn't supported or DNS-over-TLS is selected.
[   33.843046] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 46999.
[   33.843094] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
[   33.843168] systemd-resolved[773]: Retrying transaction 48695, after switching servers.
[   33.843218] systemd-resolved[773]: Cache miss for apidata.googleusercontent.com IN AAAA
[   33.843276] systemd-resolved[773]: Firing regular transaction 48695 for <apidata.googleusercontent.com IN AAAA> scope dns on wlp0s20f3/* (validate=yes).
[   33.843355] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 48695.
[   33.843413] systemd-resolved[773]: Using DNS server 75.75.76.76 for transaction 48695.
[   33.843470] systemd-resolved[773]: Sending query via TCP since UDP isn't supported or DNS-over-TLS is selected.
[   33.843524] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 48695.
[   33.843604] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
[   33.843660] systemd-resolved[773]: Retrying transaction 49723, after switching servers.
[   33.843759] systemd-resolved[773]: Cache miss for apidata.googleusercontent.com IN A
[   33.843849] systemd-resolved[773]: Firing regular transaction 49723 for <apidata.googleusercontent.com IN A> scope dns on wlp0s20f3/* (validate=yes).
[   33.843907] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 49723.
[   33.843963] systemd-resolved[773]: Using DNS server 75.75.76.76 for transaction 49723.
[   33.844044] systemd-resolved[773]: Sending query via TCP since UDP isn't supported or DNS-over-TLS is selected.
[   33.844101] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 49723.
[   33.844169] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
[   33.844228] systemd-resolved[773]: Retrying transaction 54877, after switching servers.
[   33.844329] systemd-resolved[773]: Cache miss for 2.fedora.pool.ntp.org IN AAAA
[   33.844472] systemd-resolved[773]: Firing regular transaction 54877 for <2.fedora.pool.ntp.org IN AAAA> scope dns on wlp0s20f3/* (validate=yes).
[   33.844527] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 54877.
[   33.844576] systemd-resolved[773]: Using DNS server 75.75.76.76 for transaction 54877.
[   33.844623] systemd-resolved[773]: Sending query via TCP since UDP isn't supported or DNS-over-TLS is selected.
[   33.844698] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 54877.
[   33.844749] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
[   33.844798] systemd-resolved[773]: Retrying transaction 32908, after switching servers.
[   33.844845] systemd-resolved[773]: Cache miss for 2.fedora.pool.ntp.org IN A
[   33.844895] systemd-resolved[773]: Firing regular transaction 32908 for <2.fedora.pool.ntp.org IN A> scope dns on wlp0s20f3/* (validate=yes).
[   33.844971] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 32908.
[   33.845022] systemd-resolved[773]: Using DNS server 75.75.76.76 for transaction 32908.
[   33.845070] systemd-resolved[773]: Sending query via TCP since UDP isn't supported or DNS-over-TLS is selected.
[   33.845117] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 32908.
[   33.845163] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
[   33.845230] systemd-resolved[773]: Retrying transaction 2485, after switching servers.
[   33.845280] systemd-resolved[773]: Cache miss for fedoraproject.org IN AAAA
[   33.845327] systemd-resolved[773]: Firing regular transaction 2485 for <fedoraproject.org IN AAAA> scope dns on wlp0s20f3/* (validate=yes).
[   33.845380] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 2485.
[   33.845430] systemd-resolved[773]: Using DNS server 75.75.76.76 for transaction 2485.
[   33.845502] systemd-resolved[773]: Sending query via TCP since UDP isn't supported or DNS-over-TLS is selected.
[   33.845551] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 2485.
[   33.845602] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
[   33.845684] systemd-resolved[773]: Retrying transaction 36180, after switching servers.
[   33.845736] systemd-resolved[773]: Cache miss for fedoraproject.org IN A
[   33.845785] systemd-resolved[773]: Firing regular transaction 36180 for <fedoraproject.org IN A> scope dns on wlp0s20f3/* (validate=yes).
[   33.845832] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 36180.
[   33.845909] systemd-resolved[773]: Using DNS server 75.75.76.76 for transaction 36180.
[   33.845961] systemd-resolved[773]: Sending query via TCP since UDP isn't supported or DNS-over-TLS is selected.
[   33.846019] systemd-resolved[773]: Using feature level TLS+EDNS0 for transaction 36180.
[   33.846068] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
...
[   44.091656] systemd-resolved[773]: Timeout reached on transaction 48695.
[   44.094807] systemd-resolved[773]: Retrying transaction 48695, after switching servers.
[   44.095081] systemd-resolved[773]: Switching to DNS server 2001:558:feed::1 for interface wlp0s20f3.
...
[   54.262468] systemd-resolved[773]: Retrying transaction 36180, after switching servers.
[   54.262550] systemd-resolved[773]: Cache miss for fedoraproject.org IN A
[   54.262624] systemd-resolved[773]: Firing regular transaction 36180 for <fedoraproject.org IN A> scope dns on wlp0s20f3/* (validate=yes).
[   54.262725] systemd-resolved[773]: Using feature level UDP+EDNS0 for transaction 36180.
[   54.262825] systemd-resolved[773]: Using DNS server 75.75.75.75 for transaction 36180.
[   54.262940] systemd-resolved[773]: Announcing packet size 512 in egress EDNS(0) packet.
[   54.263017] systemd-resolved[773]: Emitting UDP, link MTU is 1500, socket MTU is 0, minimal MTU is 40
[   54.263096] systemd-resolved[773]: Sending query packet with id 36180 of size 46.

I think I got the selection wrong, but it seems to wait for each of the IPv4 servers, and then twice for IPv6 servers.

@lpoetter I think we should limit the wait to something like 1s if we're in opportunistic mode.
Or maybe 3 s, but set a global limit and stop retrying further servers if we already timed out on the
first few. It's very likely that all have multiple servers on the same network with the same implementation.

Comment 10 Geoffrey Marr 2021-09-27 18:14:10 UTC
Discussed during the 2021-09-27 blocker review meeting: [0]

The decision to delay the classification of this as a blocker bug was made as this seems worrying, but we'd like to have a clearer idea of how commonly it is likely to happen in order to make a call on whether it should block the release.

[0] https://meetbot.fedoraproject.org/fedora-blocker-review/2021-09-27/f35-blocker-review.2021-09-27-16.00.txt

Comment 11 Adam Williamson 2021-09-27 19:07:45 UTC
Specifically, we'd like to know if this happens *any time you switch AP across a sleep/resume*, or if it only happens if the previous AP is still visible, but weak. It sounds like it's the latter, but I wanted to make sure. Thanks!

Comment 12 Chris Murphy 2021-09-27 20:01:02 UTC
It happens regardless of signal strength, and is even reproducible merely with "sudo systemctl restart NetworkManager". I'm currently 2000 miles from the original location, but also using Comcast/Xfinity as the local ISP, with newer equipment (but still provided by Comcast/Xfinity), and the problem remains. So it seems to me at least as widespread as Xfinity, and over multiple generations of their hardware. They have about 40% market share in the U.S.

Comment 13 Neal Gompa 2021-10-04 19:59:18 UTC
This has been confirmed by FESCo as a final blocker for Fedora Linux 35: https://pagure.io/fesco/issue/2671#comment-754650

Comment 14 Adam Williamson 2021-10-04 20:11:57 UTC
made it so.

Comment 15 Michael Catanzaro 2021-10-05 13:51:37 UTC
Any plans for this? It seems there is an upstream plan, but no code yet.

Comment 16 Adam Williamson 2021-10-05 21:52:26 UTC
I think it'd be good to follow the same policy we picked for Wireplumber on this - if we don't have an actual fix for it by Friday, we should drop the dns-over-tls feature for F35.

Comment 17 Michael Catanzaro 2021-10-05 22:27:11 UTC
(In reply to Adam Williamson from comment #16)
> I think it'd be good to follow the same policy we picked for Wireplumber on
> this - if we don't have an actual fix for it by Friday, we should drop the
> dns-over-tls feature for F35.

I agree, we're late enough in the schedule that we can't reasonably wait any longer.

That said, the contingency plan is a one-line change in the systemd spec to roll this back, so it should be easy to do if it comes to that.

Comment 18 Michael Catanzaro 2021-10-08 00:35:53 UTC
Well tomorrow is Friday. I guess it's time to call it and activate the contingency plan. Can always try again next release cycle....

Comment 19 Adam Williamson 2021-10-08 22:10:09 UTC
Yeah, agreed. I'll ping Zbigniew and if he's not around, I'll do it.

Comment 20 Fedora Update System 2021-10-11 18:00:21 UTC
FEDORA-2021-a94c7c0024 has been submitted as an update to Fedora 35. https://bodhi.fedoraproject.org/updates/FEDORA-2021-a94c7c0024

Comment 21 Fedora Update System 2021-10-11 19:27:30 UTC
FEDORA-2021-a94c7c0024 has been pushed to the Fedora 35 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2021-a94c7c0024`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2021-a94c7c0024

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 22 Fedora Update System 2021-10-12 17:37:56 UTC
FEDORA-2021-a94c7c0024 has been pushed to the Fedora 35 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 23 Adam Williamson 2021-10-12 18:38:35 UTC
Since the bug still exists, we just worked around it by disabling DNS-over-TLS, reopening for Rawhide and re-nominating as an F36 Final blocker (since the feature is still enabled on Rawhide and hence for F36 at present).

Comment 24 Michael Catanzaro 2021-11-23 15:03:27 UTC
This should hopefully be fixed by https://github.com/systemd/systemd/pull/21470.

Comment 25 Geoffrey Marr 2022-02-07 21:06:24 UTC
Discussed during the 2022-02-07 blocker review meeting: [0]

The decision to delay the classification of this as a blocker bug was made as this is an automatic transfer from F35 and we don't know the exact status of F36 currently with this bug. We are delaying a decision to ask cmurf to report back on how F36 is.

[0] https://meetbot.fedoraproject.org/fedora-blocker-review/2022-02-07/f36-blocker-review.2022-02-07-17.00.txt

Comment 26 Adam Williamson 2022-02-07 21:54:04 UTC
As per above, cmurf, can you test and advise of current status? I think the status of F36 should be that the feature is still enabled and the systemd fix mentioned above is present, but if you could confirm the situation on the ground that'd be great :D

Comment 27 Chris Murphy 2022-02-08 01:10:03 UTC
Tested with 20220201 Workstation ISO, systemd-250.3-3.fc36.x86_64. I do still see a ? with delayed availability of internet access, at the login window, but by the time I've logged in and could practically use the internet, DNS resolution is working.

[   33.939387] fedora systemd-resolved[804]: Using degraded feature set UDP+EDNS0 instead of TLS+EDNS0 for DNS server 75.75.75.75.

This is tentatively fixed but my boots are slow due to debug kernel and debug logging, so if they were more like 10s I'd probably still have a ~10-20s delay in internet access.

Comment 28 Chris Murphy 2022-02-08 01:26:54 UTC
Created attachment 1859695 [details]
journal with systemd-250.3-3.fc36

systemd.log_level=debug enabled

First line with TLS in it:
[   20.939185] systemd-resolved[804]: Using feature level TLS+EDNS0 for transaction 17253.
Fallback
[   33.939387] systemd-resolved[804]: Using degraded feature set UDP+EDNS0 instead of TLS+EDNS0 for DNS server 75.75.75.75.

So it's roughly 13 seconds for it to figure out it needs to use the degraded fallback. I'm on the fence, it's neither good nor terrible. It looks like over 20 attempts which offhand seems excessive to figure out whether or not DNS over TLS is supported by the DNS server.

Comment 29 Michael Catanzaro 2022-02-08 01:30:45 UTC
This should not be a blocker issue anymore. 13 seconds is not the end of the world. That said, remember that the "degraded" case is actually the *normal and expected* case, so I agree 13 seconds is much too long to figure out that DNS over TLS is not working in opportunistic mode. It's not like the server is broken to not offer DNS over TLS. We are just being extremely optimistic to try DNS over TLS at all.

Comment 30 Adam Williamson 2022-02-08 02:16:46 UTC
Michael: remember a significant reason we took it as a blocker was it also happened at resume from sleep, which is pretty annoying for many use cases - suspending quite often is common, and most laptops resume in a second or two these days. 13 seconds beats 30, but 11 (after a 2 second resume) is still a long time to be waiting for your internet connection to come back.

Comment 31 Chris Murphy 2022-02-08 03:27:55 UTC
I can confirm it is present upon resume from sleep.

Feb 07 20:16:51 fedora systemd-resolved[804]: Using feature level TLS+EDNS0 for transaction 3206.
...
Feb 07 20:17:00 fedora systemd-resolved[804]: Using degraded feature set UDP+EDNS0 instead of TLS+EDNS0 for DNS server 75.75.75.75.

So yeah it's in the ballpark of 10 seconds wait for internet. Even though it's connecting to the same AP and thus DNS lacking this ability, it goes through ... ok this time I counted and gave up after 60 "using feature level TLS+EDNS0.." lines. It's a lot of tries.

I agree this is probably not blocker territory anymore, and doesn't pass the "last blocker" smell test.

Comment 32 Michael Catanzaro 2022-02-08 17:07:34 UTC
To be clear: I think we should revert the change if we are unable to improve this. But not block Fedora release.

Comment 33 Ben Cotton 2022-02-08 20:05:14 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 36 development cycle.
Changing version to 36.

Comment 34 Michael Catanzaro 2022-02-14 15:16:31 UTC
I've been seeing a *lot* of spurious name resolution failures, where systemd-resolved reports that a name is unresolvable, but 'dig' works fine.

I'm not sure whether it's connected to this change or not. I'm going to turn off the opportunistic mode setting and find out.

I do notice that it seems the grace period expires (I'm not sure when, it looks arbitrary to me). I wonder if that causes name resolution to temporarily fail until it gets reinstated (maybe application timeout for name resolution is lower than systemd's timeout?). Not sure.

IMO it remains to be seen whether we can safely proceed with this change or not.

Comment 35 Geoffrey Marr 2022-02-14 19:34:27 UTC
Discussed during the 2022-02-14 blocker review meeting: [0]

The decision to classify this bug as a "RejectedBlocker (Final)" was made as this is still pretty bad if you're affected, but we think the reduction in the time it takes for the situation to resolve is sufficient that it no longer quite qualifies for release blocker status. We'll leave it up to the wisdom of the devs whether it's a better idea to revert the feature if it can't be fixed further.

[0] https://meetbot.fedoraproject.org/fedora-blocker-review/2022-02-14/f36-blocker-review.2022-02-14-17.01.txt

Comment 36 Chris Murphy 2022-02-15 03:03:29 UTC
I hit the problem Michael reports in comment 34. Suddenly I was getting 502 errors with fpo.org, github and gitlab - hammered on refresh on all of them, no joy. Did 'systemctl restart systemd-resolved` and it immediately cleared up.


Feb 14 19:40:23 fedora systemd-resolved[795]: Freeing transaction 48123.
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink: New incoming connection.
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink: Connections of user 993: 0 (of 576 max)
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: Setting state idle-server
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: New incoming message: {"method":"io.systemd.Resolve.ResolveHostname","parameters":{"name":"location.services.mozilla.com","flags":0}}
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: Changing state idle-server → processing-method
Feb 14 19:44:17 fedora systemd-resolved[795]: idn2_lookup_u8: location.services.mozilla.com → location.services.mozilla.com
Feb 14 19:44:17 fedora systemd-resolved[795]: Looking up RR for location.services.mozilla.com IN A.
Feb 14 19:44:17 fedora systemd-resolved[795]: Looking up RR for location.services.mozilla.com IN AAAA.
Feb 14 19:44:17 fedora systemd-resolved[795]: Removing cache entry for prod.detectportal.prod.cloudops.mozgcp.net IN AAAA (expired 222s ago)
Feb 14 19:44:17 fedora systemd-resolved[795]: Removing cache entry for fedoraproject.org IN A (expired 206s ago)
Feb 14 19:44:17 fedora systemd-resolved[795]: Removing cache entry for fedoraproject.org IN AAAA (expired 175s ago)
Feb 14 19:44:17 fedora systemd-resolved[795]: Removing cache entry for prod.detectportal.prod.cloudops.mozgcp.net IN A (expired 158s ago)
Feb 14 19:44:17 fedora systemd-resolved[795]: Removing cache entry for locprod2-elb-us-west-2.prod.mozaws.net IN AAAA (expired 124s ago)
Feb 14 19:44:17 fedora systemd-resolved[795]: Cache miss for location.services.mozilla.com IN A
Feb 14 19:44:17 fedora systemd-resolved[795]: Firing regular transaction 25345 for <location.services.mozilla.com IN A> scope dns on wlp0s20f3/* (validate=yes).
Feb 14 19:44:17 fedora systemd-resolved[795]: Using feature level UDP+EDNS0 for transaction 25345.
Feb 14 19:44:17 fedora systemd-resolved[795]: Using DNS server 75.75.75.75 for transaction 25345.
Feb 14 19:44:17 fedora systemd-resolved[795]: Announcing packet size 1472 in egress EDNS(0) packet.
Feb 14 19:44:17 fedora systemd-resolved[795]: Emitting UDP, link MTU is 1500, socket MTU is 0, minimal MTU is 40
Feb 14 19:44:17 fedora systemd-resolved[795]: Sending query packet with id 25345 of size 58.
Feb 14 19:44:17 fedora systemd-resolved[795]: Cache miss for location.services.mozilla.com IN AAAA
Feb 14 19:44:17 fedora systemd-resolved[795]: Firing regular transaction 11345 for <location.services.mozilla.com IN AAAA> scope dns on wlp0s20f3/* (validate=yes).
Feb 14 19:44:17 fedora systemd-resolved[795]: Using feature level UDP+EDNS0 for transaction 11345.
Feb 14 19:44:17 fedora systemd-resolved[795]: Using DNS server 75.75.75.75 for transaction 11345.
Feb 14 19:44:17 fedora systemd-resolved[795]: Announcing packet size 1472 in egress EDNS(0) packet.
Feb 14 19:44:17 fedora systemd-resolved[795]: Emitting UDP, link MTU is 1500, socket MTU is 0, minimal MTU is 40
Feb 14 19:44:17 fedora systemd-resolved[795]: Sending query packet with id 11345 of size 58.
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: Changing state processing-method → pending-method
Feb 14 19:44:17 fedora systemd-resolved[795]: Received dns UDP packet of size 206, ifindex=3, ttl=0, fragsize=0, sender=75.75.75.75, destination=10.0.0.85
Feb 14 19:44:17 fedora systemd-resolved[795]: Processing incoming packet of size 206 on transaction 25345 (rcode=SUCCESS).
Feb 14 19:44:17 fedora systemd-resolved[795]: Added positive unauthenticated non-confidential cache entry for location.services.mozilla.com IN CNAME 45s on wlp0s20f3/INET/75.75.75.75
Feb 14 19:44:17 fedora systemd-resolved[795]: Added positive unauthenticated non-confidential cache entry for locprod2-elb-us-west-2.prod.mozaws.net IN A 45s on wlp0s20f3/INET/75.75.75.75
Feb 14 19:44:17 fedora systemd-resolved[795]: Added positive unauthenticated non-confidential cache entry for locprod2-elb-us-west-2.prod.mozaws.net IN A 45s on wlp0s20f3/INET/75.75.75.75
Feb 14 19:44:17 fedora systemd-resolved[795]: Added positive unauthenticated non-confidential cache entry for locprod2-elb-us-west-2.prod.mozaws.net IN A 45s on wlp0s20f3/INET/75.75.75.75
Feb 14 19:44:17 fedora systemd-resolved[795]: Added positive unauthenticated non-confidential cache entry for locprod2-elb-us-west-2.prod.mozaws.net IN A 45s on wlp0s20f3/INET/75.75.75.75
Feb 14 19:44:17 fedora systemd-resolved[795]: Added positive unauthenticated non-confidential cache entry for locprod2-elb-us-west-2.prod.mozaws.net IN A 45s on wlp0s20f3/INET/75.75.75.75
Feb 14 19:44:17 fedora systemd-resolved[795]: Added positive unauthenticated non-confidential cache entry for locprod2-elb-us-west-2.prod.mozaws.net IN A 45s on wlp0s20f3/INET/75.75.75.75
Feb 14 19:44:17 fedora systemd-resolved[795]: Regular transaction 25345 for <location.services.mozilla.com IN A> on scope dns on wlp0s20f3/* now complete with <success> from network (unsigned; non-confidential).
Feb 14 19:44:17 fedora systemd-resolved[795]: Received dns UDP packet of size 192, ifindex=3, ttl=0, fragsize=0, sender=75.75.75.75, destination=10.0.0.85
Feb 14 19:44:17 fedora systemd-resolved[795]: Processing incoming packet of size 192 on transaction 11345 (rcode=SUCCESS).
Feb 14 19:44:17 fedora systemd-resolved[795]: Added positive unauthenticated non-confidential cache entry for location.services.mozilla.com IN CNAME 130s on wlp0s20f3/INET/75.75.75.75
Feb 14 19:44:17 fedora systemd-resolved[795]: Regular transaction 11345 for <location.services.mozilla.com IN AAAA> on scope dns on wlp0s20f3/* now complete with <success> from network (unsigned; non-confidential).
Feb 14 19:44:17 fedora systemd-resolved[795]: Freeing transaction 25345.
Feb 14 19:44:17 fedora systemd-resolved[795]: Following CNAME/DNAME location.services.mozilla.com → locprod2-elb-us-west-2.prod.mozaws.net.
Feb 14 19:44:17 fedora systemd-resolved[795]: Positive cache hit for locprod2-elb-us-west-2.prod.mozaws.net IN A
Feb 14 19:44:17 fedora systemd-resolved[795]: Regular transaction 25067 for <locprod2-elb-us-west-2.prod.mozaws.net IN A> on scope dns on wlp0s20f3/* now complete with <success> from cache (unsigned; non-confidential).
Feb 14 19:44:17 fedora systemd-resolved[795]: Cache miss for locprod2-elb-us-west-2.prod.mozaws.net IN AAAA
Feb 14 19:44:17 fedora systemd-resolved[795]: Firing regular transaction 62536 for <locprod2-elb-us-west-2.prod.mozaws.net IN AAAA> scope dns on wlp0s20f3/* (validate=yes).
Feb 14 19:44:17 fedora systemd-resolved[795]: Using feature level UDP+EDNS0 for transaction 62536.
Feb 14 19:44:17 fedora systemd-resolved[795]: Using DNS server 75.75.75.75 for transaction 62536.
Feb 14 19:44:17 fedora systemd-resolved[795]: Announcing packet size 1472 in egress EDNS(0) packet.
Feb 14 19:44:17 fedora systemd-resolved[795]: Emitting UDP, link MTU is 1500, socket MTU is 0, minimal MTU is 40
Feb 14 19:44:17 fedora systemd-resolved[795]: Sending query packet with id 62536 of size 67.
Feb 14 19:44:17 fedora systemd-resolved[795]: Freeing transaction 11345.
Feb 14 19:44:17 fedora systemd-resolved[795]: Received dns UDP packet of size 152, ifindex=3, ttl=0, fragsize=0, sender=75.75.75.75, destination=10.0.0.85
Feb 14 19:44:17 fedora systemd-resolved[795]: Processing incoming packet of size 152 on transaction 62536 (rcode=SUCCESS).
Feb 14 19:44:17 fedora systemd-resolved[795]: Added NODATA cache entry for locprod2-elb-us-west-2.prod.mozaws.net IN AAAA 267s
Feb 14 19:44:17 fedora systemd-resolved[795]: Regular transaction 62536 for <locprod2-elb-us-west-2.prod.mozaws.net IN AAAA> on scope dns on wlp0s20f3/* now complete with <success> from network (unsigned; non-confidential).
Feb 14 19:44:17 fedora systemd-resolved[795]: Freeing transaction 25067.
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: Sending message: {"parameters":{"addresses":[{"ifindex":3,"family":2,"address":[52,40,22,163]},{"ifindex":3,"family":2,"address":[34,217,232,122]},{"ifindex":3,"family":2,"address":[54,187,53,15]},{"ifindex":3,"family":2,"address":[52,89,43,233]},{"ifindex":3,"family":2,"address":[54,187,205,23]},{"ifindex":3,"family":2,"address":[35,161,134,161]}],"name":"locprod2-elb-us-west-2.prod.mozaws.net","flags":9437185}}
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: Changing state pending-method → idle-server
Feb 14 19:44:17 fedora systemd-resolved[795]: Freeing transaction 62536.
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: Got POLLHUP from socket.
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: Changing state idle-server → pending-disconnect
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: Changing state pending-disconnect → processing-disconnect
Feb 14 19:44:17 fedora systemd-resolved[795]: varlink-22: Changing state processing-disconnect → disconnected
Feb 14 19:44:59 fedora sudo[6973]:    chris : TTY=pts/2 ; PWD=/home/chris ; USER=root ; COMMAND=/usr/bin/systemctl restart systemd-resolved
Feb 14 19:44:59 fedora systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_resolved_unit_file_t:s0 tclass=service perm=start state=permissive function=bus_unit_method_start_generic path=/usr/lib/systemd/system/systemd-resolved.service cmdline=n/a: Success
Feb 14 19:44:59 fedora systemd[1]: SELinux access check scon=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tcon=system_u:object_r:systemd_resolved_unit_file_t:s0 tclass=service perm=start state=permissive function=bus_unit_queue_job path=/usr/lib/systemd/system/systemd-resolved.service cmdline=n/a: Success
Feb 14 19:44:59 fedora systemd[1]: systemd-resolved.service: Trying to enqueue job systemd-resolved.service/restart/replace
Feb 14 19:44:59 fedora systemd[1]: systemd-resolved.service: Installed new job systemd-resolved.service/restart as 4926
Feb 14 19:44:59 fedora systemd[1]: systemd-resolved.service: Enqueued job systemd-resolved.service/restart as 4926
Feb 14 19:44:59 fedora systemd-resolved[795]: Bus bus-api-resolve: changing state RUNNING → CLOSED
Feb 14 19:44:59 fedora systemd[1]: systemd-resolved.service: Changed running -> stop-sigterm
Feb 14 19:44:59 fedora systemd[1]: Stopping systemd-resolved.service - Network Name Resolution...
Feb 14 19:44:59 fedora systemd-resolved[795]: Removing scope on link wlp0s20f3, protocol dns, family *
Feb 14 19:44:59 fedora systemd-resolved[795]: Removing scope on link wlp0s20f3, protocol llmnr, family AF_INET
Feb 14 19:44:59 fedora systemd[1]: systemd-resolved.service: Got notification message from PID 795 (STOPPING=1, STATUS=Shutting down...)

Comment 37 Chris Murphy 2022-02-15 03:29:45 UTC
On second glance, the messages in c36 (and Michael's description in c34) don't look like the same thing as what this bug is about. So I'm splitting it out into its own bug 2054482.

Comment 38 Ben Cotton 2023-04-25 18:22:47 UTC
This message is a reminder that Fedora Linux 36 is nearing its end of life.
Fedora will stop maintaining and issuing updates for Fedora Linux 36 on 2023-05-16.
It is Fedora's policy to close all bug reports from releases that are no longer
maintained. At that time this bug will be closed as EOL if it remains open with a
'version' of '36'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, change the 'version' 
to a later Fedora Linux version. Note that the version field may be hidden.
Click the "Show advanced fields" button if you do not see it.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora Linux 36 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora Linux, you are encouraged to change the 'version' to a later version
prior to this bug being closed.

Comment 39 Ludek Smid 2023-05-25 19:31:59 UTC
Fedora Linux 36 entered end-of-life (EOL) status on 2023-05-16.

Fedora Linux 36 is no longer maintained, which means that it
will not receive any further security or bug fix updates. As a result we
are closing this bug.

If you can reproduce this bug against a currently maintained version of Fedora Linux
please feel free to reopen this bug against that version. Note that the version
field may be hidden. Click the "Show advanced fields" button if you do not see
the version field.

If you are unable to reopen this bug, please file a new report against an
active release.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.