Problem with moving rootFS to the new SSD drive

yaslaw · 25 February 2024 12:15

Creating a bug report/issue

Moving the rootFS to other drive always fails (at the end of coping files).

Background info:
Every couple of days my boot & RootFS that is located on the USB pendrive, is mounted in “read-only” mode. I know that its the good moment to move the RootFS to the new SSD drive.
However every time I’m using the dietpi-manager to move it to the new drive, after an hour of coping all files, its failed at the end (can’t copy it as it dissapear quite quickly, but its just “FAILED” status next to this rsync command that was displayed when the file were transfered from tmp/tmp_root to the new drive).

I have searched the existing open and closed issues

Required Information

DietPi version | G_DIETPI_VERSION_CORE=9 G_DIETPI_VERSION_SUB=1 G_DIETPI_VERSION_RC=1 G_GITBRANCH='master' G_GITOWNER='MichaIng' G_LIVE_PATCH_STATUS[0]='not applicable'
Distro version | bookworm 0
Kernel version | Linux DietPi 6.1.21-v8+ #1642 SMP PREEMPT Mon Apr 3 17:24:16 BST 2023 aarch64 GNU/Linux
Architecture | arm64
SBC model | RPi 4 Model B (aarch64)
SD card used | USB Pendrive as a boot device/rootFS (128 GB)

Steps to reproduce

execute dietpi-drivemanager
selecting the “transfer RootFS” on target drive and (which is not mounted)
formatting it into ext4 (the same FS as a current root drive)

After formatting and waiting around an hour I got error message.
Althought when I check the the disk usage I can spot that the all data is transfered to new device

Filesystem      Size  Used Avail Use% Mounted on
/dev/root       118G   56G   57G  50% /
/dev/sdc1       110G   56G   54G  51% /mnt/f1e82f43-3eb9-4ff2-90d0-629a5281dd01

Expected behaviour

Successful transfer of rootFS, updated fstab

Actual behaviour

Transfer data fails, and rootFS is still located on original USB drive

Extra info

fdisk output(after restart)

Disk /dev/ram0: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram1: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram2: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram3: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram4: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram5: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram6: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram7: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram8: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram9: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram10: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram11: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram12: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram13: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram14: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/ram15: 4 MiB, 4194304 bytes, 8192 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes


Disk /dev/loop0: 49.07 MiB, 51453952 bytes, 100496 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes


Disk /dev/loop1: 49.12 MiB, 51503104 bytes, 100592 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes


Disk /dev/loop2: 49.12 MiB, 51503104 bytes, 100592 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes


Disk /dev/loop3: 14.7 MiB, 15413248 bytes, 30104 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes


Disk /dev/loop4: 14.7 MiB, 15417344 bytes, 30112 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes


Disk /dev/loop5: 236.26 MiB, 247734272 bytes, 483856 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes


Disk /dev/loop6: 236.36 MiB, 247836672 bytes, 484056 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes


Disk /dev/loop7: 35.52 MiB, 37240832 bytes, 72736 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes


Disk /dev/sda: 2.73 TiB, 3000592982016 bytes, 5860533168 sectors
Disk model: ASM225CM
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 4096 bytes
I/O size (minimum/optimal): 4096 bytes / 4096 bytes
Disklabel type: gpt
Disk identifier: D32E17C5-6635-4461-9D3D-E18524AD581D

Device     Start        End    Sectors  Size Type
/dev/sda1   2048 5860532223 5860530176  2.7T Linux filesystem


Disk /dev/sdb: 119.08 GiB, 127865192448 bytes, 249736704 sectors
Disk model: Flash Drive
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: 0xcb891ace

Device     Boot  Start       End   Sectors  Size Id Type
/dev/sdb1  *      8192    270335    262144  128M  c W95 FAT32 (LBA)
/dev/sdb2       270336 249736703 249466368  119G 83 Linux


Disk /dev/sdc: 111.79 GiB, 120034123776 bytes, 234441648 sectors
Disk model: DSC2BW120A4
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 33553920 bytes
Disklabel type: gpt
Disk identifier: A2C33B99-2DA7-4D19-B075-89956113277F

Device     Start       End   Sectors   Size Type
/dev/sdc1  65535 234418694 234353160 111.7G Linux filesystem


Disk /dev/loop8: 35.21 MiB, 36921344 bytes, 72112 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes

fstab

#----------------------------------------------------------------
# PHYSICAL DRIVES
#----------------------------------------------------------------
PARTUUID=cb891ace-02 / ext4 noatime,lazytime,rw 0 1
PARTUUID=cb891ace-01 /boot vfat noatime,lazytime,rw 0 2
UUID=57cffb2b-d093-4373-93c6-9152e09f3ed5 /mnt/magazyn ext4 noatime,lazytime,rw,nofail,noauto,x-systemd.automount
UUID=f1e82f43-3eb9-4ff2-90d0-629a5281dd01 /mnt/f1e82f43-3eb9-4ff2-90d0-629a5281dd01 ext4 noatime,lazytime,rw,nofail,noauto,x-systemd.automount

blkid

/dev/sdb2: UUID="1ff5b9f9-2abf-4937-b25c-d1f2fa3ca4b9" BLOCK_SIZE="4096" TYPE="ext4" PARTUUID="cb891ace-02"
/dev/sdb1: UUID="B9AD-A61C" BLOCK_SIZE="512" TYPE="vfat" PARTUUID="cb891ace-01"
/dev/sdc1: UUID="f1e82f43-3eb9-4ff2-90d0-629a5281dd01" BLOCK_SIZE="4096" TYPE="ext4" PARTLABEL="primary" PARTUUID="85a58268-d5a4-47f9-95c3-1639aeed6be0"
/dev/sda1: UUID="57cffb2b-d093-4373-93c6-9152e09f3ed5" BLOCK_SIZE="4096" TYPE="ext4" PARTLABEL="primary" PARTUUID="9f5d55ff-d9b3-432e-9766-06b91ac3ab17"

