3

(Full logs are also posted here)

My RPi3B+ have ArchLinuxARM running on it (armv7h version). Latest kernel and all updates (only packages from official repos + yay installed from AUR). My SD is Samsung EVO PLUS UHS-1 class 10 SDHC card (MB-MC32GA). This page tells that it is supported and works fine. Power adaptor is 5V/2.5A. Fan is also installed but I use it only when doing some heavy tasks. No overclocking is used.

I use my RPi3B+ as Wi-Fi access point - I have hostapd installed on it and share ethernet to my devices via 5GHz. Things were fine until recently - my RPi has been running without reboot for weeks (since January) and no problems were observed. But last week I observed two strange situations (essentially, they are the same). While watching YouTube on my PC internet suddenly stopped working and after some seconds Wi-Fi link disappeared. The first time I simply logged into my RPi via keyboard and HDMI monitor and rebooted it manually with systemctl reboot. NB: I had to wait while hostapd service becomes killed for about 1.5 mins. Yesterday I've observed the same behavior and again while watching YouTube. Weird, because I've already used almost the whole available bandwith of RPi's Wi-Fi link while downloading huge amount of data, compressing the whole SD card contents into archive and so on.

I've reconstructed some history. The first hang occured on 20.03.2019 and second on 24.03.2019. Here is pacman log from 10.03.2019:

