Bug 1079672 - NetworkManager does not automatically connect to WLAN anymore
NetworkManager does not automatically connect to WLAN anymore
Status: RESOLVED FIXED
: 1081172 (view as bug list)
Classification: openSUSE
Product: openSUSE Tumbleweed
Classification: openSUSE
Component: GNOME
Current
x86-64 Other
: P2 - High : Major (vote)
: ---
Assigned To: Jonathan Kang
E-mail List
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2018-02-06 21:21 UTC by Frank Krüger
Modified: 2022-07-04 01:55 UTC (History)
12 users (show)

See Also:
Found By: ---
Services Priority:
Business Priority:
Blocker: ---
Marketing QA Status: ---
IT Deployment: ---


Attachments
Full journal of a test session with trace logging (2.11 MB, text/x-vhdl)
2018-03-02 21:21 UTC, Fabian Vogt
Details
NM 1.10.4 Log (173.33 KB, text/x-vhdl)
2018-03-02 22:12 UTC, Frank Krüger
Details
NM fail at login log (200.04 KB, text/plain)
2018-03-03 07:43 UTC, Mykola Krachkovsky
Details
startup log from sddm login to nm fail (196.11 KB, text/x-log)
2018-03-03 07:54 UTC, Mykola Krachkovsky
Details
[PATCH] Fix setting the autoconnect block reason if no agents registered (958 bytes, patch)
2018-03-03 12:15 UTC, Fabian Vogt
Details | Diff
Fix logic error for race condition detection (687 bytes, patch)
2018-03-03 13:37 UTC, Fabian Vogt
Details | Diff
NM 1.10.4-335 Log (530.81 KB, text/x-vhdl)
2018-03-03 14:04 UTC, Frank Krüger
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Frank Krüger 2018-02-06 21:21:49 UTC
Given KDE Plasma 5.11.95, after updating to NM 1.10.2 (TW20180203) it does not connect automatically to my WLAN anymore, even though the option "Automatically connect to this network when it is available” in the KDE Network applet is chosen. In fact, it tries to connect, but quits after a while with the message "no password provided", even though its there (I am using Kwallet). 

