Android 8.0频现GC crash

2017-09-14 本文已影响2118人 dumphex

问题现象

复现步骤
- 手机(Android 8.0, build id为opr6.170623.013)
- 复现场景一: app crash
  - 选择一个大的txt文档，如：228k.txt
  - 用html方式打开
  - 打开后长按内容，点击全选，后点击分享到信息
  - 选择号码后等待
  - com.android.messaging进程几乎必现native crash
- 复现场景二: system_server crash
  - 执行MSR压力测试
  - system_server高概率出现native crash

定位分析

相关log

tombstone

ABI: 'arm' 
pid: 24785, tid: 24795, name: HeapTaskDaemon  >>> system_server <<<
signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
Abort message: 'utils.cc:123] 12c00000-52c00000 rw-p 00000000 00:05 3180718    /dev/ashmem/dalvik-main space (region space) (deleted)'
    r0 00000000  r1 000060db  r2 00000006  r3 00000008
    r4 000060d1  r5 000060db  r6 9bbc11d0  r7 0000010c
    r8 0000000b  r9 9bbc1231  sl 0000000a  fp 9bbc1230
    ip 00000000  sp 9bbc11c0  lr b4fee417  pc b501e97c  cpsr 200f0010
    d0  2e656d69746e7572  d1  3031306666646631
    d2  3135373066383036  d3  6f5f646c65696638
    d4  6636633537373864  d5  6636633535373839
    d6  6636633538373837  d7  363533613338317c
    d8  0000000000000000  d9  0000000000000000
    d10 0000000000000000  d11 0000000000000000
    d12 0000000000000000  d13 0000000000000000
    d14 0000000000000000  d15 0000000000000000
    d16 2e74736973726570  d17 2e6761742e676f6c
    d18 00000000c3394019  d19 000000005c000000
    d20 0000000000000000  d21 000000000000005c
    d22 0000000400000004  d23 0000000400000004
    d24 000022c1000002c1  d25 000062c1000042c1
    d26 000022c0000002c0  d27 000062c0000042c0
    d28 720410f8720410f0  d29 7204110872041100
    d30 0000001806897c20  d31 7204110872041100
    scr 20000013
backtrace:
    #00 pc 0004a97c  /system/lib/libc.so (tgkill+12)
    #01 pc 0001a413  /system/lib/libc.so (abort+54)
    #02 pc 003385df  /system/lib/libart.so (_ZN3art7Runtime5AbortEPKc+230)
    #03 pc 00338c6f  /system/lib/libart.so (_ZN3art7Runtime7AborterEPKc+10)
    #04 pc 003efacd  /system/lib/libart.so (_ZN7android4base10LogMessageD1Ev+456)
    #05 pc 001c1c3f  /system/lib/libart.so (_ZNK3art2gc12Verification17LogHeapCorruptionENS_6ObjPtrINS_6mirror6ObjectEEENS_12MemberOffsetEPS4_b+926)
    #06 pc 001769fb  /system/lib/libart.so (_ZN3art2gc9collector17ConcurrentCopying13MarkNonMovingEPNS_6mirror6ObjectES5_NS_12MemberOffsetE+290)
    #07 pc 00178097  /system/lib/libart.so (_ZN3art6mirror6Object15VisitReferencesILb1ELNS_17VerifyObjectFlagsE0ELNS_17ReadBarrierOptionE1ENS_2gc9collector17ConcurrentCopying16RefFieldsVisitorES8_EEvRKT2_RKT3_+218)
    #08 pc 00173537  /system/lib/libart.so (_ZN3art2gc9collector17ConcurrentCopying19ProcessMarkStackRefEPNS_6mirror6ObjectE+98)
    #09 pc 00173077  /system/lib/libart.so (_ZN3art2gc9collector17ConcurrentCopying20ProcessMarkStackOnceEv+402)
    #10 pc 00172ed7  /system/lib/libart.so (_ZN3art2gc9collector17ConcurrentCopying16ProcessMarkStackEv+18)
    #11 pc 0016e695  /system/lib/libart.so (_ZN3art2gc9collector17ConcurrentCopying12MarkingPhaseEv+456)
    #12 pc 0016dc75  /system/lib/libart.so (_ZN3art2gc9collector17ConcurrentCopying9RunPhasesEv+540)
    #13 pc 0017ccc5  /system/lib/libart.so (_ZN3art2gc9collector16GarbageCollector3RunENS0_7GcCauseEb+268)
    #14 pc 00197adf  /system/lib/libart.so (_ZN3art2gc4Heap22CollectGarbageInternalENS0_9collector6GcTypeENS0_7GcCauseEb+2726)
    #15 pc 001a2f2f  /system/lib/libart.so (_ZN3art2gc4Heap12ConcurrentGCEPNS_6ThreadENS0_7GcCauseEb+70)
    #16 pc 001a8949  /system/lib/libart.so (_ZN3art2gc4Heap16ConcurrentGCTask3RunEPNS_6ThreadE+20)
    #17 pc 001c147b  /system/lib/libart.so (_ZN3art2gc13TaskProcessor11RunAllTasksEPNS_6ThreadE+30)
    #18 pc 7049a4cb  /data/dalvik-cache/arm/system@framework@boot.oat (offset 0x9a3000)

