Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 651414 - sys-apps/systemd-238-r1: update to 238 causes NM to ask for root password every time I resume from suspend
Summary: sys-apps/systemd-238-r1: update to 238 causes NM to ask for root password eve...
Status: RESOLVED FIXED
Alias: None
Product: Gentoo Linux
Classification: Unclassified
Component: Current packages (show other bugs)
Hardware: All Linux
: Normal normal
Assignee: Gentoo systemd Team
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-03-25 10:01 UTC by Pacho Ramos
Modified: 2018-03-26 22:34 UTC (History)
1 user (show)

See Also:
Package list:
Runtime testing required: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Pacho Ramos gentoo-dev 2018-03-25 10:01:01 UTC
Since some days I was suffering a "new" issue: when I was resuming from suspend to RAM (simply opening the laptop), NetworkManager was asking me for my root password and sometimes asking me to re-sent the password to connect to the router (simply resent it because the proper password was already pre-filled).

After many tries, it seems this is caused by systemd-238, and downgrading to 237-r3 work fine. Before trying to go to upstream, I would like to send it here as maybe you have seen a similar issue recently.

Comparing journalctl output running systemd-237 and 238, I see this extra message with 238:
mar 25 11:16:20 dell-2017 NetworkManager[278]: <info>  [1521969380.9857] device (wlp3s0): set-hw-addr: set MAC address to A2:63:22:23:72:80 (scanning)

A bit later I also see this with 238 after changing the status to "CONNECTING":
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.7339] device (wlp3s0): set-hw-addr: reset MAC address to 70:1C:E7:82:6E:E6 (preserve)

After this, it seems that connection behaves a bit different, with 237 (working one) it does:
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6138] policy: auto-activating connection 'Livebox-F23A'
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6145] device (wlp3s0): Activation: starting connection 'Livebox-F23A' (fdd6a936-d3e3-4cf5-b284-7dd4f2e603a0)
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6147] device (wlp3s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6149] manager: NetworkManager state is now CONNECTING
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6152] device (wlp3s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6153] device (wlp3s0): Activation: (wifi) access point 'Livebox-F23A' has security, but secrets are required.
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6153] device (wlp3s0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6179] device (wlp3s0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6182] device (wlp3s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6183] device (wlp3s0): Activation: (wifi) connection 'Livebox-F23A' has security, and secrets exist.  No new secrets needed.
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6184] Config: added 'ssid' value 'Livebox-F23A'
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6184] Config: added 'scan_ssid' value '1'
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6184] Config: added 'bgscan' value 'simple:30:-80:86400'
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6184] Config: added 'key_mgmt' value 'WPA-PSK'
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6184] Config: added 'psk' value '<hidden>'
mar 25 11:39:27 dell-2017 wpa_supplicant[419]: wlp3s0: SME: Trying to authenticate with b4:a5:ef:8c:f2:3f (SSID='Livebox-F23A' freq=5560 MHz)
mar 25 11:39:27 dell-2017 kernel: wlp3s0: authenticate with b4:a5:ef:8c:f2:3f
mar 25 11:39:27 dell-2017 kernel: wlp3s0: send auth to b4:a5:ef:8c:f2:3f (try 1/3)
mar 25 11:39:27 dell-2017 wpa_supplicant[419]: wlp3s0: Trying to associate with b4:a5:ef:8c:f2:3f (SSID='Livebox-F23A' freq=5560 MHz)
mar 25 11:39:27 dell-2017 kernel: wlp3s0: authenticated
mar 25 11:39:27 dell-2017 kernel: wlp3s0: associate with b4:a5:ef:8c:f2:3f (try 1/3)
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6407] device (wlp3s0): supplicant interface state: ready -> associating
mar 25 11:39:27 dell-2017 wpa_supplicant[419]: wlp3s0: Associated with b4:a5:ef:8c:f2:3f
mar 25 11:39:27 dell-2017 wpa_supplicant[419]: wlp3s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
mar 25 11:39:27 dell-2017 systemd-timesyncd[267]: No network connectivity, watching for changes.
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6501] device (wlp3s0): supplicant interface state: associating -> associated
mar 25 11:39:27 dell-2017 NetworkManager[344]: <info>  [1521970767.6981] device (wlp3s0): supplicant interface state: associated -> 4-way handshake
mar 25 11:39:27 dell-2017 wpa_supplicant[419]: wlp3s0: WPA: Key negotiation completed with b4:a5:ef:8c:f2:3f [PTK=CCMP GTK=CCMP]
mar 25 11:39:27 dell-2017 wpa_supplicant[419]: wlp3s0: CTRL-EVENT-CONNECTED - Connection to b4:a5:ef:8c:f2:3f completed [id=0 id_str=]