I have to connect manually by using the "connect" button in the KDE Network applet.
Comment 1 Robby Engelmann 2018-02-09 09:23:46 UTC
I can confirm that. And: kwallet does not ask for the PW anymore, when a WIFI connection should be automatically established upon startup.
I would add KDE maintainers here...
Comment 2 Wolfgang Bauer 2018-02-09 09:43:32 UTC
(In reply to Robby Engelmann from comment #1)
> I can confirm that. And: kwallet does not ask for the PW anymore, when a
> WIFI connection should be automatically established upon startup.
> I would add KDE maintainers here...

Well, it's probably to be expected that kwallet doesn't ask for a password either (because it's likely not even accessed for some reason).

Does it help if you save the WiFI key system-wide?
(Wireless Security tab in the connection settings)
Comment 3 Robby Engelmann 2018-02-09 09:54:26 UTC
No, that did not help here.
Comment 4 Wolfgang Bauer 2018-02-09 10:02:59 UTC
(In reply to Robby Engelmann from comment #3)
> No, that did not help here.

Well, then it's obviously not related to kwallet...

I suppose it's not a general problem in Plasma 5.12 either, as it works fine here on Leap 42.3 (with the key stored system-wide).

And I think in that case plasma-nm is not even involved in getting the password.
So I'd more suspect a problem in NetworkManager itself.
Could somebody maybe try with GNOME?
Comment 5 Wolfgang Bauer 2018-02-09 10:12:00 UTC
(In reply to Wolfgang Bauer from comment #4)
> I suppose it's not a general problem in Plasma 5.12 either, as it works fine
> here on Leap 42.3 (with the key stored system-wide).

But then, I have it set up as system connection ("Allow all users to connect"), so it connects during boot already, before I even login.

IIRC, it did work fine (as user connection with the key stored in kwallet) with a Krypton LiveCD last weekend too though, but I'm not completely sure at the moment.
Comment 6 Frank Krüger 2018-02-09 18:32:06 UTC
I do not think that this is related to KDE. As a matter of fact, going back to NetworkManager 1.8.6 the above-mentioned issue is gone.
Comment 7 Wolfgang Bauer 2018-02-16 12:25:28 UTC
Does it maybe work again with NetworkManager 1.10.4 from the latest snapshot?

I see this in the changelog that may be relevant here:
> + Fix libnm secret agent asynchronous initialization.
Comment 8 Robby Engelmann 2018-02-16 13:06:24 UTC
I had the hope, but unfortunately not.
Comment 9 Frank Krüger 2018-02-16 18:33:04 UTC
(In reply to Robby Engelmann from comment #8)
> I had the hope, but unfortunately not.

I can confirm that the issue remains with NM 1.10.4.
Comment 10 Frank Krüger 2018-02-16 23:31:43 UTC
Using journalctl, I get the warning "NetworkManager device (...): No agents were available for this request." Any idea?
Comment 11 Frank Krüger 2018-02-17 08:57:15 UTC
(In reply to Robby Engelmann from comment #8)
> I had the hope, but unfortunately not.

Can you confirm that the issue appears only after first login to the KDE desktop? After suspend/hibernate it works as expected.
Comment 12 Mykola Krachkovsky 2018-02-17 10:27:09 UTC
(In reply to Frank Kruger from comment #11)
> (In reply to Robby Engelmann from comment #8)
> > I had the hope, but unfortunately not.
> 
> Can you confirm that the issue appears only after first login to the KDE
> desktop? After suspend/hibernate it works as expected.

Confirm. After suspend auto connecting works fine.
Comment 13 Fabian Vogt 2018-02-17 17:33:52 UTC
I can reproduce this issue.

From what I can tell it's a race condition on login. When NM notices that there is a new session (through pam_systemd and logind), it tries to activate all connections immediately.

At this point the user is not even logged in (sddm just finished the PAM stuff) and nothing is up yet.

NM keeps trying multiple times, but all of those happen practically without delay, so the last attempt is made even before the X session/wayland compositor is running, so NM is obviously unable to connect to anything.

In this case it needs to wait for the agent provided by the networkmanagement kded module which is started in parallel to plasmashell.

IMO this is a NM issue, it needs to actually give the agent a chance to start up.
Comment 14 Robby Engelmann 2018-02-17 18:44:20 UTC
Same here, only after startup no automatic connection, after suspend-to-RAM all is fine, when the notebook comes up.
Comment 15 Frank Krüger 2018-02-17 19:48:40 UTC
(In reply to Fabian Vogt from comment #13)
> I can reproduce this issue.
> 
> From what I can tell it's a race condition on login. When NM notices that
> there is a new session (through pam_systemd and logind), it tries to
> activate all connections immediately.
> 
> At this point the user is not even logged in (sddm just finished the PAM
> stuff) and nothing is up yet.
> 
> NM keeps trying multiple times, but all of those happen practically without
> delay, so the last attempt is made even before the X session/wayland
> compositor is running, so NM is obviously unable to connect to anything.
> 
> In this case it needs to wait for the agent provided by the
> networkmanagement kded module which is started in parallel to plasmashell.
> 
> IMO this is a NM issue, it needs to actually give the agent a chance to
> start up.

Seems to be a race condition. In fact, using 'systemctl restart NetworkManager' after login and it connects automatically, as expected.
Comment 16 Fabian Vogt 2018-02-26 08:30:58 UTC
NM 1.10.4 supposedly contains a fix:

+ Fix libnm secret agent asynchronous initialization.

Does this issue still happen?
Comment 17 Robby Engelmann 2018-02-26 08:36:42 UTC
yes, it still occurs in latest TW (snapshot 20180224).
Comment 18 Frank Krüger 2018-02-26 12:33:28 UTC
(In reply to Fabian Vogt from comment #16)
> NM 1.10.4 supposedly contains a fix:
> 
> + Fix libnm secret agent asynchronous initialization.
> 
> Does this issue still happen?

Yes, cf. https://bugzilla.suse.com/show_bug.cgi?id=1079672#c9
Comment 19 Frank Krüger 2018-02-26 18:57:17 UTC
It seems that also others are experiencing the issue:

https://bugs.archlinux.org/task/56746?project=1&string=networkmanager&order=dateopened&sort=desc
Comment 20 Fabian Vogt 2018-03-01 12:29:07 UTC
Ping.

As this is clearly a NM regression, I suggest that the maintainer makes a test package with some related upstream commits reverted to find the offending one.
Comment 21 Frederic Crozat 2018-03-01 12:47:16 UTC
should be fixed with https://build.opensuse.org/request/show/580400
Comment 22 Fabian Vogt 2018-03-01 12:51:37 UTC
(In reply to Frederic Crozat from comment #21)
> should be fixed with https://build.opensuse.org/request/show/580400

That patch is for a different bug - that the password is asked for twice after saving a connection.

I can't say for sure that it doesn't fix this as well though.
Comment 23 Frank Krüger 2018-03-01 13:32:10 UTC
(In reply to Fabian Vogt from comment #22)
> (In reply to Frederic Crozat from comment #21)
> > should be fixed with https://build.opensuse.org/request/show/580400
> 
> That patch is for a different bug - that the password is asked for twice
> after saving a connection.
> 
> I can't say for sure that it doesn't fix this as well though.

I can confirm that this patch does not solve the issue.
Comment 24 Dominique Leuenberger 2018-03-01 14:13:59 UTC
(In reply to Frank Kruger from comment #23)
> 
> I can confirm that this patch does not solve the issue.

Pity, but thanks for testing.

Can we please get a log file of NetworkManaer with log level=TRACE ?

To enable, adjust /etc/NetworkManager/NetworkManager.conf and add:

>[logging]
>level=TRACE


Thanks
Comment 25 Fabian Vogt 2018-03-02 21:21:04 UTC
Created attachment 762554 [details]
Full journal of a test session with trace logging

(In reply to Dominique Leuenberger from comment #24)
> (In reply to Frank Kruger from comment #23)
> > 
> > I can confirm that this patch does not solve the issue.
> 
> Pity, but thanks for testing.

It appears to me like the failure mode changed - it no longer complains about not reaching the agent anymore.
I assume that's caused by https://github.com/NetworkManager/NetworkManager/commit/78ef571972aa3bf81b287d767ae02471e2924027

> Can we please get a log file of NetworkManaer with log level=TRACE ?

Full journal of playing around in a VM attached - except for the first connection (no secret required yet) no autoconnect worked.
Note that somewhere in the middle I installed NM 1.10.5-dev, but it made no difference.
I also don't see any difference for system wide or per user connections.

The important parts (system wide connection):

- On NM start:
Mär 02 21:24:51 localhost.localdomain NetworkManager[3392]: <debug> [1520022291.7605] settings-connection[0x55f639447360,23b03485-8ce9-4ef5-8860-bff9edf54ac3]: (802-1x:0x7f9f68005de0) secrets request error: No agents were available for this request.
Mär 02 21:24:51 localhost.localdomain NetworkManager[3392]: <warn>  [1520022291.7605] device (ens3): No agents were available for this request.

- After login:
Mär 02 21:25:18 localhost.localdomain plasmashell[3534]: org.kde.plasmaquick: New Applet  "Netzwerke" with a weight of 62
Mär 02 21:25:18 localhost.localdomain NetworkManager[3392]: <debug> [1520022318.8872] agent-manager: req[0x55f639547090, :1.146/org.kde.plasma.networkmanagement/1000]: requesting permissions
Mär 02 21:25:18 localhost.localdomain NetworkManager[3392]: <debug> [1520022318.8872] auth: call[17]: CheckAuthorization(org.freedesktop.NetworkManager.wifi.share.protected), subject=unix-process[pid=3495, uid=1000, start=155638]
Mär 02 21:25:18 localhost.localdomain NetworkManager[3392]: <debug> [1520022318.8873] auth: call[18]: CheckAuthorization(org.freedesktop.NetworkManager.wifi.share.open), subject=unix-process[pid=3495, uid=1000, start=155638]
Mär 02 21:25:18 localhost.localdomain NetworkManager[3392]: <debug> [1520022318.8919] auth: call[17]: CheckAuthorization succeeded: (is_authorized=0, is_challenge=1)
[...]
Mär 02 21:25:18 localhost.localdomain NetworkManager[3392]: <debug> [1520022318.8955] auth: call[18]: CheckAuthorization succeeded: (is_authorized=0, is_challenge=1)
Mär 02 21:25:18 localhost.localdomain NetworkManager[3392]: <debug> [1520022318.8956] agent-manager: req[0x55f639547090, :1.146/org.kde.plasma.networkmanagement/1000]: agent registered
Mär 02 21:25:18 localhost.localdomain NetworkManager[3392]: <debug> [1520022318.8957] policy: re-enabling autoconnect for all connections (only clear no-secrets flag)

Then nothing happens. I'd expect NM to enable the ens3 connection after that.
Comment 26 Frank Krüger 2018-03-02 22:12:40 UTC
Created attachment 762565 [details]
NM 1.10.4 Log

(In reply to Dominique Leuenberger from comment #24)
> (In reply to Frank Kruger from comment #23)
> > 
> > I can confirm that this patch does not solve the issue.
> 
> Pity, but thanks for testing.
> 
> Can we please get a log file of NetworkManaer with log level=TRACE ?
> 
> To enable, adjust /etc/NetworkManager/NetworkManager.conf and add:
> 
> >[logging]
> >level=TRACE

Please find enclosed the log file. By the way, NetworkManager from http://download.opensuse.org/repositories/home:/dimstar:/branches:/GNOME:/Factory/openSUSE_Factory/ does not change anything related to this bug.
Comment 27 Mykola Krachkovsky 2018-03-03 07:43:22 UTC
Created attachment 762583 [details]
NM fail at login log

Another log (`journalctl -b 0 -u NetworkManager`).
Current openSUSE Tumbleweed snapshot, updated before reboot.
Comment 28 Mykola Krachkovsky 2018-03-03 07:54:08 UTC
Created attachment 762584 [details]
startup log from sddm login to nm fail

Here is part of full journal from SDDM starting kde to final fail of NM, if some other details needed.
Comment 29 Fabian Vogt 2018-03-03 12:15:36 UTC
Created attachment 762586 [details]
[PATCH] Fix setting the autoconnect block reason if no agents registered

I debugged it a bit and I think I found the issue.
NM didn't set the right flag anymore when a connection fails because of no registered agents.
Patch attached, test package available on https://build.opensuse.org/package/show/home:Vogtinator:branches:GNOME:Factory/NetworkManager
Comment 30 Frank Krüger 2018-03-03 12:40:14 UTC
(In reply to Fabian Vogt from comment #29)
> Created attachment 762586 [details]
> [PATCH] Fix setting the autoconnect block reason if no agents registered
> 
> I debugged it a bit and I think I found the issue.
> NM didn't set the right flag anymore when a connection fails because of no
> registered agents.
> Patch attached, test package available on
> https://build.opensuse.org/package/show/home:Vogtinator:branches:GNOME:
> Factory/NetworkManager

The patch solves the issue for me, NM works as expected. Thanks!
Comment 31 Frank Krüger 2018-03-03 13:01:23 UTC
(In reply to Frank Kruger from comment #30)
> (In reply to Fabian Vogt from comment #29)
> > Created attachment 762586 [details]
> > [PATCH] Fix setting the autoconnect block reason if no agents registered
> > 
> > I debugged it a bit and I think I found the issue.
> > NM didn't set the right flag anymore when a connection fails because of no
> > registered agents.
> > Patch attached, test package available on
> > https://build.opensuse.org/package/show/home:Vogtinator:branches:GNOME:
> > Factory/NetworkManager
> 
> The patch solves the issue for me, NM works as expected. Thanks!

I was too optimistic/fast. In fact, the issue is solved after a reboot, but is still there after logout/login.
Comment 32 Fabian Vogt 2018-03-03 13:08:09 UTC
(In reply to Frank Kruger from comment #31)
> (In reply to Frank Kruger from comment #30)
> > (In reply to Fabian Vogt from comment #29)
> > > Created attachment 762586 [details]
> > > [PATCH] Fix setting the autoconnect block reason if no agents registered
> > > 
> > > I debugged it a bit and I think I found the issue.
> > > NM didn't set the right flag anymore when a connection fails because of no
> > > registered agents.
> > > Patch attached, test package available on
> > > https://build.opensuse.org/package/show/home:Vogtinator:branches:GNOME:
> > > Factory/NetworkManager
> > 
> > The patch solves the issue for me, NM works as expected. Thanks!
> 
> I was too optimistic/fast. In fact, the issue is solved after a reboot, but
> is still there after logout/login.

Hm. It's possible that the upstream commit introducing the bug has yet another bug that it doesn't consider the removal of agents correctly.
I'll try to look at that, can you upload a new set of logs?
Comment 33 Fabian Vogt 2018-03-03 13:37:47 UTC
Created attachment 762589 [details]
Fix logic error for race condition detection

(The commit I'm talking about is https://github.com/NetworkManager/NetworkManager/commit/e2c8ef45ac9fba8d4f5722ab10831bf42085a110.patch btw)

I think there is a logic error in the detection of the race condition. The attached patch should fix that and as it gets rid of the magic constant the other patch isn't necessary anymore (but still correct IMO, so not superseded).

Test package available at the same location (version 1.10.4-335)
Comment 34 Frank Krüger 2018-03-03 14:04:31 UTC
Created attachment 762590 [details]
NM 1.10.4-335 Log

(In reply to Fabian Vogt from comment #33)
> Created attachment 762589 [details]
> Fix logic error for race condition detection
> 
> (The commit I'm talking about is
> https://github.com/NetworkManager/NetworkManager/commit/
> e2c8ef45ac9fba8d4f5722ab10831bf42085a110.patch btw)
> 
> I think there is a logic error in the detection of the race condition. The
> attached patch should fix that and as it gets rid of the magic constant the
> other patch isn't necessary anymore (but still correct IMO, so not
> superseded).
> 
> Test package available at the same location (version 1.10.4-335)

Please find enclosed the log file for NM 1.10.4-335. After logout/login I first get the error message "no password provided/wlan deactivated", but then kwallet opens, asks for the password and the connection is established. So it almost works as expected.
Comment 35 Fabian Vogt 2018-03-03 14:42:22 UTC
(In reply to Frank Kruger from comment #34)
> Created attachment 762590 [details]
> NM 1.10.4-335 Log
> 
> (In reply to Fabian Vogt from comment #33)
> > Created attachment 762589 [details]
> > Fix logic error for race condition detection
> > Test package available at the same location (version 1.10.4-335)
> 
> Please find enclosed the log file for NM 1.10.4-335. After logout/login I
> first get the error message "no password provided/wlan deactivated", but
> then kwallet opens, asks for the password and the connection is established.
> So it almost works as expected.

That appears to be a different issue and should be filed separately:
NM sets the connection status to failed when it tries to enable the connection before the agent is registered. At that point the applet got started and shows the message.

So I consider the patch to be working as expected.
Comment 36 Fabian Vogt 2018-03-03 18:55:20 UTC
*** Bug 1081172 has been marked as a duplicate of this bug. ***
Comment 37 Swamp Workflow Management 2018-03-06 18:10:06 UTC
This is an autogenerated message for OBS integration:
This bug (1079672) was mentioned in
https://build.opensuse.org/request/show/583664 Factory / NetworkManager
Comment 39 Frank Krüger 2018-03-09 21:34:23 UTC
Fixed for me with update to TW20180308. Thx.
Comment 40 Arjen de Korte 2018-03-11 18:37:10 UTC
Sort of fixed for me too. Upon login, it will first show the connection could not be established, followed after a few seconds by a message that the connection was established. Previously, it would only show the last message. I don't think this really fixed things.
Comment 41 Frank Krüger 2018-03-11 20:05:19 UTC
(In reply to Arjen de Korte from comment #40)
> Sort of fixed for me too. Upon login, it will first show the connection
> could not be established, followed after a few seconds by a message that the
> connection was established. Previously, it would only show the last message.
> I don't think this really fixed things.

I made the same observation while testing the patch (see my comment above: https://bugzilla.suse.com/show_bug.cgi?id=1079672#c34), but after a reboot the issue never showed up again. I always see only the message "connection established". Please feel free to open a new bug report (cf. https://bugzilla.suse.com/show_bug.cgi?id=1079672#c35).
Comment 42 Mykola Krachkovsky 2018-03-12 13:19:00 UTC
Hmm. It looks like it depends on WiFi network. It was fine with WiFi and I thought it's ok, but today I've checked another WiFi (at work) and it connected from second attempt. I'll try to check more.
Comment 43 Frank Krüger 2018-03-12 18:41:59 UTC
(In reply to Mykola Krachkovsky from comment #42)
> Hmm. It looks like it depends on WiFi network. It was fine with WiFi and I
> thought it's ok, but today I've checked another WiFi (at work) and it
> connected from second attempt. I'll try to check more.

After today's update to TW20180311 I also experience the above issue (again). I opened a new bug report: https://bugzilla.opensuse.org/show_bug.cgi?id=1084943.