初步分析

gdb 堆栈

(gdb) bt
#0  tgkill () at bionic/libc/arch-arm/syscalls/tgkill.S:10
#1  0xb4fee416 in abort () at bionic/libc/bionic/abort.cpp:49
#2  0xb206e5e2 in art::Runtime::Abort (msg=<optimized out>) at art/runtime/runtime.cc:523
#3  0xb206ec72 in art::Runtime::Aborter (abort_message=0x979bd380 "GC tried to mark invalid reference 0x17\nref=0x17 <invalid address>\nholder=0x13780000 klass=0x6f353a18(java.lang.Class<java.lang.Object[]>) length=131069 space=main space (region space) 0x12c00000-0x52"...) at art/runtime/runtime.cc:2333
#4  0xb2125ace in std::__1::function<void (char const*)>::operator()(char const*) const (this=<optimized out>, __arg=0x979bd380 "GC tried to mark invalid reference 0x17\nref=0x17 <invalid address>\nholder=0x13780000 klass=0x6f353a18(java.lang.Class<java.lang.Object[]>) length=131069 space=main space (region space) 0x12c00000-0x52"...) at external/libcxx/include/functional:1915
#5  android::base::LogMessage::~LogMessage (this=0x9bbc1288) at system/core/base/logging.cpp:433
#6  0xb1ef7c42 in art::gc::Verification::LogHeapCorruption (this=<optimized out>, holder=..., offset=..., ref=0x17, fatal=<optimized out>) at external/libcxx/include/new:235
#7  0xb1eac9fe in art::gc::collector::ConcurrentCopying::MarkNonMoving (this=0xb22c3700, ref=0x17, holder=0x13780000, offset=...) at art/runtime/gc/collector/concurrent_copying.cc:2435
#8  0xb1eae09a in art::gc::collector::ConcurrentCopying::RefFieldsVisitor::operator() (this=<optimized out>, obj=0x13780000, offset=...) at art/runtime/gc/collector/concurrent_copying.cc:1911
#9  art::mirror::ObjectArray<art::mirror::Object>::VisitReferences<art::gc::collector::ConcurrentCopying::RefFieldsVisitor> (visitor=..., this=<optimized out>) at art/runtime/mirror/object_array-inl.h:373
#10 art::mirror::Object::VisitReferences<true, (art::VerifyObjectFlags)0, (art::ReadBarrierOption)1, art::gc::collector::ConcurrentCopying::RefFieldsVisitor, art::gc::collector::ConcurrentCopying::RefFieldsVisitor> (this=0x13780000, visitor=..., ref_visitor=...) at art/runtime/mirror/object-refvisitor-inl.h:54
#11 0xb1ea953a in art::gc::collector::ConcurrentCopying::Scan (to_ref=0x13780000, this=<optimized out>) at art/runtime/gc/collector/concurrent_copying.cc:1950
#12 art::gc::collector::ConcurrentCopying::ProcessMarkStackRef (this=0xb22c3700, to_ref=0x13780000) at art/runtime/gc/collector/concurrent_copying.cc:1446
#13 0xb1ea907a in art::gc::collector::ConcurrentCopying::ProcessMarkStackOnce (this=0xb22c3700) at art/runtime/gc/collector/concurrent_copying.cc:1347
#14 0xb1ea8eda in art::gc::collector::ConcurrentCopying::ProcessMarkStack (this=0xb22c3700) at art/runtime/gc/collector/concurrent_copying.cc:1326
#15 0xb1ea4696 in art::gc::collector::ConcurrentCopying::MarkingPhase (this=0xb22c3700) at art/runtime/gc/collector/concurrent_copying.cc:756
#16 0xb1ea3c78 in art::gc::collector::ConcurrentCopying::RunPhases (this=0xb22c3700) at art/runtime/gc/collector/concurrent_copying.cc:169
#17 0xb1eb2cc6 in art::gc::collector::GarbageCollector::Run (this=<optimized out>, gc_cause=art::gc::kGcCauseBackground, clear_soft_references=<optimized out>) at art/runtime/gc/collector/garbage_collector.cc:95
#18 0xb1ecdae2 in art::gc::Heap::CollectGarbageInternal (this=0xb22fd400, gc_type=<optimized out>, gc_cause=art::gc::kGcCauseBackground, clear_soft_references=<optimized out>) at art/runtime/gc/heap.cc:2748
#19 0xb1ed8f32 in art::gc::Heap::ConcurrentGC (this=0xb22fd400, self=<optimized out>, cause=art::gc::kGcCauseBackground, force_full=<optimized out>) at art/runtime/gc/heap.cc:3752
#20 0xb1ede94c in art::gc::Heap::ConcurrentGCTask::Run (this=<optimized out>, self=0x60db) at art/runtime/gc/heap.cc:3713
#21 0xb1ef747c in art::gc::TaskProcessor::RunAllTasks (this=0xb221eb80, self=0xaac57200) at art/runtime/gc/task_processor.cc:124
#22 0x7049a4cc in ?? ()

log分析

#3报出的abort_message完整log为
(gdb) p (char *)0x979bd380 
$1 = 0x979bd380 "GC tried to mark invalid reference 0x17\nref=0x17 <invalid address>\nholder=0x13780000 klass=0x6f353a18(java.lang.Class<java.lang.Object[]>) length=131069 space=main space (region space) 0x12c00000-0x52c00000 card=0 adjacent_ram=58775c6fd8775c6f98755c6f78785c6f|183a356f00000010fdff010008f07513field_offset=262168\n"

查看当前obj=0x17

(gdb) x /4xw 0x13780000+262168
0x137c0018:   0x00000017  0x00300032  0x00200030  0x00200035

对比实验

Nexus 6p无法复现
通过添加log, 发现没有走GC操作

深入分析

查看obj相关的region[]

... ...
$49 = {
  idx_ = 46,  
  begin_ = 0x13780000 "\030:5o", 
  top_ = {
  <std::__1::atomic<unsigned char*>> = {
    <std::__1::__atomic_base<unsigned char*, false>> = {
      __a_ = 0x137e0008 ""
    }, <No data fields>}, <No data fields>}, 
  end_ = 0x137c0000 "\260\207(o", 
  state_ = art::gc::space::RegionSpace::RegionState::kRegionStateLarge, 
  type_ = art::gc::space::RegionSpace::RegionType::kRegionTypeUnevacFromSpace, 
  objects_allocated_ = {
  <std::__1::atomic<unsigned int>> = {
    <std::__1::__atomic_base<unsigned int, true>> = {
      <std::__1::__atomic_base<unsigned int, false>> = {
        __a_ = 0
      }, <No data fields>}, <No data fields>}, <No data fields>}, 
  alloc_time_ = 13,  
  live_bytes_ = 0, 
  is_newly_allocated_ = false, 
  is_a_tlab_ = false, 
  thread_ = 0x0
}

$50 = {
  idx_ = 47,  
  begin_ = 0x137c0000 "\260\207(o", 
  top_ = {
  <std::__1::atomic<unsigned char*>> = {
    <std::__1::__atomic_base<unsigned char*, false>> = {
      __a_ = 0x137c4000 ""
    }, <No data fields>}, <No data fields>}, 
  end_ = 0x13800000 "\260\207(o", 
  state_ = art::gc::space::RegionSpace::RegionState::kRegionStateAllocated, 
  type_ = art::gc::space::RegionSpace::RegionType::kRegionTypeUnevacFromSpace, 
  objects_allocated_ = {
  <std::__1::atomic<unsigned int>> = {
    <std::__1::__atomic_base<unsigned int, true>> = {
      <std::__1::__atomic_base<unsigned int, false>> = {
        __a_ = 191
      }, <No data fields>}, <No data fields>}, <No data fields>},
  alloc_time_ = 14,
  live_bytes_ = 0,
  is_newly_allocated_ = true,
  is_a_tlab_ = false,
  thread_ = 0x0
}
... ...

可看到，

regions_[46]和regions_[47]原本是一个large object, regions_[46]的top_已指向regions_[47],
regions_[47]当前的状态为art::gc::space::RegionSpace::RegionState::kRegionStateAllocated, 表示已分配出去，理论上来讲应该是art::gc::space::RegionSpace::RegionState::kRegionStateLargeTail
regions_[46]的alloc_time是13, regions_[47]的alloc_time是14, 说明regions_[47]后续在使用过程中又被分配出去了．

网络求助
- stackoverflow
  
  https://stackoverflow.com/questions/45978282/android-o8-0-access-network-or-database-cause-native-crashheapdaemontask-dead
- Google issue tracker
  其中在65268761,　Google回复已解决，但patch会在未来的release中提供．
  
  看这几个issue的提交和回复时间，也都集中8月底~9月初，就是opr6.170623.013发布后的这几天．

Goolge ART求助

向Google ART的Nicolas Geoffray发一封求助邮件，描述复现和分析详情，很快收到回复(12分钟)．

Nicolas说此问题已解决，并提供了解决方案的链接．

Hi Tim,

The change you're looking for is:
https://android-review.googlesource.com/#/c/platform/art/+/430379/

Thanks for your links. And sorry you got hit by the bug.

同时，Nicolas又更新了https://issuetracker.google.com/issues/65268761

ng...@google.com  <ng...@google.com>  #4 Sep 6, 2017 04:58PM

The change in AOSP that fixed this is:
https://android-review.googlesource.com/#/c/platform/art/+/430379/

Unfortunately, it's not known yet when the fix will be available.

解决方案

patch

https://android-review.googlesource.com/#/c/platform/art/+/430379/
验证
- 分享228k.txt至message,不再crash
- MSR压力测试，手机不再重启

Android 8.0频现GC crash

问题现象

定位分析

初步分析

对比实验

深入分析

解决方案

猜你喜欢

热点阅读