Rpi4 hung tasks

[matteoraggi]

Hi to all, I found hung tasks that not permit to shut down the rpi4 and sometiems I can't reboot too.
tmpfs was checked and is not full. and the SD card passed a test and an fsck.
and the load is stuck at 4.0 or higher: top - 00:46:07 up 1:24, 3 users, load average: 4.01, 4.10, 4.08:

Code: Select all

[  243.674357] INFO: task kworker/1:1:32 blocked for more than 120 seconds.
[  243.674364]       Tainted: G         C        4.19.75-v7l+ #1270
[  243.674368] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.674373] kworker/1:1     D    0    32      2 0x00000000
[  243.674396] Workqueue: events get_values_poll [raspberrypi_hwmon]
[  243.674418] [<c0997424>] (__schedule) from [<c0997a94>] (schedule+0x50/0xa8)
[  243.674428] [<c0997a94>] (schedule) from [<c0997ef0>] (schedule_preempt_disabled+0x18/0x1c)
[  243.674437] [<c0997ef0>] (schedule_preempt_disabled) from [<c0998fa0>] (__mutex_lock.constprop.5+0x1a8/0x590)
[  243.674446] [<c0998fa0>] (__mutex_lock.constprop.5) from [<c09994a4>] (__mutex_lock_slowpath+0x1c/0x20)
[  243.674454] [<c09994a4>] (__mutex_lock_slowpath) from [<c0999504>] (mutex_lock+0x5c/0x60)
[  243.674463] [<c0999504>] (mutex_lock) from [<c08109d0>] (rpi_firmware_transaction+0x54/0xd0)
[  243.674471] [<c08109d0>] (rpi_firmware_transaction) from [<c0810b8c>] (rpi_firmware_property_list+0x140/0x2b0)
[  243.674478] [<c0810b8c>] (rpi_firmware_property_list) from [<c0810d78>] (rpi_firmware_property+0x7c/0xfc)
[  243.674486] [<c0810d78>] (rpi_firmware_property) from [<bf2b00c0>] (get_values_poll+0x4c/0x15c [raspberrypi_hwmon])
[  243.674505] [<bf2b00c0>] (get_values_poll [raspberrypi_hwmon]) from [<c023db40>] (process_one_work+0x170/0x458)
[  243.674513] [<c023db40>] (process_one_work) from [<c023de84>] (worker_thread+0x5c/0x5a4)
[  243.674520] [<c023de84>] (worker_thread) from [<c0244170>] (kthread+0x138/0x168)
[  243.674528] [<c0244170>] (kthread) from [<c02010ac>] (ret_from_fork+0x14/0x28)
[  243.674532] Exception stack(0xefa2ffb0 to 0xefa2fff8)
[  243.674537] ffa0:                                     00000000 00000000 00000000 00000000
[  243.674543] ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[  243.674548] ffe0: 00000000 00000000 00000000 00000000 00000013 00000000

[jamesh]

What versions are you using? Have you done an rpi_update recently?

[matteoraggi]

rpi_update? Not that I know of.
I recently ran apt update and apt dist-upgrade.
Running Raspbian Buster 10.1.
and kernel
Linux raspberrypi 4.19.75-v7l+ #1270 SMP Tue Sep 24 18:51:41 BST 2019 armv7l GNU/Linux.

[Seketh]

I have the same issue with mono.

In my case, it's rclone that hangs the application until the move command (upload) is finished:

Code: Select all

[16955.612275] INFO: task mono:1347 blocked for more than 120 seconds.
[16955.612280]       Tainted: G         C O      4.19.75-v7l+ #1270
[16955.612284] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[16955.612289] mono            D    0  1347      1 0x00000001
[16955.612314] [<c0997424>] (__schedule) from [<c0997a94>] (schedule+0x50/0xa8)
[16955.612344] [<c0997a94>] (schedule) from [<bf764aa8>] (__fuse_request_send+0x1e8/0x2c0 [fuse])
[16955.612379] [<bf764aa8>] (__fuse_request_send [fuse]) from [<bf764bd4>] (fuse_request_send+0x54/0x58 [fuse])
[16955.612411] [<bf764bd4>] (fuse_request_send [fuse]) from [<bf76e858>] (fuse_flush+0x144/0x17c [fuse])
[16955.612434] [<bf76e858>] (fuse_flush [fuse]) from [<c03abd98>] (filp_close+0x40/0x8c)
[16955.612444] [<c03abd98>] (filp_close) from [<c03d09e8>] (__close_fd+0x7c/0xa0)
[16955.612454] [<c03d09e8>] (__close_fd) from [<c03ad324>] (sys_close+0x30/0x58)
[16955.612462] [<c03ad324>] (sys_close) from [<c0201000>] (ret_fast_syscall+0x0/0x28)
[16955.612467] Exception stack(0xc5d31fa8 to 0xc5d31ff0)
[16955.612472] 1fa0:                   0000000b b0ffd9cc 0000000b b0fff4b4 00000000 00000000
[16955.612478] 1fc0: 0000000b b0ffd9cc 00425350 00000006 014bb070 00000000 00000000 b0ffdb50
[16955.612482] 1fe0: 00000002 b0ffd9b0 00000000 b6ee031c