=> After this, it's finally connected properly


While in 238, it differs a bit, it has this additional line (maybe the one that ends up causing the ask of root password to resent router password):
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8549] device (wlp3s0): supplicant interface state: disabled -> scanning

-> It seems it scans another time:

mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8430] device (wlp3s0): supplicant interface state: ready -> disabled
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8494] device (wlp3s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8495] device (wlp3s0): Activation: (wifi) access point 'Livebox-F23A' has security, but secrets are required.
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8495] device (wlp3s0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8549] device (wlp3s0): supplicant interface state: disabled -> scanning
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8577] device (wlp3s0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8580] device (wlp3s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8582] device (wlp3s0): Activation: (wifi) connection 'Livebox-F23A' has security, and secrets exist.  No new secrets needed.
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8582] Config: added 'ssid' value 'Livebox-F23A'
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8582] Config: added 'scan_ssid' value '1'
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8582] Config: added 'bgscan' value 'simple:30:-80:86400'
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8582] Config: added 'key_mgmt' value 'WPA-PSK'
mar 25 11:16:24 dell-2017 NetworkManager[278]: <info>  [1521969384.8582] Config: added 'psk' value '<hidden>'
mar 25 11:16:28 dell-2017 wpa_supplicant[405]: wlp3s0: SME: Trying to authenticate with b4:a5:ef:8c:f2:3f (SSID='Livebox-F23A' freq=5520 MHz)
mar 25 11:16:28 dell-2017 kernel: wlp3s0: authenticate with b4:a5:ef:8c:f2:3f
mar 25 11:16:28 dell-2017 kernel: wlp3s0: send auth to b4:a5:ef:8c:f2:3f (try 1/3)
mar 25 11:16:28 dell-2017 wpa_supplicant[405]: wlp3s0: Trying to associate with b4:a5:ef:8c:f2:3f (SSID='Livebox-F23A' freq=5520 MHz)
mar 25 11:16:28 dell-2017 kernel: wlp3s0: authenticated
mar 25 11:16:28 dell-2017 kernel: wlp3s0: associate with b4:a5:ef:8c:f2:3f (try 1/3)
mar 25 11:16:28 dell-2017 NetworkManager[278]: <info>  [1521969388.3979] device (wlp3s0): supplicant interface state: scanning -> authenticating
mar 25 11:16:28 dell-2017 NetworkManager[278]: <info>  [1521969388.3987] device (wlp3s0): supplicant interface state: authenticating -> associating
mar 25 11:16:28 dell-2017 wpa_supplicant[405]: wlp3s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
mar 25 11:16:28 dell-2017 systemd-timesyncd[263]: No network connectivity, watching for changes.
mar 25 11:16:28 dell-2017 kernel: wlp3s0: associated
mar 25 11:16:28 dell-2017 NetworkManager[278]: <info>  [1521969388.4120] device (wlp3s0): supplicant interface state: associating -> associated
mar 25 11:16:28 dell-2017 NetworkManager[278]: <info>  [1521969388.4587] device (wlp3s0): supplicant interface state: associated -> 4-way handshake
mar 25 11:16:28 dell-2017 kernel: wlp3s0: Limiting TX power to 30 (30 - 0) dBm as advertised by b4:a5:ef:8c:f2:3f
mar 25 11:16:32 dell-2017 systemd-timesyncd[263]: No network connectivity, watching for changes.
mar 25 11:16:32 dell-2017 kernel: wlp3s0: deauthenticated from b4:a5:ef:8c:f2:3f (Reason: 2=PREV_AUTH_NOT_VALID)
mar 25 11:16:32 dell-2017 wpa_supplicant[405]: wlp3s0: CTRL-EVENT-DISCONNECTED bssid=b4:a5:ef:8c:f2:3f reason=2
mar 25 11:16:32 dell-2017 wpa_supplicant[405]: wlp3s0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
mar 25 11:16:32 dell-2017 wpa_supplicant[405]: wlp3s0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="Livebox-F23A" auth_failures=1 duration=10 reason=WRONG_KEY
mar 25 11:16:32 dell-2017 NetworkManager[278]: <warn>  [1521969392.5851] sup-iface[0x5560f0666710,wlp3s0]: connection disconnected (reason 2)
mar 25 11:16:32 dell-2017 NetworkManager[278]: <info>  [1521969392.5903] device (wlp3s0): supplicant interface state: 4-way handshake -> disconnected
mar 25 11:16:32 dell-2017 NetworkManager[278]: <info>  [1521969392.5910] device (wlp3s0): Activation: (wifi) disconnected during association, asking for new key
mar 25 11:16:32 dell-2017 NetworkManager[278]: <info>  [1521969392.5911] device (wlp3s0): state change: config -> need-auth (reason 'supplicant-disconnect', sys-iface-state: 'managed')