[2019-03-10 17:31] [PACMAN] Running 'pacman -Syu'
[2019-03-10 17:31] [PACMAN] synchronizing package lists
[2019-03-10 17:31] [PACMAN] starting full system upgrade
[2019-03-10 17:31] [ALPM] transaction started
[2019-03-10 17:31] [ALPM] upgraded iana-etc (20190221-1 -> 20190308-1)
[2019-03-10 17:31] [ALPM] upgraded e2fsprogs (1.44.5-1 -> 1.44.6-1)
[2019-03-10 17:31] [ALPM] upgraded libatomic_ops (7.6.8-1 -> 7.6.10-1)
[2019-03-10 17:31] [ALPM] upgraded libelf (0.175-1 -> 0.176-1)
[2019-03-10 17:32] [ALPM] upgraded linux-raspberrypi (4.19.25-2 -> 4.19.27-1)
[2019-03-10 17:32] [ALPM] upgraded man-pages (4.16-2 -> 5.00-1)
[2019-03-10 17:32] [ALPM] upgraded raspberrypi-bootloader (20190224-1 -> 20190308-1)
[2019-03-10 17:32] [ALPM] upgraded raspberrypi-bootloader-x (20190224-1 -> 20190308-1)
[2019-03-10 17:32] [ALPM] upgraded raspberrypi-firmware (20190122-1 -> 20190308-1)
[2019-03-10 17:32] [ALPM] upgraded vim-runtime (8.1.0877-1 -> 8.1.0996-1)
[2019-03-10 17:32] [ALPM] upgraded vim (8.1.0877-1 -> 8.1.0996-1)
[2019-03-10 17:32] [ALPM] transaction completed
[2019-03-10 17:32] [ALPM] running '60-linux-raspberrypi.hook'...
[2019-03-10 17:32] [ALPM] running '90-linux-raspberrypi.hook'...
[2019-03-10 17:32] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux-raspberrypi.preset: 'default'
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> -k 4.19.27-1-ARCH -c /etc/mkinitcpio.conf -g /boot/initramfs-linux.img
[2019-03-10 17:32] [ALPM-SCRIPTLET] ==> Starting build: 4.19.27-1-ARCH
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [autodetect]
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [consolefont]
[2019-03-10 17:32] [ALPM-SCRIPTLET]   -> Running build hook: [keymap]
[2019-03-10 17:32] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2019-03-10 17:32] [ALPM-SCRIPTLET] ==> Creating gzip-compressed initcpio image: /boot/initramfs-linux.img
[2019-03-10 17:32] [ALPM-SCRIPTLET] ==> Image generation successful
[2019-03-10 17:32] [ALPM] running 'systemd-update.hook'...
[2019-03-10 17:32] [ALPM] running 'texinfo-install.hook'...
[2019-03-10 17:33] [PACMAN] Running 'pacman -S -u -y --config /etc/pacman.conf --'
[2019-03-10 17:33] [PACMAN] synchronizing package lists
[2019-03-10 17:33] [PACMAN] starting full system upgrade
[2019-03-17 06:18] [PACMAN] Running 'pacman -Syu'
[2019-03-17 06:18] [PACMAN] synchronizing package lists
[2019-03-17 06:18] [PACMAN] starting full system upgrade
[2019-03-17 06:18] [ALPM] transaction started
[2019-03-17 06:18] [ALPM] upgraded bash (5.0.0-1 -> 5.0.002-1)
[2019-03-17 06:18] [ALPM] upgraded e2fsprogs (1.44.6-1 -> 1.45.0-1)
[2019-03-17 06:18] [ALPM] upgraded glib2 (2.58.3-1 -> 2.60.0-1)
[2019-03-17 06:20] [ALPM] upgraded linux-firmware (20190212.28f5f7d-1 -> 20190313.efd2c1c-1)
[2019-03-17 06:20] [ALPM] upgraded s-nail (14.9.11-3 -> 14.9.13-2)
[2019-03-17 06:20] [ALPM] upgraded texinfo (6.5-2 -> 6.6-1)
[2019-03-17 06:20] [ALPM] transaction completed
[2019-03-17 06:20] [ALPM] running 'systemd-daemon-reload.hook'...
[2019-03-17 06:20] [ALPM] running 'systemd-tmpfiles.hook'...
[2019-03-17 06:20] [ALPM] running 'systemd-udev-reload.hook'...
[2019-03-17 06:20] [ALPM] running 'systemd-update.hook'...
[2019-03-17 06:20] [ALPM] running 'texinfo-install.hook'...
[2019-03-17 06:20] [PACMAN] Running 'pacman -S -y -u --config /etc/pacman.conf --'
[2019-03-17 06:20] [PACMAN] synchronizing package lists
[2019-03-17 06:20] [PACMAN] starting full system upgrade
[2019-03-20 13:08] [PACMAN] Running 'pacman -Syu'
[2019-03-20 13:08] [PACMAN] synchronizing package lists
[2019-03-20 13:08] [PACMAN] starting full system upgrade
[2019-03-20 13:08] [ALPM] transaction started
[2019-03-20 13:08] [ALPM] upgraded libseccomp (2.3.3-1 -> 2.4.0-1)
[2019-03-20 13:08] [ALPM] upgraded ca-certificates-mozilla (3.42.1-1 -> 3.43-1)
[2019-03-20 13:08] [ALPM] upgraded libssh2 (1.8.0-3 -> 1.8.1-1)
[2019-03-20 13:08] [ALPM] transaction completed
[2019-03-20 13:08] [ALPM] running 'systemd-update.hook'...
[2019-03-20 13:08] [ALPM] running 'update-ca-trust.hook'...
[2019-03-20 13:09] [PACMAN] Running 'pacman -S -y -u --config /etc/pacman.conf --'
[2019-03-20 13:09] [PACMAN] synchronizing package lists
[2019-03-20 13:09] [PACMAN] starting full system upgrade
[2019-03-20 20:56] [PACMAN] Running 'pacman -Syu'
[2019-03-20 20:56] [PACMAN] synchronizing package lists
[2019-03-20 20:56] [PACMAN] starting full system upgrade
[2019-03-20 20:56] [ALPM] transaction started
[2019-03-20 20:56] [ALPM] upgraded libgpg-error (1.35-1 -> 1.36-1)
[2019-03-20 20:56] [ALPM] transaction completed
[2019-03-20 20:56] [ALPM] running 'systemd-update.hook'...
[2019-03-20 20:56] [ALPM] running 'texinfo-install.hook'...
[2019-03-20 20:56] [PACMAN] Running 'pacman -S -u -y --config /etc/pacman.conf --'
[2019-03-20 20:56] [PACMAN] synchronizing package lists
[2019-03-20 20:56] [PACMAN] starting full system upgrade
[2019-03-20 20:58] [PACMAN] Running 'pacman -S ncdu'
[2019-03-20 20:58] [ALPM] transaction started
[2019-03-20 20:58] [ALPM] installed ncdu (1.14-1)
[2019-03-20 20:58] [ALPM] transaction completed
[2019-03-20 20:58] [ALPM] running 'systemd-update.hook'...
[2019-03-20 21:00] [PACMAN] Running 'pacman -S -c -c --config /etc/pacman.conf --'
[2019-03-23 13:36] [PACMAN] Running 'pacman -S dosfstools'
[2019-03-23 13:36] [ALPM] transaction started
[2019-03-23 13:36] [ALPM] installed dosfstools (4.1-2)
[2019-03-23 13:36] [ALPM] transaction completed
[2019-03-23 13:36] [ALPM] running 'systemd-update.hook'...
[2019-03-23 13:36] [PACMAN] Running 'pacman -Syu'
[2019-03-23 13:36] [PACMAN] synchronizing package lists
[2019-03-23 13:36] [PACMAN] starting full system upgrade
[2019-03-23 13:37] [ALPM] transaction started
[2019-03-23 13:37] [ALPM] upgraded bison (3.2-1 -> 3.3.2-1)
[2019-03-23 13:37] [ALPM] upgraded coreutils (8.30-1 -> 8.31-1)
[2019-03-23 13:37] [ALPM] upgraded firmware-raspberrypi (4-1 -> 5-1)
[2019-03-23 13:37] [ALPM] upgraded iproute2 (4.20.0-1 -> 5.0.0-1)
[2019-03-23 13:37] [ALPM] upgraded linux-raspberrypi (4.19.27-1 -> 4.19.29-1)
[2019-03-23 13:37] [ALPM] upgraded raspberrypi-bootloader (20190308-1 -> 20190320-1)
[2019-03-23 13:37] [ALPM] upgraded raspberrypi-bootloader-x (20190308-1 -> 20190320-1)
[2019-03-23 13:37] [ALPM] upgraded raspberrypi-firmware (20190308-1 -> 20190320-1)
[2019-03-23 13:37] [ALPM] transaction completed
[2019-03-23 13:37] [ALPM] running '60-linux-raspberrypi.hook'...
[2019-03-23 13:37] [ALPM] running '90-linux-raspberrypi.hook'...
[2019-03-23 13:37] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux-raspberrypi.preset: 'default'
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> -k 4.19.29-1-ARCH -c /etc/mkinitcpio.conf -g /boot/initramfs-linux.img
[2019-03-23 13:37] [ALPM-SCRIPTLET] ==> Starting build: 4.19.29-1-ARCH
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [autodetect]
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [consolefont]
[2019-03-23 13:37] [ALPM-SCRIPTLET]   -> Running build hook: [keymap]
[2019-03-23 13:37] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2019-03-23 13:37] [ALPM-SCRIPTLET] ==> Creating gzip-compressed initcpio image: /boot/initramfs-linux.img
[2019-03-23 13:37] [ALPM-SCRIPTLET] ==> Image generation successful
[2019-03-23 13:37] [ALPM] running 'systemd-update.hook'...
[2019-03-23 13:37] [ALPM] running 'texinfo-install.hook'...
[2019-03-23 13:58] [PACMAN] Running 'pacman -S mlocate'
[2019-03-23 13:58] [ALPM] transaction started
[2019-03-23 13:58] [ALPM] installed mlocate (0.26.git.20170220-1)
[2019-03-23 13:58] [ALPM] transaction completed
[2019-03-23 13:58] [ALPM] running 'systemd-daemon-reload.hook'...
[2019-03-23 13:58] [ALPM] running 'systemd-sysusers.hook'...
[2019-03-23 13:58] [ALPM] running 'systemd-update.hook'...
[2019-03-23 14:07] [PACMAN] Running 'pacman -S -c -c --config /etc/pacman.conf --'
[2019-03-23 14:26] [PACMAN] Running 'pacman -S rsync'
[2019-03-23 14:26] [ALPM] transaction started
[2019-03-23 14:26] [ALPM] installed rsync (3.1.3-1)
[2019-03-23 14:26] [ALPM] transaction completed
[2019-03-23 14:26] [ALPM] running 'systemd-daemon-reload.hook'...
[2019-03-23 14:26] [ALPM] running 'systemd-update.hook'...
[2019-03-23 14:29] [PACMAN] Running 'pacman -Scc'
[2019-03-24 01:07] [PACMAN] Running 'pacman -Syu'
[2019-03-24 01:07] [PACMAN] synchronizing package lists
[2019-03-24 01:07] [PACMAN] starting full system upgrade
[2019-03-24 13:14] [PACMAN] Running 'pacman -S dtc'
[2019-03-24 13:14] [ALPM] transaction started
[2019-03-24 13:14] [ALPM] installed dtc (1.5.0-1)
[2019-03-24 13:14] [ALPM] transaction completed
[2019-03-24 13:14] [ALPM] running 'systemd-update.hook'...