At first I thought it was just an I/O issue, given how slow the SD card is, but rclone is caching the uploads on an external HDD. I even tried moving /root to external, but had the same issue, so I don't see a way to solve this.

[jamesh]

I have the same issue with mono.

In my case, it's rclone that hangs the application until the move command (upload) is finished:

Code: Select all

[16955.612275] INFO: task mono:1347 blocked for more than 120 seconds.
[16955.612280]       Tainted: G         C O      4.19.75-v7l+ #1270
[16955.612284] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[16955.612289] mono            D    0  1347      1 0x00000001
[16955.612314] [<c0997424>] (__schedule) from [<c0997a94>] (schedule+0x50/0xa8)
[16955.612344] [<c0997a94>] (schedule) from [<bf764aa8>] (__fuse_request_send+0x1e8/0x2c0 [fuse])
[16955.612379] [<bf764aa8>] (__fuse_request_send [fuse]) from [<bf764bd4>] (fuse_request_send+0x54/0x58 [fuse])
[16955.612411] [<bf764bd4>] (fuse_request_send [fuse]) from [<bf76e858>] (fuse_flush+0x144/0x17c [fuse])
[16955.612434] [<bf76e858>] (fuse_flush [fuse]) from [<c03abd98>] (filp_close+0x40/0x8c)
[16955.612444] [<c03abd98>] (filp_close) from [<c03d09e8>] (__close_fd+0x7c/0xa0)
[16955.612454] [<c03d09e8>] (__close_fd) from [<c03ad324>] (sys_close+0x30/0x58)
[16955.612462] [<c03ad324>] (sys_close) from [<c0201000>] (ret_fast_syscall+0x0/0x28)
[16955.612467] Exception stack(0xc5d31fa8 to 0xc5d31ff0)
[16955.612472] 1fa0:                   0000000b b0ffd9cc 0000000b b0fff4b4 00000000 00000000
[16955.612478] 1fc0: 0000000b b0ffd9cc 00425350 00000006 014bb070 00000000 00000000 b0ffdb50
[16955.612482] 1fe0: 00000002 b0ffd9b0 00000000 b6ee031c

At first I thought it was just an I/O issue, given how slow the SD card is, but rclone is caching the uploads on an external HDD. I even tried moving /root to external, but had the same issue, so I don't see a way to solve this.

Sounds like a bug in rclone.

[matteoraggi]

To create the os, I was using balena etcher without clean the sd cards with SD CARD FORMATTER (windows 10), doing that instead then it works all perfectly. and the SD card was having noobs inside by default.

[jamesh]

To create the os, I was using balena etcher without clean the sd cards with SD CARD FORMATTER (windows 10), doing that instead then it works all perfectly. and the SD card was having noobs inside by default.

With etcher and the standard Raspbian image there is no need to format the card first.

If using NOOBS then it does need to be formatted.

[swahren]

Hi to all, I found hung tasks that not permit to shut down the rpi4 and sometiems I can't reboot too.
tmpfs was checked and is not full. and the SD card passed a test and an fsck.
and the load is stuck at 4.0 or higher: top - 00:46:07 up 1:24, 3 users, load average: 4.01, 4.10, 4.08:

Code: Select all

