[Перевод] Ошибка в stacktrace из продакшена
В этой статье я расскажу про исключительную ситуацию, которая произошла с одним исключением в продакшене Android приложения.
Однажды я получили краш со следующим stacktrace (Firebase Crashlytics и Google Play Console показывали примерно это):
Fatal Exception: java.lang.IllegalArgumentException:
Parameter specified as non-null is null:
method com.example.feature.c.a, parameter $this$extensionB
at com.example.extensions.ExtentionsA.extensionA(ExtentionsA.java:29)
at com.example.service.FcmService.onMessageReceived(FcmService.java:92)
...
В то время как в коде приложения было:
FcmService.java:
package com.example.service;
class FcmService {
...
void onMessageReceived() {
ExtensionsB.extensionB(someNullableString, param);
}
...
}
ExtensionB.kt:
@file:JvmName("ExtensionB")
package com.example.extensions
fun String.extensionB(param: Int) {
...
}
Как вы можете заметить, в stacktrace краша указано, что FcmService.onMessageReceived
вызывает ExtensionsA.extensionA
, хотя на самом деле он вызывает ExtensionsB.extensionB
. Похоже, что причиной данного исключения является первый аргумент метода ExtensionsB.extensionB
, который был передан из Java кода в Kotlin код со ссылкой на null
. Но почему в stacktrace указан какой-то другой класс ExtensionA
? Может быть, где-то на этапе кодогенерации/компиляции/пост-обработке байткода случилась ошибка, и теперь в результате FcmService.onMessageReceived
реально вызывает какой-то другой метод?
Если посмотреть внимательнее на crash stacktrace, то можно увидеть еще парочку неопределенностей. Во-первых, в сообщении об ошибке указан какой-то странный методcom.example.feature.c.a
. Во-вторых, там указано, что проблемный аргумент назывется $this$extensionB
. Это запутало меня окончательно, и я начал расследование!
Действующие лица
Перед тем, как начнем погружаться в кишочки глубИны проблемы, познакомимся с основными действующие лица в данной статье.
ExtensionsA.extensionA
— убийца приложения по версии Firebase Crashlytics, написан на kotlin, является extension-функцией;
ExtensionsB.extensionB
— убийца по версии исходного кода, написан на kotlin, является extension-функцией;
FcmService.onMessageReceived
— ближайший метод, в котором происходит убийство приложения, написан на Java.
R8
Наше Android приложение, как и многие другие, перед публикацией в Google Play проходит этап обфускации с использованием инструмента R8. Это в том числе означает, что после такой обфускации имена классов будут модифицированы, чтобы уменьшить конечный размер бинарного файла. Например, если в коде есть класс class ExtensionA
, то после обработки R8 он может получить другое более короткое имя class c
.
Для того, чтобы Firebase Crashlytics и Google Play могли сделать crash stacktrace читаемым, мы вместе с бинарным файлом приложения загружаем специальный mapping.txt
файл, который содержит информацию о соответствии оригинальных имен к обфусцированным. Для расшифровки таких crash stacktrace Firebase Crashlytics использует утилиту ./retrace:
$ ./retrace mapping.txt stacktrace.txt > result_stacktrace.txt
Таким образом class c
снова станет class ExtensionA
в crash stacktrace.
В этом процессе где-то произошла ошибка, и, в результате, вместо исходного class ExtensionB
получился class ExtensionA
.
Давайте посмотрим на mapping.txt
, и найдем ExtensionA
и все его методы:
com.example.feature.R$style -> com.example.feature.c:
1:1:void com.example.ExtensionsA.extensionA(java.lang.String,java.lang.Integer,java.lang.Integer):29:30 -> a
...
9:9:android.view.View com.example.feature.extensions.AndroidExtensionsKt.inflate(android.view.ViewGroup,int,boolean):0:0 -> a
9:9:android.view.View com.example.feature.AndroidExtensionsKt.inflate$default(android.view.ViewGroup,int,boolean,int,java.lang.Object):23 -> a
10:10:android.view.View com.example.feature.extensions.AndroidExtensionsKt.inflate(android.view.ViewGroup,int,boolean):24:24 -> a
10:10:android.view.View com.example.feature.extensions.AndroidExtensionsKt.inflate$default(android.view.ViewGroup,int,boolean,int,java.lang.Object):23 -> a
...
14:15:void com.example.ExtensionsA.extensionC(java.lang.CharSequence,java.lang.String):11:12 -> a
16:17:void com.example.ExtensionsA.extensionC(java.lang.CharSequence,java.lang.String):15:16 -> a
18:18:void com.example.ExtensionsA.extensionC(java.lang.CharSequence,java.lang.String) -> a
19:19:void com.example.ExtensionsA.extensionC(java.lang.CharSequence,java.lang.String):17:17 -> a
...
27:28:void com.example.ExtensionsB.extensionB(java.lang.String,java.lang.Integer):18:19 -> a
Тут видно, что очень много методов класса com.exampe.feature.c
имеют одно и то же имя — a
(отличия только в аргументах и в типах возвращаемого значения, так что их сигнатуры уникальны). Чтобы убедиться, что это действительно так, посмотрим на байткод этого класса из бинарного файла приложения. Это можно сделать, например, из AndroidStudio:
Build → Analyse APK… →
Байткод класса com.example.feature.c
28 методов этого класса имеют имя a
, и один имеет имя b
.
Так же интересно, почему в классе com.example.feature.R$style
находятся методы ExtensionB
, и других утилитных (extension-функции, написанные в отдельном файле в байткоде выглядят, как utility класс) классов? Ответ лежит где-то среди оптимизаций R8, конкретно в class/merging оптимизации. R8 может «схлопывать» несколько классов в один. Вот, что произошло: com.example.feature.R$style
был пустым и статические методы из других утилитных классов были перемещены в этот класс, чтобы минимизировать итоговое количество классов в *.dex файле.
Kotlin std-lib
Давайте держать в голове факты, которые мы уже обнаружили, и попробуем разобраться с другим вопросом: почему сообщение из crash stacktrace содержит обфусцированное имя класса com.example.feature.c
:
Parameter specified as non-null is null:
method com.example.feature.c.a, parameter $this$extensionB
Почему это странно? Потому что crash stacktrace всегда проходит деобфускцию с помощью ./retrace, но имя этого класса осталось обфусцированным.
Так как это исключение было брошено из kotlin кода, то самое время открыть байткод класса ExtensionB.extensionB
, чтобы понять причину (для упрощения декомпилируем этот байткод в Java):
public final class ExtensionsB {
@NotNull
public static void extensionB(
@NotNull String $this$extensionB,
final int param
) {
Intrinsics.checkParameterIsNotNull(
$this$extensionB,
"$this$extensionB"
);
...
}
}
Тут видно, что имя аргумента хранится строковым литералом. Конечно, R8 не сможет такое обфусцировать. Дальше нам нужно посмотреть на реализацию Intrinsics.checkParameterIsNotNull в стандартной библиотеке kotlin (на тот момент наш проект использовал kotlin версии 1.3.50):
StackTraceElement[] stackTraceElements = Thread.currentThread().getStackTrace();
StackTraceElement caller = stackTraceElements[3];
String className = caller.getClassName();
String methodName = caller.getMethodName();
IllegalArgumentException exception = new IllegalArgumentException(
"Parameter specified as non-null is null: " +
"method " + className + "." + methodName +
", parameter " + paramName
);
throw sanitizeStackTrace(exception);
Так, полное имя класса, содержащее имя пакета и имя класса, как и имя метода, берутся из stacktrace текущего потока и как есть вставляются в сообщение исключения. Естественно, ./retrace не деобфусцирует сообщения исключений, только stacktrace. Поэтому из за связки R8 + kotlin stdlib имя класса (осталось обфусцированным) и метода (осталось деобфусцированным) мы видим в реальности такими.
Перед тем, как мы сделаем финальный шаг в нашем расследовании, давайте подытожим имеющиеся знания о проблеме:
Разоблачение
Чтобы полностью понять, что произошло, мы пропустили один элемент — текст оригинального (до обработки утилитой ./retrace) crash stacktrace. К сожалению, ни Firebase Crashlytics, ни Google Play Console не предоставляют возможность взгялнуть на текст реального crash. Поэтому придется воссоздать этот крэш в домашних условиях, и отловить его в логах. В нашем случае это удалось сделать достаточно просто (падение воспроизводилось по известным шагам):
java.lang.IllegalArgumentException:
Parameter specified as non-null is null:
method com.example.feature.c.a, parameter $this$extensionB
at com.example.feature.c.a(Unknown Source:2)
at com.example.service.FcmListenerService.onMessageReceived(SourceFile:4)
Проблема в Unknown Source:2
. Мы помним, что в байткоде класса com.example.feature.c
28 методов по имени a
. ./retrace, очевидно, не смог найти нужный и взял первый попавшийся. Unknown Source:2
— этой информации недостаточно. Я полагаю, так могло произойти из за того, что ExtensionB.extensionB
стал частью R$style
, а R$style
изначально был «вкомпилирован» в бинарный файл (так как начиная с версии Android Gradle Plugin 3.3.0 R.java больше не генерируется):
Previously, the Android Gradle plugin would generate an
R.java
file for each of your project’s dependencies and then compile those R classes alongside your app’s other classes. The plugin now generates a JAR containing your app’s compiled R class directly, without first building intermediateR.java
classes.
Что теперь делать
Убийца найден. Это все таки не тот парень, которого подставила Firebase Crashlytics, а ExtensionB.extensionB
. Но легче от этого не стало. Вдруг еще будут убийства со скрытием реального злодея? Надо что-то предпринять.
Кажется, что достаточно выключить R8 оптимизацию, которая склеивает классы. ProGuard синтаксис даже позволяет это сделать:
-optimizations !class/merging/*
Однако, R8 игноирует все правила, связанные с дискретными оптимизациями ради вашего же блага для упрощения поддержки и разработки R8. Есть возможность выключить все оптимизации с помощью правила -dontoptimize
, но это может сказаться не лучшим образом на производительности приложения в продакшене.
В момент получения этого исключения наше приложение использовало Androir Gradle Plugin версии 3.6.2, который, в свою очередь, использовал R8 версии 1.6.82. После обновления AGP до версии 4.2.2 (который стал использовать R8 версии 2.2.71), поведение R8 оптимизаций слегка изменилось. Теперь, если методы имеют различные имена в оригинальном коде, то они будут иметь различные имена и после обфускации. Взглянем на mapping.txt
теперь:
com.example.feature.R$style -> com.example.feature.c:
1:1:void com.example.ExtensionsA.extensionA(java.lang.String,java.lang.Integer,java.lang.Integer):29:30 -> A
...
9:9:android.view.View com.example.feature.extensions.AndroidExtensionsKt.inflate(android.view.ViewGroup,int,boolean):0:0 -> B
9:9:android.view.View com.example.feature.AndroidExtensionsKt.inflate$default(android.view.ViewGroup,int,boolean,int,java.lang.Object):23 -> B
10:10:android.view.View com.example.feature.extensions.AndroidExtensionsKt.inflate(android.view.ViewGroup,int,boolean):24:24 -> B
10:10:android.view.View com.example.feature.extensions.AndroidExtensionsKt.inflate$default(android.view.ViewGroup,int,boolean,int,java.lang.Object):23 -> B
...
14:15:void com.example.ExtensionsA.extensionC(java.lang.CharSequence,java.lang.String):11:12 -> C
16:17:void com.example.ExtensionsA.extensionC(java.lang.CharSequence,java.lang.String):15:16 -> C
18:18:void com.example.ExtensionsA.extensionC(java.lang.CharSequence,java.lang.String) -> C
19:19:void com.example.ExtensionsA.extensionC(java.lang.CharSequence,java.lang.String):17:17 -> C
...
27:28:void com.example.ExtensionsB.extensionB(java.lang.String,java.lang.Integer):18:19 -> D
Теперь ./retrace без проблем и ошибок сделает деобфускацию stacktrace.
В конце концов я просто обновил Android Gradle Plugin в нашем проекте и больше странных исключений в Firebase Crashlytics не видел. Но, так как это не всегда может помочь, то хорошо будет понимать, что конкретно происходит во всем этом нетривиальном процессе от написания кода до разбора исключений из продакшена.