Joulinar · 25 February 2024 13:38

why not moving the entire system to the new connected SSD instead of RootFS only? Moving a running DietPi system to a USB stick/disk or an onboard eMMC – DietPi Blog

can you share following

lsblk -o name,fstype,label,size,ro,type,mountpoint,partuuid,uuid

anika200 · 25 February 2024 16:33

After the error you should try to capture the error so you can see what it says.
At the terminal of course,

sudo journalctl --since "today" | grep rsync

or if you know the date

sudo journalctl -since "2024-02-23" | grep rsync

Not sure what will actually report the error it may be dietpi-drivemanager but I would try rsync first.

yaslaw · 3 March 2024 19:11

Hi, sorry for the delay in responding.
Thanks for the hints; I decided to move the entire system to new drive instead of the RootFS only as @Joulinar pointed to (many, many thanks for that!).
It works as a charm, and the system booted with the SSD.
And the story could end here, but from this point, it started to be a bit more interesting.

My issue with “read-only RootFS” was solved, and I thought that it would a reason of the problem that I had for a long time - namely my rpi after a couple of hours/days, without any particular reason started to be unresponsive, even with no noticeable jobs runnings. This makes establishing an SSH connection impossible, or even if the SSH was initialized already, it was so slow that I almost couldn’t type any commands.

As I said, I thought that a faulty USB drive was the reason. But to my surprise, the problem still occurred precisely as before. I tried to disable all unnecessary services, docker, but even on very “light” workload (with only cloudflare tunnel and one light docker) the problem persisted.

Then, after being in despair, I accidentally found a root cause. The problem lies with the kernel threads that started to make this system unresponsive.
Please see the attached picture.

So, I found that the problem is well known and occurs on some systems that are connected only via WIFI (my RPI was connected to the Internet that way)

The problem was related to two components (kworker/u2:0-brcmf_wq/mmc1:0001:1 - which is responsible for WIFI stack, and the second problem is related to very well known kswapd0 which is responsible for swap.)

Please see

github.com/raspberrypi/linux

kworker hogs CPU only when using WIFI

opened 06:10PM - 22 Feb 21 UTC

ssackett

