Pogoplug V3, Oxnas, oom-killer, 18.xx.x

woodsnake · July 20, 2019, 4:57pm

Hello Community,

I have updated my Pogoplug V3 from Lede 17.01.4 to Openwrt 18.06.4.
Now I get always an oom-killer if I install some software.

e.g. opkg update; opkg install gcc

Parsing documentation for coderay-1.1.2
[  733.516454] ruby2.5-bin invoked oom-killer: gfp_mask=0x14080c0(GFP_KERNEL|__GFP_ZERO), nodemask=(null),  order=0, oom_score_adj=0
[  733.528128] CPU: 0 PID: 872 Comm: ruby2.5-bin Not tainted 4.14.131 #0
[  733.534538] Hardware name: Generic DT based system
[  733.539310] Function entered at [<c0109878>] from [<c010556c>]
[  733.545116] Function entered at [<c010556c>] from [<c04e8850>]
[  733.550924] Function entered at [<c04e8850>] from [<c018f98c>]
[  733.556728] Function entered at [<c018f98c>] from [<c018eba8>]
[  733.562534] Function entered at [<c018eba8>] from [<c018f84c>]
[  733.568340] Function entered at [<c018f84c>] from [<c0193d88>]
[  733.574146] Function entered at [<c0193d88>] from [<c01b1e98>]
[  733.579952] Function entered at [<c01b1e98>] from [<c01b4be4>]
[  733.585758] Function entered at [<c01b4be4>] from [<c0109ee0>]
[  733.591564] Function entered at [<c0109ee0>] from [<c01012a0>]
[  733.597370] Function entered at [<c01012a0>] from [<c010645c>]
[  733.603174] Exception stack(0xc227ffb0 to 0xc227fff8)
[  733.608202] ffa0:                                     01dff000 00000001 01e01000 00002001
[  733.616345] ffc0: 01dff000 01dff000 b6f6dbbc 00000001 00ddb184 076be629 01dfd800 b6f5b021
[  733.624486] ffe0: b6f6dbb0 be959de8 be159dcc b6f0ff60 60000010 ffffffff
[  733.631157] Mem-Info:
[  733.633443] active_anon:7681 inactive_anon:5 isolated_anon:0
[  733.633443]  active_file:50 inactive_file:89 isolated_file:0
[  733.633443]  unevictable:0 dirty:0 writeback:0 unstable:0
[  733.633443]  slab_reclaimable:298 slab_unreclaimable:1500
[  733.633443]  mapped:143 shmem:13 pagetables:64 bounce:0
[  733.633443]  free:19836 free_pcp:0 free_cma:16309
[  733.665338] Node 0 active_anon:30724kB inactive_anon:20kB active_file:200kB inactive_file:356kB unevictable:0kB isolated(anon):0kB isolao
----> [  733.687459] Normal free:79284kB min:16384kB low:20480kB high:24576kB active_anon:30724kB inactive_anon:20kB    active_file:200kB inactive_fB
[  733.715174] lowmem_reserve[]: 0 0
[  733.718487] Normal: 83*4kB (UMEC) 52*8kB (UE) 27*16kB (UEC) 19*32kB (UME) 11*64kB (UMEC) 6*128kB (UMEC) 3*256kB (UME) 3*512kB (UEC) 2*10B
[  733.736002] 170 total pagecache pages
[  733.739645] 0 pages in swap cache
[  733.742942] Swap cache stats: add 0, delete 0, find 0/0
[  733.748185] Free swap  = 0kB
[  733.751050] Total swap = 0kB
[  733.753909] 32768 pages RAM
[  733.756746] 0 pages HighMem/MovableOnly
[  733.760563] 1990 pages reserved
[  733.763686] 16384 pages cma reserved
[  733.767285] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
[  733.775836] [  166]     0   166      255        9       3       0        0             0 ubusd
[  733.784460] [  172]     0   172      280        6       3       0        0             0 ash
[  733.792862] [  350]     0   350      264       47       3       0        0             0 logd
[  733.801397] [  369]     0   369      343       24       3       0        0             0 rpcd
[  733.809935] [  389]     0   389      289        7       3       0        0             0 mdadm
[  733.818557] [  416]     0   416      216        6       3       0        0             0 dropbear
[  733.827435] [  471]     0   471      395       38       4       0        0             0 netifd
[  733.836144] [  593]     0   593      282       11       3       0        0             0 uhttpd
[  733.844858] [  718]     0   718      281       11       3       0        0             0 ntpd
[  733.853347] [  872]     0   872     9956     7498      21       0        0             0 ruby2.5-bin
[  733.862479] [  924]     0   924      280        6       3       0        0             0 udhcpc
[  733.871191] [ 1047]     0  1047      232       24       3       0        0             0 dropbear
[  733.880076] [ 1048]     0  1048      280        6       3       0        0             0 ash
[  733.888540] [ 1059]     0  1059      280        9       3       0        0             0 top
[  733.896985] Out of memory: Kill process 872 (ruby2.5-bin) score 236 or sacrifice child
[  733.904944] Killed process 872 (ruby2.5-bin) total-vm:39824kB, anon-rss:29472kB, file-rss:516kB, shmem-rss:4kB
[  733.929679] oom_reaper: reaped process 872 (ruby2.5-bin), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Killed

Free RAM are available. (Look at the ----> in the log )

Does anyone know where is the failure ?

takimata · July 20, 2019, 5:06pm

It does what it says on the tin: The system is running out of memory, and it kills Ruby. 128 MB of RAM might not quite be enough to run Ruby in the first place.

woodsnake · July 20, 2019, 5:27pm

Hi takimata,

I have run Ruby on other chips e.g. Marvell Kirkwood with 128 MB RAM.
And on Version 17.01.4 it worked too.

The oom-killer comes with too, if i setup a new system an install gcc.
Please explain me, what says the marked row.

takimata · July 20, 2019, 9:48pm

oom-killer is invoked if an application is asking for more memory than the system can provide. This means that in the report, your system can very well still show lots of free memory.

Which doesn't mean that everything is completely right here. The longer I stare at your report, the more I would rather pass this on to someone more intimately familiar with Linux memory management. Some values look particularly funky to me, for example

[  733.763686] 16384 pages cma reserved

... the system reserving a whopping half of the RAM for Contiguous Memory Allocation.

What I can comment on is the fact that the OXNAS target received a complete overhaul between 17.01 and 18.06, and that not everything went completely smooth in the beginning. You may very well have stumbled onto something here.

woodsnake · July 20, 2019, 9:53pm

Thank you for your help