Figure

1. 内存严重不足：

05-21 01:42:07.406 0 0 I [43392.934776] binder: 1539:7636 transaction failed 29189/-22, size 84-0 line 3071
05-21 01:42:07.406 0 0 W [43392.934837] unevictable: 27184 dirty:106 writeback:0 unstable:0
05-21 01:42:07.406 0 0 W [43392.934837] slab_reclaimable: 13532 slab_unreclaimable:76857
05-21 01:42:07.406 0 0 W [43392.934837] mapped: 37662 shmem:5216 pagetables:44818 bounce:0
05-21 01:42:07.406 0 0 W [43392.934837] free: 19134 free_pcp:1350 free_cma:0
05-21 01:42:07.406 0 0 W : [43392.934843] Node 0 active_anon:4908580kB inactive_anon:708080kB active_file:15716kB inactive_file:33416kB unevictable:108736kB
isolated(anon):84kB isolated(file):128kB mapped:150648kB dirty:424kB writeback:0kB shmem:20864kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
05-21 01:42:07.406 0 0 W : [43392.934852] Normal free:74488kB min:7040kB low:41492kB high:43252kB active_anon:3377924kB inactive_anon:564480kB active_file:15872kB
inactive_file:33572kB unevictable:107988kB writepending:424kB present:5960896kB managed:5799092kB mlocked:107988kB kernel_stack:65760kB pagetables:179272kB bounce:0kB free_pcp:4664kB
local_pcp:500kB free_cma:0kB
05-21 01:42:07.406 0 0 W [43392.934853] lowmem_reserve[]: 0 16384
05-21 01:42:07.406 0 0 W : [43392.934862] Movable free:2048kB min:2544kB low:15000kB high:15636kB active_anon:1531244kB inactive_anon:143600kB active_file:0kB
inactive_file:0kB unevictable:748kB writepending:0kB present:2097152kB managed:2097152kB mlocked:748kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:736kB local_pcp:0kB
free_cma:0kB
05-21 01:42:07.406 0 0 W [43392.934863] lowmem_reserve[]: 0 0
05-21 01:42:07.406 0 0 W [43392.934866] Normal: 151*4kB (U) 614*8kB (UE) 254*16kB (UE) 675*32kB (UE) 610*64kB (UE) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 1*4096kB (H) = 74316kB
05-21 01:42:07.406 0 0 W [43392.934881] Movable: 64*4kB (M) 23*8kB (M) 12*16kB (M) 9*32kB (M) 9*64kB (M) 3*128kB (M) 0*256kB 1*512kB (M) 0*1024kB 0*2048kB 0*4096kB = 2392kB
05-21 01:42:07.406 0 0 W : [43392.934897] 48765 total pagecache pages
05-21 01:42:07.406 0 0 W : [43392.934903] 4327 pages in swap cache
05-21 01:42:07.406 0 0 W : [43392.934905] Swap cache stats: add 2522505, delete 2521175, find 2976618/4088946
05-21 01:42:07.406 0 0 W : [43392.934907] Free swap = 0kB
05-21 01:42:07.406 0 0 W : [43392.934908] Total swap = 4194300kB
05-21 01:42:07.406 0 0 W : [43392.934910] 2014512 pages RAM
05-21 01:42:07.406 0 0 W : [43392.934912] 0 pages HighMem/MovableOnly
05-21 01:42:07.406 0 0 W : [43392.934913] 40451 pages reserved
05-21 01:42:07.406 0 0 W : [43392.934914] 89088 pages cma reserved

2.从现有log看monkey 最后运行的时间：

05-21 01:42:15.011 10350 10350 I Monkey : Sleeping for 500 milliseconds

3.system_server 已经在异常重启了

./FSEM_000501_0046_0521090725/logcat/000501_persist_00824_230521_090710.log:613:05-21 09:07:11.285 16797 16797 I system_server_start: [2,70096813,70096813]

具体请查看：000501_persist_00824_230521_090710.log

1. system_server被杀

05-21 09:07:08.793     0     0 E         : [70094.313803] Out of memory: Kill process 1539 (system_server) score 0 or sacrifice child
 05-21 09:07:08.796     0     0 E         : [70094.315833] Killed process 1539 (system_server) total-vm:21624184kB, anon-rss:0kB, file-rss:0kB, shmem-rss:8308kB oom_score_adj=-900

2.具体请看log文件

000501_persist_00821_230521_090643.log

3.发现在此阶段的时间内system_server在大量GC

000501_persist_00766_230521_085422.log:1539:05-21 08:54:41.686  1539  1556 I system_server: Background concurrent copying GC freed 141761(8252KB) AllocSpace objects, 40(5112KB) LOS objects, 46% 
free, 27MB/51MB, paused 51us,66us total 185.006ms
000501_persist_00770_230521_085549.log:878:05-21  08:55:58.141   1539  1556 I system_server: Background concurrent copying GC freed 101376(5931KB) AllocSpace objects, 34(3340KB) LOS objects, 
46% free, 27MB/51MB, paused 53us,66us total 157.516ms
000501_persist_00774_230521_085646.log:300:05-21  08:56:46.702   1539  1556 I system_server: Background concurrent copying GC freed 297891(15MB) AllocSpace objects, 64(8528KB) LOS objects, 45% free, 28MB/52MB, paused 699us,58us total 195.428ms
000501_persist_00778_230521_085756.log:1575:05-21 08:58:04.562  1539  1556 I system_server: Background concurrent copying GC freed 326696(21MB) AllocSpace objects, 84(10MB) LOS objects, 45% free, 28MB/52MB, paused 41us,55us total 219.358ms
000501_persist_00782_230521_085843.log:1231:05-21 08:58:48.764  1539  1556 I system_server: Background concurrent copying GC freed 329334(15MB) AllocSpace objects, 73(10MB) LOS objects, 45% free, 28MB/52MB, paused 10.306ms,60us total 164.712ms
000501_persist_00789_230521_085957.log:673:05-21  09:00:00.391   1539  1556 I system_server: Background concurrent copying GC freed 361624(16MB) AllocSpace objects, 48(7552KB) LOS objects, 46% free, 27MB/51MB, paused 42us,54us total 206.875ms
000501_persist_00795_230521_090114.log:1099:05-21 09:01:23.767  1539  1556 I system_server: Background concurrent copying GC freed 259591(16MB) AllocSpace objects, 95(9000KB) LOS objects, 45% free, 28MB/52MB, paused 67us,59us total 158.328ms
000501_persist_00799_230521_090207.log:1200:05-21 09:02:14.978  1539  1556 I system_server: Background concurrent copying GC freed 310333(15MB) AllocSpace objects, 64(9092KB) LOS objects, 46% free, 27MB/51MB, paused 44us,57us total 115.428ms
000501_persist_00803_230521_090301.log:1649:05-21 09:03:12.067  1539  1556 I system_server: Background concurrent copying GC freed 310174(15MB) AllocSpace objects, 69(9540KB) LOS objects, 45% free, 28MB/52MB, paused 825us,958us total 171.950ms
 

4. 下一步，请AF调查一下上面的情况是否何理？

与bug118126相同 #[[https://share.thundersoft.com/redmine/issues/118126]]

05-21 09:07:08.793 0 0 E : [70094.313803] Out of memory: Kill process 1539 (system_server) score 0 or sacrifice child
05-21 09:07:08.796 0 0 E : [70094.315833] Killed process 1539 (system_server) total-vm:21624184kB, anon-rss:0kB, file-rss:0kB, shmem-rss:8308kB oom_score_adj=-90