Arch Linux

jondaeh

Member

Registered: 2013-08-20

Posts: 5

[Solved] Wifi at startup fails after upgrading to wpa_supplicant 2.8

Hi everyone,

Did system update a few days ago, and realized that wifi did no longer connect at startup. Downgraded wpa_supplicant to version 2.6, and it worked again.

I have used

systemctl enable wpa_supplicant@wp3s0
systemctl enable dhcpcd@wlp3s0

to get connected automatically at boot. Reverted to wpa_supplicant version 2.6, ant compared the output of

journalctl -b | grep -E "dhcpcd|wpa_supplicant"

Result with version 2.6 :

mai 14 19:50:49 Jon-Arch systemd[1]: Created slice system-dhcpcd.slice.
mai 14 19:50:49 Jon-Arch systemd[1]: Created slice system-wpa_supplicant.slice.
mai 14 19:50:50 Jon-Arch audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=wpa_supplicant@wlp3s0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
mai 14 19:50:50 Jon-Arch systemd[1]: Starting dhcpcd on wlp3s0...
mai 14 19:50:50 Jon-Arch wpa_supplicant[450]: Successfully initialized wpa_supplicant
mai 14 19:50:50 Jon-Arch dhcpcd[451]: wlp3s0: waiting for carrier
mai 14 19:50:50 Jon-Arch dhcpcd[451]: wlp3s0: carrier acquired
mai 14 19:50:50 Jon-Arch dhcpcd[451]: DUID 00:01:00:01:22:27:4b:50:84:3a:4b:6a:f6:40
mai 14 19:50:50 Jon-Arch dhcpcd[451]: wlp3s0: IAID 4b:6a:f6:40
mai 14 19:50:50 Jon-Arch dhcpcd[451]: wlp3s0: adding address fe80::1b89:3d79:d7ce:ea07
mai 14 19:50:50 Jon-Arch dhcpcd[451]: wlp3s0: carrier lost
mai 14 19:50:50 Jon-Arch kernel: random: dhcpcd: uninitialized urandom read (112 bytes read)
mai 14 19:50:50 Jon-Arch kernel: random: wpa_supplicant: uninitialized urandom read (32 bytes read)
mai 14 19:50:50 Jon-Arch dhcpcd[451]: wlp3s0: deleting address fe80::1b89:3d79:d7ce:ea07
mai 14 19:50:53 Jon-Arch wpa_supplicant[450]: wlp3s0: SME: Trying to authenticate with 10:7b:ef:7d:4e:fc (SSID='Telenor7203sko' freq=2417 MHz)
mai 14 19:50:53 Jon-Arch wpa_supplicant[450]: wlp3s0: Trying to associate with 10:7b:ef:7d:4e:fc (SSID='Telenor7203sko' freq=2417 MHz)
mai 14 19:50:53 Jon-Arch wpa_supplicant[450]: wlp3s0: Associated with 10:7b:ef:7d:4e:fc
mai 14 19:50:53 Jon-Arch wpa_supplicant[450]: wlp3s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
mai 14 19:50:53 Jon-Arch kernel: random: wpa_supplicant: uninitialized urandom read (4096 bytes read)
mai 14 19:50:53 Jon-Arch wpa_supplicant[450]: wlp3s0: WPA: Key negotiation completed with 10:7b:ef:7d:4e:fc [PTK=CCMP GTK=CCMP]
mai 14 19:50:53 Jon-Arch wpa_supplicant[450]: wlp3s0: CTRL-EVENT-CONNECTED - Connection to 10:7b:ef:7d:4e:fc completed [id=0 id_str=]
mai 14 19:50:53 Jon-Arch dhcpcd[451]: wlp3s0: carrier acquired
mai 14 19:50:53 Jon-Arch dhcpcd[451]: wlp3s0: IAID 4b:6a:f6:40
mai 14 19:50:53 Jon-Arch dhcpcd[451]: wlp3s0: adding address fe80::6d95:5751:ceef:6545
mai 14 19:50:54 Jon-Arch dhcpcd[451]: wlp3s0: rebinding lease of 10.0.0.96
mai 14 19:50:54 Jon-Arch dhcpcd[451]: wlp3s0: soliciting an IPv6 router
mai 14 19:50:55 Jon-Arch dhcpcd[451]: wlp3s0: leased 10.0.0.96 for 86400 seconds
mai 14 19:50:55 Jon-Arch dhcpcd[451]: wlp3s0: adding route to 10.0.0.0/24
mai 14 19:50:55 Jon-Arch dhcpcd[451]: wlp3s0: adding default route via 10.0.0.138
mai 14 19:50:55 Jon-Arch dhcpcd[451]: forked to background, child pid 542
mai 14 19:50:55 Jon-Arch systemd[1]: Started dhcpcd on wlp3s0.
mai 14 19:50:55 Jon-Arch audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd@wlp3s0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
mai 14 19:50:55 Jon-Arch kernel: audit: type=1130 audit(1557856255.245:19): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd@wlp3s0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
mai 14 19:50:55 Jon-Arch dhcpcd[542]: wlp3s0: Router Advertisement from fe80::127b:efff:fe7d:4efb
mai 14 19:50:55 Jon-Arch dhcpcd[542]: wlp3s0: adding address 2001:4662:f8e:0:2ed4:560:78c7:2ef7/64
mai 14 19:50:55 Jon-Arch dhcpcd[542]: wlp3s0: adding route to 2001:4662:f8e::/64
mai 14 19:50:55 Jon-Arch dhcpcd[542]: wlp3s0: adding default route via fe80::127b:efff:fe7d:4efb
mai 14 19:50:55 Jon-Arch dhcpcd[542]: wlp3s0: soliciting a DHCPv6 lease
mai 14 19:50:55 Jon-Arch dhcpcd[542]: wlp3s0: DHCPv6 REPLY: No Addresses Available
mai 14 19:50:58 Jon-Arch dbus-daemon[442]: [system] Activating via systemd: service name='fi.w1.wpa_supplicant1' unit='wpa_supplicant.service' requested by ':1.48' (uid=993 pid=685 comm="/usr/lib/geoclue ")
mai 14 19:50:58 Jon-Arch dbus-daemon[442]: [system] Successfully activated service 'fi.w1.wpa_supplicant1'
mai 14 19:50:58 Jon-Arch audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=wpa_supplicant comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
mai 14 19:50:58 Jon-Arch wpa_supplicant[697]: Successfully initialized wpa_supplicant

