Hi there
I'm having this issue with a new install on a RPi 4.
The image I'm using is the latest (dated 05-Feb-2021 23:46) which has an md5sum
12921ff5a58b547521f1121ece1e87ee
The error seems to be (and i think there is one cause afaik i'm not messing things up this time) however not in this image, but in a package that gets updated when I issue 'pacman -Syu' which i believe is recommended before installing further packages.
So I actually update the system (pacman -Syu) in a fresh install through the wifi network, and it keeps working until I reboot.
Then I can see no message in the output of journalctl regarding wlan0.
Also there's no wlan0 in /sys/class/net which showed to be there before the reboot.
$this->bbcode_second_pass_code('', '
[alarm@alarmpi ~]$ ls /sys/class/net/
eth0 lo
[alarm@alarmpi ~]$
')
the 'ip addr' command also doesn't list the wlan0 device, which it did before the reboot.
I'll just paste the pacman.log file here:
$this->bbcode_second_pass_code('', '
[2021-02-17T12:34:30+0000] [PACMAN] Running 'pacman -Syu'
[2021-02-17T12:34:30+0000] [PACMAN] synchronizing package lists
[2021-02-17T12:34:58+0000] [PACMAN] starting full system upgrade
[2021-02-17T12:40:05+0000] [ALPM] transaction started
[2021-02-17T12:40:05+0000] [ALPM] upgraded linux-api-headers (5.8-1 -> 5.10.13-1)
[2021-02-17T12:40:05+0000] [ALPM] upgraded iana-etc (20201229-1 -> 20210202-1)
[2021-02-17T12:40:05+0000] [ALPM] upgraded util-linux-libs (2.36.1-4 -> 2.36.2-1)
[2021-02-17T12:40:06+0000] [ALPM] upgraded e2fsprogs (1.46.0-1 -> 1.46.1-1)
[2021-02-17T12:40:06+0000] [ALPM] upgraded libcap (2.47-1 -> 2.48-1)
[2021-02-17T12:40:06+0000] [ALPM] upgraded device-mapper (2.02.187-3 -> 2.03.11-4)
[2021-02-17T12:40:06+0000] [ALPM] upgraded cryptsetup (2.3.4-1 -> 2.3.4-2)
[2021-02-17T12:40:06+0000] [ALPM] upgraded findutils (4.7.0-2 -> 4.8.0-1)
[2021-02-17T12:40:07+0000] [ALPM] upgraded glib2 (2.66.6-1 -> 2.66.7-1)
[2021-02-17T12:40:07+0000] [ALPM] upgraded hwids (20200813.1-1 -> 20201207-1)
[2021-02-17T12:40:07+0000] [ALPM] upgraded libassuan (2.5.4-1 -> 2.5.4-2)
[2021-02-17T12:40:42+0000] [ALPM] upgraded linux-firmware (20201218.646f159-1 -> 20210208.b79d239-1)
[2021-02-17T12:40:44+0000] [ALPM] upgraded util-linux (2.36.1-4 -> 2.36.2-1)
[2021-02-17T12:40:52+0000] [ALPM] upgraded linux-raspberrypi4 (5.10.13-3 -> 5.10.16-3)
[2021-02-17T12:40:53+0000] [ALPM] upgraded npth (1.6-2 -> 1.6-3)
[2021-02-17T12:40:53+0000] [ALPM] upgraded pacman (5.2.2-1 -> 5.2.2-2)
[2021-02-17T12:40:53+0000] [ALPM] upgraded psmisc (23.3-4 -> 23.4-1)
[2021-02-17T12:40:54+0000] [ALPM] upgraded raspberrypi-bootloader (20210205-1 -> 20210216-1)
[2021-02-17T12:40:54+0000] [ALPM] upgraded raspberrypi-bootloader-x (20210205-1 -> 20210216-1)
[2021-02-17T12:40:55+0000] [ALPM] upgraded raspberrypi-firmware (20210128-1 -> 20210128-2)
[2021-02-17T12:40:55+0000] [ALPM] upgraded tar (1.33-1 -> 1.34-1)
[2021-02-17T12:40:56+0000] [ALPM] upgraded wpa_supplicant (2:2.9-7 -> 2:2.9-8)
[2021-02-17T12:40:56+0000] [ALPM] transaction completed
[2021-02-17T12:40:56+0000] [ALPM] running '20-systemd-sysusers.hook'...
[2021-02-17T12:40:56+0000] [ALPM] running '30-systemd-daemon-reload.hook'...
[2021-02-17T12:40:57+0000] [ALPM] running '30-systemd-tmpfiles.hook'...
[2021-02-17T12:40:57+0000] [ALPM] running '30-systemd-udev-reload.hook'...
[2021-02-17T12:40:57+0000] [ALPM] running '30-systemd-update.hook'...
[2021-02-17T12:40:57+0000] [ALPM] running '60-depmod.hook'...
[2021-02-17T12:40:57+0000] [ALPM] running '60-linux-raspberrypi4.hook'...
[2021-02-17T12:41:03+0000] [ALPM] running '90-linux-raspberrypi4.hook'...
[2021-02-17T12:41:03+0000] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux-raspberrypi4.preset: 'default'
[2021-02-17T12:41:03+0000] [ALPM-SCRIPTLET] -> -k 5.10.16-3-ARCH -c /etc/mkinitcpio.conf -g /boot/initramfs-linux.img
[2021-02-17T12:41:03+0000] [ALPM-SCRIPTLET] ==> Starting build: 5.10.16-3-ARCH
[2021-02-17T12:41:04+0000] [ALPM-SCRIPTLET] -> Running build hook: [base]
[2021-02-17T12:41:04+0000] [ALPM-SCRIPTLET] -> Running build hook: [udev]
[2021-02-17T12:41:05+0000] [ALPM-SCRIPTLET] -> Running build hook: [autodetect]
[2021-02-17T12:41:05+0000] [ALPM-SCRIPTLET] -> Running build hook: [modconf]
[2021-02-17T12:41:05+0000] [ALPM-SCRIPTLET] -> Running build hook: [block]
[2021-02-17T12:41:06+0000] [ALPM-SCRIPTLET] -> Running build hook: [filesystems]
[2021-02-17T12:41:06+0000] [ALPM-SCRIPTLET] -> Running build hook: [keyboard]
[2021-02-17T12:41:06+0000] [ALPM-SCRIPTLET] -> Running build hook: [fsck]
[2021-02-17T12:41:06+0000] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2021-02-17T12:41:06+0000] [ALPM-SCRIPTLET] ==> Creating gzip-compressed initcpio image: /boot/initramfs-linux.img
[2021-02-17T12:41:09+0000] [ALPM-SCRIPTLET] ==> Image generation successful
[2021-02-17T12:41:09+0000] [ALPM] running '90-mkinitcpio-install.hook'...
[2021-02-17T12:41:09+0000] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux-raspberrypi4.preset: 'default'
[2021-02-17T12:41:09+0000] [ALPM-SCRIPTLET] -> -k 5.10.16-3-ARCH -c /etc/mkinitcpio.conf -g /boot/initramfs-linux.img
[2021-02-17T12:41:10+0000] [ALPM-SCRIPTLET] ==> Starting build: 5.10.16-3-ARCH
[2021-02-17T12:41:10+0000] [ALPM-SCRIPTLET] -> Running build hook: [base]
[2021-02-17T12:41:10+0000] [ALPM-SCRIPTLET] -> Running build hook: [udev]
[2021-02-17T12:41:11+0000] [ALPM-SCRIPTLET] -> Running build hook: [autodetect]
[2021-02-17T12:41:11+0000] [ALPM-SCRIPTLET] -> Running build hook: [modconf]
[2021-02-17T12:41:11+0000] [ALPM-SCRIPTLET] -> Running build hook: [block]
[2021-02-17T12:41:12+0000] [ALPM-SCRIPTLET] -> Running build hook: [filesystems]
[2021-02-17T12:41:12+0000] [ALPM-SCRIPTLET] -> Running build hook: [keyboard]
[2021-02-17T12:41:12+0000] [ALPM-SCRIPTLET] -> Running build hook: [fsck]
[2021-02-17T12:41:12+0000] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2021-02-17T12:41:12+0000] [ALPM-SCRIPTLET] ==> Creating gzip-compressed initcpio image: /boot/initramfs-linux.img
[2021-02-17T12:41:15+0000] [ALPM-SCRIPTLET] ==> Image generation successful
[2021-02-17T12:41:15+0000] [ALPM] running 'dbus-reload.hook'...
')
I can only suspect of these packages:
hwids
linux-firmware
linux-raspberrypi4
raspberrypi-firmware
I don't really know as of now how to further debug this.
When I first stumbled upon this I had enabled the wpa_supplicant and dhcpcd services and hoped for it to automatically connect, but surprise! XD
Connected to a screen I then realized there were messages of this sort:
$this->bbcode_second_pass_code('', '
sys-subsystem-net-devices-wlan0.device: Job sys-subsystem-net-devices-wlan0.device/start timed out.
')
$this->bbcode_second_pass_code('', '
Timed out waiting for device /sys/subsystem/net/devices/wlan0 dependency
')
When those services are disabled it boots right away and nothing times out, yet the interface is not available.
i'll also share some grepped output from journalctl... if that's of any use
$this->bbcode_second_pass_code('', '
[alarm@alarmpi ~]$ journalctl | grep wlan0
Feb 03 21:52:39 alarmpi audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=wpa_supplicant@wlan0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 03 21:52:39 alarmpi kernel: audit: type=1130 audit(1612389159.229:45): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=wpa_supplicant@wlan0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 03 21:52:39 alarmpi systemd-networkd[252]: wlan0: Link UP
Feb 03 21:52:42 alarmpi wpa_supplicant[339]: wlan0: Trying to associate with SSID 'bastian'
Feb 03 21:52:44 alarmpi wpa_supplicant[339]: wlan0: Associated with 70:4f:57:a2:7a:be
Feb 03 21:52:44 alarmpi wpa_supplicant[339]: wlan0: CTRL-EVENT-CONNECTED - Connection to 70:4f:57:a2:7a:be completed [id=0 id_str=]
Feb 03 21:52:44 alarmpi systemd-networkd[252]: wlan0: Gained carrier
Feb 03 21:52:44 alarmpi wpa_supplicant[339]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Feb 03 21:52:44 alarmpi kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Feb 03 21:52:44 alarmpi systemd-networkd[252]: wlan0: Connected WiFi access point: bastian (70:4f:57:a2:7a:be)
Feb 03 21:52:46 alarmpi systemd-networkd[252]: wlan0: Gained IPv6LL
Feb 03 21:53:02 alarmpi dhcpcd[351]: wlan0: connected to Access Point: bastian
Feb 03 21:53:02 alarmpi dhcpcd[351]: wlan0: IAID 32:bd:ef:9a
Feb 03 21:53:03 alarmpi dhcpcd[351]: wlan0: soliciting an IPv6 router
Feb 03 21:53:04 alarmpi dhcpcd[351]: wlan0: soliciting a DHCP lease
Feb 03 21:53:07 alarmpi dhcpcd[351]: wlan0: offered 10.10.90.163 from 10.10.90.254
Feb 03 21:53:07 alarmpi dhcpcd[351]: wlan0: probing address 10.10.90.163/24
Feb 03 21:53:13 alarmpi dhcpcd[351]: wlan0: leased 10.10.90.163 for 43200 seconds
Feb 03 21:53:13 alarmpi dhcpcd[351]: wlan0: adding route to 10.10.90.0/24
Feb 03 21:53:13 alarmpi dhcpcd[351]: wlan0: adding default route via 10.10.90.254
Feb 03 21:53:15 alarmpi dhcpcd[351]: wlan0: no IPv6 Routers available
Feb 17 12:41:54 alarmpi wpa_supplicant[339]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0
Feb 17 12:41:54 alarmpi dhcpcd[351]: wlan0: removing interface
Feb 17 12:41:54 alarmpi wpa_supplicant[339]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING
Feb 17 12:41:54 alarmpi wpa_supplicant[339]: wlan0: CTRL-EVENT-DISCONNECTED bssid=70:4f:57:a2:7a:be reason=3 locally_generated=1
Feb 17 12:41:54 alarmpi wpa_supplicant[339]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Feb 17 12:41:55 alarmpi wpa_supplicant[339]: wlan0: CTRL-EVENT-TERMINATING
Feb 17 12:41:55 alarmpi systemd[1]: wpa_supplicant@wlan0.service: Succeeded.
Feb 17 12:41:55 alarmpi audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=wpa_supplicant@wlan0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[alarm@alarmpi ~]$
')
$this->bbcode_second_pass_code('', '
[alarm@alarmpi ~]$ journalctl | grep reboot
Feb 17 12:41:54 alarmpi systemd[1]: Requested transaction contradicts existing jobs: Transaction for systemd-networkd.service/start is destructive (reboot.target has 'start' job queued, but 'stop' is included in transaction).
Feb 17 12:41:54 alarmpi systemd[1]: systemd-networkd.socket: Failed to queue service startup job (Maybe the service file is missing or not a non-template unit?): Transaction for systemd-networkd.service/start is destructive (reboot.target has 'start' job queued, but 'stop' is included in transaction).
Feb 17 12:41:55 alarmpi systemd[1]: systemd-reboot.service: Succeeded.
Feb 17 12:41:55 alarmpi audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-reboot comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 17 12:41:55 alarmpi audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-reboot comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[alarm@alarmpi ~]$
')
$this->bbcode_second_pass_code('', '
[alarm@alarmpi ~]$ journalctl | grep eth0
Feb 03 21:51:27 alarmpi systemd-networkd[252]: eth0: Link UP
Feb 03 21:51:27 alarmpi kernel: bcmgenet fd580000.ethernet eth0: Link is Down
Feb 03 21:51:28 alarmpi kernel: bcmgenet fd580000.ethernet eth0: Link is Down
Feb 03 21:51:28 alarmpi systemd-networkd[253]: eth0: Link UP
Feb 03 21:53:02 alarmpi dhcpcd[351]: eth0: waiting for carrier
Feb 17 12:41:54 alarmpi dhcpcd[351]: eth0: removing interface
Feb 17 12:41:54 alarmpi systemd-networkd[252]: eth0: DHCPv6 lease lost
Feb 17 12:51:00 alarmpi dhcpcd[354]: eth0: waiting for carrier
Feb 17 12:53:25 alarmpi dhcpcd[354]: eth0: carrier acquired
Feb 17 12:53:25 alarmpi kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Feb 17 12:53:25 alarmpi kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Feb 17 12:53:25 alarmpi systemd-networkd[253]: eth0: Gained carrier
Feb 17 12:53:25 alarmpi dhcpcd[354]: eth0: IAID 32:bd:ef:99
Feb 17 12:53:25 alarmpi dhcpcd[354]: eth0: adding address fe80::dde8:ea0f:acc7:7445
Feb 17 12:53:26 alarmpi dhcpcd[354]: eth0: soliciting a DHCP lease
Feb 17 12:53:26 alarmpi dhcpcd[354]: eth0: soliciting an IPv6 router
Feb 17 12:53:27 alarmpi systemd-networkd[253]: eth0: Gained IPv6LL
Feb 17 12:53:28 alarmpi dhcpcd[354]: eth0: offered 10.10.90.161 from 10.10.90.254
Feb 17 12:53:28 alarmpi dhcpcd[354]: eth0: NAK: address in use from 10.10.90.254
Feb 17 12:53:28 alarmpi dhcpcd[354]: eth0: message: address in use
Feb 17 12:53:29 alarmpi systemd-networkd[253]: eth0: DHCPv4 address 10.10.90.161/24 via 10.10.90.254
Feb 17 12:53:29 alarmpi dhcpcd[354]: eth0: soliciting a DHCP lease
Feb 17 12:53:32 alarmpi dhcpcd[354]: eth0: offered 10.10.90.164 from 10.10.90.254
Feb 17 12:53:32 alarmpi dhcpcd[354]: eth0: probing address 10.10.90.164/24
Feb 17 12:53:36 alarmpi dhcpcd[354]: eth0: leased 10.10.90.164 for 43200 seconds
Feb 17 12:53:36 alarmpi dhcpcd[354]: eth0: adding route to 10.10.90.0/24
Feb 17 12:53:36 alarmpi dhcpcd[354]: eth0: adding default route via 10.10.90.254
Feb 17 12:53:39 alarmpi dhcpcd[354]: eth0: no IPv6 Routers available
[alarm@alarmpi ~]$
')
here's
the whole journalctl output in pastebin if there's someone interested in the whole thing
any help would be very much appreciated.. please ask for any other information needed to clear this
meanwhile I may try to go around the system update and see if this install is of any use as it is right out of the image
