Package: guix;
Reported by: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
Date: Thu, 19 Dec 2019 04:25:02 UTC
Severity: normal
Done: maxim.cournoyer <at> gmail.com
Bug is archived. No further changes may be made.
To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 38667 in the body.
You can then email your comments to 38667 AT debbugs.gnu.org in the normal way.
Toggle the display of automated, internal messages from the tracker.
View this report as an mbox folder, status mbox, maintainer mbox
bug-guix <at> gnu.org
:bug#38667
; Package guix
.
(Thu, 19 Dec 2019 04:25:02 GMT) Full text and rfc822 format available.Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
:bug-guix <at> gnu.org
.
(Thu, 19 Dec 2019 04:25:02 GMT) Full text and rfc822 format available.Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):
From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com> To: bug-guix <bug-guix <at> gnu.org> Subject: Network-Manager (sometimes) fails reconnecting to network automatically Date: Wed, 18 Dec 2019 23:23:51 -0500
I was bit by this problem a couple times, so I'm reporting it here. I don't know what causes it or how to reproduce it, but the following /var/log/messages was captured at the time it occurred: --8<---------------cut here---------------start------------->8--- Dec 14 14:31:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 14:41:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 14:51:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 15:01:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 15:01:40 localhost vmunix: [2511470.602960] wlp18s0: deauthenticated from 20:4e:7f:85:ab:13 (Reason: 2=PREV_AUTH_NOT_VALID) Dec 14 15:01:40 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-DISCONNECTED bssid=20:4e:7f:85:ab:13 reason=2 Dec 14 15:01:40 localhost wpa_supplicant[297]: dbus: wpa_dbus_property_changed: no property SessionLength in object /fi/w1/wpa_supplicant1/Interfaces/0 Dec 14 15:01:40 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Dec 14 15:01:40 localhost NetworkManager[298]: <warn> [1576353700.9145] sup-iface[0x20f30d0,wlp18s0]: connection disconnected (reason 2) Dec 14 15:01:40 localhost NetworkManager[298]: <info> [1576353700.9199] device (wlp18s0): supplicant interface state: completed -> disconnected Dec 14 15:01:41 localhost NetworkManager[298]: <info> [1576353701.0209] device (wlp18s0): supplicant interface state: disconnected -> scanning Dec 14 15:01:42 localhost vmunix: [2511471.859993] wlp18s0: authenticate with 20:4e:7f:85:ab:13 Dec 14 15:01:42 localhost wpa_supplicant[297]: wlp18s0: SME: Trying to authenticate with 20:4e:7f:85:ab:13 (SSID='MY-AP-NAME' freq=2422 MHz) Dec 14 15:01:42 localhost vmunix: [2511471.873637] wlp18s0: send auth to 20:4e:7f:85:ab:13 (try 1/3) Dec 14 15:01:42 localhost NetworkManager[298]: <info> [1576353702.0864] device (wlp18s0): supplicant interface state: scanning -> authenticating Dec 14 15:01:42 localhost vmunix: [2511471.876696] wlp18s0: authenticated Dec 14 15:01:42 localhost wpa_supplicant[297]: wlp18s0: Trying to associate with 20:4e:7f:85:ab:13 (SSID='MY-AP-NAME' freq=2422 MHz) Dec 14 15:01:42 localhost vmunix: [2511471.883450] wlp18s0: associate with 20:4e:7f:85:ab:13 (try 1/3) Dec 14 15:01:42 localhost NetworkManager[298]: <info> [1576353702.0970] device (wlp18s0): supplicant interface state: authenticating -> associating Dec 14 15:01:42 localhost vmunix: [2511471.887256] wlp18s0: RX AssocResp from 20:4e:7f:85:ab:13 (capab=0x431 status=0 aid=2) Dec 14 15:01:42 localhost vmunix: [2511471.887498] wlp18s0: associated Dec 14 15:01:42 localhost wpa_supplicant[297]: wlp18s0: Associated with 20:4e:7f:85:ab:13 Dec 14 15:01:42 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 14 15:01:42 localhost NetworkManager[298]: <info> [1576353702.1100] device (wlp18s0): supplicant interface state: associating -> 4-way handshake Dec 14 15:01:42 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA Dec 14 15:01:43 localhost ntpd[299]: Deleting interface #141 wlp18s0, 192.168.10.159#123, interface stats: received=1435, sent=1440, dropped=0, active_time=144600 secs Dec 14 15:01:43 localhost ntpd[299]: 192.99.2.172 local addr 192.168.10.159 -> <null> Dec 14 15:01:43 localhost ntpd[299]: 54.39.13.155 local addr 192.168.10.159 -> <null> Dec 14 15:01:43 localhost ntpd[299]: 149.56.121.16 local addr 192.168.10.159 -> <null> Dec 14 15:01:43 localhost ntpd[299]: 149.56.27.12 local addr 192.168.10.159 -> <null> Dec 14 15:01:43 localhost ntpd[299]: 192.99.2.8 local addr 192.168.10.159 -> <null> Dec 14 15:01:43 localhost ntpd[299]: 54.39.23.64 local addr 192.168.10.159 -> <null> Dec 14 15:01:43 localhost ntpd[299]: 50.101.251.61 local addr 192.168.10.159 -> <null> Dec 14 15:01:43 localhost ntpd[299]: 162.159.200.1 local addr 192.168.10.159 -> <null> Dec 14 15:01:43 localhost ntpd[299]: 172.105.3.89 local addr 192.168.10.159 -> <null> Dec 14 15:01:43 localhost ntpd[299]: Deleting interface #142 wlp18s0, fdb5:f1eb:7663::2a3#123, interface stats: received=0, sent=0, dropped=0, active_time=144600 secs Dec 14 15:01:43 localhost ntpd[299]: Deleting interface #143 wlp18s0, fdb5:f1eb:7663:0:3f6a:8955:6109:580#123, interface stats: received=0, sent=0, dropped=0, active_time=144600 secs Dec 14 15:01:43 localhost ntpd[299]: Deleting interface #144 wlp18s0, fe80::105:d3cb:cb27:ba08%3#123, interface stats: received=0, sent=0, dropped=0, active_time=144600 secs Dec 14 15:01:44 localhost wpa_supplicant[297]: wlp18s0: WPA: Key negotiation completed with 20:4e:7f:85:ab:13 [PTK=CCMP GTK=CCMP] Dec 14 15:01:44 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-CONNECTED - Connection to 20:4e:7f:85:ab:13 completed [id=0 id_str=] Dec 14 15:01:44 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-69 noise=-91 txrate=1000 Dec 14 15:01:44 localhost NetworkManager[298]: <info> [1576353704.1193] device (wlp18s0): supplicant interface state: 4-way handshake -> completed Dec 14 15:01:45 localhost ntpd[299]: Listen normally on 145 wlp18s0 192.168.10.159:123 Dec 14 15:01:45 localhost ntpd[299]: Listen normally on 146 wlp18s0 [fdb5:f1eb:7663::2a3]:123 Dec 14 15:01:45 localhost ntpd[299]: Listen normally on 147 wlp18s0 [fdb5:f1eb:7663:0:3f6a:8955:6109:580]:123 Dec 14 15:01:45 localhost ntpd[299]: Listen normally on 148 wlp18s0 [fe80::105:d3cb:cb27:ba08%3]:123 Dec 14 15:02:38 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-62 noise=-91 txrate=52000 Dec 14 15:11:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 15:21:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 15:31:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 15:41:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 15:51:12 localhost sshd[10646]: error: kex_exchange_identification: banner line contains invalid characters Dec 14 15:51:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 16:01:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 16:11:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 16:21:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 16:23:20 localhost dhclient: PRC: Renewing lease on wlp18s0. Dec 14 16:23:20 localhost dhclient: XMT: Renew on wlp18s0, interval 10350ms. Dec 14 16:23:20 localhost dhclient: RCV: Reply message on wlp18s0 from fe80::204e:7fff:fe85:ab13. Dec 14 16:23:20 localhost NetworkManager[298]: <info> [1576358600.9195] dhcp6 (wlp18s0): valid_lft 4294967295 Dec 14 16:23:20 localhost NetworkManager[298]: <info> [1576358600.9196] dhcp6 (wlp18s0): preferred_lft 4294967295 Dec 14 16:23:20 localhost NetworkManager[298]: <info> [1576358600.9196] dhcp6 (wlp18s0): address fdb5:f1eb:7663::2a3 Dec 14 16:23:20 localhost NetworkManager[298]: <info> [1576358600.9196] dhcp6 (wlp18s0): nameserver 'fdb5:f1eb:7663::1' Dec 14 16:23:20 localhost NetworkManager[298]: <info> [1576358600.9197] dhcp6 (wlp18s0): state changed bound -> bound, event ID="da:5d:2f:2f|1576358600" Dec 14 16:31:36 localhost wpa_supplicant[297]: wlp18s0: WPA: Group rekeying completed with 20:4e:7f:85:ab:13 [GTK=CCMP] Dec 14 16:31:40 localhost vmunix: [2516870.552438] wlp18s0: deauthenticated from 20:4e:7f:85:ab:13 (Reason: 2=PREV_AUTH_NOT_VALID) Dec 14 16:31:40 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-DISCONNECTED bssid=20:4e:7f:85:ab:13 reason=2 Dec 14 16:31:40 localhost wpa_supplicant[297]: dbus: wpa_dbus_property_changed: no property SessionLength in object /fi/w1/wpa_supplicant1/Interfaces/0 Dec 14 16:31:40 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Dec 14 16:31:40 localhost NetworkManager[298]: <warn> [1576359100.9141] sup-iface[0x20f30d0,wlp18s0]: connection disconnected (reason 2) Dec 14 16:31:40 localhost NetworkManager[298]: <info> [1576359100.9198] device (wlp18s0): supplicant interface state: completed -> disconnected Dec 14 16:31:41 localhost NetworkManager[298]: <info> [1576359101.0208] device (wlp18s0): supplicant interface state: disconnected -> scanning Dec 14 16:31:42 localhost vmunix: [2516871.785618] wlp18s0: authenticate with 20:4e:7f:85:ab:13 Dec 14 16:31:42 localhost wpa_supplicant[297]: wlp18s0: SME: Trying to authenticate with 20:4e:7f:85:ab:13 (SSID='MY-AP-NAME' freq=2422 MHz) Dec 14 16:31:42 localhost vmunix: [2516871.799005] wlp18s0: send auth to 20:4e:7f:85:ab:13 (try 1/3) Dec 14 16:31:42 localhost NetworkManager[298]: <info> [1576359102.0854] device (wlp18s0): supplicant interface state: scanning -> authenticating Dec 14 16:31:42 localhost vmunix: [2516871.812655] wlp18s0: authenticated Dec 14 16:31:42 localhost wpa_supplicant[297]: wlp18s0: Trying to associate with 20:4e:7f:85:ab:13 (SSID='MY-AP-NAME' freq=2422 MHz) Dec 14 16:31:42 localhost NetworkManager[298]: <info> [1576359102.0994] device (wlp18s0): supplicant interface state: authenticating -> associating Dec 14 16:31:42 localhost vmunix: [2516871.816776] wlp18s0: associate with 20:4e:7f:85:ab:13 (try 1/3) Dec 14 16:31:42 localhost vmunix: [2516871.891608] wlp18s0: RX AssocResp from 20:4e:7f:85:ab:13 (capab=0x431 status=0 aid=2) Dec 14 16:31:42 localhost vmunix: [2516871.891773] wlp18s0: associated Dec 14 16:31:42 localhost wpa_supplicant[297]: wlp18s0: Associated with 20:4e:7f:85:ab:13 Dec 14 16:31:42 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 14 16:31:42 localhost NetworkManager[298]: <info> [1576359102.1836] device (wlp18s0): supplicant interface state: associating -> 4-way handshake Dec 14 16:31:42 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA Dec 14 16:31:43 localhost ntpd[299]: Deleting interface #145 wlp18s0, 192.168.10.159#123, interface stats: received=107, sent=107, dropped=0, active_time=5398 secs Dec 14 16:31:43 localhost ntpd[299]: 192.99.2.172 local addr 192.168.10.159 -> <null> Dec 14 16:31:43 localhost ntpd[299]: 54.39.13.155 local addr 192.168.10.159 -> <null> Dec 14 16:31:43 localhost ntpd[299]: 149.56.121.16 local addr 192.168.10.159 -> <null> Dec 14 16:31:43 localhost ntpd[299]: 149.56.27.12 local addr 192.168.10.159 -> <null> Dec 14 16:31:43 localhost ntpd[299]: 192.99.2.8 local addr 192.168.10.159 -> <null> Dec 14 16:31:43 localhost ntpd[299]: 54.39.23.64 local addr 192.168.10.159 -> <null> Dec 14 16:31:43 localhost ntpd[299]: 50.101.251.61 local addr 192.168.10.159 -> <null> Dec 14 16:31:43 localhost ntpd[299]: 162.159.200.1 local addr 192.168.10.159 -> <null> Dec 14 16:31:43 localhost ntpd[299]: 172.105.3.89 local addr 192.168.10.159 -> <null> Dec 14 16:31:43 localhost ntpd[299]: Deleting interface #146 wlp18s0, fdb5:f1eb:7663::2a3#123, interface stats: received=0, sent=0, dropped=0, active_time=5398 secs Dec 14 16:31:43 localhost ntpd[299]: Deleting interface #147 wlp18s0, fdb5:f1eb:7663:0:3f6a:8955:6109:580#123, interface stats: received=0, sent=0, dropped=0, active_time=5398 secs Dec 14 16:31:43 localhost ntpd[299]: Deleting interface #148 wlp18s0, fe80::105:d3cb:cb27:ba08%3#123, interface stats: received=0, sent=0, dropped=0, active_time=5398 secs Dec 14 16:31:46 localhost vmunix: [2516875.929689] wlp18s0: deauthenticated from 20:4e:7f:85:ab:13 (Reason: 2=PREV_AUTH_NOT_VALID) Dec 14 16:31:46 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-DISCONNECTED bssid=20:4e:7f:85:ab:13 reason=2 Dec 14 16:31:46 localhost wpa_supplicant[297]: wlp18s0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect Dec 14 16:31:46 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="MY-AP-NAME" auth_failures=1 duration=10 reason=WRONG_KEY Dec 14 16:31:46 localhost wpa_supplicant[297]: dbus: wpa_dbus_property_changed: no property SessionLength in object /fi/w1/wpa_supplicant1/Interfaces/0 Dec 14 16:31:46 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Dec 14 16:31:46 localhost NetworkManager[298]: <warn> [1576359106.2542] sup-iface[0x20f30d0,wlp18s0]: connection disconnected (reason 2) Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.2594] device (wlp18s0): supplicant interface state: 4-way handshake -> disconnected Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.2604] device (wlp18s0): Activation: (wifi) disconnected during association, asking for new key Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.2606] device (wlp18s0): state change: activated -> need-auth (reason 'supplicant-disconnect', sys-iface-state: 'managed') Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.2932] dhcp4 (wlp18s0): canceled DHCP transaction, DHCP client pid 10342 Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.2932] dhcp4 (wlp18s0): state changed bound -> done Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.2952] dhcp6 (wlp18s0): canceled DHCP transaction, DHCP client pid 10355 Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.2954] dhcp6 (wlp18s0): state changed bound -> done Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.2968] manager: NetworkManager state is now CONNECTING Dec 14 16:31:46 localhost NetworkManager[298]: <warn> [1576359106.3021] device (wlp18s0): No agents were available for this request. Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.3023] device (wlp18s0): state change: need-auth -> failed (reason 'no-secrets', sys-iface-state: 'managed') Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.3033] manager: NetworkManager state is now DISCONNECTED Dec 14 16:31:46 localhost NetworkManager[298]: <warn> [1576359106.3042] device (wlp18s0): Activation: failed for connection 'MY-AP-NAME' Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.3048] device (wlp18s0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed') Dec 14 16:31:46 localhost avahi-daemon[306]: Withdrawing address record for fdb5:f1eb:7663::2a3 on wlp18s0. Dec 14 16:31:46 localhost avahi-daemon[306]: Withdrawing address record for fdb5:f1eb:7663:0:3f6a:8955:6109:580 on wlp18s0. Dec 14 16:31:46 localhost avahi-daemon[306]: Leaving mDNS multicast group on interface wlp18s0.IPv6 with address fdb5:f1eb:7663:0:3f6a:8955:6109:580. Dec 14 16:31:46 localhost avahi-daemon[306]: Joining mDNS multicast group on interface wlp18s0.IPv6 with address fe80::105:d3cb:cb27:ba08. Dec 14 16:31:46 localhost avahi-daemon[306]: Registering new address record for fe80::105:d3cb:cb27:ba08 on wlp18s0.*. Dec 14 16:31:46 localhost avahi-daemon[306]: Withdrawing address record for fe80::105:d3cb:cb27:ba08 on wlp18s0. Dec 14 16:31:46 localhost avahi-daemon[306]: Leaving mDNS multicast group on interface wlp18s0.IPv6 with address fe80::105:d3cb:cb27:ba08. Dec 14 16:31:46 localhost avahi-daemon[306]: Interface wlp18s0.IPv6 no longer relevant for mDNS. Dec 14 16:31:46 localhost avahi-daemon[306]: Withdrawing address record for 192.168.10.159 on wlp18s0. Dec 14 16:31:46 localhost avahi-daemon[306]: Leaving mDNS multicast group on interface wlp18s0.IPv4 with address 192.168.10.159. Dec 14 16:31:46 localhost avahi-daemon[306]: Interface wlp18s0.IPv4 no longer relevant for mDNS. Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.3211] device (wlp18s0): set-hw-addr: set MAC address to 5E:13:04:81:23:C6 (scanning) Dec 14 16:31:46 localhost nscd: 264 monitored file `/etc/resolv.conf` was moved into place, adding watch Dec 14 16:31:46 localhost nscd: 264 monitored file `/etc/resolv.conf` was moved into place, adding watch Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.3474] device (wlp18s0): supplicant interface state: disconnected -> disabled Dec 14 16:31:46 localhost NetworkManager[298]: <info> [1576359106.3754] device (wlp18s0): supplicant interface state: disabled -> inactive Dec 14 16:31:46 localhost wpa_supplicant[297]: wlp18s0: Reject scan trigger since one is already pending Dec 14 16:37:27 localhost NetworkManager[298]: <info> [1576359447.2136] device (wlp18s0): set-hw-addr: set MAC address to 02:EF:36:24:62:CE (scanning) Dec 14 16:37:27 localhost NetworkManager[298]: <info> [1576359447.2331] device (wlp18s0): supplicant interface state: inactive -> disabled Dec 14 16:37:27 localhost NetworkManager[298]: <info> [1576359447.2351] device (wlp18s0): supplicant interface state: disabled -> inactive Dec 14 16:37:27 localhost wpa_supplicant[297]: wlp18s0: Reject scan trigger since one is already pending Dec 14 16:42:42 localhost NetworkManager[298]: <info> [1576359762.1565] device (wlp18s0): set-hw-addr: set MAC address to CE:98:BC:D0:F1:B9 (scanning) Dec 14 16:42:42 localhost NetworkManager[298]: <info> [1576359762.1758] device (wlp18s0): supplicant interface state: inactive -> disabled Dec 14 16:42:42 localhost NetworkManager[298]: <info> [1576359762.1996] device (wlp18s0): supplicant interface state: disabled -> inactive [...] --8<---------------cut here---------------end--------------->8--- The workaround is to reconnect manually with for example using --8<---------------cut here---------------start------------->8--- nmcli con up ACESS-POINT-NAME --8<---------------cut here---------------end--------------->8--- Which gives the following messages: --8<---------------cut here---------------start------------->8--- Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4205] agent-manager: req[0x2173a70, :1.46/nmcli-connect/1000]: agent registered Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4208] policy: auto-activating connection 'MY-AP-NAME' (172b7c50-4a3b-4b24-9d74-2e567aed460a) Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4223] device (wlp18s0): Activation: starting connection 'MY-AP-NAME' (172b7c50-4a3b-4b24-9d74-2e567aed460a) Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4226] device (wlp18s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4233] manager: NetworkManager state is now CONNECTING Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4385] device (wlp18s0): set-hw-addr: reset MAC address to C0:F8:DA:5D:2F:2F (preserve) Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4653] device (wlp18s0): supplicant interface state: inactive -> disabled Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4656] device (wlp18s0): state change: prepare -> deactivating (reason 'new-activation', sys-iface-state: 'managed') Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4666] manager: NetworkManager state is now DISCONNECTING Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4674] device (wlp18s0): disconnecting for new activation request. Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4675] audit: op="connection-activate" uuid="172b7c50-4a3b-4b24-9d74-2e567aed460a" name="MY-AP-NAME" pid=6513 uid=1000 result="success" Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4677] device (wlp18s0): state change: deactivating -> disconnected (reason 'new-activation', sys-iface-state: 'managed') Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.4842] device (wlp18s0): set-hw-addr: set MAC address to C2:40:8A:91:21:5F (scanning) Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5023] manager: NetworkManager state is now DISCONNECTED Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5032] device (wlp18s0): Activation: starting connection 'MY-AP-NAME' (172b7c50-4a3b-4b24-9d74-2e567aed460a) Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5053] device (wlp18s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5067] manager: NetworkManager state is now CONNECTING Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5348] device (wlp18s0): set-hw-addr: reset MAC address to C0:F8:DA:5D:2F:2F (preserve) Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5511] device (wlp18s0): supplicant interface state: disabled -> inactive Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5517] device (wlp18s0): supplicant interface state: inactive -> disabled Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5519] device (wlp18s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5526] device (wlp18s0): Activation: (wifi) access point 'MY-AP-NAME' has security, but secrets are required. Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5528] device (wlp18s0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5585] device (wlp18s0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5594] device (wlp18s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5601] device (wlp18s0): Activation: (wifi) connection 'MY-AP-NAME' has security, and secrets exist. No new secrets needed. Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5603] Config: added 'ssid' value 'MY-AP-NAME' Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5604] Config: added 'scan_ssid' value '1' Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5605] Config: added 'bgscan' value 'simple:30:-80:86400' Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5607] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256' Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5608] Config: added 'psk' value '<hidden>' Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5609] Config: added 'ieee80211w' value '1' Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.5913] device (wlp18s0): supplicant interface state: disabled -> inactive Dec 18 22:00:48 localhost NetworkManager[298]: <info> [1576724448.6136] device (wlp18s0): supplicant interface state: inactive -> scanning Dec 18 22:00:49 localhost vmunix: [2882214.304001] wlp18s0: authenticate with 20:4e:7f:85:ab:13 Dec 18 22:00:49 localhost wpa_supplicant[297]: wlp18s0: SME: Trying to authenticate with 20:4e:7f:85:ab:13 (SSID='MY-AP-NAME' freq=2422 MHz) Dec 18 22:00:49 localhost vmunix: [2882214.322552] wlp18s0: send auth to 20:4e:7f:85:ab:13 (try 1/3) Dec 18 22:00:49 localhost vmunix: [2882214.325084] wlp18s0: authenticated Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.6772] device (wlp18s0): supplicant interface state: scanning -> authenticating Dec 18 22:00:49 localhost wpa_supplicant[297]: wlp18s0: Trying to associate with 20:4e:7f:85:ab:13 (SSID='MY-AP-NAME' freq=2422 MHz) Dec 18 22:00:49 localhost vmunix: [2882214.329953] wlp18s0: associate with 20:4e:7f:85:ab:13 (try 1/3) Dec 18 22:00:49 localhost vmunix: [2882214.335176] wlp18s0: RX AssocResp from 20:4e:7f:85:ab:13 (capab=0x431 status=0 aid=2) Dec 18 22:00:49 localhost vmunix: [2882214.335346] wlp18s0: associated Dec 18 22:00:49 localhost wpa_supplicant[297]: wlp18s0: Associated with 20:4e:7f:85:ab:13 Dec 18 22:00:49 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.6903] device (wlp18s0): supplicant interface state: authenticating -> associating Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.6959] device (wlp18s0): supplicant interface state: associating -> associated Dec 18 22:00:49 localhost wpa_supplicant[297]: wlp18s0: WPA: Key negotiation completed with 20:4e:7f:85:ab:13 [PTK=CCMP GTK=CCMP] Dec 18 22:00:49 localhost vmunix: [2882214.348804] IPv6: ADDRCONF(NETDEV_CHANGE): wlp18s0: link becomes ready Dec 18 22:00:49 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-CONNECTED - Connection to 20:4e:7f:85:ab:13 completed [id=0 id_str=] Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7044] device (wlp18s0): supplicant interface state: associated -> 4-way handshake Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7095] device (wlp18s0): supplicant interface state: 4-way handshake -> completed Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7096] device (wlp18s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "MY-AP-NAME" Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7102] device (wlp18s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7110] dhcp4 (wlp18s0): activation: beginning transaction (timeout in 45 seconds) Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7170] dhcp4 (wlp18s0): dhclient started with pid 6519 Dec 18 22:00:49 localhost avahi-daemon[306]: Joining mDNS multicast group on interface wlp18s0.IPv6 with address fe80::105:d3cb:cb27:ba08. Dec 18 22:00:49 localhost avahi-daemon[306]: New relevant interface wlp18s0.IPv6 for mDNS. Dec 18 22:00:49 localhost avahi-daemon[306]: Registering new address record for fe80::105:d3cb:cb27:ba08 on wlp18s0.*. Dec 18 22:00:49 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=CA Dec 18 22:00:49 localhost dhclient: DHCPREQUEST for 192.168.10.159 on wlp18s0 to 255.255.255.255 port 67 Dec 18 22:00:49 localhost dhclient: DHCPACK of 192.168.10.159 from 192.168.10.1 Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7801] dhcp4 (wlp18s0): address 192.168.10.159 Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7801] dhcp4 (wlp18s0): plen 24 (255.255.255.0) Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7801] dhcp4 (wlp18s0): gateway 192.168.10.1 Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7802] dhcp4 (wlp18s0): lease time 4294967295 Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7802] dhcp4 (wlp18s0): hostname 'apteryx' Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7802] dhcp4 (wlp18s0): nameserver '192.168.10.1' Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7802] dhcp4 (wlp18s0): domain name 'lan' Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7803] dhcp4 (wlp18s0): state changed unknown -> bound Dec 18 22:00:49 localhost avahi-daemon[306]: Joining mDNS multicast group on interface wlp18s0.IPv4 with address 192.168.10.159. Dec 18 22:00:49 localhost avahi-daemon[306]: New relevant interface wlp18s0.IPv4 for mDNS. Dec 18 22:00:49 localhost avahi-daemon[306]: Registering new address record for 192.168.10.159 on wlp18s0.IPv4. Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7857] device (wlp18s0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:49 localhost dhclient: Timeout too large reducing to: 2147483646 (TIME_MAX - 1) Dec 18 22:00:49 localhost dhclient: bound to 192.168.10.159 -- renewal in 2147483648 seconds. Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7907] device (wlp18s0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7915] device (wlp18s0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed') Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.7973] manager: NetworkManager state is now CONNECTED_LOCAL Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.8058] manager: NetworkManager state is now CONNECTED_SITE Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.8066] policy: set 'MY-AP-NAME' (wlp18s0) as default for IPv4 routing and DNS Dec 18 22:00:49 localhost nscd: 264 monitored file `/etc/resolv.conf` was moved into place, adding watch Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.8103] device (wlp18s0): Activation: successful, device activated. Dec 18 22:00:49 localhost NetworkManager[298]: <info> [1576724449.8116] manager: NetworkManager state is now CONNECTED_GLOBAL Dec 18 22:00:50 localhost wpa_supplicant[297]: wlp18s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-74 noise=-91 txrate=19500 --8<---------------cut here---------------end--------------->8--- Maxim
maxim.cournoyer <at> gmail.com
:Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
:Message #10 received at 38667-done <at> debbugs.gnu.org (full text, mbox):
From: maxim.cournoyer <at> gmail.com To: Maxim Cournoyer <maxim.cournoyer <at> gmail.com> Cc: 38667-done <at> debbugs.gnu.org Subject: Re: bug#38667: Network-Manager (sometimes) fails reconnecting to network automatically Date: Fri, 01 May 2020 09:40:19 -0400
I haven't seen this problem in a long time, so I'm closing the issue. I suspect it is more a problem with Network Manager than with Guix. Maxim
Debbugs Internal Request <help-debbugs <at> gnu.org>
to internal_control <at> debbugs.gnu.org
.
(Sat, 30 May 2020 11:24:06 GMT) Full text and rfc822 format available.
GNU bug tracking system
Copyright (C) 1999 Darren O. Benham,
1997,2003 nCipher Corporation Ltd,
1994-97 Ian Jackson.