As you can see, at 10.03.2019 there were two critical updates:

[2019-03-10 17:32] [ALPM] upgraded linux-raspberrypi (4.19.25-2 -> 4.19.27-1)
[2019-03-10 17:32] [ALPM] upgraded raspberrypi-firmware (20190122-1 -> 20190308-1)

but RPi has been working for a week after that (I always reboot after installing such important updates). And on 17.03.2019 there was another update:

[2019-03-17 06:20] [ALPM] upgraded linux-firmware (20190212.28f5f7d-1 -> 20190313.efd2c1c-1)

After that the first hang observed on 20.03.2019 - only after 3 days. I've rebooted RPi several times on 23.03.2019 and the next hang was observed almost immediately - after 12 hours on 24.03.2019. Seems like linux-firmware-20190313.efd2c1c has introduced some bug... It's interesting to know your experience.

I looked through logs and found that (excerpt from journalctl):

Mar 24 00:58:22 desolve-rpi3bplus kernel: mmc1: Timeout waiting for hardware interrupt.
Mar 24 00:58:12 desolve-rpi3bplus kernel: brcmfmac: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Mar 24 00:58:12 desolve-rpi3bplus kernel: brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Mar 24 00:58:12 desolve-rpi3bplus kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Mar 24 00:58:12 desolve-rpi3bplus kernel: brcmfmac: brcmf_sdiod_sglist_rw: CMD53 sg block write failed -110
Mar 24 00:58:12 desolve-rpi3bplus kernel: mmc1: Timeout waiting for hardware interrupt.
Mar 24 00:58:02 desolve-rpi3bplus kernel: brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Mar 24 00:58:02 desolve-rpi3bplus kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Mar 24 00:58:02 desolve-rpi3bplus kernel: brcmfmac: brcmf_sdiod_sglist_rw: CMD53 sg block write failed -110
Mar 24 00:58:02 desolve-rpi3bplus kernel: mmc1: Timeout waiting for hardware interrupt.
Mar 24 00:57:52 desolve-rpi3bplus kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Mar 24 00:57:52 desolve-rpi3bplus kernel: brcmfmac: brcmf_sdiod_sglist_rw: CMD53 sg block write failed -110
Mar 24 00:57:52 desolve-rpi3bplus kernel: mmc1: Timeout waiting for hardware interrupt.
Mar 24 00:57:42 desolve-rpi3bplus kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Mar 24 00:57:41 desolve-rpi3bplus kernel: brcmfmac: brcmf_sdiod_sglist_rw: CMD53 sg block write failed -84

