VLAN connection starts late

[Thomas Haller]

On Mon, 2024-09-23 at 09:20 +0200, Marco Moock wrote:
> Am 20.09.2024 um 11:40:56 Uhr schrieb Marco Moock:
> 
> > How can I further diagnose that?
> 
> I've now done trace logging and see that DHCPv4 fails.
> This can be reproduced at every boot. DHCPv4 normally works fine and
> the problem exists since I use the VLAN trunk.
> This effect doesn't occur on untagged interfaces (on this machine and
> on others).
> 
>  manager: (enp3s0): new Ethernet device
> (/org/freedesktop/NetworkManager/Devices/2)
>  device (enp3s0): state change: unmanaged -> unavailable (reason
> 'managed', managed-type: 'external')
>  manager: (vlan2): new VLAN device
> (/org/freedesktop/NetworkManager/Devices/3)
>  device (vlan2): state change: unmanaged -> unavailable (reason
> 'managed', managed-type: 'external')
>  device (enp3s0): carrier: link connected
>  device (vlan2): carrier: link connected
>  device (enp3s0): state change: unavailable -> disconnected (reason
> 'carrier-changed', managed-type: 'full')
>  device (vlan2): state change: unavailable -> disconnected (reason
> 'carrier-changed', managed-type: 'full')
>  policy: auto-activating connection 'VLAN2' (2626fdcc-2a74-4b64-9e56-
> 2822fcac55cf)
>  device (enp3s0): Activation: starting connection 'Kabelgebundene
> Verbindung 2' (c225ec75-2abd-349b-96eb-59a8a0281196)
>  device (vlan2): Activation: starting connection 'VLAN2' (2626fdcc-
> 2a74-4b64-9e56-2822fcac55cf)
>  device (enp3s0): state change: disconnected -> prepare (reason
> 'none', managed-type: 'full')
>  device (enp3s0): state change: prepare -> config (reason 'none',
> managed-type: 'full')
>  device (vlan2): state change: disconnected -> prepare (reason
> 'none', managed-type: 'full')
>  device (vlan2): state change: prepare -> config (reason 'none',
> managed-type: 'full')
>  device (enp3s0): state change: config -> ip-config (reason 'none',
> managed-type: 'full')
>  device (enp3s0): state change: ip-config -> ip-check (reason 'none',
> managed-type: 'full')
>  device (enp3s0): state change: ip-check -> secondaries (reason
> 'none', managed-type: 'full')
>  device (enp3s0): state change: secondaries -> activated (reason
> 'none', managed-type: 'full')
>  device (enp3s0): Activation: successful, device activated.
>  device (vlan2): state change: config -> ip-config (reason 'none',
> managed-type: 'full')
>  dhcp4 (vlan2): activation: beginning transaction (timeout in 45
> seconds)
>  device (vlan2): state change: ip-config -> failed (reason 'ip-
> config-unavailable', managed-type: 'full')
>  device (vlan2): Activation: failed for connection 'VLAN2'
>  device (vlan2): state change: failed -> disconnected (reason 'none',
> managed-type: 'full')
>  dhcp4 (vlan2): canceled DHCP transaction
>  dhcp4 (vlan2): state changed no lease
>  device (vlan2): state change: disconnected -> unmanaged (reason
> 'user-requested', managed-type: 'full')
>  policy: auto-activating connection 'VLAN2' (2626fdcc-2a74-4b64-9e56-
> 2822fcac55cf)
>  device (vlan2): state change: unmanaged -> unavailable (reason
> 'managed', managed-type: 'external')
>  device (vlan2): state change: unavailable -> disconnected (reason
> 'user-requested', managed-type: 'full')
>  device (vlan2): Activation: starting connection 'VLAN2' (2626fdcc-
> 2a74-4b64-9e56-2822fcac55cf)
>  device (vlan2): carrier: link connected
>  device (vlan2): state change: disconnected -> prepare (reason
> 'none', managed-type: 'full')
>  device (vlan2): state change: prepare -> config (reason 'none',
> managed-type: 'full')
>  device (vlan2): state change: config -> ip-config (reason 'none',
> managed-type: 'full')
>  dhcp4 (vlan2): activation: beginning transaction (timeout in 45
> seconds)
>  dhcp4 (vlan2): state changed new lease, address=172.17.1.1, acd
> pending
>  dhcp4 (vlan2): state changed new lease, address=172.17.1.1
>  policy: set 'VLAN2' (vlan2) as default for IPv4 routing and DNS
>  policy: set 'VLAN2' (vlan2) as default for IPv6 routing and DNS
>  device (vlan2): state change: ip-config -> ip-check (reason 'none',
> managed-type: 'full')
>  device (vlan2): state change: ip-check -> secondaries (reason
> 'none', managed-type: 'full')
>  device (vlan2): state change: secondaries -> activated (reason
> 'none', managed-type: 'full')
>  device (vlan2): Activation: successful, device activated.
> 
> 
> Is there a way to enable more logging for the dhcp client of NM?


Hi,

see "DEBUGGING" in `man NetworkManager`.

In short, create a file /etc/NetworkManaer/conf.d/99-mine.conf with

  [logging]
  level=TRACE
  domains=ALL

and `systemctl restart NetworkManager`.

Finally, grep the log file for "dhcp" or "DHCP".


Thomas