I need some help from a trained eye in spotting what I’m missing.
Backstory:
- Earlier today HA (core) restarted for no apparent reason. Both core and supervisor logs didn’t record anything beforehand. I only know about it because I happened to be tailing the log file and saw the familiar boot messages out of the corner of my eye while doing something else.
- Then an hour or so later parts of the HA (maybe) stopped responding (this is the second time this has happened in a week). The frontend was working (I could navigate around, but when I went to the Z-wave integration log, there were no z-wave messages being seen like normal when I trigger the motion sensor on and off that I have on my desk in front of me. It’s set to trigger instantly so i can generate messages every few seconds easily for my testing.
So before I rebooted the host, I grabbed the log file. Below is what was in it. I’m looking for help at pointing our the culprit if there is something in it, and more importantly what I should look for the next time this happens. It says out of memory, but that doesn’t really tell me where to look does it?
Setup (on a RPi3B):
Host log file:
[11950.455396] audit: type=1700 audit(1620434123.738:185): dev=vethe04a2d1 prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295
[211449.831765] cp210x ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
[211451.456013] cp210x ttyUSB1: usb_serial_generic_read_bulk_callback - urb stopped: -32
[240459.856787] python3 invoked oom-killer: gfp_mask=0x100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0
[240459.856806] CPU: 3 PID: 80153 Comm: python3 Tainted: G C 5.4.83-v8 #1
[240459.856810] Hardware name: Raspberry Pi 3 Model B Rev 1.2 (DT)
[240459.856815] Call trace:
[240459.856829] dump_backtrace+0x0/0x150
[240459.856835] show_stack+0x24/0x30
[240459.856843] dump_stack+0xd8/0x160
[240459.856851] dump_header+0x48/0x200
[240459.856857] oom_kill_process+0x1c4/0x1d0
[240459.856862] out_of_memory+0xe0/0x2c0
[240459.856874] __alloc_pages_slowpath+0xa08/0xbe0
[240459.856880] __alloc_pages_nodemask+0x2ac/0x330
[240459.856888] __handle_mm_fault+0x43c/0xb60
[240459.856894] handle_mm_fault+0x168/0x1d0
[240459.856902] do_page_fault+0x148/0x4a0
[240459.856907] do_translation_fault+0xb0/0xcc
[240459.856913] do_mem_abort+0x50/0xb0
[240459.856918] el0_da+0x1c/0x20
[240459.856923] Mem-Info:
[240459.856940] active_anon:83322 inactive_anon:84389 isolated_anon:0
[240459.856940] active_file:344 inactive_file:524 isolated_file:0
[240459.856940] unevictable:0 dirty:0 writeback:0 unstable:0
[240459.856940] slab_reclaimable:13977 slab_unreclaimable:19907
[240459.856940] mapped:585 shmem:12 pagetables:3195 bounce:0
[240459.856940] free:3702 free_pcp:71 free_cma:7
[240459.856952] Node 0 active_anon:333288kB inactive_anon:337556kB active_file:1376kB inactive_file:2096kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:2340kB dirty:0kB writeback:0kB shmem:48kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[240459.856967] DMA free:14808kB min:3860kB low:4824kB high:5788kB active_anon:333320kB inactive_anon:337556kB active_file:1560kB inactive_file:2064kB unevictable:0kB writepending:0kB present:970752kB managed:934448kB mlocked:0kB kernel_stack:8096kB pagetables:12780kB bounce:0kB free_pcp:284kB local_pcp:0kB free_cma:28kB
[240459.856973] lowmem_reserve[]: 0 0 0 0
[240459.856991] DMA: 689*4kB (UMEHC) 441*8kB (UMEH) 263*16kB (UEH) 109*32kB (EH) 15*64kB (H) 1*128kB (H) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 15068kB
[240459.857047] 1461 total pagecache pages
[240459.857056] 603 pages in swap cache
[240459.857063] Swap cache stats: add 474561, delete 473954, find 409184/703490
[240459.857069] Free swap = 0kB
[240459.857075] Total swap = 233608kB
[240459.857082] 242688 pages RAM
[240459.857087] 0 pages HighMem/MovableOnly
[240459.857093] 9076 pages reserved
[240459.857099] 16384 pages cma reserved
[240459.857106] Tasks state (memory values in pages):
[240459.857112] [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name
[240459.857139] [ 103] 0 103 56059 140 409600 95 -250 systemd-journal
[240459.857150] [ 122] 0 122 3304 26 53248 292 -1000 systemd-udevd
[240459.857171] [ 282] 1003 282 4492 185 65536 872 0 systemd-resolve
[240459.857182] [ 283] 1004 283 58236 0 81920 168 0 systemd-timesyn
[240459.857193] [ 287] 1001 287 1793 244 45056 50 -900 dbus-daemon
[240459.857204] [ 291] 0 291 280284 852 176128 179 0 NetworkManager
[240459.857214] [ 302] 0 302 58302 9 77824 246 0 rauc
[240459.857226] [ 305] 0 305 75203 0 73728 124 0 rngd
[240459.857237] [ 309] 0 309 2756 47 49152 132 0 systemd-logind
[240459.857248] [ 313] 0 313 2383 71 45056 97 0 wpa_supplicant
[240459.857259] [ 355] 0 355 516 9 28672 18 0 hciattach
[240459.857270] [ 359] 0 359 1859 48 36864 45 0 bluetoothd
[240459.857280] [ 401] 0 401 410183 5803 339968 1087 -500 dockerd
[240459.857291] [ 408] 0 408 626522 2632 356352 861 -500 containerd
[240459.857302] [ 569] 0 569 268512 0 118784 168 -500 docker-proxy
[240459.857312] [ 575] 0 575 325074 363 147456 135 -499 containerd-shim
[240459.857323] [ 590] 0 590 48 0 28672 4 0 s6-svscan
[240459.857334] [ 681] 0 681 48 0 28672 3 0 s6-supervise
[240459.857345] [ 830] 0 830 48 0 28672 4 0 s6-supervise
[240459.857360] [ 833] 0 833 178209 451 94208 214 0 observer
[240459.857371] [ 860] 0 860 351921 1690 233472 318 0 docker
[240459.857382] [ 861] 0 861 917 15 36864 36 0 agetty
[240459.857393] [ 898] 0 898 325490 546 155648 191 -499 containerd-shim
[240459.857404] [ 914] 0 914 48 0 28672 4 0 s6-svscan
[240459.857415] [ 994] 0 994 48 0 28672 4 0 s6-supervise
[240459.857426] [ 1176] 0 1176 48 0 28672 4 0 s6-supervise
[240459.857436] [ 1177] 0 1177 48 0 28672 3 0 s6-supervise
[240459.857447] [ 1179] 0 1179 37409 7475 319488 7328 0 python3
[240459.857457] [ 1180] 0 1180 1092 121 32768 397 0 bash
[240459.857525] [ 1498] 0 1498 325426 380 151552 160 -499 containerd-shim
[240459.857537] [ 1514] 0 1514 48 0 28672 4 0 s6-svscan
[240459.857547] [ 1589] 0 1589 48 0 28672 3 0 s6-supervise
[240459.857558] [ 1738] 0 1738 325074 374 155648 155 -499 containerd-shim
[240459.857569] [ 1760] 0 1760 48 0 28672 5 0 s6-svscan
[240459.857580] [ 1805] 0 1805 48 0 28672 4 0 s6-supervise
[240459.857591] [ 1809] 0 1809 179872 1975 110592 435 0 coredns
[240459.857609] [ 1882] 0 1882 48 0 28672 4 0 s6-supervise
[240459.857621] [ 2099] 0 2099 325426 308 155648 150 -499 containerd-shim
[240459.857632] [ 2125] 0 2125 48 0 28672 6 0 s6-svscan
[240459.857643] [ 2306] 0 2306 44 0 16384 6 0 foreground
[240459.857653] [ 2308] 0 2308 48 0 28672 4 0 s6-supervise
[240459.857664] [ 2323] 0 2323 43 0 16384 4 0 foreground
[240459.857675] [ 2497] 0 2497 410 0 28672 2 0 sleep
[240459.857685] [ 2527] 0 2527 325010 370 155648 125 -499 containerd-shim
[240459.857696] [ 2542] 0 2542 48 0 28672 3 0 s6-supervise
[240459.857707] [ 2543] 0 2543 48 0 28672 3 0 s6-supervise
[240459.857717] [ 2546] 0 2546 23667 121 90112 536 0 pulseaudio
[240459.857729] [ 2549] 0 2549 1079 2 36864 504 0 bash
[240459.857739] [ 2579] 0 2579 48 0 28672 4 0 s6-svscan
[240459.857749] [ 2586] 0 2586 1080 0 36864 503 0 bash
[240459.857760] [ 2587] 0 2587 1282 1 45056 79 0 udevadm
[240459.857770] [ 2623] 0 2623 48 0 28672 3 0 s6-supervise
[240459.857781] [ 2800] 0 2800 48 0 28672 3 0 s6-supervise
[240459.857792] [ 2804] 0 2804 217 11 28672 0 0 mdns-repeater
[240459.857802] [ 2856] 0 2856 323811 0 135168 189 -500 docker-proxy
[240459.857813] [ 2865] 0 2865 343859 342 163840 138 -499 containerd-shim
[240459.857824] [ 2882] 0 2882 48 3 28672 1 0 s6-svscan
[240459.857835] [ 2959] 0 2959 48 0 28672 3 0 s6-supervise
[240459.857845] [ 3193] 0 3193 325074 353 151552 154 -499 containerd-shim
[240459.857860] [ 3241] 0 3241 48 0 28672 5 0 s6-svscan
[240459.857871] [ 3377] 0 3377 48 0 28672 3 0 s6-supervise
[240459.857881] [ 3498] 0 3498 325074 297 147456 131 -499 containerd-shim
[240459.857892] [ 3541] 0 3541 48 0 28672 4 0 s6-svscan
[240459.857903] [ 3685] 0 3685 48 0 28672 4 0 s6-supervise
[240459.857914] [ 3882] 0 3882 48 0 28672 3 0 s6-supervise
[240459.857925] [ 3883] 0 3883 48 0 28672 3 0 s6-supervise
[240459.857935] [ 3885] 0 3885 1061 35 36864 87 0 sshd
[240459.857945] [ 3888] 0 3888 5369 13 77824 4173 0 ttyd
[240459.857956] [ 3986] 0 3986 48 0 28672 4 0 s6-supervise
[240459.857967] [ 3990] 0 3990 75694 10352 811008 2423 0 node
[240459.857980] [ 4339] 0 4339 48 0 28672 4 0 s6-supervise
[240459.857991] [ 4340] 0 4340 48 0 28672 3 0 s6-supervise
[240459.858001] [ 4343] 0 4343 6943 73 90112 334 0 nmbd
[240459.858012] [ 4345] 0 4345 10642 68 114688 479 0 smbd
[240459.858023] [ 4362] 0 4362 10143 74 106496 445 0 smbd-notifyd
[240459.858034] [ 4363] 0 4363 10145 51 106496 468 0 cleanupd
[240459.858045] [ 4681] 0 4681 325362 328 155648 172 -499 containerd-shim
[240459.858056] [ 4724] 0 4724 198 5 28672 4 0 docker-init
[240459.858067] [ 4770] 0 4770 48 0 28672 8 0 s6-svscan
[240459.858078] [ 4799] 0 4799 48 0 28672 4 0 s6-supervise
[240459.858089] [ 4992] 0 4992 325426 370 151552 127 -499 containerd-shim
[240459.858100] [ 5041] 0 5041 48 0 28672 4 0 s6-svscan
[240459.858111] [ 5396] 0 5396 48 0 28672 3 0 s6-supervise
[240459.858121] [ 5577] 0 5577 48 0 28672 4 0 s6-supervise
[240459.858132] [ 5583] 0 5583 7578 137 94208 4540 0 hass-configurat
[240459.858142] [ 5835] 0 5835 305378 0 126976 179 -500 docker-proxy
[240459.858153] [ 5890] 0 5890 325074 341 155648 134 -499 containerd-shim
[240459.858164] [ 5909] 0 5909 198 4 28672 5 0 docker-init
[240459.858174] [ 5971] 0 5971 11823 2203 122880 4635 0 python3
[240459.858184] [ 6333] 0 6333 48 0 28672 4 0 s6-supervise
[240459.858195] [ 6335] 0 6335 48 0 28672 3 0 s6-supervise
[240459.858205] [ 6338] 0 6338 1484 2 36864 208 0 nginx
[240459.858216] [ 6339] 0 6339 15717 14 102400 694 0 php-fpm7
[240459.858231] [ 6735] 100 6735 15717 1 90112 709 0 php-fpm7
[240459.858241] [ 6736] 100 6736 15717 4 90112 708 0 php-fpm7
[240459.858252] [ 6737] 100 6737 15717 4 90112 708 0 php-fpm7
[240459.858262] [ 6738] 65534 6738 15716 4 90112 709 0 php-fpm7
[240459.858272] [ 6739] 65534 6739 15716 3 90112 709 0 php-fpm7
[240459.858283] [ 6741] 0 6741 1541 0 36864 265 0 nginx
[240459.858294] [ 75160] 0 75160 4347 2 65536 125 0 git
[240459.858305] [ 79602] 0 79602 325362 404 151552 122 -499 containerd-shim
[240459.858315] [ 79618] 0 79618 48 0 28672 5 0 s6-svscan
[240459.858326] [ 79663] 0 79663 48 0 28672 3 0 s6-supervise
[240459.858336] [ 79828] 0 79828 48 0 28672 4 0 s6-supervise
[240459.858346] [ 79831] 0 79831 764545 124934 5595136 22663 0 python3
[240459.858357] [ 122931] 0 122931 10706 252 114688 312 0 smbd
[240459.858368] [ 123341] 0 123341 1069 33 40960 99 0 sshd
[240459.858379] [ 123345] 0 123345 894 314 40960 8 0 bash
[240459.858389] [ 123372] 0 123372 411 13 36864 0 0 tail
[240459.858406] [ 126450] 0 126450 410 1 36864 0 0 sleep
[240459.858416] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=f15fb402a18904130ea7617ba8b7756d7b756863d96c3f6a3d570c6512bcf660,mems_allowed=0,global_oom,task_memcg=/docker/f15fb402a18904130ea7617ba8b7756d7b756863d96c3f6a3d570c6512bcf660,task=python3,pid=79831,uid=0
[240459.858971] Out of memory: Killed process 79831 (python3) total-vm:3058180kB, anon-rss:499784kB, file-rss:0kB, shmem-rss:0kB, UID:0 pgtables:5464kB oom_score_adj:0
[240460.101902] oom_reaper: reaped process 79831 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
[244186.150321] cp210x ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32