[  243.674357] INFO: task kworker/1:1:32 blocked for more than 120 seconds.
[  243.674364]       Tainted: G         C        4.19.75-v7l+ #1270
[  243.674368] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.674373] kworker/1:1     D    0    32      2 0x00000000
[  243.674396] Workqueue: events get_values_poll [raspberrypi_hwmon]
[  243.674418] [<c0997424>] (__schedule) from [<c0997a94>] (schedule+0x50/0xa8)
[  243.674428] [<c0997a94>] (schedule) from [<c0997ef0>] (schedule_preempt_disabled+0x18/0x1c)
[  243.674437] [<c0997ef0>] (schedule_preempt_disabled) from [<c0998fa0>] (__mutex_lock.constprop.5+0x1a8/0x590)
[  243.674446] [<c0998fa0>] (__mutex_lock.constprop.5) from [<c09994a4>] (__mutex_lock_slowpath+0x1c/0x20)
[  243.674454] [<c09994a4>] (__mutex_lock_slowpath) from [<c0999504>] (mutex_lock+0x5c/0x60)
[  243.674463] [<c0999504>] (mutex_lock) from [<c08109d0>] (rpi_firmware_transaction+0x54/0xd0)
[  243.674471] [<c08109d0>] (rpi_firmware_transaction) from [<c0810b8c>] (rpi_firmware_property_list+0x140/0x2b0)
[  243.674478] [<c0810b8c>] (rpi_firmware_property_list) from [<c0810d78>] (rpi_firmware_property+0x7c/0xfc)
[  243.674486] [<c0810d78>] (rpi_firmware_property) from [<bf2b00c0>] (get_values_poll+0x4c/0x15c [raspberrypi_hwmon])
[  243.674505] [<bf2b00c0>] (get_values_poll [raspberrypi_hwmon]) from [<c023db40>] (process_one_work+0x170/0x458)
[  243.674513] [<c023db40>] (process_one_work) from [<c023de84>] (worker_thread+0x5c/0x5a4)
[  243.674520] [<c023de84>] (worker_thread) from [<c0244170>] (kthread+0x138/0x168)
[  243.674528] [<c0244170>] (kthread) from [<c02010ac>] (ret_from_fork+0x14/0x28)
[  243.674532] Exception stack(0xefa2ffb0 to 0xefa2fff8)
[  243.674537] ffa0:                                     00000000 00000000 00000000 00000000
[  243.674543] ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[  243.674548] ffe0: 00000000 00000000 00000000 00000000 00000013 00000000

Interesting. The VC firmware doesn't reply (maybe crashed). The firmware version might be helpful, but more important what causing this issue.

Does it always happen so soon after boot?

[matteoraggi]

Here the error trying to compile vlc 4.0 on raspbian buster:

Code: Select all

 CC       input/vlm_event.lo
  CC       input/vlmshell.lo
  CCLD     libvlccore.la
/usr/bin/ld: input/.libs/es_out.o: in function `decoder_on_new_audio_stats':
/home/pi/vlc-4.0.0-dev/src/input/es_out.c:379: undefined reference to `__atomic_fetch_add_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/es_out.c:381: undefined reference to `__atomic_fetch_add_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/es_out.c:383: undefined reference to `__atomic_fetch_add_8'
/usr/bin/ld: input/.libs/es_out.o: in function `decoder_on_new_video_stats':
/home/pi/vlc-4.0.0-dev/src/input/es_out.c:354: undefined reference to `__atomic_fetch_add_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/es_out.c:356: undefined reference to `__atomic_fetch_add_8'
/usr/bin/ld: input/.libs/es_out.o:/home/pi/vlc-4.0.0-dev/src/input/es_out.c:358: more undefined references to `__atomic_fetch_add_8' follow
/usr/bin/ld: input/.libs/stats.o: in function `input_stats_Create':
/home/pi/vlc-4.0.0-dev/src/input/stats.c:62: undefined reference to `__atomic_store_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/stats.c:63: undefined reference to `__atomic_store_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/stats.c:63: undefined reference to `__atomic_store_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/stats.c:64: undefined reference to `__atomic_store_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/stats.c:65: undefined reference to `__atomic_store_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/stats.c:66: undefined reference to `__atomic_store_8'
/usr/bin/ld: input/.libs/stats.o:/home/pi/vlc-4.0.0-dev/src/input/stats.c:67: more undefined references to `__atomic_store_8' follow
/usr/bin/ld: input/.libs/stats.o: in function `input_stats_Compute':
/home/pi/vlc-4.0.0-dev/src/input/stats.c:93: undefined reference to `__atomic_load_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/stats.c:95: undefined reference to `__atomic_load_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/stats.c:99: undefined reference to `__atomic_load_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/stats.c:101: undefined reference to `__atomic_load_8'
/usr/bin/ld: /home/pi/vlc-4.0.0-dev/src/input/stats.c:103: undefined reference to `__atomic_load_8'
/usr/bin/ld: input/.libs/stats.o:/home/pi/vlc-4.0.0-dev/src/input/stats.c:107: more undefined references to `__atomic_load_8' follow
collect2: error: ld returned 1 exit status
make[3]: *** [Makefile:2668: libvlccore.la] Error 1
make[3]: Leaving directory '/home/pi/vlc-4.0.0-dev/src'
make[2]: *** [Makefile:2143: all] Error 2
make[2]: Leaving directory '/home/pi/vlc-4.0.0-dev/src'
make[1]: *** [Makefile:1569: all-recursive] Error 1
make[1]: Leaving directory '/home/pi/vlc-4.0.0-dev'
make: *** [Makefile:1454: all] Error 2