Intel WiFi 8620 on Lenovo X260 - DHCP-Client timeout on poweroff

Hi,

I have a Lenovo X260 running NixOS (22.11.20220616.3d7435c (Raccoon)) using Kernel Linux rie 5.15.46 #1-NixOS SMP Thu Jun 9 08:23:32 UTC 2022 x86_64 GNU/Linux. Very often when I shutdown the laptop via the poweroff command, it is hanging for about 1:30 until the DHCP Client is timing out (or systemd is giving up). I’m primarily using the WiFi interface (Intel AC 8260) on this machine. I’m using the declarative network configuration as seen on ~bwolf/dotfiles (master): hosts/rie/configuration.nix - sourcehut git.

dmesg output on boot:

[    3.574157] Intel(R) Wireless WiFi driver for Linux
[    3.574737] iwlwifi 0000:04:00.0: enabling device (0000 -> 0002)
[    3.581120] thinkpad_acpi: battery 2 registered (start 0, stop 100)
[    3.581910] e1000e: Intel(R) PRO/1000 Network Driver
[    3.581912] e1000e: Copyright(c) 1999 - 2015 Intel Corporation

Mostly I pair the WiFi with my cell phone (on train) but the behaviour also happens when pairing the WiFi adapter to an access point. Sometimes it even refuses to pair with a known AP (rebooting fixes that).

dhcp-client sample logs:

Jun 23 08:09:56 rie systemd[1]: Started DHCP Client.
Jun 23 08:10:02 rie dhcpcd[634]: wlp4s0: no IPv6 Routers available
Jun 23 08:13:11 rie dhcpcd[634]: wlp4s0: carrier lost
Jun 23 08:13:11 rie systemd[1]: Stopping DHCP Client...
Jun 23 08:13:11 rie dhcpcd[634]: wlp4s0: deleting address fe80::f2d5:bfff:fe0f:d2ff
Jun 23 08:13:11 rie dhcpcd[634]: wlp4s0: deleting route to 172.16.20.0/24
Jun 23 08:13:11 rie dhcpcd[634]: wlp4s0: deleting default route via 172.16.20.1
Jun 23 08:14:41 rie systemd[1]: dhcpcd.service: State 'stop-sigterm' timed out. Killing.
Jun 23 08:14:41 rie systemd[1]: dhcpcd.service: Killing process 633 (dhcpcd) with signal SIGKILL.
Jun 23 08:14:41 rie systemd[1]: dhcpcd.service: Killing process 634 (dhcpcd) with signal SIGKILL.
Jun 23 08:14:41 rie systemd[1]: dhcpcd.service: Killing process 635 (dhcpcd) with signal SIGKILL.
Jun 23 08:14:41 rie systemd[1]: dhcpcd.service: Killing process 636 (dhcpcd) with signal SIGKILL.
Jun 23 08:14:41 rie systemd[1]: dhcpcd.service: Main process exited, code=killed, status=9/KILL
Jun 23 08:14:41 rie systemd[1]: dhcpcd.service: Failed with result 'timeout'.
Jun 23 08:14:41 rie systemd[1]: Stopped DHCP Client.
Jun 23 08:14:41 rie systemd[1]: dhcpcd.service: Consumed 378ms CPU time, received 36.3K IP traf
fic, sent 224B IP traffic.

I really wonder what I can do about this. I have this behavior for a long time and was ignoring it. I hope this is fixable because this laptop is (besides being slow) a nice simple machine which works for me (so far).

I was looking at some way to upgrade the firmware but I’m unsure how to proceed with this (anything regarding this will be helpful). I’m hoping that someone else has seen a similar behavior with a workaround. Especially this is getting on my nerves when you want to quickly shutdown the machine (e.g. get out of the train).

Thanks

I’ve noticed occasional delays during shutdowns as well. I didn’t think it was due to dhcp, but I have logs similar to yours:

