Android P内联优化导致的一个诡异Bug

赵裕(vimerzhao)

2020-04-24 (最后修改: 2023-04-01)

Android

本文约 3500 字，阅读需 7 分钟。

问题背景

最近，我们的业务在动态加载一款第三方游戏时出现了奇怪的现象，本地开发测试体验良好，但是使用CI构建的正式包体验时会出现启动闪退。

问题分析

分析日志

首先，我们自然而然看了下Crash日志，如下：

    --------- beginning of crash
2020-04-16 09:19:07.724 31492-31596/? E/AndroidRuntime: FATAL EXCEPTION: PriorityExecutor #1
    Process: com.example.脱敏:脱敏00, PID: 31492
    java.lang.RuntimeException: An error occured while executing doInBackground()
        at com.youzu.android.framework.task.PriorityAsyncTask$2.done(PriorityAsyncTask.java:87)
        at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:383)
        at java.util.concurrent.FutureTask.setException(FutureTask.java:252)
        at java.util.concurrent.FutureTask.run(FutureTask.java:271)
        at com.youzu.android.framework.task.PriorityRunnable.run(PriorityRunnable.java:16)
        at java.util.concurrent.ThreadPoolExecutor.processTask(ThreadPoolExecutor.java:1187)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:784)
     Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'java.lang.String java.net.URI.toString()' on a null object reference
        at com.youzu.android.framework.http.HttpHandler.sendRequest(HttpHandler.java:183)
        at com.youzu.android.framework.http.HttpHandler.doInBackground(HttpHandler.java:212)
        at com.youzu.android.framework.http.HttpHandler.doInBackground(HttpHandler.java:52)
        at com.youzu.android.framework.task.PriorityAsyncTask$1.call(PriorityAsyncTask.java:74)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at com.youzu.android.framework.task.PriorityRunnable.run(PriorityRunnable.java:16)
        at java.util.concurrent.ThreadPoolExecutor.processTask(ThreadPoolExecutor.java:1187)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:784)

是游戏里面产生的Crash，这时候问题就产生了：为什么debug包可以正常启动，release包就不行呢？

经过反复测试，我们发现是debuggable这个字段在作祟。那么问题就变成了：为什么我们宿主的debuggable为false时会导致被加载的游戏Crash？

同时，在Crash日志之外，我们还发现一个系统打印的Error级别的日志：

Maybe bug 77342775, looking for Lorg/apache/http/HttpEntity; 0x14021040[continuous;main space (region space)] defined in /system/framework/org.apache.http.legacy.boot.jar/0xe8aa5300
  with loader: com.tencent.脱敏.core.脱敏ClassLoader/0xdfa67020[hit:continuous;main space (region space)];java.lang.BootClassLoader/0xe8aa0260
  in interface table for Ljava/util/concurrent/locks/ReentrantLock; 0x6f101c78[image;/data/dalvik-cache/arm/system@framework@boot.art;+;0x6f080000] defined in /system/framework/core-oj.jar/0xe8aa3380 ifcount=2
  with loader BootClassLoader
  iface #0: java.util.concurrent.locks.Lock
  iface #1: java.io.Serializable

但是我们逆向了这个游戏之后，发现这几个类根本对应不上！！HttpEntity和Lock没有任何关联。

缩小范围

一时没有头绪，于是我们做了以下实验来缩小问题范围：

release包加载，debug包覆盖安装，打开游戏失败
debug包加载，release包覆盖安装，打开游戏成功
8.0加载，打开成功；9.0加载，打开失败
华为9.0、小米9.0均会出现这个错误
其他游戏release包加载后也能打开

由此可以得出三个结论：

这个问题产生的位置是加载，而不是打开
这个问题是Android P普遍存在的一个问题
问题游戏包一定有什么特殊的代码存在(Apache)

第二点意味着我们可以从Android的源码里面挖掘一些信息了！！！

发现突破点

既然是加载阶段的问题，那我们就比较一下加载阶段的产物，果然有重大发现：

这时候，我们在审视一下之前的日志：

