On Thu, 2018-06-28 at 15:52 -0400, Brian J. Murrell wrote:
On Thu, 2018-06-28 at 21:11 +0200, Thomas Haller wrote:Hi,Hi, Thanks again for looking at this...The number following "remove_pending_action" indicates how many remaining pending actions are still there (after removal).I had wondered if that is what that was. Is that total pending actions or pending actions for just that device?
per-device.
So, the repeated lines with (enp2s0): remove_pending_action (0): say that in fact nothing is left pending.Interesting.I would think, that the log message about removing 'activation-0x55d746892f60' was rate-limited by journald. If that is the case, you'd see a message in journal about dropped messages. You can also disable rate-limiting, via the RateLimitIntervalSec and RateLimitBurst settings, see `man journald.conf`.I don't think there was any rate limiting going on: Jun 27 15:00:58 bmurrell-mobl.amr.corp.intel.com systemd- journald[645]: Suppressed 5245 messages from /user.slice/user- 1001.slice Jun 28 09:33:02 bmurrell-mobl.amr.corp.intel.com systemd- journald[645]: Suppressed 928 messages from /user.slice/user- 1001.slice Those are the last and first messages about supression after and before the logs provided in the previous message.Anyway, you post here the content of [1530181596.5848] manager: check_if_startup_complete returns FALSE because of enp2s0 at a time when clearly there were still pending actions: [1530181597.9974] device[0x55d7468810e0] (enp2s0): add_pending_action (2): 'queued-state-change-disconnected'But even now, hours after the boot has completed and there don't appear to be any pending actions, "nm-online -s" is still saying offline.you don't show the log, later, when there are no more pending actions on enp2s0. But if rate-limiting of journal hit, then the interesting line likely is missing too.Per the above, it does not appear that any rate-limiting hit so this shouldn't be the case. I didn't want to bull-doze you earlier with the whole log since it's biggish. The whole log for the NetworkManager.service and NetworkManager-online.service units from boot until about 34 minutes later can be found at http://brian.interlinx.bc.ca/NetworkManager.debug
in this log, there is a message:
systemd-journald[621]: Suppressed 1100 messages from NetworkManager.service
and you see that there are no debug messages for 30 seconds (starting
at 06:26:39).
Anyway, after <debug> is logged again, you see that enp2s0 as no more
pending action. But as startup-complete was still not reached, you
likely missed a line
manager: check_if_startup_complete returns FALSE because of $SOME_OTHER_REASON
also, there is
(pc_bridge): add_pending_action (2): 'carrier-wait' already pending (expected)
which is the last (visible) message telling something about pending-actions on pc_bridge device.
Likely, that one is hanging.
you would also see in the output of
nmcli device
that pc_bridge is in fact not fully activated (but pending activation).
A bridge cannot complete activation, until any slaves are attached. Hence, it is expected that
startup-complete is never successfully reached (because activation is still pending for the bridge).
The fix for that would be to either
- don't mark the bridge-profile to autoconnect at boot
- ensure that you also autoconnect at least one slave profile (so that the bridge
device can complete activation).
- just don't care about `nm-online -s` and NetworkManager-wait-online.service.
Preferably, your services can cope with networking appearing dynamically, and
don't bother for NetworkManager whether activation is still pending at boot.
"nm-online -s" printing "offline" is a misleading. Opened a pull-request
for that: https://github.com/NetworkManager/NetworkManager/pull/152
best,
Thomas
Cheers, b. _______________________________________________ networkmanager-list mailing list networkmanager-list gnome org https://mail.gnome.org/mailman/listinfo/networkmanager-list
Attachment:
signature.asc
Description: This is a digitally signed message part