Posts by tempestnano

    For what it's worth, I mitigated the issue by moving the external HDD to a USB 2.0 port and limiting my download speed to 10 MB/s. It seems the best way to prevent the issue it to not do a lot of I/O, so not ideal at all but at least I can use the system again. I'm still having trouble unrar-ing a large 30 GB files though.

    I am not even sure it is limited to USB usage. I setup a second rpi4 as an nfs, and ran a docker torrent client on Libreelec accessing its share over samba, and I still got the error. This is backed up by this comment on github where a user is able to reliably trigger the error with a script that employs a using a virtual filesystem. Oh, I see that you are already participating in that issue thread.

    My rpi4 running raspbian with the 64-bit kernel handles these docker containers without breaking a sweat. I would very much like to address this somehow, but at this point, I am not sure where to start. It seems that this is unlikely to be fixed in the 32-bit kernel upstream when arm_64bit=1 works in most use cases.

    Edit: Disregard this, this only delayed the problems for an extra hour or so before the oom-killer kicked in.


    I have tried tons of things to fix this, and I believe I have finally cracked it. I am fairly certain that adding these two lines to my autostart.sh has stopped the condition that summons the oom-killer. Naturally, there is still some underlying problem that is merely sidestepped here.

    Code: /storage/.config/autostart.sh
    sysctl vm.dirty_background_ratio=5
    sysctl vm.dirty_ratio=8

    Details:

    I found that before the oom killer was invoked, the kernel process kswapd0 was using %100 cpu. I found that if the caches were flushed via echo 4 > /proc/sys/vm/drop_caches, it resolved the problem temporarily. This led me to mess with the cache ratios to force the system to keep the caches as empty as possible.

    Setup

    • RPi4 4GB
    • 12TB USB 3.0 Drive
    • LE 10 beta
    • Docker

    I am encountering constant oom events when there is plenty of available ram. The oom-killer can fire as often as every 30 seconds, and it loves to kill kodi. I know I can tell it to avoid killing kodi, but the underlying problem would persist. I've encountered this before on 9.2.6, but not nearly as often as on the new build.

    I do a fresh install of LE10, attach my external USB3 drive, add my media libraries and add any docker image that generates lots of disk io (transmission, rsync, medusa, etc), and after a few minutes the oom-killer will begin decimating my processes every few minutes. My rpi4 memory usage never really goes over 1 GB or so (out of 4GB). I have seen the oom events occur even before docker and Kodi loads. I don't believe that memory fragmentation is a problem, as I always have plenty of 4096kB blocks of DMA and HiMem. I have been beating my head against this, and I believe it is possibly related to USB3 disk writes trigger OOM reaper on Pi 4. Any suggestions on how best to try to debug this?

    I really love the design philosophy of LE and I would rather not shift to a normal distro, but other users report a 64 bit kernel alleviates may oom errors. Would it even be possible for me to compile a 64 bit version of LE for the rpi4 knowing that this would force software x264 decoding and loss of widevine?

    Things I have tried:

    • Enabling cgroups and limiting the docker images to only 256MB (limiting works, but oom persists)
    • "sysctl vm.overcommit_memory=2" This causes the system to crash during boot
    • cron job of "echo 4 > /proc/sys/vm/drop_caches" every minute. This reduces the frequency of oom events, but it doesn't stop them.
    • mucking about with "vm.extfrag_threshold, vm.vfs_cache_pressure, swappiness": no real change
    • Adding a massive swap file: It never gets used.
    • Fresh LE10 install on both a large SD card and a usb 3.0 attached ssd.
    • Even without docker, I believe I have seen one or two oom events, but they are rare.

    Thanks!

    Raspberry Pi 4, 9.2.0.

    Cec standby and wake works like a charm for the first few minutes after restarting the Kodi service or manually powering on the TV, but it stops working altogether after a few minutes. The TV will stubbornly stay away or asleep despite what Kodi thinks it is telling it to do. However, if I then go to the command line and manually tell the TV to power on via:

    Code
    LibreELEC:~ # echo 'on 0' | cec-client -s -d 1
    opening a connection to the CEC adapter...

    The TV responds properly and wakes up. Which makes me think that I can rule out the TV as the source of the problem.

    Any help parsing the following debug logs would be appreciated.

    Normal wake from standby

    2019-12-21 17:37:51.371 T:2560471920 DEBUG: CecLogMessage - GetPhysicalAddress - physical address = 1000

    2019-12-21 17:37:51.371 T:2560471920 DEBUG: CecLogMessage - physical address unchanged (1000)

    2019-12-21 17:37:51.996 T:2560471920 DEBUG: CecLogMessage - << powering on 'TV' (0)

    2019-12-21 17:37:51.997 T:2560471920 DEBUG: CecLogMessage - << 10:04

    2019-12-21 17:37:52.057 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> broadcast (F): active source (1000)

    2019-12-21 17:37:52.057 T:2560471920 DEBUG: CecLogMessage - << 1f:82:10:00

    2019-12-21 17:37:52.177 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): menu state 'activated'

    2019-12-21 17:37:52.177 T:2560471920 DEBUG: CecLogMessage - 'menu status' is marked as unsupported feature for device 'TV'

    2019-12-21 17:37:52.711 T:2560471920 DEBUG: CecLogMessage - >> 0f:80:00:00:10:00

    2019-12-21 17:37:52.711 T:2560471920 DEBUG: CecLogMessage - Recorder 1 (1) was already marked as active source

    2019-12-21 17:37:52.711 T:2560471920 DEBUG: CecLogMessage - >> source activated: Recorder 1 (1)

    2019-12-21 17:37:52.712 T:2560471920 DEBUG: CecLogMessage - sending active source message for 'Recorder 1'

    2019-12-21 17:37:52.712 T:2560471920 DEBUG: CecLogMessage - << powering on 'TV' (0)

    2019-12-21 17:37:52.712 T:2560471920 DEBUG: CecLogMessage - << 10:04

    2019-12-21 17:37:52.712 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): routing change (80)

    2019-12-21 17:37:52.802 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> broadcast (F): active source (1000)

    2019-12-21 17:37:52.802 T:2560471920 DEBUG: CecLogMessage - << 1f:82:10:00

    2019-12-21 17:37:52.922 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): menu state 'activated'

    2019-12-21 17:37:52.922 T:2560471920 DEBUG: CecLogMessage - 'menu status' is marked as unsupported feature for device 'TV'

    2019-12-21 17:37:53.368 T:2560471920 DEBUG: CecLogMessage - >> 01:00:04:00

    2019-12-21 17:37:53.368 T:2560471920 DEBUG: CecLogMessage - marking opcode 'image view on' as unsupported feature for device 'TV'

    2019-12-21 17:37:53.368 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): feature abort ( 0)

    2019-12-21 17:37:53.551 T:2560471920 DEBUG: CecLogMessage - >> 0f:84:00:00:00

    2019-12-21 17:37:53.551 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> broadcast (F): physical address 1000

    2019-12-21 17:37:53.551 T:2560471920 DEBUG: CecLogMessage - << 1f:84:10:00:01

    2019-12-21 17:37:53.551 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): report physical address (84)

    2019-12-21 17:37:53.898 T:2560471920 DEBUG: CecLogMessage - >> 0f:87:6d:74:6b

    2019-12-21 17:37:53.898 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> Broadcast (F): vendor id Pulse Eight (1582)

    2019-12-21 17:37:53.898 T:2560471920 DEBUG: CecLogMessage - << 1f:87:00:15:82

    2019-12-21 17:37:53.898 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): device vendor id (87)

    2019-12-21 17:37:55.842 T:2560471920 DEBUG: CecLogMessage - >> 4f:84:20:00:04

    2019-12-21 17:37:55.842 T:2560471920 DEBUG: CecLogMessage - >> Playback 1 (4) -> Broadcast (F): report physical address (84)

    2019-12-21 17:37:55.909 T:2560471920 DEBUG: CecLogMessage - >> 01:83

    2019-12-21 17:37:55.909 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> broadcast (F): physical address 1000

    2019-12-21 17:37:55.910 T:2560471920 DEBUG: CecLogMessage - << 1f:84:10:00:01

    2019-12-21 17:37:55.910 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): give physical address (83)

    2019-12-21 17:37:56.615 T:2560471920 DEBUG: CecLogMessage - >> 01:46

    2019-12-21 17:37:56.615 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): OSD name 'Kodi'

    2019-12-21 17:37:56.616 T:2560471920 DEBUG: CecLogMessage - << 10:47:4b:6f:64:69

    2019-12-21 17:37:56.616 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): give osd name (46)

    2019-12-21 17:37:56.985 T:2560471920 DEBUG: CecLogMessage - >> 4f:87:08:00:46

    2019-12-21 17:37:56.985 T:2560471920 DEBUG: CecLogMessage - >> Playback 1 (4) -> Broadcast (F): device vendor id (87)

    2019-12-21 17:37:57.052 T:2560471920 DEBUG: CecLogMessage - >> 01:8c

    2019-12-21 17:37:57.052 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): vendor id Pulse Eight (1582)

    2019-12-21 17:37:57.052 T:2560471920 DEBUG: CecLogMessage - << 1f:87:00:15:82

    2019-12-21 17:37:57.052 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): give device vendor id (8C)

    2019-12-21 17:37:57.455 T:2560471920 DEBUG: CecLogMessage - >> 01:8f

    2019-12-21 17:37:57.455 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): on

    2019-12-21 17:37:57.455 T:2560471920 DEBUG: CecLogMessage - << 10:90:00

    2019-12-21 17:37:57.455 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): give device power status (8F)

    2019-12-21 17:37:57.610 T:2560471920 DEBUG: CecLogMessage - >> 01:8f

    2019-12-21 17:37:57.610 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): on

    2019-12-21 17:37:57.610 T:2560471920 DEBUG: CecLogMessage - << 10:90:00

    2019-12-21 17:37:57.610 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): give device power status (8F)

    2019-12-21 17:37:57.994 T:2560471920 DEBUG: CecLogMessage - >> 01:8f

    2019-12-21 17:37:57.994 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): on

    2019-12-21 17:37:57.994 T:2560471920 DEBUG: CecLogMessage - << 10:90:00

    2019-12-21 17:37:57.994 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): give device power status (8F)

    2019-12-21 17:37:58.230 T:2560471920 DEBUG: CecLogMessage - >> 0f:86:10:00

    2019-12-21 17:37:58.230 T:2560471920 DEBUG: CecLogMessage - >> TV (0) sets stream path to physical address 1000

    2019-12-21 17:37:58.230 T:2560471920 DEBUG: CecLogMessage - Recorder 1 (1) was already marked as active source

    2019-12-21 17:37:58.230 T:2560471920 DEBUG: CecLogMessage - >> source activated: Recorder 1 (1)

    2019-12-21 17:37:58.230 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> broadcast (F): active source (1000)

    2019-12-21 17:37:58.231 T:2560471920 DEBUG: CecLogMessage - << 1f:82:10:00

    2019-12-21 17:37:58.231 T:2560471920 DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): set stream path (86)

    Failed wake from standby

    2019-12-21 17:43:16.846 T:2560471920 DEBUG: CecLogMessage - Recorder 1 (1) was already marked as active source

    2019-12-21 17:43:16.846 T:2560471920 DEBUG: CecLogMessage - >> source activated: Recorder 1 (1)

    2019-12-21 17:43:16.846 T:2560471920 DEBUG: CecLogMessage - sending active source message for 'Recorder 1'

    2019-12-21 17:43:16.847 T:2560471920 DEBUG: CecLogMessage - << powering on 'TV' (0)

    2019-12-21 17:43:16.847 T:2560471920 DEBUG: CecLogMessage - 'image view on' is marked as unsupported feature for device 'TV'

    2019-12-21 17:43:16.847 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> broadcast (F): active source (1000)

    2019-12-21 17:43:16.847 T:2560471920 DEBUG: CecLogMessage - << 1f:82:10:00

    2019-12-21 17:43:16.876 T:3011833872 DEBUG: ToggleDeviceState - waking up CEC device...

    2019-12-21 17:43:16.966 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): menu state 'activated'

    2019-12-21 17:43:16.966 T:2560471920 DEBUG: CecLogMessage - 'menu status' is marked as unsupported feature for device 'TV'

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - Recorder 1 (1) was already marked as active source

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - >> source activated: Recorder 1 (1)

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - sending active source message for 'Recorder 1'

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - << powering on 'TV' (0)

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - 'image view on' is marked as unsupported feature for device 'TV'

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> broadcast (F): active source (1000)

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - << 1f:82:10:00

    2019-12-21 17:43:17.091 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): menu state 'activated'

    2019-12-21 17:43:17.091 T:2560471920 DEBUG: CecLogMessage - 'menu status' is marked as unsupported feature for device 'TV'

    Failed when using: kodi-send --action=CECActivateSource

    2019-12-21 17:43:16.846 T:2560471920 DEBUG: CecLogMessage - Recorder 1 (1) was already marked as active source

    2019-12-21 17:43:16.846 T:2560471920 DEBUG: CecLogMessage - >> source activated: Recorder 1 (1)

    2019-12-21 17:43:16.846 T:2560471920 DEBUG: CecLogMessage - sending active source message for 'Recorder 1'

    2019-12-21 17:43:16.847 T:2560471920 DEBUG: CecLogMessage - << powering on 'TV' (0)

    2019-12-21 17:43:16.847 T:2560471920 DEBUG: CecLogMessage - 'image view on' is marked as unsupported feature for device 'TV'

    2019-12-21 17:43:16.847 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> broadcast (F): active source (1000)

    2019-12-21 17:43:16.847 T:2560471920 DEBUG: CecLogMessage - << 1f:82:10:00

    2019-12-21 17:43:16.876 T:3011833872 DEBUG: ToggleDeviceState - waking up CEC device...

    2019-12-21 17:43:16.966 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): menu state 'activated'

    2019-12-21 17:43:16.966 T:2560471920 DEBUG: CecLogMessage - 'menu status' is marked as unsupported feature for device 'TV'

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - Recorder 1 (1) was already marked as active source

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - >> source activated: Recorder 1 (1)

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - sending active source message for 'Recorder 1'

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - << powering on 'TV' (0)

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - 'image view on' is marked as unsupported feature for device 'TV'

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> broadcast (F): active source (1000)

    2019-12-21 17:43:16.971 T:2560471920 DEBUG: CecLogMessage - << 1f:82:10:00

    2019-12-21 17:43:17.091 T:2560471920 DEBUG: CecLogMessage - << Recorder 1 (1) -> TV (0): menu state 'activated'

    2019-12-21 17:43:17.091 T:2560471920 DEBUG: CecLogMessage - 'menu status' is marked as unsupported feature for device 'TV'

    2019-12-21 17:43:17.879 T:3011833872 DEBUG: ------ Window Deinit () ------