=> For some reason it ends up failing to connect (wpa_supplicant says that because of bad key... even if it's the same exact key used in all cases and is the one that will be sent again (and succeed) as soon as I fill root password to sent again the same router password)

I am not sure what causes this change in behavior between systemd 237 or 238... I would point to that strange changes in MAC, but maybe you think it's a different issue

Thanks a lot
Comment 1 Pacho Ramos gentoo-dev 2018-03-25 10:13:22 UTC
I think I found the fix :D

For now it seems to work, but I will keep testing it a bit before committing:
https://src.fedoraproject.org/rpms/systemd/raw/master/f/0004-udev-net-id-Fix-check-for-address-to-keep-interface-.patch
Comment 2 Pacho Ramos gentoo-dev 2018-03-26 21:13:47 UTC
[master 21bf005cd5e] sys-apps/systemd: Apply upstream patch to fix check for address to keep interface names stable (also fixing bug #651414 affecting NM failing to reconnect properly after suspend).
 2 files changed, 474 insertions(+)
 create mode 100644 sys-apps/systemd/files/238-0003-udev-net-id-Fix-check-for-address-to-keep-interface-8458.patch
 create mode 100644 sys-apps/systemd/systemd-238-r2.ebuild
Comment 3 Mike Gilbert gentoo-dev 2018-03-26 21:19:54 UTC
(In reply to Pacho Ramos from comment #2)

Pacho: Please format your commit messages according to GLEP 66.

https://www.gentoo.org/glep/glep-0066.html#id8

A single line with 179 characters is unacceptable.
Comment 4 Pacho Ramos gentoo-dev 2018-03-26 21:34:32 UTC
Ah, I wasn't aware of that rule. 

OK, to do that are you relying on dropping "-m" and getting the EDITOR opened then or is there a way to pass the summary and "body" in command line directly? The idea would be to not need to go though EDITOR every time as, sometimes, the commit message is the same for multiple commits affecting different packages. Currently that is easy simply relying on bash history... but needing to go always into EDITOR would for me to copy&paste the message all the time and also manually edit the package name (that now is set automatically when run from command line directly)

Thanks
Comment 5 Pacho Ramos gentoo-dev 2018-03-26 21:35:43 UTC
(In reply to Pacho Ramos from comment #4)
[...]
> but needing to go always into EDITOR would for me to copy&paste the message


*force me to
Comment 6 Mike Gilbert gentoo-dev 2018-03-26 21:42:23 UTC
(In reply to Pacho Ramos from comment #4)

Personally, I always type my commit message into $EDITOR.

For repeated commits, you can type your message into a file and pass the filename to repoman -M (capital-m).
Comment 7 Pacho Ramos gentoo-dev 2018-03-26 22:34:08 UTC
Ah ok, checking man page I also discovered that I can pass cat/pkg there without needing to use the old "hack" suggested in the old Git Workflow page for the same substitution