I thought initially that my SD card dies (strange, because it's brand new). Then I tried to force fsck on my partitions (I've done it on RPi itself via /forcefsck, tune2fs and other tricks and on my PC by my hands too). But fsck says that filesystems are clean:

[viktor@desolve-nettop ~]$ LANG=en_US.UTF-8 sudo fdisk -l /dev/sdc
Disk /dev/sdc: 29.8 GiB, 32010928128 bytes, 62521344 sectors
Disk model: STORAGE DEVICE  
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x0bc7e6c4

Device     Boot  Start      End  Sectors  Size Id Type
/dev/sdc1         2048   206847   204800  100M  c W95 FAT32 (LBA)
/dev/sdc2       206848 62521343 62314496 29.7G 83 Linux

[viktor@desolve-nettop ~]$ LANG=en_US.UTF-8 sudo fsck /dev/sdc1
fsck from util-linux 2.33.1
fsck.fat 4.1 (2017-01-24)
/dev/sdc1: 175 files, 13185/51091 clusters

[viktor@desolve-nettop ~]$ LANG=en_US.UTF-8 sudo fsck /dev/sdc2
fsck from util-linux 2.33.1
e2fsck 1.45.0 (6-Mar-2019)
/dev/sdc2: clean, 56175/1949696 files, 599895/7789312 blocks

