| Summary: | [2.5 M1 RC3] LTP Test: LTP tests hung up on NUC7 and not able to complete full run | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [QA/Testing] Runtime Testing | Reporter: | yeoh ee peng <ee.peng.yeoh> | ||||
| Component: | general | Assignee: | Anuj Mittal <anuj.mittal> | ||||
| Status: | RESOLVED WONTFIX | QA Contact: | |||||
| Severity: | normal | ||||||
| Priority: | Medium | CC: | juro.bystricky, randy.macleod, stephano | ||||
| Version: | 2.5 | ||||||
| Target Milestone: | 2.5 M4 | ||||||
| Hardware: | NUC | ||||||
| OS: | Multiple | ||||||
| Whiteboard: | |||||||
| OS type for building Yocto: | --- | Type of Regression: | --- | ||||
| Verified: | Documentation change: | No (bug/feature does not impact docs) | |||||
| Attachments: |
|
||||||
Hello Yeoh Ee Peng, in order to determine the severity of the problem, can you please answer the following few questions: Is this a regression? Is this problem reproducible or just occasional? How did you determine the tests hung, (as opposed to just taking too long)? Does the test pass with other images (other than core-image-lsb-sdk-genericx86-64) ? Were there any errors displayed in console (there are none in the log)? Was there anything unusual in dmesg? If so, can you attach the log? Thanks. Hi Juro,
Please see you answer.
Is this a regression? No, this was the first time we are running LTP test on NUC7. Previously we run LTP test on NUC6 where LTP test was running fine.
Is this problem reproducible or just occasional? This problem was reproducible, it was hung every time we run LTP test on NUC7. We did run LTP test on NUC7 using core-image-lsb-sdk-genericx86-64 from 2.4.1.rc1 and 2.5 M1 rc3, where can hung issue happen.
How did you determine the tests hung, (as opposed to just taking too long)? The SSH connection to the DUT return with message: packet_write_wait: Connection to 172.30.199.34 port 22: Broken pipe. Furthermore, we no longer able to SSH into the DUT, and the mouse and keyboard connected to the DUT are not responding anymore.
Does the test pass with other images (other than core-image-lsb-sdk-genericx86-64)? Not sure, we have not run LTP test on other image. We shall run the LTP test to core-image-lsb-genericx86-64.hddimg, will post the result after done.
Were there any errors displayed in console (there are none in the log)?
Was there anything unusual in dmesg? If so, can you attach the log?
Moment before the DUT hung, we captured the below dmesg where it show: Out of memory.
[ 2876.151468] min_free_kbytes invoked oom-killer: gfp_mask=0x24280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=0, order=0, oom_score_adj=0
[ 2876.152621] min_free_kbytes cpuset=/ mems_allowed=0
[ 2876.153740] CPU: 0 PID: 15997 Comm: min_free_kbytes Not tainted 4.9.49-yocto-standard #1
[ 2876.154859] Hardware name: Intel Corporation NUC7i7BNH/NUC7i7BNB, BIOS BNKBL357.86A.0049.2017.0724.1541 07/24/2017
[ 2876.155934] ffffc900086d7bf8 ffffffff813ca2ec ffffc900086d7dd0 ffff880107418000
[ 2876.157006] ffffc900086d7c70 ffffffff81181215 0000000000000000 0000000000000000
[ 2876.158076] ffffffff81e2d340 0000000000000015 ffff880107418000 0000000000000000
[ 2876.159179] Call Trace:
[ 2876.160262] [<ffffffff813ca2ec>] dump_stack+0x4d/0x71
[ 2876.161335] [<ffffffff81181215>] dump_header+0x7b/0x208
[ 2876.162410] [<ffffffff8112bc0a>] oom_kill_process+0x26a/0x410
[ 2876.163428] [<ffffffff8112c0c3>] out_of_memory+0x103/0x2a0
[ 2876.164469] [<ffffffff811305a8>] __alloc_pages_nodemask+0x998/0xea0
[ 2876.165467] [<ffffffff8115a635>] handle_mm_fault+0x945/0xe70
[ 2876.166468] [<ffffffff8116022d>] ? do_mmap+0x27d/0x480
[ 2876.167445] [<ffffffff8104b7ac>] __do_page_fault+0x23c/0x500
[ 2876.168407] [<ffffffff8104ba7c>] do_page_fault+0xc/0x10
[ 2876.169359] [<ffffffff81907d02>] page_fault+0x22/0x30
[ 2876.170310] Mem-Info:
[ 2876.171329] active_anon:1980699 inactive_anon:626 isolated_anon:0
active_file:40 inactive_file:38 isolated_file:55
unevictable:572 dirty:20 writeback:7 unstable:0
slab_reclaimable:3237 slab_unreclaimable:4882
mapped:517 shmem:692 pagetables:4374 bounce:0
free:13614 free_pcp:127 free_cma:0
[ 2876.177089] Node 0 active_anon:7922796kB inactive_anon:2504kB active_file:160kB inactive_file:300kB unevictable:2288kB isolated(anon):0kB isolated(file):220kB mapped:2068kB dirty:80kB writeback:28kB shmem:2768kB writeback_tmp:0kB unstable:0kB pages_scanned:850 all_unreclaimable? no
[ 2876.179018] DMA free:15888kB min:20kB low:32kB high:44kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15988kB managed:15888kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 2876.181150] lowmem_reserve[]: 0 1863 7850 7850
[ 2876.182147] DMA32 free:26552kB min:2684kB low:4588kB high:6492kB active_anon:1877232kB inactive_anon:0kB active_file:16kB inactive_file:0kB unevictable:0kB writepending:0kB present:1987056kB managed:1907712kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:3668kB bounce:0kB free_pcp:120kB local_pcp:0kB free_cma:0kB
[ 2876.184203] lowmem_reserve[]: 0 0 5987 5987
[ 2876.185230] Normal free:11816kB min:8628kB low:14756kB high:20884kB active_anon:6045564kB inactive_anon:2504kB active_file:160kB inactive_file:268kB unevictable:2288kB writepending:108kB present:6275072kB managed:6130712kB mlocked:2288kB slab_reclaimable:12916kB slab_unreclaimable:19528kB kernel_stack:2416kB pagetables:13828kB bounce:0kB free_pcp:732kB local_pcp:16kB free_cma:0kB
[ 2876.187395] lowmem_reserve[]: 0 0 0 0
[ 2876.188468] DMA: 2*4kB (U) 3*8kB (U) 3*16kB (U) 0*32kB 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (U) 3*4096kB (M) = 15888kB
[ 2876.189585] DMA32: 2*4kB (U) 4*8kB (UM) 5*16kB (UM) 2*32kB (U) 0*64kB 3*128kB (UM) 0*256kB 1*512kB (M) 1*1024kB (M) 0*2048kB 6*4096kB (UM) = 26680kB
[ 2876.190684] Normal: 588*4kB (UME) 230*8kB (UME) 258*16kB (UME) 36*32kB (UME) 30*64kB (E) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 11392kB
[ 2876.191798] 1343 total pagecache pages
[ 2876.192891] 0 pages in swap cache
[ 2876.194046] Swap cache stats: add 0, delete 0, find 0/0
[ 2876.195087] Free swap = 0kB
[ 2876.196099] Total swap = 0kB
[ 2876.197235] 2069529 pages RAM
[ 2876.198291] 0 pages HighMem/MovableOnly
[ 2876.199331] 55951 pages reserved
[ 2876.200359] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name
[ 2876.201364] [ 438] 0 438 7725 888 14 3 0 -1000 udevd
[ 2876.202391] [ 782] 999 782 4947 356 13 3 0 0 dbus-daemon
[ 2876.203375] [ 785] 0 785 10579 439 20 3 0 0 connmand
[ 2876.204345] [ 793] 0 793 11436 240 26 3 0 0 wpa_supplicant
[ 2876.205376] [ 838] 0 838 7121 360 18 3 0 -1000 sshd
[ 2876.206388] [ 844] 998 844 2699 400 10 3 0 0 rpcbind
[ 2876.207305] [ 857] 0 857 1087 358 8 3 0 -1000 watchdog
[ 2876.208214] [ 863] 996 863 4376 505 13 3 0 0 rpc.statd
[ 2876.209122] [ 868] 0 868 1073 23 6 3 0 0 acpid
[ 2876.210019] [ 874] 0 874 4218 376 12 3 0 0 atd
[ 2876.210899] [ 892] 0 892 4873 270 13 3 0 0 bluetoothd
[ 2876.211769] [ 918] 0 918 4947 128 12 3 0 0 rpc.mountd
[ 2876.212636] [ 938] 0 938 1625 25 8 3 0 0 xinetd
[ 2876.213490] [ 944] 997 944 7576 503 20 3 0 0 avahi-daemon
[ 2876.214395] [ 945] 997 945 7545 62 19 3 0 0 avahi-daemon
[ 2876.215254] [ 951] 0 951 5145 241 13 3 0 0 ofonod
[ 2876.216113] [ 962] 0 962 7038 113 16 3 0 0 lighttpd
[ 2876.216945] [ 967] 0 967 2310 350 9 3 0 0 crond
[ 2876.217763] [ 982] 0 982 9344 512 18 3 0 0 tcf-agent
[ 2876.218597] [ 989] 0 989 12539 495 29 3 0 0 login
[ 2876.219399] [ 1011] 0 1011 4776 724 14 3 0 0 sh
[ 2876.220164] [ 1017] 0 1017 10778 559 26 3 0 0 sshd
[ 2876.220953] [ 1019] 0 1019 10778 535 26 3 0 0 sshd
[ 2876.221730] [ 1021] 0 1021 4776 701 14 3 0 0 sh
[ 2876.222504] [ 1024] 0 1024 3191 426 11 3 0 0 sftp-server
[ 2876.223246] [ 1033] 0 1033 10778 561 26 3 0 0 sshd
[ 2876.224014] [ 1035] 0 1035 4776 706 14 4 0 0 sh
[ 2876.224779] [ 1047] 0 1047 9269 1144 22 3 0 0 compliance_test
[ 2876.225550] [ 1052] 0 1052 2410 56 9 3 0 0 sh
[ 2876.226288] [ 1053] 0 1053 2575 612 10 3 0 0 runltp
[ 2876.227057] [ 1187] 0 1187 1101 426 6 3 0 0 ltp-pan
[ 2876.227825] [27434] 0 27434 2122 388 10 4 0 0 syslogd
[ 2876.228592] [15991] 0 15991 1600 175 8 3 0 0 min_free_kbytes
[ 2876.229333] [15992] 0 15992 1633 323 8 3 0 0 min_free_kbytes
[ 2876.230104] [15997] 0 15997 1977185 1975656 3866 10 0 0 min_free_kbytes
[ 2876.230872] Out of memory: Kill process 15997 (min_free_kbytes) score 953 or sacrifice child
[ 2876.231679] Killed process 15997 (min_free_kbytes) total-vm:7908740kB, anon-rss:7901792kB, file-rss:832kB, shmem-rss:0kB
[ 2881.574376] min_free_kbytes invoked oom-killer: gfp_mask=0x24280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=0, order=0, oom_score_adj=0
[ 2881.575561] min_free_kbytes cpuset=/ mems_allowed=0
[ 2881.576738] CPU: 2 PID: 16001 Comm: min_free_kbytes Not tainted 4.9.49-yocto-standard #1
[ 2881.577914] Hardware name: Intel Corporation NUC7i7BNH/NUC7i7BNB, BIOS BNKBL357.86A.0049.2017.0724.1541 07/24/2017
[ 2881.579105] ffffc900086f7bf8 ffffffff813ca2ec ffffc900086f7dd0 ffff880107418000
[ 2881.580308] ffffc900086f7c70 ffffffff81181215 0000000000000000 0000000000000000
[ 2881.581511] ffffffff81e2d340 0000000000000015 ffff880107418000 0000000000000000
[ 2881.582682] Call Trace:
[ 2881.583787] [<ffffffff813ca2ec>] dump_stack+0x4d/0x71
[ 2881.584854] [<ffffffff81181215>] dump_header+0x7b/0x208
[ 2881.585880] [<ffffffff8112bc0a>] oom_kill_process+0x26a/0x410
[ 2881.586762] [<ffffffff8112c0c3>] out_of_memory+0x103/0x2a0
[ 2881.587606] [<ffffffff811305a8>] __alloc_pages_nodemask+0x998/0xea0
[ 2881.588415] [<ffffffff8115a635>] handle_mm_fault+0x945/0xe70
[ 2881.589208] [<ffffffff8116022d>] ? do_mmap+0x27d/0x480
[ 2881.589959] [<ffffffff8104b7ac>] __do_page_fault+0x23c/0x500
[ 2881.590671] [<ffffffff8104ba7c>] do_page_fault+0xc/0x10
[ 2881.591328] [<ffffffff81907d02>] page_fault+0x22/0x30
[ 2881.591939] Mem-Info:
[ 2881.592537] active_anon:1981533 inactive_anon:626 isolated_anon:0
active_file:75 inactive_file:49 isolated_file:0
unevictable:572 dirty:5 writeback:0 unstable:0
slab_reclaimable:3159 slab_unreclaimable:4882
mapped:525 shmem:692 pagetables:4375 bounce:0
free:12784 free_pcp:0 free_cma:0
[ 2881.595973] Node 0 active_anon:7926132kB inactive_anon:2504kB active_file:300kB inactive_file:196kB unevictable:2288kB isolated(anon):0kB isolated(file):0kB mapped:2100kB dirty:20kB writeback:0kB shmem:2768kB writeback_tmp:0kB unstable:0kB pages_scanned:756 all_unreclaimable? yes
[ 2881.597134] DMA free:15888kB min:20kB low:32kB high:44kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15988kB managed:15888kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 2881.598424] lowmem_reserve[]: 0 1863 7850 7850
[ 2881.599058] DMA32 free:26628kB min:2684kB low:4588kB high:6492kB active_anon:1877120kB inactive_anon:0kB active_file:64kB inactive_file:24kB unevictable:0kB writepending:0kB present:1987056kB managed:1907712kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:3664kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 2881.600434] lowmem_reserve[]: 0 0 5987 5987
[ 2881.601169] Normal free:8620kB min:8628kB low:14756kB high:20884kB active_anon:6049012kB inactive_anon:2504kB active_file:128kB inactive_file:232kB unevictable:2288kB writepending:16kB present:6275072kB managed:6130712kB mlocked:2288kB slab_reclaimable:12636kB slab_unreclaimable:19528kB kernel_stack:2432kB pagetables:13836kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 2881.602689] lowmem_reserve[]: 0 0 0 0
[ 2881.603478] DMA: 2*4kB (U) 3*8kB (U) 3*16kB (U) 0*32kB 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (U) 3*4096kB (M) = 15888kB
[ 2881.604332] DMA32: 9*4kB (UM) 10*8kB (UM) 14*16kB (UM) 8*32kB (UM) 4*64kB (U) 3*128kB (UM) 2*256kB (U) 1*512kB (M) 2*1024kB (UM) 1*2048kB (U) 5*4096kB (M) = 26836kB
[ 2881.605176] Normal: 288*4kB (UME) 62*8kB (UME) 28*16kB (UME) 13*32kB (UME) 12*64kB (UME) 12*128kB (ME) 12*256kB (ME) 2*512kB (E) 0*1024kB 0*2048kB 0*4096kB = 8912kB
[ 2881.606057] 1340 total pagecache pages
[ 2881.606882] 0 pages in swap cache
[ 2881.607704] Swap cache stats: add 0, delete 0, find 0/0
[ 2881.608531] Free swap = 0kB
[ 2881.609356] Total swap = 0kB
[ 2881.610178] 2069529 pages RAM
[ 2881.610997] 0 pages HighMem/MovableOnly
[ 2881.611823] 55951 pages reserved
[ 2881.612684] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name
[ 2881.613532] [ 438] 0 438 7725 888 14 3 0 -1000 udevd
[ 2881.614367] [ 782] 999 782 4947 356 13 3 0 0 dbus-daemon
[ 2881.615220] [ 785] 0 785 10579 439 20 3 0 0 connmand
[ 2881.616080] [ 793] 0 793 11436 240 26 3 0 0 wpa_supplicant
[ 2881.616939] [ 838] 0 838 7121 360 18 3 0 -1000 sshd
[ 2881.617842] [ 844] 998 844 2699 400 10 3 0 0 rpcbind
[ 2881.618673] [ 857] 0 857 1087 358 8 3 0 -1000 watchdog
[ 2881.619563] [ 863] 996 863 4376 505 13 3 0 0 rpc.statd
[ 2881.620415] [ 868] 0 868 1073 23 6 3 0 0 acpid
[ 2881.621276] [ 874] 0 874 4218 376 12 3 0 0 atd
[ 2881.622144] [ 892] 0 892 4873 270 13 3 0 0 bluetoothd
[ 2881.623003] [ 918] 0 918 4947 128 12 3 0 0 rpc.mountd
[ 2881.623919] [ 938] 0 938 1625 25 8 3 0 0 xinetd
[ 2881.624759] [ 944] 997 944 7576 503 20 3 0 0 avahi-daemon
[ 2881.625760] [ 945] 997 945 7545 62 19 3 0 0 avahi-daemon
[ 2881.626605] [ 951] 0 951 5145 241 13 3 0 0 ofonod
[ 2881.627445] [ 962] 0 962 7038 113 16 3 0 0 lighttpd
[ 2881.628286] [ 967] 0 967 2310 350 9 3 0 0 crond
[ 2881.629223] [ 982] 0 982 9344 341 18 3 0 0 tcf-agent
[ 2881.630032] [ 989] 0 989 12539 495 29 3 0 0 login
[ 2881.630832] [ 1011] 0 1011 4776 724 14 3 0 0 sh
[ 2881.631743] [ 1017] 0 1017 10778 463 26 3 0 0 sshd
[ 2881.632522] [ 1019] 0 1019 10778 487 26 3 0 0 sshd
[ 2881.633290] [ 1021] 0 1021 4776 701 14 3 0 0 sh
[ 2881.634055] [ 1024] 0 1024 3191 426 11 3 0 0 sftp-server
[ 2881.634821] [ 1033] 0 1033 10778 442 26 3 0 0 sshd
[ 2881.635581] [ 1035] 0 1035 4776 706 14 4 0 0 sh
[ 2881.636335] [ 1047] 0 1047 9269 1144 22 3 0 0 compliance_test
[ 2881.637137] [ 1052] 0 1052 2410 56 9 3 0 0 sh
[ 2881.637909] [ 1053] 0 1053 2575 612 10 3 0 0 runltp
[ 2881.638685] [ 1187] 0 1187 1101 426 6 3 0 0 ltp-pan
[ 2881.639462] [27434] 0 27434 2122 380 10 4 0 0 syslogd
[ 2881.640228] [15991] 0 15991 1600 175 8 3 0 0 min_free_kbytes
[ 2881.641000] [15992] 0 15992 1633 241 8 3 0 0 min_free_kbytes
[ 2881.641772] [16001] 0 16001 1977953 1976446 3867 10 0 0 min_free_kbytes
[ 2881.642547] Out of memory: Kill process 16001 (min_free_kbytes) score 953 or sacrifice child
[ 2881.643328] Killed process 16001 (min_free_kbytes) total-vm:7911812kB, anon-rss:7904952kB, file-rss:832kB, shmem-rss:0kB
[ 2883.557356] min_free_kbytes invoked oom-killer: gfp_mask=0x24280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=0, order=0, oom_score_adj=0
[ 2883.559066] min_free_kbytes cpuset=/ mems_allowed=0
[ 2883.560814] CPU: 0 PID: 16002 Comm: min_free_kbytes Not tainted 4.9.49-yocto-standard #1
[ 2883.562544] Hardware name: Intel Corporation NUC7i7BNH/NUC7i7BNB, BIOS BNKBL357.86A.0049.2017.0724.1541 07/24/2017
[ 2883.563721] ffffc900086ffbf8 ffffffff813ca2ec ffffc900086ffdd0 ffff880107418000
[ 2883.564571] ffffc900086ffc70 ffffffff81181215 0000000000000000 0000000000000000
[ 2883.565473] ffffffff81e2d340 0000000000000015 ffff880107418000 0000000000000000
[ 2883.566346] Call Trace:
[ 2883.567091] [<ffffffff813ca2ec>] dump_stack+0x4d/0x71
[ 2883.567845] [<ffffffff81181215>] dump_header+0x7b/0x208
[ 2883.568567] [<ffffffff8112bc0a>] oom_kill_process+0x26a/0x410
[ 2883.569254] [<ffffffff8112c0c3>] out_of_memory+0x103/0x2a0
[ 2883.570061] [<ffffffff811305a8>] __alloc_pages_nodemask+0x998/0xea0
[ 2883.570722] [<ffffffff8115a635>] handle_mm_fault+0x945/0xe70
[ 2883.571372] [<ffffffff8116022d>] ? do_mmap+0x27d/0x480
[ 2883.571957] [<ffffffff8104b7ac>] __do_page_fault+0x23c/0x500
[ 2883.572555] [<ffffffff8104ba7c>] do_page_fault+0xc/0x10
[ 2883.573100] [<ffffffff81907d02>] page_fault+0x22/0x30
[ 2883.573741] Mem-Info:
[ 2883.574303] active_anon:1978793 inactive_anon:626 isolated_anon:0
active_file:68 inactive_file:46 isolated_file:0
unevictable:572 dirty:0 writeback:1 unstable:0
slab_reclaimable:3159 slab_unreclaimable:4882
mapped:472 shmem:692 pagetables:4369 bounce:0
free:15580 free_pcp:42 free_cma:0
[ 2883.577357] Node 0 active_anon:7915172kB inactive_anon:2504kB active_file:272kB inactive_file:184kB unevictable:2288kB isolated(anon):0kB isolated(file):0kB mapped:1888kB dirty:0kB writeback:4kB shmem:2768kB writeback_tmp:0kB unstable:0kB pages_scanned:6162 all_unreclaimable? yes
[ 2883.578648] DMA free:15888kB min:44kB low:56kB high:68kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15988kB managed:15888kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 2883.579945] lowmem_reserve[]: 0 1863 7850 7850
[ 2883.580595] DMA32 free:29320kB min:5372kB low:7276kB high:9180kB active_anon:1874532kB inactive_anon:0kB active_file:0kB inactive_file:136kB unevictable:0kB writepending:0kB present:1987056kB managed:1907712kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:3664kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 2883.582046] lowmem_reserve[]: 0 0 5987 5987
[ 2883.582789] Normal free:17112kB min:17264kB low:23392kB high:29520kB active_anon:6040640kB inactive_anon:2504kB active_file:272kB inactive_file:56kB unevictable:2288kB writepending:4kB present:6275072kB managed:6130712kB mlocked:2288kB slab_reclaimable:12636kB slab_unreclaimable:19528kB kernel_stack:2432kB pagetables:13812kB bounce:0kB free_pcp:168kB local_pcp:0kB free_cma:0kB
[ 2883.584333] lowmem_reserve[]: 0 0 0 0
[ 2883.585085] DMA: 2*4kB (U) 3*8kB (U) 3*16kB (U) 0*32kB 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (U) 3*4096kB (M) = 15888kB
[ 2883.586037] DMA32: 7*4kB (UM) 13*8kB (UM) 8*16kB (UM) 6*32kB (U) 2*64kB (U) 1*128kB (U) 2*256kB (UM) 1*512kB (U) 1*1024kB (U) 1*2048kB (U) 6*4096kB (M) = 29380kB
[ 2883.586921] Normal: 68*4kB (UE) 89*8kB (UE) 24*16kB (ME) 12*32kB (UME) 12*64kB (UME) 8*128kB (E) 5*256kB (ME) 2*512kB (E) 1*1024kB (M) 1*2048kB (U) 2*4096kB (M) = 17112kB
[ 2883.587913] 1282 total pagecache pages
[ 2883.588722] 0 pages in swap cache
[ 2883.589679] Swap cache stats: add 0, delete 0, find 0/0
[ 2883.590558] Free swap = 0kB
[ 2883.591493] Total swap = 0kB
[ 2883.592343] 2069529 pages RAM
[ 2883.593176] 0 pages HighMem/MovableOnly
[ 2883.594135] 55951 pages reserved
[ 2883.594965] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name
[ 2883.595971] [ 438] 0 438 7725 888 14 3 0 -1000 udevd
[ 2883.596824] [ 782] 999 782 4947 356 13 3 0 0 dbus-daemon
[ 2883.597838] [ 785] 0 785 10579 439 20 3 0 0 connmand
[ 2883.598705] [ 793] 0 793 11436 240 26 3 0 0 wpa_supplicant
[ 2883.599538] [ 838] 0 838 7121 360 18 3 0 -1000 sshd
[ 2883.600403] [ 844] 998 844 2699 400 10 3 0 0 rpcbind
[ 2883.601257] [ 857] 0 857 1087 358 8 3 0 -1000 watchdog
[ 2883.602113] [ 863] 996 863 4376 505 13 3 0 0 rpc.statd
[ 2883.602970] [ 868] 0 868 1073 23 6 3 0 0 acpid
[ 2883.603824] [ 874] 0 874 4218 376 12 3 0 0 atd
[ 2883.604678] [ 892] 0 892 4873 270 13 3 0 0 bluetoothd
[ 2883.605536] [ 918] 0 918 4947 128 12 3 0 0 rpc.mountd
[ 2883.606391] [ 938] 0 938 1625 25 8 3 0 0 xinetd
[ 2883.607244] [ 944] 997 944 7576 503 20 3 0 0 avahi-daemon
[ 2883.608103] [ 945] 997 945 7545 62 19 3 0 0 avahi-daemon
[ 2883.608958] [ 951] 0 951 5145 241 13 3 0 0 ofonod
[ 2883.609812] [ 962] 0 962 7038 113 16 3 0 0 lighttpd
[ 2883.610686] [ 967] 0 967 2310 350 9 3 0 0 crond
[ 2883.611522] [ 982] 0 982 9344 263 18 3 0 0 tcf-agent
[ 2883.612343] [ 989] 0 989 12539 495 29 3 0 0 login
[ 2883.613151] [ 1011] 0 1011 4776 724 14 3 0 0 sh
[ 2883.613958] [ 1017] 0 1017 10778 463 26 3 0 0 sshd
[ 2883.614754] [ 1019] 0 1019 10778 487 26 3 0 0 sshd
[ 2883.615536] [ 1021] 0 1021 4776 701 14 3 0 0 sh
[ 2883.616314] [ 1024] 0 1024 3191 426 11 3 0 0 sftp-server
[ 2883.617095] [ 1033] 0 1033 10778 442 26 3 0 0 sshd
[ 2883.617867] [ 1035] 0 1035 4776 706 14 4 0 0 sh
[ 2883.618638] [ 1047] 0 1047 9269 1144 22 3 0 0 compliance_test
[ 2883.619417] [ 1052] 0 1052 2410 56 9 3 0 0 sh
[ 2883.620192] [ 1053] 0 1053 2575 612 10 3 0 0 runltp
[ 2883.620966] [ 1187] 0 1187 1101 426 6 3 0 0 ltp-pan
[ 2883.621740] [27434] 0 27434 2122 380 10 4 0 0 syslogd
[ 2883.622513] [15991] 0 15991 1600 175 8 3 0 0 min_free_kbytes
[ 2883.623286] [15992] 0 15992 1633 323 8 3 0 0 min_free_kbytes
[ 2883.624065] [16002] 0 16002 1975393 1973796 3862 10 0 0 min_free_kbytes
[ 2883.624820] Out of memory: Kill process 16002 (min_free_kbytes) score 952 or sacrifice child
[ 2883.625629] Killed process 16002 (min_free_kbytes) total-vm:7901572kB, anon-rss:7894352kB, file-rss:832kB, shmem-rss:0kB
[ 2883.799123] oom_reaper: reaped process 16002 (min_free_kbytes), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
[ 2885.357330] min_free_kbytes invoked oom-killer: gfp_mask=0x24280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=0, order=0, oom_score_adj=0
[ 2885.359054] min_free_kbytes cpuset=/ mems_allowed=0
[ 2885.360814] CPU: 1 PID: 16003 Comm: min_free_kbytes Not tainted 4.9.49-yocto-standard #1
[ 2885.362531] Hardware name: Intel Corporation NUC7i7BNH/NUC7i7BNB, BIOS BNKBL357.86A.0049.2017.0724.1541 07/24/2017
[ 2885.363548] ffffc900086ffbf8 ffffffff813ca2ec ffffc900086ffdd0 ffff88010741f2c0
[ 2885.364393] ffffc900086ffc70 ffffffff81181215 0000000000000000 0000000000000000
[ 2885.365204] ffffffff81e2d340 0000000000000015 ffff88010741f2c0 0000000000000000
[ 2885.365967] Call Trace:
[ 2885.366737] [<ffffffff813ca2ec>] dump_stack+0x4d/0x71
[ 2885.367439] [<ffffffff81181215>] dump_header+0x7b/0x208
[ 2885.368138] [<ffffffff8112bc0a>] oom_kill_process+0x26a/0x410
[ 2885.368844] [<ffffffff8112c0c3>] out_of_memory+0x103/0x2a0
[ 2885.369483] [<ffffffff811305a8>] __alloc_pages_nodemask+0x998/0xea0
[ 2885.370140] [<ffffffff8115a635>] handle_mm_fault+0x945/0xe70
[ 2885.370764] [<ffffffff8116022d>] ? do_mmap+0x27d/0x480
[ 2885.371319] [<ffffffff8104b7ac>] __do_page_fault+0x23c/0x500
[ 2885.371862] [<ffffffff8104ba7c>] do_page_fault+0xc/0x10
[ 2885.372412] [<ffffffff81907d02>] page_fault+0x22/0x30
[ 2885.372951] Mem-Info:
[ 2885.373474] active_anon:1955488 inactive_anon:626 isolated_anon:0
active_file:49 inactive_file:51 isolated_file:0
unevictable:572 dirty:2 writeback:0 unstable:0
slab_reclaimable:3159 slab_unreclaimable:4882
mapped:555 shmem:692 pagetables:4310 bounce:0
free:38759 free_pcp:181 free_cma:0
[ 2885.376436] Node 0 active_anon:7821952kB inactive_anon:2504kB active_file:196kB inactive_file:204kB unevictable:2288kB isolated(anon):0kB isolated(file):0kB mapped:2220kB dirty:8kB writeback:0kB shmem:2768kB writeback_tmp:0kB unstable:0kB pages_scanned:1794 all_unreclaimable? yes
[ 2885.377553] DMA free:15888kB min:228kB low:284kB high:340kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15988kB managed:15888kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[ 2885.378830] lowmem_reserve[]: 0 1863 7850 7850
[ 2885.379477] DMA32 free:51292kB min:27384kB low:34228kB high:41072kB active_anon:1852440kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:1987056kB managed:1907712kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:3604kB bounce:0kB free_pcp:248kB local_pcp:0kB free_cma:0kB
[ 2885.380931] lowmem_reserve[]: 0 0 5987 5987
[ 2885.381661] Normal free:87856kB min:88012kB low:110012kB high:132012kB active_anon:5969508kB inactive_anon:2504kB active_file:264kB inactive_file:228kB unevictable:2288kB writepending:8kB present:6275072kB managed:6130712kB mlocked:2288kB slab_reclaimable:12636kB slab_unreclaimable:19528kB kernel_stack:2432kB pagetables:13636kB bounce:0kB free_pcp:476kB local_pcp:284kB free_cma:0kB
[ 2885.383198] lowmem_reserve[]: 0 0 0 0
[ 2885.383992] DMA: 2*4kB (U) 3*8kB (U) 3*16kB (U) 0*32kB 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (U) 3*4096kB (M) = 15888kB
[ 2885.384843] DMA32: 2*4kB (U) 4*8kB (U) 5*16kB (U) 2*32kB (UM) 4*64kB (UM) 6*128kB (UM) 0*256kB 2*512kB (UM) 2*1024kB (UM) 1*2048kB (U) 11*4096kB (M) = 51384kB
[ 2885.385707] Normal: 172*4kB (UME) 21*8kB (UE) 26*16kB (UE) 10*32kB (E) 12*64kB (UME) 10*128kB (UME) 5*256kB (ME) 4*512kB (UE) 1*1024kB (U) 1*2048kB (M) 19*4096kB (M) = 87864kB
[ 2885.386608] 1357 total pagecache pages
[ 2885.387459] 0 pages in swap cache
[ 2885.388297] Swap cache stats: add 0, delete 0, find 0/0
[ 2885.389138] Free swap = 0kB
[ 2885.389987] Total swap = 0kB
[ 2885.390852] 2069529 pages RAM
[ 2885.391685] 0 pages HighMem/MovableOnly
[ 2885.392556] 55951 pages reserved
[ 2885.393388] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name
[ 2885.394241] [ 438] 0 438 7725 888 14 3 0 -1000 udevd
[ 2885.395102] [ 782] 999 782 4947 356 13 3 0 0 dbus-daemon
[ 2885.395960] [ 785] 0 785 10579 439 20 3 0 0 connmand
[ 2885.396826] [ 793] 0 793 11436 216 26 3 0 0 wpa_supplicant
[ 2885.397689] [ 838] 0 838 7121 360 18 3 0 -1000 sshd
[ 2885.398559] [ 844] 998 844 2699 400 10 3 0 0 rpcbind
[ 2885.399424] [ 857] 0 857 1087 358 8 3 0 -1000 watchdog
[ 2885.400278] [ 863] 996 863 4376 505 13 3 0 0 rpc.statd
[ 2885.401132] [ 868] 0 868 1073 23 6 3 0 0 acpid
[ 2885.401967] [ 874] 0 874 4218 376 12 3 0 0 atd
[ 2885.402861] [ 892] 0 892 4873 270 13 3 0 0 bluetoothd
[ 2885.403727] [ 918] 0 918 4947 128 12 3 0 0 rpc.mountd
[ 2885.404627] [ 938] 0 938 1625 25 8 3 0 0 xinetd
[ 2885.405489] [ 944] 997 944 7576 503 20 3 0 0 avahi-daemon
[ 2885.406376] [ 945] 997 945 7545 62 19 3 0 0 avahi-daemon
[ 2885.407227] [ 951] 0 951 5145 241 13 3 0 0 ofonod
[ 2885.408056] [ 962] 0 962 7038 113 16 3 0 0 lighttpd
[ 2885.408910] [ 967] 0 967 2310 350 9 3 0 0 crond
[ 2885.409744] [ 982] 0 982 9344 232 18 3 0 0 tcf-agent
[ 2885.410603] [ 989] 0 989 12539 495 29 3 0 0 login
[ 2885.411414] [ 1011] 0 1011 4776 724 14 3 0 0 sh
[ 2885.412220] [ 1017] 0 1017 10778 463 26 3 0 0 sshd
[ 2885.413022] [ 1019] 0 1019 10778 487 26 3 0 0 sshd
[ 2885.413803] [ 1021] 0 1021 4776 701 14 3 0 0 sh
[ 2885.414588] [ 1024] 0 1024 3191 426 11 3 0 0 sftp-server
[ 2885.415367] [ 1033] 0 1033 10778 442 26 3 0 0 sshd
[ 2885.416111] [ 1035] 0 1035 4776 706 14 4 0 0 sh
[ 2885.416892] [ 1047] 0 1047 9269 1144 22 3 0 0 compliance_test
[ 2885.417669] [ 1052] 0 1052 2410 56 9 3 0 0 sh
[ 2885.418436] [ 1053] 0 1053 2575 612 10 3 0 0 runltp
[ 2885.419196] [ 1187] 0 1187 1101 426 6 3 0 0 ltp-pan
[ 2885.419940] [27434] 0 27434 2122 380 10 4 0 0 syslogd
[ 2885.420744] [15991] 0 15991 1600 175 8 3 0 0 min_free_kbytes
[ 2885.421519] [15992] 0 15992 1633 285 8 3 0 0 min_free_kbytes
[ 2885.422311] [16003] 0 16003 1952097 1950456 3817 10 0 0 min_free_kbytes
[ 2885.423072] Out of memory: Kill process 16003 (min_free_kbytes) score 941 or sacrifice child
[ 2885.423824] Killed process 16003 (min_free_kbytes) total-vm:7808388kB, anon-rss:7800928kB, file-rss:896kB, shmem-rss:0kB
[ 2885.592252] oom_reaper: reaped process 16003 (min_free_kbytes), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
(In reply to comment #2) > Is this a regression? No, this was the first time we are running LTP test on > NUC7. Previously we run LTP test on NUC6 where LTP test was running fine. > Just to clarify, the very same image core-image-lsb-sdk-genericx86-64 runs LTP test just fine using NUC6 but has problems with NUC7? Not all NUC7 have the same amount of memory installed. Can you update this report with HW info regarding your NUC7? Thanks Yes the same image core-image-lsb-sdk-genericx86-64 runs LTP test just fine using NUC6 but has problems with NUC7. The NUC7 memory installed is 8GB while the NUC6 memory installed is 16GB. Do you suspect the issue here is related to total memory available? (In reply to comment #5) > Yes the same image core-image-lsb-sdk-genericx86-64 runs LTP test just fine > using NUC6 but has problems with NUC7. > The NUC7 memory installed is 8GB while the NUC6 memory installed is 16GB. > Do you suspect the issue here is related to total memory available? My NUC7 has 8GB DRAM as well. I built my own NUC image, and successfully ran all tests (some failed, but that is not a new issue here). (The LTP test is a new one, with "meltdown" test as well.) Not clear anymore what the NEEDINFO is. where exactly did you get the image for nuc (core-image-lsb-sdk-genericx86-64)? We get the core-image-lsb-sdk-genericx86-64 from https://autobuilder.yocto.io/pub/releases/yocto-2.5_M1.rc3 I downloaded https://autobuilder.yocto.io/pub/releases/yocto-2.5_M2.rc1/machines/genericx86-64-lsb/core-image-lsb-sdk-genericx86-64.wic placed in on a flash drive: sudo dd if=core-image-lsb-sdk-genericx86-64.wic of=/dev/sde And booted nuc7 with the image Then I ran the test: # /opt/ltp/runltp The test ran for several hours, but eventually finished. (I did not try to run 2.5_M1 builds, as they have been superseded) Do you still experience crashes with 2.5_M2_rc1 builds? Hi Juro, I tested recently using lsb-sdk image from 2.5 M2 rc1 on both NUC6 and NUC7. It was still the passing on NUC6 and hung on NUC7. I am not sure why it behave differently and it seems that I need to identify how we can consistently reproduce this hung issue on NUC7. Do you think we shall close this ticket for now as I try to identify the root cause or way to consistently reproduce this? (In reply to comment #11) > Hi Juro, > > I tested recently using lsb-sdk image from 2.5 M2 rc1 on both NUC6 and NUC7. > It was still the passing on NUC6 and hung on NUC7. > > I am not sure why it behave differently and it seems that I need to identify > how we can consistently reproduce this hung issue on NUC7. > > Do you think we shall close this ticket for now as I try to identify the > root cause or way to consistently reproduce this? Is it possible to try a different NUC7? Hi Juro, We have added 2 new NUC7 for testing. Unfortunately the result is mixing, 1 NUC7 inside office hung during the LTP test while 1 NUC7 inside the lab was able to complete LTP test. While we are not able to consistently reproduce this hung issue, let me close this ticket first, we will monitor this during our QA cycle. Hope this make sense. Closed as it was not able to consistently reproduce the hung issue. QA will monitor this for up coming release cycle. Anuj volunteered to dig deeper into this... I checked the NUC in question and the test that hangs is float_power. It's trying to execute 20 * 6 threads and hangs while executing read/write syscall for *.ref files that it uses. It works reliably if I reduce the number of threads to 15 * 6. export LTPTEST=/opt/ltp /opt/ltp/testcases/bin/float_power -v The log attached is probably not related to this failure. min_free_kbytes in isolation works fine and it is supposed to eat up all the memory to test min_free_kbytes tune setting in kernel. I will check this with latest kernel on this NUC. It works 1 out of 3 times for me, so that could be a reason why we see this on some setups and not on others. strace output shows that it is a race between different threads doing writes to a file & float computation threads performing reads on those files. Works just fine if I add a sleep(1) before start of every float computation thread. We should just reduce the count of threads here since that isn't important to testing this particular use case. Ee Peng mentioned that he is going to revise the tests that we run in future so he will take this into consideration as well. Ee Peng will update the tests. |
Created attachment 4181 [details] LTP log Boot up NUC with core-image-lsb-sdk-genericx86-64, run LTP test suite but not able to complete LTP full tests.