Re: nm-online -s errors but nnonline doesn't (and networking is up)

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:



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
or pending actions for just that device?


So, the
repeated lines with

  (enp2s0): remove_pending_action (0):

say that in fact nothing is left pending.


I would think, that the log
message about removing 'activation-0x55d746892f60' was rate-limited
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

I don't think there was any rate limiting going on:

Jun 27 15:00:58 systemd-
journald[645]: Suppressed 5245 messages from /user.slice/user-
Jun 28 09:33:02 systemd-
journald[645]: Suppressed 928 messages from /user.slice/user-

Those are the last and first messages about supression after and
the logs provided in the previous message.

Anyway, you post here the content of
  [1530181596.5848] manager: check_if_startup_complete returns
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
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
on enp2s0.
But if rate-limiting of journal hit, then the interesting line
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

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:


networkmanager-list mailing list
networkmanager-list gnome org

Attachment: signature.asc
Description: This is a digitally signed message part

[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]