Here is also tune2fs output:

[root@desolve-rpi3bplus ~]# tune2fs -l /dev/mmcblk0p2 
tune2fs 1.45.0 (6-Mar-2019)
Filesystem volume name:   <none>
Last mounted on:          /
Filesystem UUID:          24fb8874-4cf9-40d3-b87b-59b0865c119b
Filesystem magic number:  0xEF53
Filesystem revision #:    1 (dynamic)
Filesystem features:      has_journal ext_attr resize_inode dir_index filetype needs_recovery extent 64bit flex_bg sparse_super large_file huge_file dir_nlink extra_isize metadata_csum
Filesystem flags:         signed_directory_hash 
Default mount options:    user_xattr acl
Filesystem state:         clean
Errors behavior:          Continue
Filesystem OS type:       Linux
Inode count:              1949696
Block count:              7789312
Reserved block count:     389465
Free blocks:              7189417
Free inodes:              1893521
First block:              0
Block size:               4096
Fragment size:            4096
Group descriptor size:    64
Reserved GDT blocks:      1024
Blocks per group:         32768
Fragments per group:      32768
Inodes per group:         8192
Inode blocks per group:   512
Flex block group size:    16
Filesystem created:       Sat Dec 22 23:08:00 2018
Last mount time:          Thu Jan  1 03:00:05 1970
Last write time:          Thu Jan  1 03:00:05 1970
Mount count:              3
Maximum mount count:      20
Last checked:             Sat Dec 22 23:08:00 2018
Check interval:           0 (<none>)
Lifetime writes:          22 GB
Reserved blocks uid:      0 (user root)
Reserved blocks gid:      0 (group root)
First inode:              11
Inode size:           256
Required extra isize:     32
Desired extra isize:      32
Journal inode:            8
Default directory hash:   half_md4
Directory Hash Seed:      ced42565-d16c-4a57-ac49-c676b8e52dad
Journal backup:           inode blocks
Checksum type:            crc32c
Checksum:                 0x3f25d8b6

So I came to conclusion that my SD card is good and problem is not so obvious. Searching on the forum and with google told me that this problem is not distro- and card-related, so it seems like regression started with the latest updates (I believe that the firmwares that were released on this week may contain some bugs). So I'm asking for your help.

Thank you!

  • Most of us use official supported Raspbian ... – Ingo Mar 24 at 19:01
  • @Ingo, I know, that Raspbian is the recommended choice. But quick investigation of the problem revealed that similar error occurs sometimes and it is not distro-specific and card-specific. What makes this situation unique: in found cases this occurs at the bootup time blocking the whole startup. In my case it occured randomly during stable work, although before the update of (official!) firmware things were fine for a weeks of uptime – Drobot Viktor Mar 25 at 7:00

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.