Bug #118416

测试 Test-ST #113421: V4.0功能与专项测试

测试 Test-ST #113422: V4.0专项--AF专项--monkey测试

【AF】【EVT3】【Monkey】Monkey测试12小时，出现CRASH:com.android.documentsui（5）

Added by CD TEST-方永红 about 2 years ago. Updated almost 2 years ago.

Status:CLOSEDStart date:2023-06-01
Priority:NormalDue date:
Assignee:CD TEST-方永红% Done:

100%

Category:CD-APP
Target version:-
Need_Info:-- Found Version:0106(529版）
Resolution:FIXED Degrated:No
Severity:Critical Verified Version:
Reproducibility:Rarely Fixed Version:2023-06-27
Test Type:Monkey Test Root cause:AOSP问题

Description

【测试环境】
副屏连接中控、喇叭、音频通路正常

【执行命令】
monkey --pkg-blacklist-file /sdcard/blacklist.txt --ignore-crashes --ignore-timeouts --ignore-security-exceptions --monitor-native-crashes --ignore-native-crashes -s 20 --throttle 500 --pct-touch 30 --pct-motion 15 --pct-nav 15 --pct-majornav 15 --pct-syskeys 5 --pct-appswitch 10 --pct-anyevent 10 --ignore-crashes -v -v -v 1432000 3>/sdcard/monkey.log 2>/sdcard/error.txt 1>/sdcard/info.txt

【错误信息】

// CRASH: com.android.documentsui (pid 10329)
// Short Msg: Native crash
// Long Msg: Native crash: Segmentation fault
// Build Label: HiPhi/PassengerDisplay_CN/PassengerDisplay:12/SKQ1.220201.001/3688:user/test-keys
// Build Changelist: 3688
// Build Time: 1685344778000
// *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
// Build fingerprint: 'HiPhi/PassengerDisplay_CN/PassengerDisplay:12/SKQ1.220201.001/3688:user/test-keys'
// Revision: '0'
// ABI: 'arm64'
// Timestamp: 2023-05-31 23:42:10.494946481+0800
// Process uptime: 0s
// Cmdline: com.android.documentsui
// pid: 10329, tid: 10417, name: oid.documentsui  >>> com.android.documentsui <<<
// uid: 10028
// signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0xf8
// Cause: null pointer dereference
//     x0  0000000000000000  x1  000000006f7171d0  x2  000000006f7171d0  x3  0000000012dc0000
//     x4  0000000012dc00a0  x5  0000000000000004  x6  0000000012dc00a8  x7  0000000000000008
//     x8  0000000000000030  x9  000000006fbb9bb0  x10 0000007c7a71f0b0  x11 0000007c7aa1880c
//     x12 0000007c7aa18854  x13 0000007c7aa1889c  x14 0000007c7aa188fc  x15 0000000000000000
//     x16 0000007c76275070  x17 000000000004b700  x18 0000007bffb14000  x19 b400007df0812ad0
//     x20 0000000000000000  x21 0000000012dc0020  x22 000000006f7171d0  x23 0000000012dc0000
//     x24 0000000000000005  x25 0000000000000001  x26 0000000012dc00a0  x27 0000000000000043
//     x28 0000007c68c54000  x29 0000007c68c53560
//     lr  000000006fbb9c34  sp  0000007c68c534e0  pc  000000006fbb9c68  pst 0000000080001000
// backtrace:
//       #00 pc 00000000001bdc68  /apex/com.android.art/javalib/arm64/boot.oat (java.lang.Thread.<init>+184) (BuildId: 00b6ebba4595f735d971a61f9f2a0128c2015607)
//       #01 pc 0000000000218964  /apex/com.android.art/lib64/libart.so (art_quick_invoke_stub+548) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #02 pc 0000000000285ff0  /apex/com.android.art/lib64/libart.so (art::ArtMethod::Invoke(art::Thread*, unsigned int*, unsigned int, art::JValue*, char const*)+192) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #03 pc 000000000062d838  /apex/com.android.art/lib64/libart.so (art::JValue art::InvokeWithVarArgs<art::ArtMethod*>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, art::ArtMethod*, std::__va_list)+452) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #04 pc 000000000062dd2c  /apex/com.android.art/lib64/libart.so (art::JValue art::InvokeWithVarArgs<_jmethodID*>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jmethodID*, std::__va_list)+96) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #05 pc 000000000048a95c  /apex/com.android.art/lib64/libart.so (art::JNI<false>::CallNonvirtualVoidMethodV(_JNIEnv*, _jobject*, _jclass*, _jmethodID*, std::__va_list)+624) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #06 pc 00000000006850a8  /apex/com.android.art/lib64/libart.so (_JNIEnv::CallNonvirtualVoidMethod(_jobject*, _jclass*, _jmethodID*, ...)+120) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #07 pc 000000000068440c  /apex/com.android.art/lib64/libart.so (art::Thread::CreatePeer(char const*, bool, _jobject*)+980) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #08 pc 0000000000681398  /apex/com.android.art/lib64/libart.so (art::Thread::Attach(char const*, bool, _jobject*, bool)+488) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #09 pc 000000000063450c  /apex/com.android.art/lib64/libart.so (art::Runtime::AttachCurrentThread(char const*, bool, _jobject*, bool)+96) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #10 pc 000000000042bd88  /apex/com.android.art/lib64/libart.so (art::ProfileSaver::RunProfileSaverThread(void*)+92) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
//       #11 pc 00000000000b6a24  /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+264) (BuildId: 369edc656806aeaf384cbeb8f7a347af)
//       #12 pc 00000000000532bc  /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+68) (BuildId: 369edc656806aeaf384cbeb8f7a347af)
//

error.txt Magnifier (2.46 MB) CD TEST-方永红, 2023-06-01 10:55

Related issues

Related to Figure - Bug #118126: 【IOVDEV-29542】【自动化测试】【稳定性测试】【VC1】【副屏】副屏重启 CLOSED 2023-05-23 2023-05-26

History

#2 Updated by CD APP-王营 about 2 years ago

  • Status changed from New to ASSIGNED

#3 Updated by CD APP-王营 about 2 years ago

【状态】
分析中

【分析】
DocumentUI在monkey测试中发生了*Native Crash*

05-31 23:42:12.366 8923 8937 W Monkey : // CRASH: com.android.documentsui (pid 10329)
05-31 23:42:12.367 8923 8937 W Monkey : // Short Msg: Native crash
05-31 23:42:12.367 8923 8937 W Monkey : // Long Msg: Native crash: Segmentation fault
05-31 23:42:12.367 8923 8937 W Monkey : // Build Label: HiPhi/PassengerDisplay_CN/PassengerDisplay:12/SKQ1.220201.001/3688:user/test-keys
05-31 23:42:12.368 8923 8937 W Monkey : // Build Changelist: 3688
05-31 23:42:12.368 8923 8937 W Monkey : // Build Time: 1685344778000
05-31 23:42:12.368 8923 8937 W Monkey : // *
05-31 23:42:12.368 8923 8937 W Monkey : // Build fingerprint: 'HiPhi/PassengerDisplay_CN/PassengerDisplay:12/SKQ1.220201.001/3688:user/test-keys'
05-31 23:42:12.368 8923 8937 W Monkey : // Revision: '0'
05-31 23:42:12.368 8923 8937 W Monkey : // ABI: 'arm64'
05-31 23:42:12.368 8923 8937 W Monkey : // Timestamp: 2023-05-31 23:42:10.494946481+0800
05-31 23:42:12.368 8923 8937 W Monkey : // Process uptime: 0s
05-31 23:42:12.368 8923 8937 W Monkey : // Cmdline: com.android.documentsui
05-31 23:42:12.368 8923 8937 W Monkey : // pid: 10329, tid: 10417, name: oid.documentsui >>> com.android.documentsui <<<
05-31 23:42:12.368 8923 8937 W Monkey : // uid: 10028
05-31 23:42:12.368 8923 8937 W Monkey : // signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0xf8
05-31 23:42:12.368 8923 8937 W Monkey : // Cause: null pointer dereference
05-31 23:42:12.368 8923 8937 W Monkey : // x0 0000000000000000 x1 000000006f7171d0 x2 000000006f7171d0 x3 0000000012dc0000
05-31 23:42:12.368 8923 8937 W Monkey : // x4 0000000012dc00a0 x5 0000000000000004 x6 0000000012dc00a8 x7 0000000000000008
05-31 23:42:12.368 8923 8937 W Monkey : // x8 0000000000000030 x9 000000006fbb9bb0 x10 0000007c7a71f0b0 x11 0000007c7aa1880c
05-31 23:42:12.368 8923 8937 W Monkey : // x12 0000007c7aa18854 x13 0000007c7aa1889c x14 0000007c7aa188fc x15 0000000000000000
05-31 23:42:12.368 8923 8937 W Monkey : // x16 0000007c76275070 x17 000000000004b700 x18 0000007bffb14000 x19 b400007df0812ad0
05-31 23:42:12.368 8923 8937 W Monkey : // x20 0000000000000000 x21 0000000012dc0020 x22 000000006f7171d0 x23 0000000012dc0000
05-31 23:42:12.368 8923 8937 W Monkey : // x24 0000000000000005 x25 0000000000000001 x26 0000000012dc00a0 x27 0000000000000043
05-31 23:42:12.368 8923 8937 W Monkey : // x28 0000007c68c54000 x29 0000007c68c53560
05-31 23:42:12.368 8923 8937 W Monkey : // lr 000000006fbb9c34 sp 0000007c68c534e0 pc 000000006fbb9c68 pst 0000000080001000
05-31 23:42:12.368 8923 8937 W Monkey : // backtrace:
05-31 23:42:12.368 8923 8937 W Monkey : // #00 pc 00000000001bdc68 /apex/com.android.art/javalib/arm64/boot.oat (java.lang.Thread.<init>+184) (BuildId: 00b6ebba4595f735d971a61f9f2a0128c2015607)
05-31 23:42:12.368 8923 8937 W Monkey : // #01 pc 0000000000218964 /apex/com.android.art/lib64/libart.so (art_quick_invoke_stub+548) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #02 pc 0000000000285ff0 /apex/com.android.art/lib64/libart.so (art::ArtMethod::Invoke(art::Thread, unsigned int*, unsigned int, art::JValue*, char const*)+192) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #03 pc 000000000062d838 /apex/com.android.art/lib64/libart.so (art::JValue art::InvokeWithVarArgs<art::ArtMethod*>(art::ScopedObjectAccessAlreadyRunnable const&, jobject*, art::ArtMethod*, std::_va_list)+452) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #04 pc 000000000062dd2c /apex/com.android.art/lib64/libart.so (art::JValue art::InvokeWithVarArgs<_jmethodID*>(art::ScopedObjectAccessAlreadyRunnable const&, jobject*, _jmethodID*, std::_va_list)+96) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #05 pc 000000000048a95c /apex/com.android.art/lib64/libart.so (art::JNI<false>::CallNonvirtualVoidMethodV(JNIEnv*, _jobject*, _jclass*, _jmethodID*, std::_va_list)+624) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #06 pc 00000000006850a8 /apex/com.android.art/lib64/libart.so (JNIEnv::CallNonvirtualVoidMethod(_jobject*, _jclass*, _jmethodID*, ...)+120) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #07 pc 000000000068440c /apex/com.android.art/lib64/libart.so (art::Thread::CreatePeer(char const*, bool, _jobject*)+980) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #08 pc 0000000000681398 /apex/com.android.art/lib64/libart.so (art::Thread::Attach(char const*, bool, _jobject*, bool)+488) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #09 pc 000000000063450c /apex/com.android.art/lib64/libart.so (art::Runtime::AttachCurrentThread(char const*, bool, _jobject*, bool)+96) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #10 pc 000000000042bd88 /apex/com.android.art/lib64/libart.so (art::ProfileSaver::RunProfileSaverThread(void*)+92) (BuildId: 5dc9131f1682d0e95179a6a72087253c)
05-31 23:42:12.368 8923 8937 W Monkey : // #11 pc 00000000000b6a24 /apex/com.android.runtime/lib64/bionic/libc.so (_pthread_start(void*)+264) (BuildId: 369edc656806aeaf384cbeb8f7a347af)
05-31 23:42:12.368 8923 8937 W Monkey : // #12 pc 00000000000532bc /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+68) (BuildId: 369edc656806aeaf384cbeb8f7a347af)
05-31 23:42:12.368 8923 8937 W Monkey : //

在DocumentUI发生 Native Crash时间点向前查看log，lowmemoryKiller机制触发，说明设备出现性能问题，内存过低，怀疑在低内存情况下，内存地址被挤占会出现此问题。

【下一步】

1、使用工具来分析log，查看native层的堆栈信息。
2、继续查看问题发生之前的log，调查是否有内存溢出情况发生。

#4 Updated by CD APP-王营 about 2 years ago

【分析】

在Crash发生前出现大量oom, lowmemorykiller开始杀进程

05-31 23:28:37.897 519 519 I lowmemorykiller: Ignoring pressure since per-zone watermarks ok
05-31 23:28:37.908 519 519 I lowmemorykiller: Ignoring pressure since per-zone watermarks ok
05-31 23:28:37.921 519 519 I lowmemorykiller: Ignoring pressure since per-zone watermarks ok
05-31 23:28:37.929 519 519 I killinfo: [17872,10028,995,606,22864,-1,7896240,93580,767788,46408,428,57988,109688,4194300,322812,2208460,547836,256436,346540,104028,372984,138496,215672,0,0,156,0,4,0,0,50456,0]
05-31 23:28:37.929 519 519 I lowmemorykiller: Kill 'com.android.documentsui' (17872), uid 10028, oom_score_adj 995 to free 22864kB rss, 50456kb swap
05-31 23:28:37.929 519 519 I lowmemorykiller: Reclaimed 22864kB at oom_score_adj 606
05-31 23:28:37.938 0 0 I [ 5673.813163] binder: 17872:17921 ioctl c0306201 7c68f0a9f8 returned -14
05-31 23:28:37.938 0 0 I [ 5673.813298] binder: 17872:17947 ioctl c0306201 7c68e0c9f8 returned -14
05-31 23:28:37.938 0 0 I [ 5673.814124] binder: 17872:17917 ioctl c0306201 7c690089f8 returned -14
05-31 23:28:37.938 0 0 I [ 5673.821260] oom_reaper: reaped process 17872 (oid.documentsui), now anon-rss:0kB, file-rss:0kB, shmem-rss:380kB
05-31 23:28:37.938 1533 2967 W ActivityManager: Missing app error report, app = com.baidu.appsearch crashing = false notResponding = true
05-31 23:28:37.942 689 689 I Zygote : Process 17872 exited due to signal 9 (Killed)
05-31 23:28:37.945 1533 28044 I ActivityManager: Process com.android.documentsui (pid 17872) has died: cch+95 CEM
05-31 23:28:37.945 1533 1635 I libprocessgroup: Successfully killed process cgroup uid 10028 pid 17872 in 0ms
05-31 23:28:37.945 1533 28044 I am_proc_died: [0,17872,com.android.documentsui,995,19]
05-31 23:28:37.946 1533 28044 I am_uid_stopped: 10028
05-31 23:28:37.948 519 519 E libprocessgroup: set_timerslack_ns write failed: No such process
05-31 23:28:37.948 1533 28044 I am_mem_factor: [1,0]
05-31 23:28:37.955 519 519 I killinfo: [17943,10095,995,606,632,-1,7896240,114408,768212,46408,428,57988,109688,4194300,327776,2185712,546676,254668,348492,104028,372984,138272,214892,0,0,0,16,16,1,0,47160,0]

Tlog应用存在内存泄露，正式解决方案已经入库。

【下一步】

跑monkey测试，复测此问题

#5 Updated by CD APP-王营 about 2 years ago

【分析】

lowmemorykiller杀进程的详细信息如下：

Line  992: 05-31 23:28:37.929   519   519 I lowmemorykiller: Kill 'com.android.documentsui' (17872), uid 10028, oom_score_adj 995 to free 22864kB rss, 50456kb swap
    Line 1007: 05-31 23:28:37.955   519   519 I lowmemorykiller: Kill 'com.ss.android.article.video.landscape' (17943), uid 10095, oom_score_adj 995 to free 632kB rss, 47160kb swap
    Line 1023: 05-31 23:28:37.988   519   519 I lowmemorykiller: Kill 'com.tencent.wemeet.app:xg_vip_service' (13170), uid 10109, oom_score_adj 990 to free 18196kB rss, 61048kb swap
    Line 1032: 05-31 23:28:38.008   519   519 I lowmemorykiller: Kill 'com.qualcomm.qti.qccauthmgr' (15160), uid 10080, oom_score_adj 999 to free 20928kB rss, 46988kb swap
    Line 1046: 05-31 23:28:38.026   519   519 I lowmemorykiller: Kill 'com.hunantv.imgo.activity:QS' (16702), uid 10107, oom_score_adj 999 to free 15740kB rss, 59824kb swap
    Line 1067: 05-31 23:28:38.046   519   519 I lowmemorykiller: Kill 'com.netease.newsreader.activity:pushservice' (19838), uid 10113, oom_score_adj 999 to free 9644kB rss, 60372kb swap
    Line 1081: 05-31 23:28:38.089   519   519 I lowmemorykiller: Kill 'com.netease.newsreader.activity' (19579), uid 10113, oom_score_adj 999 to free 816kB rss, 86584kb swap
    Line 1093: 05-31 23:28:38.101   519   519 I lowmemorykiller: Kill 'com.hunantv.imgo.activity:pushservice' (11246), uid 10107, oom_score_adj 999 to free 612kB rss, 74576kb swap
    Line 1118: 05-31 23:28:38.175   519   519 I lowmemorykiller: Kill 'com.smile.gifmaker' (25744), uid 10106, oom_score_adj 999 to free 48176kB rss, 106548kb swap
    Line 1146: 05-31 23:28:38.245   519   519 I lowmemorykiller: Kill 'air.tv.douyu.android' (17875), uid 10102, oom_score_adj 995 to free 684kB rss, 77208kb swap
    Line 1260: 05-31 23:28:38.427   519   519 I lowmemorykiller: Kill 'com.tencent.wemeet.app' (12682), uid 10109, oom_score_adj 990 to free 11636kB rss, 92744kb swap

【下一步】

从log中分析Tlog的内存占用情况

#6 Updated by CD APP-王营 about 2 years ago

【状态】
分析中

【分析】
1、在Log中过滤关键字scudo : Stats: SizeClassAllocator64，未发现Tlog相关pid,目前无法将此问题很Tlog内存泄露直接关联

【下一步】
1、结合系统卡顿问题一起分析。
2、使用发生问题时的版本，分析Native crash，定位art库中发生空指针的具体代码。

#7 Updated by CDTS_TEST 王成 about 2 years ago

  • Severity changed from Major to Critical

#8 Updated by CD APP-王营 about 2 years ago

  • Status changed from ASSIGNED to RESOLVED
  • Assignee changed from CD APP-王营 to CD TEST-方永红
  • % Done changed from 0 to 100
  • Resolution changed from -- to FIXED
  • Degrated changed from -- to No
  • Fixed Version set to 2023-06-27
  • Root cause set to AOSP问题

【分析】
涉及低内存性能问题已作出以下优化
1、控制后台任务数量最多3个。
2、优化客户ota_hht_mgr应用selinux权限问题。
3、此问题发生时Tlog内存泄露优化方案未入库，目前Tlog已经优化。

基于以上3点建议在最新版本上跟踪验证，看此问题是否复现。

【下一步】
请测试同事跟踪测试此问题

#9 Updated by CD TEST-方永红 almost 2 years ago

  • Status changed from RESOLVED to VERIFIED

120
0712
0713
三个版本未复现，先关闭

#10 Updated by CD TEST-方永红 almost 2 years ago

  • Status changed from VERIFIED to CLOSED

Also available in: Atom PDF