Maybe bug 77342775, looking for Lorg/apache/http/HttpEntity; 0x14021040[continuous;main space (region space)] defined in /system/framework/org.apache.http.legacy.boot.jar/0xe8aa5300
  with loader: com.tencent.脱敏.core.脱敏ClassLoader/0xdfa67020[hit:continuous;main space (region space)];java.lang.BootClassLoader/0xe8aa0260
  in interface table for Ljava/util/concurrent/locks/ReentrantLock; 0x6f101c78[image;/data/dalvik-cache/arm/system@framework@boot.art;+;0x6f080000] defined in /system/framework/core-oj.jar/0xe8aa3380 ifcount=2
  with loader BootClassLoader
  iface #0: java.util.concurrent.locks.Lock
  iface #1: java.io.Serializable

这个日志可以在源码里面找到，以下是相关代码：

// http://androidxref.com/9.0.0_r3/xref/art/runtime/debug_print.cc#132
void DumpB77342775DebugData(ObjPtr<mirror::Class> target_class, ObjPtr<mirror::Class> src_class) {
  ......
  LOG(ERROR) << "Maybe bug 77342775, looking for " << target_descriptor
      << " " << target_class.Ptr() << "[" << DescribeSpace(target_class) << "]"
      << " defined in " << target_class->GetDexFile().GetLocation()
      << "/" << static_cast<const void*>(&target_class->GetDexFile())
      << "\n  with loader: " << DescribeLoaders(target_class->GetClassLoader(), target_descriptor);
  if (target_class->IsInterface()) {
    ObjPtr<mirror::IfTable> iftable = src_class->GetIfTable();
    CHECK(iftable != nullptr);
    size_t ifcount = iftable->Count();
    LOG(ERROR) << "  in interface table for " << source_descriptor
        << " " << src_class.Ptr() << "[" << DescribeSpace(src_class) << "]"
        << " defined in " << src_class->GetDexFile().GetLocation()
        << "/" << static_cast<const void*>(&src_class->GetDexFile())
        << " ifcount=" << ifcount
        << "\n  with loader " << DescribeLoaders(src_class->GetClassLoader(), source_descriptor);
  ......
}  // namespace art


// http://androidxref.com/9.0.0_r3/xref/art/runtime/common_throws.cc#272
void ThrowIncompatibleClassChangeErrorClassForInterfaceSuper(ArtMethod* method,
                                                             ObjPtr<mirror::Class> target_class,
                                                             ObjPtr<mirror::Object> this_object,
                                                             ArtMethod* referrer) {
  // Referrer is calling interface_method on this_object, however, the interface_method isn't
  // implemented by this_object.
  CHECK(this_object != nullptr);
  std::ostringstream msg;
  msg << "Class '" << mirror::Class::PrettyDescriptor(this_object->GetClass())
      << "' does not implement interface '" << mirror::Class::PrettyDescriptor(target_class)
      << "' in call to '"
      << ArtMethod::PrettyMethod(method) << "'";
  DumpB77342775DebugData(target_class, this_object->GetClass());
  ThrowException("Ljava/lang/IncompatibleClassChangeError;",
                 referrer != nullptr ? referrer->GetDeclaringClass() : nullptr,
                 msg.str().c_str());
}


// http://androidxref.com/9.0.0_r3/xref/art/runtime/entrypoints/entrypoint_utils-inl.h#432
template<InvokeType type, bool access_check>
inline ArtMethod* FindMethodFromCode(uint32_t method_idx,
                                     ObjPtr<mirror::Object>* this_object,
                                     ArtMethod* referrer,
                                     Thread* self) {
  ClassLinker* const class_linker = Runtime::Current()->GetClassLinker();
  constexpr ClassLinker::ResolveMode resolve_mode =
      access_check ? ClassLinker::ResolveMode::kCheckICCEAndIAE
                   : ClassLinker::ResolveMode::kNoChecks;
  ArtMethod* resolved_method;
  ......
        // It is an interface.
        if (access_check) {
          if (!method_reference_class->IsAssignableFrom(h_this->GetClass())) {
            ThrowIncompatibleClassChangeErrorClassForInterfaceSuper(resolved_method,
                                                                    method_reference_class,
                                                                    h_this.Get(),
                                                                    referrer);
            return nullptr;  // Failure.
          }
        }
  ......
}

同时，结合谷歌官方文档关于Android P的一项变更：

在 Android 6.0 中，我们移除了对 Apache HTTP 客户端的支持。从 Android 9 开始，该内容库已从 bootclasspath 中移除，且默认情况下应用无法使用它。

至此，问题似乎有了一个靠谱的怀疑方向：

被加载的游戏包内置了一个Apache的jar包，但是里面什么也没有，纯粹为了编译，我们加载的时候这个jar包里面的类发生了内联优化，真正打开的时候，我们又去模拟系统把真正的Apache的jar包放在最前面，这样游戏包就会拿着发生了内联的方法索引，去没有做相同内联优化的系统的Apache的jar包里面寻找对应方法，由此发生了错误。

这样，Maybe bug 77342775这个错误，为什么发生在Android 9版本，为什么debug包被release覆盖安装后没问题、为什么odex的大小发生了变化、为什么其他游戏包没有问题就都可以解释了。

但是不是这样呢?

系统安装

如果是这样，系统安装为什么没问题呢？于是，我们抓取了系统安装、debug加载、release加载的日志，如下：

//系统安装
I/dex2oat: /system/bin/dex2oat --input-vdex-fd=-1 --output-vdex-fd=31 --compiler-filter=speed-profile -j4 --classpath-dir=/data/app/com.tencent.tmgp.youzu.脱敏-oJz4mDEvj93nM4l8cFRHMA== --class-loader-context=PCL[/system/framework/org.apache.http.legacy.boot.jar] --generate-mini-debug-info --compact-dex-level=none --compilation-reason=install

// debug加载
I/dex2oat: The ClassLoaderContext is a special shared library.
I/dex2oat: /system/bin/dex2oat --debuggable -j4 --debuggable --generate-mini-debug-info --dex-file=/data/user/0/com.example.脱敏/脱敏/com.tencent.tmgp.youzu.脱敏/apk/base-1.apk --output-vdex-fd=64 --oat-fd=66 --oat-location=/data/user/0/com.example.脱敏/脱敏/com.tencent.tmgp.youzu.脱敏/apk/oat/arm/base-1.odex --compiler-filter=quicken --class-loader-context=& --compilation-reason=dynamic-load
I/dex2oat: runtime mdmPath /system/emui/base/jar/Mdm/hw_mdm_framework.jar
W/dex2oat: Accessing hidden field Landroid/graphics/drawable/Drawable;->DEFAULT_TINT_MODE:Landroid/graphics/PorterDuff$Mode; (dark greylist, linking)
I/dex2oat: dex2oat took 1.719s (3.040s cpu) (threads: 4) arena alloc=252KB (258240B) java alloc=5MB (5400672B) native alloc=6MB (7064328B) free=4MB (4994296B)

//release加载
I/dex2oat: The ClassLoaderContext is a special shared library.
I/dex2oat: /system/bin/dex2oat -j4 --dex-file=/data/user/0/com.example.脱敏/脱敏/com.tencent.tmgp.youzu.脱敏/apk/base-1.apk --output-vdex-fd=55 --oat-fd=57 --oat-location=/data/user/0/com.example.脱敏/脱敏/com.tencent.tmgp.youzu.脱敏/apk/oat/arm/base-1.odex --compiler-filter=quicken --class-loader-context=& --compilation-reason=dynamic-load
I/dex2oat: runtime mdmPath /system/emui/base/jar/Mdm/hw_mdm_framework.jar
W/dex2oat: Accessing hidden field Landroid/graphics/drawable/Drawable;->DEFAULT_TINT_MODE:Landroid/graphics/PorterDuff$Mode; (dark greylist, linking)
I/dex2oat: dex2oat took 2.276s (3.511s cpu) (threads: 4) arena alloc=376KB (385944B) java alloc=5MB (5384288B) native alloc=10MB (10731936B) free=3MB (3423840B)

通过查阅资料，我们发现--debuggable这个参数，会阻止内联，所以debug包一直没有暴露这个问题，而系统之所以没有这个问题就在于--class-loader-context这个字段，系统安装直接把真正的jar的路径作为上下文传过去了，所以就算内联索引也是能对上号了，我们就惨了～

问题解决

如果猜想正确，那么有以下几个方向：

让游戏方不要把这个仅用于编译的jar包打包进去
我们也传一个--class-loader-context的上下文
禁用dex2oat

首先第一个不太现实，第二个和第三个本质都是要修改Runtime的变量，第三个相对来说会简单一些（第二个的传递路径极其复杂，源码直接把我看懵逼了）。可能有人会觉得这个能力是系统提供的，禁用的是不是会影响性能？

我们查阅Android 10的行为变更会发现以下信息：

Android 运行时 (ART) 不再从应用进程调用 dex2oat。这项变更意味着 ART 将仅接受系统生成的 OAT 文件。

可能，谷歌也觉察到了开发者的各种骚操作会破坏用户体验，于是干脆不提供给应用进程了，本着先解决，后优化的思想，我们选择了第三种方案。

通过ART的源码可知：

// jni.h
jint GetJavaVM(JavaVM** vm) {
    return functions->GetJavaVM(this, vm);
}

可以通过这个jni方法拿到ART虚拟机的指针，进一步拿到运行时的指针。再看一下运行时的结构

// http://androidxref.com/9.0.0_r3/xref/art/runtime/runtime.h#840

 private:
  ...
  static constexpr uint32_t kCalleeSaveSize = 6u;

  // 64 bit so that we can share the same asm offsets for both 32 and 64 bits.
  uint64_t callee_save_methods_[kCalleeSaveSize];
  GcRoot<mirror::Throwable> pre_allocated_OutOfMemoryError_;
  GcRoot<mirror::Throwable> pre_allocated_NoClassDefFoundError_;
  ArtMethod* resolution_method_;
  ArtMethod* imt_conflict_method_;
  // Unresolved method has the same behavior as the conflict method, it is used by the class linker
  // for differentiating between unfilled imt slots vs conflict slots in superclasses.
  ArtMethod* imt_unimplemented_method_;

  // Special sentinel object used to invalid conditions in JNI (cleared weak references) and
  // JDWP (invalid references).
  GcRoot<mirror::Object> sentinel_;

  InstructionSet instruction_set_;
  QuickMethodFrameInfo callee_save_method_frame_infos_[kCalleeSaveSize];

  CompilerCallbacks* compiler_callbacks_;
  bool is_zygote_;
  bool must_relocate_;
  bool is_concurrent_gc_enabled_;
  bool is_explicit_gc_disabled_;
  bool dex2oat_enabled_;
  bool image_dex2oat_enabled_;

我们要修改的dex2oat_enabled_前面有一些变量，于是我们可以用指针+偏移拿到这个变量的指针地址，进而赋值，具体操作见这篇文章 art dex2oat 加载加速浅析。

这个解法也存在一些风险，就是如果厂商修改了这个结构体，我们的偏移就错了，因此存在一定的兼容性问题。但是，也可以做一些校验预警，比如InstructionSet的结构如下：

enum class InstructionSet {
  kNone,
  kArm,
  kArm64,
  kThumb2,
  kX86,
  kX86_64,
  kMips,
  kMips64,
  kLast = kMips64
};

那么如果指针偏移错了，那么instruction_set_的值也很难落在0~7这个区间

复盘总结

本文的分析总结处于一个上帝视角，其实解决这个问题的过程中，我和另外一个同事也是饱受煎熬，花了将近一周的时间才从千头万绪中找到真相。尤其是分析问题原因的时候，由于错误日志和原因之间的联系并不是那么明显，很多推测也无法立刻验证，中间的很多尝试由于篇幅都没有写出来，最后是反复通过阅读Android的源码和做对比实验才找到原因。

参考文章

update: 2021-06-08

尝试在修改JavaVM的字段之前做类型校验
直接修改 bootclasspath 的 jar 包加载顺序是否也可以解决这个问题（兼容性更好）

总阅读量次。