**Describe the bug** kworker hogs the CPU only when using WIFI, wired network c…onnections are not affected. **To reproduce** This configuration allows a USB peripheral connected to the Pi4 to be controlled by a client running on a remote computer by emulating a USB connection over an IP network. Install the VirtualHere service named "vhusbdarmpi4", connect SDRPlaydx to USB on the Pi4 and start the client software named "vhui64.exe" on a Windows 10 connected by wire to the same subnet as the Pi4. Note the Pi4 communicates to a router using WIFI and the Win10 computer is connected to the same router but with a wired connection. Using the client software connect remotely to the SDRPlaydx. Note the VirtualHere software uses a USBIP protocol to make it appear that the SDRPlaydx is connected directly to the client via wired USB. On the client start the application "SDRuno". SDRuno is an application that controlls the SDRPlaydx. **Expected behaviour** I expect that the configuration to work as well when the Pi4 communicates over WIFI as it does when using a wired connection. **Actual behaviour** When the Pi4 uses a WIFI connection a kworker hogs the CPU and lowers the performance of the communications. **System** System Information ------------------ Raspberry Pi 4 Model B Rev 1.1 PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" Raspberry Pi reference 2021-01-26 Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, ddba443b028e3673570b52d2fbf471da0341afd4, stage3 Linux playground 5.10.16-v7l+ #1402 SMP Tue Feb 16 14:12:18 GMT 2021 armv7l GNU/Linux Revision : c03111 Serial : 10000000d9860c20 Model : Raspberry Pi 4 Model B Rev 1.1 Throttled flag : throttled=0x0 Camera : supported=0 detected=0 Videocore information --------------------- Feb 16 2021 14:17:31 Copyright (c) 2012 Broadcom version d6d82cf99bcb3e9a166a34cfde53130957a36bd3 (clean) (release) (start) alloc failures: 0 compactions: 0 legacy block fails: 0 Filesystem information ---------------------- Filesystem 1K-blocks Used Available Use% Mounted on /dev/root 30456660 2676036 26504584 10% / devtmpfs 1827468 0 1827468 0% /dev tmpfs 1959564 16 1959548 1% /dev/shm tmpfs 1959564 8708 1950856 1% /run tmpfs 5120 4 5116 1% /run/lock tmpfs 1959564 0 1959564 0% /sys/fs/cgroup tmpfs 65536 0 65536 0% /tmp/openwebrx /dev/mmcblk0p1 258095 49864 208232 20% /boot tmpfs 391912 0 391912 0% /run/user/1000 Filename Type Size Used Priority /var/swap file 102396 0 -2 Package version information --------------------------- raspberrypi-ui-mods: Installed: (none) raspberrypi-sys-mods: Installed: 20210208 openbox: Installed: (none) lxpanel: Installed: (none) pcmanfm: Installed: (none) rpd-plym-splash: Installed: (none) Networking Information ---------------------- eth0: flags=4099<UP,BROADCAST,MULTICAST> mtu 1500 ether m.m.m.m txqueuelen 1000 (Ethernet) RX packets 3641 bytes 560693 (547.5 KiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 3454 bytes 489750 (478.2 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 lo: flags=73<UP,LOOPBACK,RUNNING> mtu 65536 inet x.x.x.x netmask x.x.x.x inet6 ::1 prefixlen 128 scopeid 0x10<host> loop txqueuelen 1000 (Local Loopback) RX packets 0 bytes 0 (0.0 B) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 0 bytes 0 (0.0 B) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 wlan0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500 inet x.x.x.x netmask x.x.x.x broadcast x.x.x.x inet6 y::y.y.y.y prefixlen 64 scopeid 0x20<link> ether m.m.m.m txqueuelen 1000 (Ethernet) RX packets 8352567 bytes 393262742 (375.0 MiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 17850755 bytes 1601157876 (1.4 GiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 USB Information --------------- /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M |__ Port 1: Dev 6, If 0, Class=Vendor Specific Class, Driver=usbfs, 480M |__ Port 2: Dev 4, If 0, Class=Vendor Specific Class, Driver=, 480M |__ Port 3: Dev 5, If 0, Class=Human Interface Device, Driver=usbhid, 12M |__ Port 3: Dev 5, If 1, Class=Human Interface Device, Driver=usbhid, 12M |__ Port 3: Dev 5, If 2, Class=Human Interface Device, Driver=usbhid, 12M config.txt ---------- arm_freq=1500 audio_pwm_mode=514 config_hdmi_boost=5 core_freq=500 core_freq_min=200 disable_commandline_tags=2 disable_l2cache=1 display_hdmi_rotate=-1 display_lcd_rotate=-1 dvfs=2 enable_gic=1 force_eeprom_read=1 force_pwm_open=1 framebuffer_ignore_alpha=1 framebuffer_swap=1 gpu_freq=500 gpu_freq_min=250 init_uart_clock=0x2dc6c00 lcd_framerate=60 mask_gpu_interrupt0=1024 mask_gpu_interrupt1=0x10000 max_framebuffers=2 over_voltage_avs=-17500 pause_burst_frames=1 program_serial_random=1 total_mem=4096 hdmi_force_cec_address:0=65535 hdmi_force_cec_address:1=65535 hdmi_pixel_freq_limit:0=0x11e1a300 hdmi_pixel_freq_limit:1=0x11e1a300 device_tree=- overlay_prefix=overlays/ hdmi_cvt:0= hdmi_cvt:1= hdmi_edid_filename:0= hdmi_edid_filename:1= hdmi_timings:0= hdmi_timings:1= cmdline.txt ----------- coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1920x1080M@60,margin_left=48,margin_right=48,margin_top=48,margin_bottom=48 smsc95xx.macaddr=DC:A6:32:25:EB:2D vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyS0,115200 console=tty1 root=PARTUUID=d57429e7-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait raspi-gpio settings ------------------- BANK0 (GPIO 0 to 27): GPIO 0: level=1 fsel=0 func=INPUT pull=UP GPIO 1: level=1 fsel=0 func=INPUT pull=UP GPIO 2: level=1 fsel=0 func=INPUT pull=UP GPIO 3: level=1 fsel=0 func=INPUT pull=UP GPIO 4: level=1 fsel=0 func=INPUT pull=UP GPIO 5: level=1 fsel=0 func=INPUT pull=UP GPIO 6: level=1 fsel=0 func=INPUT pull=UP GPIO 7: level=1 fsel=0 func=INPUT pull=UP GPIO 8: level=1 fsel=0 func=INPUT pull=UP GPIO 9: level=0 fsel=0 func=INPUT pull=DOWN GPIO 10: level=0 fsel=0 func=INPUT pull=DOWN GPIO 11: level=0 fsel=0 func=INPUT pull=DOWN GPIO 12: level=0 fsel=0 func=INPUT pull=DOWN GPIO 13: level=0 fsel=0 func=INPUT pull=DOWN GPIO 14: level=1 fsel=0 func=INPUT pull=NONE GPIO 15: level=1 fsel=0 func=INPUT pull=UP GPIO 16: level=0 fsel=0 func=INPUT pull=DOWN GPIO 17: level=0 fsel=0 func=INPUT pull=DOWN GPIO 18: level=0 fsel=0 func=INPUT pull=DOWN GPIO 19: level=0 fsel=0 func=INPUT pull=DOWN GPIO 20: level=0 fsel=0 func=INPUT pull=DOWN GPIO 21: level=0 fsel=0 func=INPUT pull=DOWN GPIO 22: level=0 fsel=0 func=INPUT pull=DOWN GPIO 23: level=0 fsel=0 func=INPUT pull=DOWN GPIO 24: level=0 fsel=0 func=INPUT pull=DOWN GPIO 25: level=0 fsel=0 func=INPUT pull=DOWN GPIO 26: level=0 fsel=0 func=INPUT pull=DOWN GPIO 27: level=0 fsel=0 func=INPUT pull=DOWN BANK1 (GPIO 28 to 45): GPIO 28: level=1 fsel=2 alt=5 func=RGMII_MDIO pull=UP GPIO 29: level=0 fsel=2 alt=5 func=RGMII_MDC pull=DOWN GPIO 30: level=0 fsel=7 alt=3 func=CTS0 pull=UP GPIO 31: level=0 fsel=7 alt=3 func=RTS0 pull=NONE GPIO 32: level=1 fsel=7 alt=3 func=TXD0 pull=NONE GPIO 33: level=1 fsel=7 alt=3 func=RXD0 pull=UP GPIO 34: level=1 fsel=7 alt=3 func=SD1_CLK pull=NONE GPIO 35: level=1 fsel=7 alt=3 func=SD1_CMD pull=UP GPIO 36: level=1 fsel=7 alt=3 func=SD1_DAT0 pull=UP GPIO 37: level=1 fsel=7 alt=3 func=SD1_DAT1 pull=UP GPIO 38: level=1 fsel=7 alt=3 func=SD1_DAT2 pull=UP GPIO 39: level=1 fsel=7 alt=3 func=SD1_DAT3 pull=UP GPIO 40: level=0 fsel=4 alt=0 func=PWM1_0 pull=NONE GPIO 41: level=0 fsel=4 alt=0 func=PWM1_1 pull=NONE GPIO 42: level=0 fsel=1 func=OUTPUT pull=UP GPIO 43: level=1 fsel=0 func=INPUT pull=UP GPIO 44: level=1 fsel=0 func=INPUT pull=UP GPIO 45: level=1 fsel=0 func=INPUT pull=UP BANK2 (GPIO 46 to 53): GPIO 46: level=0 fsel=0 func=INPUT pull=UP GPIO 47: level=0 fsel=0 func=INPUT pull=UP GPIO 48: level=0 fsel=0 func=INPUT pull=DOWN GPIO 49: level=0 fsel=0 func=INPUT pull=DOWN GPIO 50: level=0 fsel=0 func=INPUT pull=DOWN GPIO 51: level=0 fsel=0 func=INPUT pull=DOWN GPIO 52: level=0 fsel=0 func=INPUT pull=DOWN GPIO 53: level=0 fsel=0 func=INPUT pull=DOWN vcdbg log messages ------------------ 005413.756: arasan: arasan_emmc_open 005564.380: brfs: File read: /mfs/sd/config.txt 005565.190: brfs: File read: 1809 bytes 005658.925: brfs: File read: /mfs/sd/config.txt 005675.239: brfs: File read: 1809 bytes 006154.825: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined 006157.322: *** Restart logging 006161.249: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead 006198.045: HDMI0: hdmi_pixel_encoding: 300000000 006198.057: HDMI1: hdmi_pixel_encoding: 300000000 006203.003: dtb_file 'bcm2711-rpi-4-b.dtb' 006208.733: brfs: File read: /mfs/sd/bcm2711-rpi-4-b.dtb 006208.747: Loading 'bcm2711-rpi-4-b.dtb' to 0x100 size 0xbeee 006221.206: brfs: File read: 48878 bytes 006232.633: brfs: File read: /mfs/sd/overlays/overlay_map.dtb 006296.190: brfs: File read: 1523 bytes 006298.795: brfs: File read: /mfs/sd/config.txt 006299.274: dtparam: audio=on 006309.082: brfs: File read: 1809 bytes 006322.474: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d.dtbo 006339.447: Loaded overlay 'vc4-fkms-v3d' 006339.491: dtparam: sd_poll_once=on 006408.359: brfs: File read: 1446 bytes 006410.760: brfs: File read: /mfs/sd/cmdline.txt 006410.824: Read command line from file 'cmdline.txt': 006410.848: 'console=serial0,115200 console=tty1 root=PARTUUID=d57429e7-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait' 007618.685: brfs: File read: 121 bytes 008937.091: brfs: File read: /mfs/sd/kernel7l.img 008937.130: Loading 'kernel7l.img' to 0x8000 size 0x65ff38 008937.180: Device tree loaded to 0x2eff3a00 (size 0xc526) 008944.364: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined 012451.259: vchiq_core: vchiq_init_state: slot_zero = 0xded80000, is_master = 1 012454.791: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead 012462.924: TV service:host side not connected, dropping notification 0x00000002, 0x00000001, 0x00000010 016374.365: TV service:host side not connected, dropping notification 0x00000008, 0x00000004, 0x00000001 dmesg log --------- [ 0.000000] Booting Linux on physical CPU 0x0 [ 0.000000] Linux version 5.10.16-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1402 SMP Tue Feb 16 14:12:18 GMT 2021 [ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d [ 0.000000] CPU: div instructions available: patching division code [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache [ 0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1 [ 0.000000] Memory policy: Data cache writealloc [ 0.000000] Reserved memory: created CMA memory pool at 0x000000001ec00000, size 256 MiB [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000000000-0x000000002fffffff] [ 0.000000] Normal empty [ 0.000000] HighMem [mem 0x0000000030000000-0x00000000fbffffff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000000000-0x000000003b3fffff] [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff] [ 0.000000] On node 0 totalpages: 1012736 [ 0.000000] DMA zone: 2304 pages used for memmap [ 0.000000] DMA zone: 0 pages reserved [ 0.000000] DMA zone: 196608 pages, LIFO batch:63 [ 0.000000] HighMem zone: 816128 pages, LIFO batch:63 [ 0.000000] percpu: Embedded 20 pages/cpu s50636 r8192 d23092 u81920 [ 0.000000] pcpu-alloc: s50636 r8192 d23092 u81920 alloc=20*4096 [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1010432 [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1920x1080M@60,margin_left=48,margin_right=48,margin_top=48,margin_bottom=48 smsc95xx.macaddr=m.m.m.m vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyS0,115200 console=tty1 root=PARTUUID=d57429e7-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait [ 0.000000] Kernel parameter elevator= does not have any effect anymore. Please use sysfs to set IO scheduler for individual devices. [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off [ 0.000000] software IO TLB: mapped [mem 0x0000000017cc0000-0x000000001bcc0000] (64MB) [ 0.000000] Memory: 3654940K/4050944K available (10240K kernel code, 1358K rwdata, 3156K rodata, 2048K init, 890K bss, 133860K reserved, 262144K cma-reserved, 3264512K highmem) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] ftrace: allocating 33892 entries in 67 pages [ 0.000000] ftrace: allocated 67 pages with 3 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] random: get_random_bytes called from start_kernel+0x3c8/0x598 with crng_init=0 [ 0.000009] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns [ 0.000036] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns [ 0.000104] bcm2835: system timer (irq = 25) [ 0.000751] arch_timer: cp15 timer(s) running at 54.00MHz (phys). [ 0.000772] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns [ 0.000794] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns [ 0.000812] Switching to timer-based delay loop, resolution 18ns [ 0.001066] Console: colour dummy device 80x30 [ 0.001808] printk: console [tty1] enabled [ 0.001874] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) [ 0.001928] pid_max: default: 32768 minimum: 301 [ 0.002110] LSM: Security Framework initializing [ 0.002309] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) [ 0.002355] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) [ 0.003993] Disabling memory control group subsystem [ 0.004135] CPU: Testing write buffer coherency: ok [ 0.004628] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 [ 0.005880] Setting up static identity map for 0x200000 - 0x20003c [ 0.006100] rcu: Hierarchical SRCU implementation. [ 0.007079] smp: Bringing up secondary CPUs ... [ 0.008363] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 [ 0.009772] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 [ 0.011233] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 [ 0.011391] smp: Brought up 1 node, 4 CPUs [ 0.011438] SMP: Total of 4 processors activated (432.00 BogoMIPS). [ 0.011468] CPU: All CPU(s) started in HYP mode. [ 0.011494] CPU: Virtualization extensions available. [ 0.012391] devtmpfs: initialized [ 0.026598] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 [ 0.026870] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.026925] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) [ 0.034278] pinctrl core: initialized pinctrl subsystem [ 0.035354] NET: Registered protocol family 16 [ 0.039557] DMA: preallocated 1024 KiB pool for atomic coherent allocations [ 0.040361] audit: initializing netlink subsys (disabled) [ 0.040642] audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1 [ 0.041264] thermal_sys: Registered thermal governor 'step_wise' [ 0.042003] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. [ 0.042058] hw-breakpoint: maximum watchpoint size is 8 bytes. [ 0.042483] Serial: AMBA PL011 UART driver [ 0.074588] bcm2835-mbox fe00b880.mailbox: mailbox enabled [ 0.090922] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-02-16T14:17:31, variant start [ 0.100936] raspberrypi-firmware soc:firmware: Firmware hash is d6d82cf99bcb3e9a166a34cfde53130957a36bd3 [ 0.145505] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 [ 0.149752] vgaarb: loaded [ 0.150232] SCSI subsystem initialized [ 0.150478] usbcore: registered new interface driver usbfs [ 0.150555] usbcore: registered new interface driver hub [ 0.150641] usbcore: registered new device driver usb [ 0.151383] usb_phy_generic phy: supply vcc not found, using dummy regulator [ 0.153343] clocksource: Switched to clocksource arch_sys_counter [ 1.114354] VFS: Disk quotas dquot_6.6.0 [ 1.114473] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) [ 1.114671] FS-Cache: Loaded [ 1.114903] CacheFiles: Loaded [ 1.116002] simple-framebuffer 3e4e0000.framebuffer: framebuffer at 0x3e4e0000, 0x6e7000 bytes, mapped to 0x(ptrval) [ 1.116047] simple-framebuffer 3e4e0000.framebuffer: format=a8r8g8b8, mode=1824x984x32, linelength=7296 [ 1.125659] Console: switching to colour frame buffer device 228x61 [ 1.134439] simple-framebuffer 3e4e0000.framebuffer: fb0: simplefb registered! [ 1.145142] NET: Registered protocol family 2 [ 1.146063] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) [ 1.146291] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) [ 1.146435] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear) [ 1.146581] TCP: Hash tables configured (established 8192 bind 8192) [ 1.146823] UDP hash table entries: 512 (order: 2, 16384 bytes, linear) [ 1.146931] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) [ 1.147276] NET: Registered protocol family 1 [ 1.148066] RPC: Registered named UNIX socket transport module. [ 1.148147] RPC: Registered udp transport module. [ 1.148212] RPC: Registered tcp transport module. [ 1.148276] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.148364] PCI: CLS 0 bytes, default 64 [ 1.151405] Initialise system trusted keyrings [ 1.151706] workingset: timestamp_bits=14 max_order=20 bucket_order=6 [ 1.160482] zbud: loaded [ 1.162382] FS-Cache: Netfs 'nfs' registered for caching [ 1.163440] NFS: Registering the id_resolver key type [ 1.163535] Key type id_resolver registered [ 1.163598] Key type id_legacy registered [ 1.163774] nfs4filelayout_init: NFSv4 File Layout Driver Registering... [ 1.164910] Key type asymmetric registered [ 1.164976] Asymmetric key parser 'x509' registered [ 1.165221] bounce: pool size: 64 pages [ 1.165309] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) [ 1.168152] io scheduler mq-deadline registered [ 1.170740] io scheduler kyber registered [ 1.178028] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: [ 1.180719] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] [ 1.183532] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 [ 1.186116] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000 [ 1.245448] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) [ 1.248411] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 [ 1.250966] pci_bus 0000:00: root bus resource [bus 00-ff] [ 1.253511] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) [ 1.256183] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 [ 1.258985] pci 0000:00:00.0: PME# supported from D0 D3hot [ 1.264991] PCI: bus0: Fast back to back transfers disabled [ 1.267832] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 [ 1.270391] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] [ 1.273426] pci 0000:01:00.0: PME# supported from D0 D3cold [ 1.279416] PCI: bus1: Fast back to back transfers disabled [ 1.282014] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] [ 1.284615] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] [ 1.287179] pci 0000:00:00.0: PCI bridge to [bus 01] [ 1.289735] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] [ 1.292690] pcieport 0000:00:00.0: enabling device (0140 -> 0142) [ 1.295470] pcieport 0000:00:00.0: PME: Signaling with IRQ 62 [ 1.306675] iproc-rng200 fe104000.rng: hwrng registered [ 1.309554] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) [ 1.313036] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 [ 1.328101] brd: module loaded [ 1.343176] loop: module loaded [ 1.347509] Loading iSCSI transport class v2.0-870. [ 1.352436] libphy: Fixed MDIO Bus: probed [ 1.356736] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 [ 1.373412] libphy: bcmgenet MII bus: probed [ 1.453485] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus [ 1.457132] usbcore: registered new interface driver r8152 [ 1.459639] usbcore: registered new interface driver lan78xx [ 1.462100] usbcore: registered new interface driver smsc95xx [ 1.466171] xhci_hcd 0000:01:00.0: enabling device (0140 -> 0142) [ 1.468603] xhci_hcd 0000:01:00.0: xHCI Host Controller [ 1.470927] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 [ 1.476712] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000030000000890 [ 1.480452] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10 [ 1.482906] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.485284] usb usb1: Product: xHCI Host Controller [ 1.487664] usb usb1: Manufacturer: Linux 5.10.16-v7l+ xhci-hcd [ 1.490091] usb usb1: SerialNumber: 0000:01:00.0 [ 1.493258] hub 1-0:1.0: USB hub found [ 1.495768] hub 1-0:1.0: 1 port detected [ 1.498817] xhci_hcd 0000:01:00.0: xHCI Host Controller [ 1.501186] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 [ 1.503537] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed [ 1.506490] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10 [ 1.508928] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.511357] usb usb2: Product: xHCI Host Controller [ 1.513798] usb usb2: Manufacturer: Linux 5.10.16-v7l+ xhci-hcd [ 1.516225] usb usb2: SerialNumber: 0000:01:00.0 [ 1.519225] hub 2-0:1.0: USB hub found [ 1.521656] hub 2-0:1.0: 4 ports detected [ 1.525773] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) [ 1.528465] dwc_otg: FIQ enabled [ 1.528480] dwc_otg: NAK holdoff enabled [ 1.528494] dwc_otg: FIQ split-transaction FSM enabled [ 1.528513] Module dwc_common_port init [ 1.528975] usbcore: registered new interface driver uas [ 1.531434] usbcore: registered new interface driver usb-storage [ 1.534045] mousedev: PS/2 mouse device common for all mice [ 1.538024] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer [ 1.544061] sdhci: Secure Digital Host Controller Interface driver [ 1.546475] sdhci: Copyright(c) Pierre Ossman [ 1.549546] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe [ 1.552496] sdhci-pltfm: SDHCI platform and OF driver helper [ 1.559027] ledtrig-cpu: registered to indicate activity on CPUs [ 1.561748] hid: raw HID events driver (C) Jiri Kosina [ 1.564330] usbcore: registered new interface driver usbhid [ 1.566678] usbhid: USB HID core driver [ 1.574966] Initializing XFRM netlink socket [ 1.577409] NET: Registered protocol family 17 [ 1.579899] Key type dns_resolver registered [ 1.582739] Registering SWP/SWPB emulation handler [ 1.585202] registered taskstats version 1 [ 1.587487] Loading compiled-in X.509 certificates [ 1.590647] Key type ._fscrypt registered [ 1.592946] Key type .fscrypt registered [ 1.595331] Key type fscrypt-provisioning registered [ 1.609125] uart-pl011 fe201000.serial: there is not valid maps for state default [ 1.611754] uart-pl011 fe201000.serial: cts_event_workaround enabled [ 1.614139] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2 [ 1.623570] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver [ 1.627007] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 [ 1.629354] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated [ 1.661090] of_cfs_init [ 1.663774] of_cfs_init: OK [ 1.682121] mmc1: queuing unknown CIS tuple 0x80 (2 bytes) [ 1.686094] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) [ 1.690029] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) [ 1.695293] mmc1: queuing unknown CIS tuple 0x80 (7 bytes) [ 1.697594] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA [ 1.700525] Waiting for root device PARTUUID=d57429e7-02... [ 1.701776] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) [ 1.751042] random: fast init done [ 1.802871] mmc1: new high speed SDIO card at address 0001 [ 1.814375] mmc0: new ultra high speed DDR50 SDHC card at address 0001 [ 1.817532] mmcblk0: mmc0:0001 GB1QT 29.8 GiB [ 1.821514] mmcblk0: p1 p2 [ 1.860443] EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesystem [ 1.862758] EXT4-fs (mmcblk0p2): write access will be enabled during recovery [ 1.873394] usb 1-1: new high-speed USB device number 2 using xhci_hcd [ 1.951656] EXT4-fs (mmcblk0p2): recovery complete [ 1.956710] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) [ 1.959126] VFS: Mounted root (ext4 filesystem) readonly on device 179:2. [ 1.962353] devtmpfs: mounted [ 1.973828] Freeing unused kernel memory: 2048K [ 1.976453] Run /sbin/init as init process [ 1.978737] with arguments: [ 1.978752] /sbin/init [ 1.978766] with environment: [ 1.978781] HOME=/ [ 1.978795] TERM=linux [ 2.056397] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 [ 2.058797] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 [ 2.061192] usb 1-1: Product: USB2.0 Hub [ 2.065880] hub 1-1:1.0: USB hub found [ 2.068525] hub 1-1:1.0: 4 ports detected [ 2.397523] systemd[1]: System time before build time, advancing clock. [ 2.403396] usb 1-1.1: new high-speed USB device number 3 using xhci_hcd [ 2.504311] NET: Registered protocol family 10 [ 2.508188] Segment Routing with IPv6 [ 2.544368] usb 1-1.1: New USB device found, idVendor=1df7, idProduct=3030, bcdDevice= 2.00 [ 2.546916] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 2.563305] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) [ 2.569802] systemd[1]: Detected architecture arm. [ 2.653404] usb 1-1.2: new high-speed USB device number 4 using xhci_hcd [ 2.659863] systemd[1]: Set hostname to <playground>. [ 2.784487] usb 1-1.2: New USB device found, idVendor=03eb, idProduct=800c, bcdDevice= 1.00 [ 2.787388] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 2.790220] usb 1-1.2: Product: AIRSPY HF+ [ 2.792949] usb 1-1.2: Manufacturer: www.airspy.com [ 2.796151] usb 1-1.2: SerialNumber: AIRSPYHF SN:C852EB5DF5353936 [ 2.903457] usb 1-1.3: new full-speed USB device number 5 using xhci_hcd [ 3.042397] usb 1-1.3: New USB device found, idVendor=046d, idProduct=c52b, bcdDevice=24.01 [ 3.045310] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 3.048036] usb 1-1.3: Product: USB Receiver [ 3.050732] usb 1-1.3: Manufacturer: Logitech [ 3.066733] input: Logitech USB Receiver as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/0003:046D:C52B.0001/input/input0 [ 3.144423] hid-generic 0003:046D:C52B.0001: input,hidraw0: USB HID v1.11 Keyboard [Logitech USB Receiver] on usb-0000:01:00.0-1.3/input0 [ 3.157094] input: Logitech USB Receiver Mouse as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:046D:C52B.0002/input/input1 [ 3.160654] input: Logitech USB Receiver Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:046D:C52B.0002/input/input2 [ 3.243763] input: Logitech USB Receiver System Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:046D:C52B.0002/input/input3 [ 3.247546] hid-generic 0003:046D:C52B.0002: input,hiddev96,hidraw1: USB HID v1.11 Mouse [Logitech USB Receiver] on usb-0000:01:00.0-1.3/input1 [ 3.257514] hid-generic 0003:046D:C52B.0003: hiddev97,hidraw2: USB HID v1.11 Device [Logitech USB Receiver] on usb-0000:01:00.0-1.3/input2 [ 3.395632] random: systemd: uninitialized urandom read (16 bytes read) [ 3.409362] random: systemd: uninitialized urandom read (16 bytes read) [ 3.413688] systemd[1]: Listening on udev Kernel Socket. [ 3.421880] random: systemd: uninitialized urandom read (16 bytes read) [ 3.425794] systemd[1]: Listening on Journal Audit Socket. [ 3.434522] systemd[1]: Listening on Journal Socket. [ 3.442622] systemd[1]: Condition check resulted in Huge Pages File System being skipped. [ 3.454730] systemd[1]: Starting Set the console keyboard layout... [ 3.464633] systemd[1]: Created slice system-getty.slice. [ 3.474013] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. [ 4.212794] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null) [ 4.316562] systemd-journald[127]: Received request to flush runtime journal from PID 1 [ 4.927330] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000 [ 4.930311] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000 [ 4.930932] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000 [ 4.931691] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000 [ 4.991558] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. [ 4.993925] bcm2835_vc_sm_cma_probe: Videocore shared memory driver [ 4.993954] [vc_sm_connected_init]: start [ 4.995373] [vc_sm_connected_init]: installed successfully [ 5.012960] mc: Linux media interface: v0.10 [ 5.021418] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. [ 5.072150] bcm2835_audio bcm2835_audio: card created with 4 channels [ 5.092888] videodev: Linux video capture interface: v2.00 [ 5.115886] bcm2835_audio bcm2835_audio: card created with 4 channels [ 5.161065] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. [ 5.161086] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. [ 5.172307] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. [ 5.190018] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. [ 5.191574] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. [ 5.204168] bcm2835-codec bcm2835-codec: Device registered as /dev/video10 [ 5.204219] bcm2835-codec bcm2835-codec: Loaded V4L2 decode [ 5.208416] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 [ 5.209064] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 [ 5.209532] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 [ 5.209950] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 [ 5.209985] bcm2835-isp bcm2835-isp: Register output node 0 with media controller [ 5.210012] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller [ 5.210035] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller [ 5.210057] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller [ 5.210270] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp [ 5.212980] bcm2835-codec bcm2835-codec: Device registered as /dev/video11 [ 5.213030] bcm2835-codec bcm2835-codec: Loaded V4L2 encode [ 5.225533] bcm2835-codec bcm2835-codec: Device registered as /dev/video12 [ 5.225617] bcm2835-codec bcm2835-codec: Loaded V4L2 isp [ 5.295494] vc4-drm gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4]) [ 5.295522] checking generic (3e4e0000 6e7000) vs hw (0 ffffffffffffffff) [ 5.295540] fb0: switching to vc4drmfb from simple [ 5.296223] Console: switching to colour dummy device 80x30 [ 5.297949] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 0 [ 5.458695] cfg80211: Loading compiled-in X.509 certificates for regulatory database [ 5.507160] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 1 [ 5.514027] Console: switching to colour frame buffer device 240x67 [ 5.545223] vc4-drm gpu: [drm] fb0: vc4drmfb frame buffer device [ 5.558312] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' [ 5.602987] brcmfmac: F1 signature read @0x18000000=0x15264345 [ 5.634606] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 [ 5.635104] usbcore: registered new interface driver brcmfmac [ 5.661034] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.txt failed with error -2 [ 5.913463] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 [ 5.934778] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Jan 4 2021 19:56:29 version 7.45.229 (617f1f5 CY) FWID 01-2dbd9d2e [ 6.294657] logitech-djreceiver 0003:046D:C52B.0003: hiddev96,hidraw0: USB HID v1.11 Device [Logitech USB Receiver] on usb-0000:01:00.0-1.3/input2 [ 6.438655] input: Logitech Wireless Device PID:404d Keyboard as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.2/0003:046D:C52B.0003/0003:046D:404D.0004/input/input5 [ 6.440010] input: Logitech Wireless Device PID:404d Mouse as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.2/0003:046D:C52B.0003/0003:046D:404D.0004/input/input6 [ 6.440610] input: Logitech Wireless Device PID:404d Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.2/0003:046D:C52B.0003/0003:046D:404D.0004/input/input7 [ 6.440965] input: Logitech Wireless Device PID:404d System Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.2/0003:046D:C52B.0003/0003:046D:404D.0004/input/input8 [ 6.441359] hid-generic 0003:046D:404D.0004: input,hidraw1: USB HID v1.11 Keyboard [Logitech Wireless Device PID:404d] on usb-0000:01:00.0-1.3/input2:1 [ 6.444917] input: Logitech Wireless Device PID:4016 Keyboard as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.2/0003:046D:C52B.0003/0003:046D:4016.0005/input/input12 [ 6.452123] input: Logitech Wireless Device PID:4016 Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.2/0003:046D:C52B.0003/0003:046D:4016.0005/input/input13 [ 6.452516] input: Logitech Wireless Device PID:4016 System Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.2/0003:046D:C52B.0003/0003:046D:4016.0005/input/input14 [ 6.452921] hid-generic 0003:046D:4016.0005: input,hidraw2: USB HID v1.11 Keyboard [Logitech Wireless Device PID:4016] on usb-0000:01:00.0-1.3/input2:3 [ 7.062566] input: Logitech K400 Plus as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.2/0003:046D:C52B.0003/0003:046D:404D.0004/input/input18 [ 7.064247] logitech-hidpp-device 0003:046D:404D.0004: input,hidraw1: USB HID v1.11 Keyboard [Logitech K400 Plus] on usb-0000:01:00.0-1.3/input2:1 [ 7.127309] random: crng init done [ 7.127332] random: 7 urandom warning(s) missed due to ratelimiting [ 7.249991] uart-pl011 fe201000.serial: no DMA platform data [ 7.539165] 8021q: 802.1Q VLAN Support v1.8 [ 7.592840] input: Logitech K330 as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.2/0003:046D:C52B.0003/0003:046D:4016.0005/input/input19 [ 7.597324] logitech-hidpp-device 0003:046D:4016.0005: input,hidraw2: USB HID v1.11 Keyboard [Logitech K330] on usb-0000:01:00.0-1.3/input2:3 [ 7.639502] Adding 102396k swap on /var/swap. Priority:-2 extents:1 across:102396k SSFS [ 8.031538] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled [ 8.509411] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) [ 8.509899] bcmgenet fd580000.ethernet eth0: Link is Down [ 12.633709] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx [ 12.633758] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 14.015232] Bluetooth: Core ver 2.22 [ 14.015344] NET: Registered protocol family 31 [ 14.015361] Bluetooth: HCI device and connection manager initialized [ 14.015391] Bluetooth: HCI socket layer initialized [ 14.015413] Bluetooth: L2CAP socket layer initialized [ 14.015449] Bluetooth: SCO socket layer initialized [ 14.024778] Bluetooth: HCI UART driver ver 2.3 [ 14.024801] Bluetooth: HCI UART protocol H4 registered [ 14.024917] Bluetooth: HCI UART protocol Three-wire (H5) registered [ 14.025260] Bluetooth: HCI UART protocol Broadcom registered [ 14.188030] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 [ 14.188041] Bluetooth: BNEP filters: protocol multicast [ 14.188057] Bluetooth: BNEP socket layer initialized [ 25.552828] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready [ 63.219999] ICMPv6: process `dhcpcd' is using deprecated sysctl (syscall) net.ipv6.neigh.eth0.retrans_time - use net.ipv6.neigh.eth0.retrans_time_ms instead [ 1734.916050] bcmgenet fd580000.ethernet eth0: Link is Down [ 1766.706811] usb 1-1.1: reset high-speed USB device number 3 using xhci_hcd [ 1767.096806] usb 1-1.1: reset high-speed USB device number 3 using xhci_hcd [ 1767.421285] usb 1-1.1: USB disconnect, device number 3 [ 1767.736546] usb 1-1.1: new high-speed USB device number 6 using xhci_hcd [ 1767.877523] usb 1-1.1: New USB device found, idVendor=1df7, idProduct=3030, bcdDevice= 2.07 [ 1767.877545] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=1 [ 1767.877563] usb 1-1.1: SerialNumber: 2010053743 [ 1768.846843] usb 1-1.1: reset high-speed USB device number 6 using xhci_hcd [ 1769.226872] usb 1-1.1: reset high-speed USB device number 6 using xhci_hcd [ 1780.777056] usb 1-1.1: reset high-speed USB device number 6 using xhci_hcd [ 1781.057073] usb 1-1.1: reset high-speed USB device number 6 using xhci_hcd [ 2948.045653] logitech-hidpp-device 0003:046D:404D.0004: HID++ 4.1 device connected. root@playground:/home/pi# **Logs** If applicable, add the relevant output from `dmesg` or similar. **Additional context** I have a PI 4B and am experiencing a kworker that hogs the cpu only when using WIFI. I have updated the kernel to 5.10.16-v7l+ and added "dtparam=sd_poll_once=on" to config.txt. I have verified that "sd_poll_once" is active using "dtc -I fs /proc/device-tree" which shows "sd_poll_once = "\0\0\0?non-removable?";". None of these changes fixed the problem. Using top the the first two lines are: 1387 root 20 0 0 0 0 I 21.6 0.0 0:16.66 kworker/u8:2-brcmf_wq/mmc1:0001:1 839 root 20 0 6964 2380 4 S 14.0 0.1 0:18.22 vhusbdarmpi4 The offending kworker always shows as "kworker/u8:2-brcmf_wq/mmc1:0001:1" with the number after "/u8:" changing between 2, 3, and 4. Also the number is followed alternately by "+" and "-" (ie: "u8:2+brcmf" and "u8:2-brcmf"). The process "vhusbdarmpi4" is running as a service started by systemd, it is communicating via WIFI and is running a USBIP protocol. If I use a wired connection instead of WIFI the kworker disappears and the service runs as expected. Thanks, Steve

https://forums.raspberrypi.com/viewtopic.php?t=317429

So, not to make this offtopic too long, after disabling wifi on rpi4 and connecting the system via ethernet, the system is perfectly stable and working as expected.

I hope that this will help anyone who faces unexpected sluggishness of RPI with troubleshooting if they are connected only via a WIFI channel,

system · 1 June 2024 19:11

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.