Closed Bug 1104507 Opened 11 years ago Closed 7 years ago

[tarako] current app was killed by system due to lowmem_shrink

Categories

(Firefox OS Graveyard :: Stability, defect)

Product:
Firefox OS Graveyard
Component:
Stability
Platform:
ARM
Gonk (Firefox OS)
Type:
defect
Priority:
Not set
Severity:
major

Tracking

(Not tracked)

Status:
RESOLVED WONTFIX

People

(Reporter: dave.xu, Unassigned)

Details

Attachments

(3 files)

main.log
1.73 MB, text/x-log
Details
kernel.log
178.75 KB, text/x-log
Details
main.log
1.92 MB, text/x-log
Details
Attached file main.log —
step: 1.open music and play 2.click ‘home’ to let it play in backgroud 3.open gallory to browse picture and enlarge the picture. apearence: the screen stumble,and music stop. This bug is submited by our customer, I read the log,know gallery and music is killed. music and gallory current process,system should not kill it. refer to android,it should kill other process.
Hi reporter, By logcat, I didn't find music was killed by lmk. I saw Camera and Gallery were killed by lmk or oom, but their oom_adj is 10, it means those two application are running at background. So I think the kills are normal. 01-19 18:53:12.360 88 88 E OomLogger: [Kill]: lowmem_shrink select 1897 (Camera), adj 10, size 5901, to kill 01-19 18:53:12.360 88 88 E OomLogger: [Kill]: lowmem_shrink send sigkill to 1897 (Camera), adj 10, size 5901 01-19 18:53:20.970 88 88 E OomLogger: [Kill]: oom-killer use lmk strategy, send sigkill to 2199 ((Preallocated a), adj 4, size 2674 01-19 18:53:26.290 88 88 E OomLogger: [Kill]: oom-killer use lmk strategy, send sigkill to 2123 (Gallery), adj 10, size 6112 01-19 18:55:07.130 88 88 E OomLogger: [Kill]: oom-killer use lmk strategy, send sigkill to 2343 ((Preallocated a), adj 4, size 3782 01-19 18:55:41.060 88 88 E OomLogger: [Kill]: lowmem_shrink select 2263 (Camera), adj 10, size 5949, to kill 01-19 18:55:41.060 88 88 E OomLogger: [Kill]: lowmem_shrink send sigkill to 2263 (Camera), adj 10, size 5949 01-19 18:56:02.010 88 88 E OomLogger: [Kill]: oom-killer use lmk strategy, send sigkill to 2435 ((Preallocated a), adj 4, size 2803 Please try to have available logcat and dmesg with full memory dump (maybe you need to test on debug build), then we can do further analysis. Thanks,
Music stop for a while, it was not killed. This problem's key point is not that music was killed, The key point is that the foreground application(gallery) was killed, the oom-killer should prior to kill background application and process, current situation is foreground is killed.
Hi reporter, By logcat log, gallery is running at background (oom_adj is 10), it's not foreground application. 01-19 18:53:26.290 88 88 E OomLogger: [Kill]: oom-killer use lmk strategy, send sigkill to 2123 (Gallery), adj 10, size 6112 So I think LMK/OOM works normally, could you provide STR or full log include memory dump for further analysis? Thanks,
How do you know gallery is not running at foreground by the log? May be there is some wrong with oom_adj in the system. gallery is last opened application,but it was killed. The custommer submit this kind of issue many times. You can reproduct this problem: open many apps,finally open camera or gallory. And you said STR/memory dump is usefull, can you tell me how to get these information?
(In reply to 徐棚 from comment #4) > How do you know gallery is not running at foreground by the log? May be oom_adj is 10 means application is running at background. > there is some wrong with oom_adj in the system. gallery is last opened > application,but it was killed. > The custommer submit this kind of issue many times. You can reproduct this > problem: open many apps,finally open camera or gallory. I tried it but cannot reproduce it, do you also reproduce it by yourself? > And you said STR/memory dump is usefull, can you tell me how to get these > information? STR = Steps to Reproduce, please provide the reproduce steps in detail, such as sw version, what's the content in sdcard, environment setting and test steps (step by step). memory dump will be trigger in userdebug build, you just need to provide slog on userdebug with issue happened.
Is memory dump file like this pattern: sysdump.core.00 sysdump.core.01_0x80000000-0x87ffffff_dump.lst sysdump.core.02_0x88000000-0x8989ffff_dump.lst sysdump.core.03_0x898a0000-0x8a7fffff_dump.lst ?
(In reply to 徐棚 from comment #6) > Is memory dump file like this pattern: > sysdump.core.00 > sysdump.core.01_0x80000000-0x87ffffff_dump.lst > sysdump.core.02_0x88000000-0x8989ffff_dump.lst > sysdump.core.03_0x898a0000-0x8a7fffff_dump.lst > > ? NI Danny -- Keven
Flags: needinfo?(dliang)
(In reply to 徐棚 from comment #6) > Is memory dump file like this pattern: > sysdump.core.00 > sysdump.core.01_0x80000000-0x87ffffff_dump.lst > sysdump.core.02_0x88000000-0x8989ffff_dump.lst > sysdump.core.03_0x898a0000-0x8a7fffff_dump.lst These are sysdump, not memory information dump in slog. > > ? The memory dump exists in kernel.log and format as following: 05-26 02:48:15.031 <4>0[ 527.075344] lowmem_shrink select 502 (Settings), adj 10, size 5054, to kill 05-26 02:48:15.031 <4>0[ 527.075421] lowmem_shrink send sigkill to 502 (Settings), adj 10, size 5054 05-26 02:48:15.031 <4>0[ 527.075479] kswapd0 invoked lowmemorykiller: gfp_mask=0xd0, oom_adj=0, oom_score_adj=0 05-26 02:48:15.031 <4>0[ 527.075539] Backtrace: 05-26 02:48:15.031 <4>0[ 527.075594] [<c4537ad8>] (dump_backtrace+0x0/0x110) from [<c4889ffc>] (dump_stack+0x18/0x1c) 05-26 02:48:15.031 <4>0[ 527.075660] r7:c70f5f78 r6:000000d0 r5:c15c7440 r4:c70f4000 05-26 02:48:15.031 <4>0[ 527.075739] [<c4889fe4>] (dump_stack+0x0/0x1c) from [<c47796c4>] (lowmem_shrink+0x4b8/0x594) 05-26 02:48:15.031 <4>0[ 527.075813] [<c477920c>] (lowmem_shrink+0x0/0x594) from [<c45a4a40>] (shrink_slab+0x114/0x1c0) 05-26 02:48:15.031 <4>0[ 527.075885] [<c45a492c>] (shrink_slab+0x0/0x1c0) from [<c45a5074>] (kswapd+0x588/0x924) 05-26 02:48:15.031 <4>0[ 527.075955] [<c45a4aec>] (kswapd+0x0/0x924) from [<c456b7d0>] (kthread+0x8c/0x94) 05-26 02:48:15.031 <4>0[ 527.076022] [<c456b744>] (kthread+0x0/0x94) from [<c45547a4>] (do_exit+0x0/0x5fc) 05-26 02:48:15.031 <4>0[ 527.076080] r7:00800013 r6:c45547a4 r5:c456b744 r4:c7029f20 05-26 02:48:15.031 <4>0[ 527.076143] Mem-info: 05-26 02:48:15.031 <4>0[ 527.076167] Normal per-cpu: 05-26 02:48:15.031 <4>0[ 527.076195] CPU 0: hi: 42, btch: 7 usd: 40 05-26 02:48:15.031 <4>0[ 527.076248] active_anon:6660 inactive_anon:6660 isolated_anon:0 05-26 02:48:15.031 <4>0[ 527.076255] active_file:1756 inactive_file:715 isolated_file:0 05-26 02:48:15.031 <4>0[ 527.076263] unevictable:83 dirty:0 writeback:0 unstable:0 05-26 02:48:15.031 <4>0[ 527.076270] free:623 slab_reclaimable:271 slab_unreclaimable:1063 05-26 02:48:15.031 <4>0[ 527.076278] mapped:3626 shmem:587 pagetables:439 bounce:0 05-26 02:48:15.031 <4>0[ 527.076485] Normal free:2492kB min:1352kB low:2200kB high:2540kB active_anon:26640kB inactive_anon:26640kB active_file:7024kB inactive_file:2860kB unevictable:332kB isolated(anon):0kB isolated(file):0kB present:114408kB mlocked:0kB dirty:0kB writeback:0kB mapped:14504kB shmem:2348kB slab_reclaimable:1084kB slab_unreclaimable:4252kB kernel_stack:2056kB pagetables:1756kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:9 all_unreclaimable? no 05-26 02:48:15.031 <4>0[ 527.076748] lowmem_reserve[]: 0 0 0 05-26 02:48:15.031 <4>0[ 527.076796] Normal: 293*4kB 69*8kB 32*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2492kB 05-26 02:48:15.031 <4>0[ 527.076928] 5789 total pagecache pages 05-26 02:48:15.031 <4>0[ 527.076961] 600 pages in swap cache 05-26 02:48:15.031 <4>0[ 527.076994] Swap cache stats: add 22842, delete 22242, find 161/8375 05-26 02:48:15.031 <4>0[ 527.077043] Free swap = 31620kB 05-26 02:48:15.031 <4>0[ 527.077072] Total swap = 65532kB 05-26 02:48:15.031 <4>0[ 527.078423] 28854 pages of RAM 05-26 02:48:15.031 <4>0[ 527.078455] 1277 free pages 05-26 02:48:15.031 <4>0[ 527.078482] 1709 reserved pages 05-26 02:48:15.031 <4>0[ 527.078510] 981 slab pages 05-26 02:48:15.031 <4>0[ 527.078536] 15994 pages shared 05-26 02:48:15.031 <4>0[ 527.078564] 600 pages swap cached 05-26 02:48:15.031 <6>0[ 527.078594] [ pid ] uid tgid total_vm rss swap cpu oom_adj oom_score_adj name 05-26 02:48:15.031 <6>0[ 527.078674] [ 63] 0 63 78 23 22 0 -16 -941 ueventd 05-26 02:48:15.031 <6>0[ 527.078746] [ 78] 1000 78 207 38 19 0 -16 -941 servicemanager 05-26 02:48:15.031 <6>0[ 527.078820] [ 79] 0 79 1005 45 65 0 -16 -941 vold 05-26 02:48:15.031 <6>0[ 527.078888] [ 80] 0 80 62 2 4 0 -16 -941 vcharged 05-26 02:48:15.031 <6>0[ 527.078958] [ 81] 1000 81 170 37 17 0 -16 -941 sprd_monitor 05-26 02:48:15.031 <6>0[ 527.079030] [ 84] 0 84 34813 9601 2023 0 0 0 b2g 05-26 02:48:15.031 <6>0[ 527.079098] [ 85] 1001 85 205 47 20 0 -16 -941 rilproxy 05-26 02:48:15.031 <6>0[ 527.079168] [ 86] 0 86 1855 49 71 0 -16 -941 netd 05-26 02:48:15.031 <6>0[ 527.079236] [ 87] 0 87 173 37 17 0 -16 -941 debuggerd 05-26 02:48:15.031 <6>0[ 527.079308] [ 88] 1013 88 5079 83 266 0 -16 -941 mediaserver 05-26 02:48:15.031 <6>0[ 527.079380] [ 89] 1002 89 333 37 27 0 -16 -941 dbus-daemon 05-26 02:48:15.031 <6>0[ 527.079452] [ 90] 1017 90 433 36 39 0 -16 -941 keystore 05-26 02:48:15.031 <6>0[ 527.079523] [ 91] 0 91 319 50 43 0 -16 -941 nvm_daemon 05-26 02:48:15.031 <6>0[ 527.079595] [ 92] 1000 92 461 44 24 0 -16 -941 modemd 05-26 02:48:15.050 664] [ 95] 1001 95 2419 92 41 0 -16 -941 rild_sp 05-26 02:48:15.050 <6>0[ 527.079734] [ 96] 1001 96 205 44 22 0 -16 -941 rilproxy 05-26 02:48:15.050 <6>0[ 527.079805] [ 98] 0 98 278 38 28 0 -16 -941 engmoded 05-26 02:48:15.050 <6>0[ 527.079875] [ 101] 1001 101 2419 57 61 0 -16 -941 rild_sp 05-26 02:48:15.050 <6>0[ 527.079946] [ 159] 1000 159 7179 60 107 0 -16 -941 phoneserver_2si 05-26 02:48:15.050 <6>0[ 527.080020] [ 162] 1000 162 2103 62 101 0 -16 -941 engpcclient 05-26 02:48:15.050 <6>0[ 527.080093] [ 169] 1000 169 468 42 28 0 -16 -941 engmodemclient 05-26 02:48:15.050 <6>0[ 527.080167] [ 171] 1000 171 464 38 24 0 -16 -941 engservice 05-26 02:48:15.050 <6>0[ 527.080238] [ 311] 0 311 1326 76 25 0 -16 -941 slog 05-26 02:48:15.050 <6>0[ 527.080306] [ 333] 0 333 11926 1598 1913 0 0 0 (Nuwa) 05-26 02:48:15.050 <6>0[ 527.080376] [ 375] 10375 375 16317 2707 3225 0 8 534 Homescreen 05-26 02:48:15.050 <6>0[ 527.080447] [ 413] 10413 413 18219 5614 1073 0 2 134 Music 05-26 02:48:15.050 <6>0[ 527.080516] [ 502] 10502 502 14510 3811 1243 0 10 667 Settings 05-26 02:48:15.050 <6>0[ 527.080587] [ 544] 0 544 1116 49 4 0 -16 -941 adbd 05-26 02:48:15.050 <6>0[ 527.080656] [ 679] 1010 679 625 70 60 0 -16 -941 wpa_supplicant 05-26 02:48:15.050 <6>0[ 527.080730] [ 832] 0 832 189 74 18 0 0 0 sh 05-26 02:48:15.050 <6>0[ 527.080796] [ 834] 0 834 172 57 12 0 0 0 orng 05-26 02:48:15.050 <6>0[ 527.080865] [ 861] 0 861 14228 3798 936 0 4 267 (Preallocated a 05-26 02:48:15.050 <4>0[ 527.080939] zram0 status unit(page): 05-26 02:48:15.050 <4>0[ 527.080945] mem_used_total: 2999 05-26 02:48:15.050 <4>0[ 527.080950] compr_data_size: 2932 05-26 02:48:15.050 <4>0[ 527.080956] orig_data_size: 8137 05-26 02:48:15.050 <4>0[ 527.080961] num_reads: 8214 05-26 02:48:15.050 <4>0[ 527.080967] num_writes: 14631 You might need to use userdebug/eng build to enable memory information dump.
Flags: needinfo?(dliang)
Attached file kernel.log —
Attached file main.log —
I updated the log，this log is our customer supplied to me. memery dump is in kernel.log Can you please analysis the content of the log
(In reply to 徐棚 from comment #11) > I updated the log，this log is our customer supplied to me. > memery dump is in kernel.log > Can you please analysis the content of the log By attached kernel.log, we can find all LMK operations are correct. I also checked memory dump, it looks normal, LMK killed the background applications (oom_adj = 10) due to satisfy below condition: total pagecache - pages swap - shmem < 4608 pages (18MB) below is the mapping of oom_adj and lmk threshold: oom_adj min_free 0 4096 KB 1 5120 KB 2 6144 KB 6 7168 KB 8 8192 KB 10 18432 KB dannyliang@dannyliang-ubuntu-pc:~/work/tarako/1104507$ grep sigkill ./kernel.log -r 01-19 00:22:31.203 <4>0[ 228.572404] lowmem_shrink send sigkill to 361 (Settings), adj 10, size 6056 01-19 00:23:06.962 <4>0[ 264.342365] lowmem_shrink send sigkill to 437 (Gallery), adj 10, size 6045 01-19 00:23:41.813 <4>0[ 299.202449] lowmem_shrink send sigkill to 602 (Camera), adj 10, size 6685 01-19 00:24:35.813 <4>0[ 353.187678] lowmem_shrink send sigkill to 672 (Gallery), adj 10, size 6795 01-19 00:25:07.853 <4>0[ 385.240236] lowmem_shrink send sigkill to 722 (Camera), adj 10, size 4927 01-19 00:26:32.843 <4>0[ 470.236647] lowmem_shrink send sigkill to 781 (Gallery), adj 10, size 6563 Could you provide STR or video and we can do further investiagtion?
STR :1.open the music and play a music and then press 'home' 2.open camera and take some picture, and then press 'home' 3.open galery and open the picture and click the screen to enlarge the picture.and then swipe the screen to open other picture and do the some thing. can you tell me how to comfirm current available memery from the kenel.log?
(In reply to 徐棚 from comment #13) > STR :1.open the music and play a music and then press 'home' > 2.open camera and take some picture, and then press 'home' > 3.open galery and open the picture and click the screen to enlarge the > picture.and then swipe the screen to open other picture and do the some > thing. I cannot reproduce it by your STR, could you also attach your content in sdcard? > > can you tell me how to comfirm current available memery from the kenel.log? 05-26 02:48:15.031 <4>0[ 527.076796] Normal: 293*4kB 69*8kB 32*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2492kB => It means there are 2494kB free memory, there are 293 4kB pages, 69 8kB pages and etc...
Firefox OS is not being worked on
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: