UC浏览器闪退问题分析报告

【NE现场】

02-24 16:16:42.352 14969 14975 I art     : Do partial code cache collection, code=96KB, data=100KB
02-24 16:16:42.353 14969 14975 I art     : After code cache collection, code=96KB, data=100KB
02-24 16:16:42.353 14969 14975 I art     : Increasing code cache capacity to 512KB
02-24 16:16:42.407 14969 15400 E TUnionLoginManager: not tblogin module, not handle and module is video
02-24 16:16:42.991 14969 14969 I art     : CrashHandler::Action in:0
02-24 16:16:42.992 14969 14969 I art     :     trap_no 00000000  error_code 00000000  oldmask 00001204  fault_address ebcc3000
02-24 16:16:42.992 14969 14969 I art     :     r0 cd7d3c50  r1 00004001  r2 00000000  r3 00000002
02-24 16:16:42.992 14969 14969 I art     :     r4 00000001  r5 c7e1f720  r6 c614f014  r7 33dd2da0
02-24 16:16:42.992 14969 14969 I art     :     r8 33352a28  r9 e9d85400  sl 33dd2db0  fp 00000001
02-24 16:16:42.992 14969 14969 I art     :     ip ec8fc010  sp ffba3978  lr ec9cac0f  pc ebcc3000  cpsr 800e0010
02-24 16:16:42.992 14969 14969 I art     : Generating CrashHandler
02-24 16:16:42.992 14969 14969 I DEBUG   : begin to generate native report
02-24 16:16:43.108 14969 15039 I DEBUG   : Resume native log stat thread 15039
02-24 16:16:43.566 14969 14969 I DEBUG   : generate native report finished
02-24 16:16:43.608  1556  2225 I ActivityManager: Process com.UCMobile (pid 14969) has died
02-24 16:16:43.608  1556  1573 I libprocessgroup: Killing pid 15503 in uid 10134 as part of process group 14969

日志解读如下：

1.art标签：系统的Dump模块发现一个SIGSEGV异常后打印了CPU信息，后面应该还有更多的dump信息，但没有执行。

2.DEBUG标签：UC的异常收集模块发现一个Native异常后收集FC信息。

3.AMS打印UC has died。

因为UC截获了异常时候的SIGNAL后没有继续发给Debuggerd，所以系统无法dump tombstone。

好在UC的同事提供了他们收集到的异常信息

FC的现场来看，和系统的Dump逻辑截获的异常不一样，而且指明了是系统的Dump逻辑出了异常。

上图中ArtDumpJavaStack()就是系统的Dump逻辑。

所以这里有两个异常，系统的Dump逻辑捕获一个SIGSEGV异常后，执行dump操作时，又触发一个SIGSEGV异常。

系统的dump逻辑是2月23号进的代码，而问题是24号爆发的，所以判断这段逻辑肯定有问题。

问题是即使是没有这个change，那第一个SIGSEGV异常，默认情况下必然会导致应用FC，但23号版本中不会出现闪退现象。

唯一的解释是，UC截获了这个异常，且这个异常很可能是UC故意搞出来的。

后来跟UC工程师沟通后证实了这个猜想：

UC为了跳过Android N的加载so库的限制，搞了个"黑科技"，会主动触发一个SIGSEGV。

方法是PC指向一个没有可执行权限的内存，这样会触发一个SIGSEGV，sig code为SIGV_ACCERR。

他们会注册SIGSEGV的信号处理函数，在这个信号处理函数中执行"黑科技"。

而系统的dump逻辑却把这个当做异常来处理，在执行dump过程中出现某个异常，导致了新的异常。

UC提供的日志就是系统的dump逻辑产生的异常相关的信息。

出错的原因是未定义指令异常（ILL_ILLOPC），也就是PC指向了一个非法指令。

但实际上PC的值0xe8609dd4指向的是正确的值，也就是ArtDumpJavaStack()。

那为什么是未定义的指令呢？原因是因为cprs的Thumb位(bit5)为0，CUP把ArtDumpJavaStack()当做arm指令了。

而实际上ArtDumpJavaStack()是Thumb Code。

跟UC同事确认，他们没改过cpsr，那很可能是系统的dump逻辑中cpsr没有正确赋值。

Review代码，发现确实有问题：

@art/runtime/fault_handler_crash.cc
  ...
#if defined(__arm__)
  sc->arm_sp -= (SIGSEGV_PROTECT_SP_SIZE);
  sc->arm_r0 = reinterpret_cast<unsigned long>(&savedSigInfo);
  sc->arm_r1 = reinterpret_cast<unsigned long>(&savedContext);
  sc->arm_pc = reinterpret_cast<uintptr_t>(ArtDumpJavaStack);

这里只修改了pc，没有对应地修改cpsr。

修改代码，将cpsr的Thumb位置上后发现依然FC。

但FC的日志跟之前有很大的改变：

02-28 11:36:59.236 26154 26154 I art     : Handling fault
02-28 11:36:59.236 26154 26154 I art     : CrashHandler::Action in:0
02-28 11:36:59.236 26154 26154 I art     :     trap_no 00000000  error_code 00000000  oldmask 00001204  fault_address f5b69000
02-28 11:36:59.236 26154 26154 I art     :     r0 d766f550  r1 00004001  r2 00000000  r3 00000000
02-28 11:36:59.236 26154 26154 I art     :     r4 00000001  r5 f65f7c21  r6 cfa58b75  r7 ceca0b00
02-28 11:36:59.236 26154 26154 I art     :     r8 d0d9d1a8  r9 f3a23230  sl 00000001  fp 00000001
02-28 11:36:59.236 26154 26154 I art     :     ip f65291d0  sp ffe1a7d0  lr f65f7c0f  pc f5b69000  cpsr 80070010
02-28 11:36:59.236 26154 26154 I art     :     trap_no 00000000  error_code 00000000  oldmask 00001204  fault_address f5b69000
02-28 11:36:59.236 26154 26154 I art     :     r0 f3a3d9f8  r1 f3a3d710  r2 00000000  r3 00000000
02-28 11:36:59.236 26154 26154 I art     :     r4 00000001  r5 f65f7c21  r6 cfa58b75  r7 ceca0b00
02-28 11:36:59.237 26154 26154 I art     :     r8 d0d9d1a8  r9 f3a23230  sl 00000001  fp 00000001
02-28 11:36:59.237 26154 26154 I art     :     ip f65291d0  sp ffe1a3d0  lr f65f7c0f  pc f388a160  cpsr 80070030
02-28 11:36:59.237 26154 26154 I art     : Generating CrashHandler
02-28 11:36:59.237 26154 26154 I art     : ArtDumpJavaStack in
02-28 11:36:59.237 26154 26154 I art     : Checking for generated code
02-28 11:36:59.237 26154 26154 I art     : not runnable
02-28 11:36:59.237 26154 26154 I art     : in_generated_code:0
02-28 11:36:59.237 26154 26154 I art     : DumpSigsegvJavaStack
02-28 11:36:59.237 26154 26154 I art     : --------------QuickFrame: 0xffe1aa40 QuickFramePc:0 ShadowFrame:0x0
02-28 11:36:59.237 26154 26154 I art     : sought_offset:24a199eb
02-28 11:36:59.237 26154 26154 I art     :
...
02-28 11:36:59.240 26154 26154 I art     : --------------QuickFrame: 0xffe1b7b0 QuickFramePc:75626805 ShadowFrame:0x0
02-28 11:36:59.240 26154 26154 I art     : --------------#18:com.android.internal.os.ZygoteInit.main(ZygoteInit.java:764)
02-28 11:36:59.241 26154 26154 I art     : ArtDumpJavaStack raise second sigsegv
02-28 11:36:59.241 26154 26154 I art     : Handling fault
02-28 11:36:59.241 26154 26154 I art     : Checking for generated code
 
02-28 11:36:59.241 26154 26154 I art     : CrashHandler::Action in:1
02-28 11:36:59.241 26154 26154 I art     : Caught unknown SIGSEGV in ART fault handler - chaining to next handler.
 
02-28 11:36:59.243 26154 26154 I android_uc_loader: load /data/app/com.UCMobile-1/lib/arm/libandroid_uc_44.so(0xd76f5014) success, hw_accel=1, api_level=24, window=1080x1920, display=1080x1920, cores=4, max_freq=1593, mem=2710, aggressive=0
 
02-28 11:36:59.254 26154 26154 I art     : Handling fault
02-28 11:36:59.254 26154 26154 I art     : CrashHandler::Action in:1
02-28 11:36:59.255 26154 26154 I art     : Caught unknown SIGSEGV in ART fault handler - chaining to next handler.
 
02-28 11:36:59.255 26154 26154 I art     : Handling fault
02-28 11:36:59.255 26154 26154 I art     : CrashHandler::Action in:1
02-28 11:36:59.255 26154 26154 I art     : Caught unknown SIGSEGV in ART fault handler - chaining to next handler.
 
02-28 11:36:59.256 26154 26154 E chromium: [ERROR:icu_util.cc(121)] InitFuncsFromSystemICU failed, status: 2
02-28 11:36:59.256 26154 26154 F chromium: [FATAL:content_main_runner.cc(760)] Check failed: base::i18n::InitializeICU().
 
02-28 11:36:59.256 26154 26154 I art     : Handling fault
02-28 11:36:59.256 26154 26154 I art     : CrashHandler::Action in:1
02-28 11:36:59.256 26154 26154 I art     : Caught unknown SIGSEGV in ART fault handler - chaining to next handler.
 
02-28 11:36:59.256 26154 26154 I DEBUG   : begin to generate native report
02-28 11:36:59.470 26154 26229 I DEBUG   : Resume native log stat thread 26229
02-28 11:36:59.998 26154 26154 I DEBUG   : generate native report finished
02-28 11:37:00.064 11427 11480 I ActivityManager: Process com.UCMobile (pid 26154) has died
02-28 11:37:00.065 11427 11480 D ActivityManager: cleanUpApplicationRecord -- 26154

从日志中可以看到，系统的dump逻辑走完了，同时也有UC额日志输出。那为什么会FC呢?

打印signal的trace信息，如下：

com.UCMobile-6223  [003] d..2   659.442572: signal_generate: sig=11 errno=0    code=196610(SEGV_ACCERR) comm=com.UCMobile pid=6223 grp=0 res=0
com.UCMobile-6223  [003] d..2   659.442964: signal_deliver: sig=11 errno=0     code=196610(SEGV_ACCERR) sa_handler=f29dc2dd sa_flags=c000004
 
com.UCMobile-6223  [003] d..2   659.449876: signal_generate: sig=11 errno=0 code=196609(SEGV_MAPERR) comm=com.UCMobile pid=6223 grp=0 res=0
com.UCMobile-6223  [003] d..2   659.450257: signal_deliver: sig=11 errno=0    code=196609(SEGV_MAPERR) sa_handler=f29dc2dd sa_flags=c000004
 
com.UCMobile-6223  [003] d..2   659.464690: signal_generate: sig=11 errno=0 code=196610(SEGV_ACCERR) comm=com.UCMobile pid=6223 grp=0 res=0
com.UCMobile-6223  [003] d..2   659.465068: signal_deliver: sig=11 errno=0    code=196610(SEGV_ACCERR) sa_handler=f29dc2dd sa_flags=c000004
 
com.UCMobile-6223  [003] d..2   659.468323: signal_generate: sig=11 errno=0 code=196610(SEGV_ACCERR) comm=com.UCMobile pid=6223 grp=0 res=0
com.UCMobile-6223  [003] d..2   659.468645: signal_deliver: sig=11 errno=0    code=196610(SEGV_ACCERR) sa_handler=f29dc2dd sa_flags=c000004
 
com.UCMobile-6223  [003] d..2   659.470047: signal_generate: sig=11 errno=0 code=196609(SEGV_MAPERR) comm=com.UCMobile pid=6223 grp=0 res=0
com.UCMobile-6223  [003] d..2   659.470369: signal_deliver: sig=11 errno=0    code=196609(SEGV_MAPERR) sa_handler=f29dc2dd sa_flags=c000004

其中FC过程中一共有5个signal，

其中第一个信号SEGV_ACCERR是UC主动触发的异常，第二个信号SEGV_MAPERR是系统的Dump逻辑主动触发的异常。

如果说第一个信号SEGV_ACCERR是UC为了加载so库触发的，那第二个信号SEGV_MAPERR后有UC的日志，那说明一个so的加载过程结束了。

后面的两个SEGV_ACCERR和可能就是加载其他库时触发的。

而系统的dump逻辑设计时没考虑这种多个异常信号的case，它只考虑单个异常。

从日志中也能看出来，它只dump了第一个SEGV_ACCERR，后面的异常都没打印。

review代码后找到相关逻辑：

bool CrashHandler::Action(int sig ATTRIBUTE_UNUSED, siginfo_t *siginfo, void *context) {
  LogD << "CrashHandler::Action in:" << counter;
  if (1 == counter) {
      struct ucontext *uc = reinterpret_cast<struct ucontext *>(context);
      memcpy(uc, &savedContext, sizeof(struct ucontext));
      memcpy(siginfo, &savedSigInfo, sizeof(siginfo_t));
      return false;
  }
  counter++;
  struct ucontext *uc = reinterpret_cast<struct ucontext *>(context);
  struct sigcontext *sc = reinterpret_cast<struct sigcontext *>(&uc->uc_mcontext);
  DumpSigContext(uc->uc_mcontext);
  memcpy(&savedContext, uc, sizeof(struct ucontext));
  memcpy(&savedSigInfo, siginfo, sizeof(siginfo_t));
  ...

它在第一次(SEGV_ACCERR)进异常处理函数的时候保存上下问到savedContext里，第二次进来时(SEGV_MAPERR)要恢复上下文。

而第三次(SEGV_ACCERR)进来时，用第一次保存下来的上下文覆盖当前上下文，这明显是逻辑错误。

第三次进来时，应该是重新进行新一次的dump才对。

如何修改呢？很简单，重置一下counter就可以了

bool CrashHandler::Action(int sig ATTRIBUTE_UNUSED, siginfo_t *siginfo, void *context) {
  LogD << "CrashHandler::Action in:" << counter;
  if (1 == counter) {
      counter = 0;
      struct ucontext *uc = reinterpret_cast<struct ucontext *>(context);
      memcpy(uc, &savedContext, sizeof(struct ucontext));
      memcpy(siginfo, &savedSigInfo, sizeof(siginfo_t));
      return false;
  }
  counter++;
  struct ucontext *uc = reinterpret_cast<struct ucontext *>(context);
  struct sigcontext *sc = reinterpret_cast<struct sigcontext *>(&uc->uc_mcontext);
  DumpSigContext(uc->uc_mcontext);
  memcpy(&savedContext, uc, sizeof(struct ucontext));
  memcpy(&savedSigInfo, siginfo, sizeof(siginfo_t));
  ...

posted @ 2017-05-15 21:26 YYPapa 阅读(1478) 评论(0) 编辑收藏举报

刷新页面返回顶部

YYPapa

UC浏览器闪退问题分析报告

公告