/code]
Result with version 2.8 :

mai 14 19:43:02 Jon-Arch systemd[1]: Created slice system-dhcpcd.slice.
mai 14 19:43:03 Jon-Arch systemd[1]: Starting dhcpcd on wlp3s0...
mai 14 19:43:03 Jon-Arch audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=wpa_supplicant@wlp3s0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
mai 14 19:43:03 Jon-Arch wpa_supplicant[452]: Successfully initialized wpa_supplicant
mai 14 19:43:03 Jon-Arch dhcpcd[451]: wlp3s0: waiting for carrier
mai 14 19:43:03 Jon-Arch dhcpcd[451]: wlp3s0: carrier acquired
mai 14 19:43:03 Jon-Arch dhcpcd[451]: DUID 00:01:00:01:22:27:4b:50:84:3a:4b:6a:f6:40
mai 14 19:43:03 Jon-Arch dhcpcd[451]: wlp3s0: IAID 4b:6a:f6:40
mai 14 19:43:03 Jon-Arch dhcpcd[451]: wlp3s0: adding address fe80::1b89:3d79:d7ce:ea07
mai 14 19:43:03 Jon-Arch dhcpcd[451]: wlp3s0: carrier lost
mai 14 19:43:03 Jon-Arch kernel: random: dhcpcd: uninitialized urandom read (112 bytes read)
mai 14 19:43:03 Jon-Arch dhcpcd[451]: wlp3s0: deleting address fe80::1b89:3d79:d7ce:ea07
mai 14 19:43:33 Jon-Arch dhcpcd[451]: timed out
mai 14 19:43:33 Jon-Arch systemd[1]: dhcpcd@wlp3s0.service: Control process exited, code=exited, status=1/FAILURE
mai 14 19:43:33 Jon-Arch dhcpcd[451]: timed out
mai 14 19:43:33 Jon-Arch systemd[1]: dhcpcd@wlp3s0.service: Failed with result 'exit-code'.
mai 14 19:43:33 Jon-Arch dhcpcd[451]: dhcpcd exited
mai 14 19:43:33 Jon-Arch audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd@wlp3s0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
mai 14 19:43:33 Jon-Arch systemd[1]: Failed to start dhcpcd on wlp3s0.
mai 14 19:43:33 Jon-Arch kernel: audit: type=1130 audit(1557855813.956:20): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd@wlp3s0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
mai 14 19:43:37 Jon-Arch dbus-daemon[415]: [system] Activating via systemd: service name='fi.w1.wpa_supplicant1' unit='wpa_supplicant.service' requested by ':1.48' (uid=993 pid=593 comm="/usr/lib/geoclue ")
mai 14 19:43:37 Jon-Arch dbus-daemon[415]: [system] Successfully activated service 'fi.w1.wpa_supplicant1'
mai 14 19:43:37 Jon-Arch wpa_supplicant[604]: Successfully initialized wpa_supplicant
mai 14 19:43:37 Jon-Arch audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=wpa_supplicant comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
mai 14 19:43:38 Jon-Arch wpa_supplicant[452]: wlp3s0: SME: Trying to authenticate with 10:7b:ef:7d:4e:fc (SSID='Telenor7203sko' freq=2417 MHz)
mai 14 19:43:38 Jon-Arch wpa_supplicant[452]: wlp3s0: Trying to associate with 10:7b:ef:7d:4e:fc (SSID='Telenor7203sko' freq=2417 MHz)
mai 14 19:43:38 Jon-Arch wpa_supplicant[452]: wlp3s0: Associated with 10:7b:ef:7d:4e:fc
mai 14 19:43:38 Jon-Arch wpa_supplicant[452]: wlp3s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
mai 14 19:43:38 Jon-Arch wpa_supplicant[452]: wlp3s0: WPA: Key negotiation completed with 10:7b:ef:7d:4e:fc [PTK=CCMP GTK=CCMP]
mai 14 19:43:38 Jon-Arch wpa_supplicant[452]: wlp3s0: CTRL-EVENT-CONNECTED - Connection to 10:7b:ef:7d:4e:fc completed [id=0 id_str=]

An obvious difference is the missing

systemd[1]: Created slice system-wpa_supplicant.slice.

for version 2.8, however I have no idea what that means.

For now it works to use version 2.6, and ignore the update, but it seems like a temporary solution. Anyone having an idea whats causing this?

Best regards,
Jon.

Last edited by jondaeh (2019-05-14 17:54:32)

V1del

Forum Moderator

Registered: 2012-10-16

Posts: 21,657

Re: [Solved] Wifi at startup fails after upgrading to wpa_supplicant 2.8

You are not getting enough entropy during early boot. If your cpu supports it (lscpu | grep rdrand returns something) add

random.trust_cpu=on

to your kernel params, otherwise install and enable haveged.

Last edited by V1del (2019-05-14 17:13:32)

jondaeh

Member

Registered: 2013-08-20

Posts: 5

Re: [Solved] Wifi at startup fails after upgrading to wpa_supplicant 2.8

Adding the kernel parameter solved the issue, boot actually seems to be a bit faster now as well:)

Thanks for quick response!

Jon.