Jun 21 17:21:37 nixos-laptop dhcpcd[1935]: protonvpn: carrier lost
Jun 21 17:21:37 nixos-laptop dhcpcd[1935]: protonvpn: removing interface
Jun 21 17:21:37 nixos-laptop dhcpcd[1935]: wlo1: carrier lost
Jun 21 17:21:37 nixos-laptop dhcpcd[1935]: wlo1: deleting address 2603:9000:ad0c:278:36cf:f6ff:fef9:e101/64
Jun 21 17:21:37 nixos-laptop dhcpcd[1935]: wlo1: deleting route to 2603:9000:ad0c:278::/64
Jun 21 17:21:37 nixos-laptop dhcpcd[1935]: wlo1: deleting default route via fe80::86a0:6eff:fe9d:bc8a
Jun 21 17:21:37 nixos-laptop dhcpcd[1935]: wlo1: deleting address fe80::36cf:f6ff:fef9:e101
Jun 21 17:21:37 nixos-laptop dhcpcd[1935]: wlo1: deleting route to 192.168.1.0/24
Jun 21 17:21:37 nixos-laptop dhcpcd[1935]: wlo1: deleting default route via 192.168.1.1
Jun 21 17:21:37 nixos-laptop systemd[1]: Stopping DHCP Client...
Jun 21 17:23:07 nixos-laptop systemd[1]: dhcpcd.service: State 'stop-sigterm' timed out. Killing.
Jun 21 17:23:07 nixos-laptop systemd[1]: dhcpcd.service: Killing process 1934 (dhcpcd) with signal SIGKILL.
Jun 21 17:23:07 nixos-laptop systemd[1]: dhcpcd.service: Killing process 1935 (dhcpcd) with signal SIGKILL.
Jun 21 17:23:07 nixos-laptop systemd[1]: dhcpcd.service: Killing process 1936 (dhcpcd) with signal SIGKILL.
Jun 21 17:23:07 nixos-laptop systemd[1]: dhcpcd.service: Killing process 1938 (dhcpcd) with signal SIGKILL.
Jun 21 17:23:07 nixos-laptop systemd[1]: dhcpcd.service: Main process exited, code=killed, status=9/KILL
Jun 21 17:23:07 nixos-laptop systemd[1]: dhcpcd.service: Failed with result 'timeout'.
Jun 21 17:23:07 nixos-laptop systemd[1]: Stopped DHCP Client.

The delay is confirmed by the time difference between these two consecutive lines:

Jun 21 17:21:37 nixos-laptop systemd[1]: Stopping DHCP Client...
Jun 21 17:23:07 nixos-laptop systemd[1]: dhcpcd.service: State 'stop-sigterm' timed out. Killing.

This is in contrast to a shutdown without delays:

Jun 18 20:12:12 nixos-laptop dhcpcd[1937]: wlo1: carrier lost
Jun 18 20:12:12 nixos-laptop dhcpcd[1937]: wlo1: deleting address 2603:9000:ad0c:278:36cf:f6ff:fef9:e101/64
Jun 18 20:12:12 nixos-laptop dhcpcd[1937]: wlo1: deleting route to 2603:9000:ad0c:278::/64
Jun 18 20:12:12 nixos-laptop dhcpcd[1937]: wlo1: deleting default route via fe80::86a0:6eff:fe9d:bc8a
Jun 18 20:12:12 nixos-laptop dhcpcd[1937]: wlo1: deleting address fe80::36cf:f6ff:fef9:e101
Jun 18 20:12:13 nixos-laptop dhcpcd[1937]: wlo1: deleting route to 192.168.1.0/24
Jun 18 20:12:13 nixos-laptop dhcpcd[1937]: wlo1: deleting default route via 192.168.1.1
Jun 18 20:12:13 nixos-laptop dhcpcd[1937]: protonvpn: carrier lost
Jun 18 20:12:13 nixos-laptop dhcpcd[1937]: protonvpn: removing interface
Jun 18 20:12:13 nixos-laptop dhcpcd[1937]: received SIGTERM, stopping
Jun 18 20:12:13 nixos-laptop dhcpcd[1937]: wlo1: removing interface
Jun 18 20:12:13 nixos-laptop systemd[1]: Stopping DHCP Client...
Jun 18 20:12:13 nixos-laptop dhcpcd[1937]: eno1: removing interface
Jun 18 20:12:13 nixos-laptop systemd[1]: dhcpcd.service: Deactivated successfully.
Jun 18 20:12:13 nixos-laptop systemd[1]: Stopped DHCP Client.

The logs show a difference in the order in which the interfaces are removed by dhcpd, and when there’s a delay the eno1 interface (which I’m not using) is not shown as being removed.

This is interesting. I’ll have to dig into it myself.

1 Like

Thank you. It seems I’ll have to find out the reason by myself. Hopefully it is not hardware related.