Привет, Хабр! Меня зовут Саша Лепехин, я разрабатываю мобильное приложение СберИнвестор под Android. Во время разработки и тестирования мобильного приложения мне часто нужно  просматривать логи внутри приложения, причем без подключения по adb.

В принципе, есть множество приложений, которые позволяют просматривать содержимое logcat на устройств. Но с ними часто возникают самые разные проблемы:  такие приложения нуждаются в специальных разрешениях или наличии root доступа, запускают отдельные процессы или сервисы. Или же они могут просто не работать на некоторых устройствах (например, там, где выключен logd). В этой небольшой статье предложено решение большинства подобных проблем. Оно основано на трансформации байт-кода приложения. Поехали!

Постановка задачи

Добавить возможность просмотра логов в приложении.

• Фича должна работать только в debug build type.

• Где-то в приложении должен быть RecyclerView, содержащий последние N записей из лога.

• Важно, чтобы можно было просматривать сообщения, залогированные как внутри нашего приложения (исходный код принадлежит нам и мы можем вносить в него изменения), так и во внешних библиотеках.

• Нет необходимости в логах операционной системы и других приложений.

Разбираемся с проблемами

Runtime.exec()

Задача с первого взгляда простая и решение, которое сразу приходит в голову — выполнить команду logcat с помощью, допустим, Runtime.exec(). То есть - получить список сообщений, распарсить какой-нибудь регуляркой и вывести на экран. Но на самом деле это не очень хорошая реализация. Дело в том, что мы выполняем какую-то стороннюю команду, поведение которой нами не регулируется — может измениться формат вывод, из-за чего  придется править регулярное выражение, да и логирование может быть выключено на уровне операционной системы. В итоге получим не очень стабильное решение.

Но есть же Timber!

К сожалению, Timber тут не поможет. Можно было бы сделать свою реализацию Timber.log.Tree, но это никак не решит проблему с логированием сообщений из внешних библиотек, к которым нет доступа.

Еще варианты?

Здорово, если бы существовала возможность перехватить вызов методов android.util.Log и сохранить сообщение в свой Storage. Почему здорово? В этом случае не нужно логировать другие приложения, поэтому достаточно в apk поменять вызовы android.util.Log на какой-то собственный логгер). И это вполне реализуемо.

Самое время проанализировать, из каких частей может состоять наше решение.

1. Storage — место где хранятся залогированные сообщения (например, какой-нибудь циклический буфер в памяти).

2. Appender — компонент, который доставляет сообщение в storage.

3. Viewer — читает сообщения из storage и выводит пользователю.

В системе логирования Android можно сказать, что storage — набор циклических буферов, управляемых демоном logd, Appender — android.util.Log и библиотека liblog, а Viewer — logcat (https://developer.android.com/studio/command-line/logcat#Overview, https://developer.android.com/reference/android/util/Log). В коде вызываем методы android.util.Log, которые вызывают метод из liblog, а он, в свою очередь, отправляет сообщение в соответствующий буфер.

android.util.Log.d() → my.app.util.Log.d()

Gradle и AGP позволяют преобразовывать байт-код. Можно написать свой AsmClassVisitorFactory и ClassVisitor, который и будет производить эту трансформацию. Такая возможность есть — подобные преобразования выполняют многие библиотеки и фреймворки. 

 Что для этого нужно:

1. Реализовать свой Appender, методы которого будут вызываться вместо android.util.Log.

2. Написать ClassVisitor, который будет преобразовывать вызовы методов android.util.Log в соответствующие методы Appender. Тут воспользуемся относительно простым решением: в инструкции INVOKE_STATIC можно просто подменить один класс (method owner) на другой, при условии, что их дескрипторы идентичны (подходит и  MethodHandle, но это доступно только начиная с "Android O").

3. Воспользоваться удобной возможностью по преобразованию байт-кода предоставляемой AGP.

4. Реализовать свой Storage, где будут храниться логи.

5. Реализовать Viewer, чтобы можно было бы удобно просматривать логи, искать нужные сообщения и шарить логи между приложениями (почта/мессенджер).

Ну что ж, приступим...

К делу!

Appender

В реализации Appender (назовем его LogProxy) нет ничего сложного, но нужно обратить внимание на следующие моменты:

1. В принципе, это не обязательно, но для простоты реализации трансформера байт-кода повторим бинарный интерфейс методов логирования (v(), i(), w(), d(), e()) из класса android.uril.Log.

2. Кроме добавления сообщения в Storage оставим нативное логирование через android.util.Log, чтобы просматривать логи с помощью logcat.

3. Метод логирования должен быть быстрым и не блокировать поток, или сводить такие блокировки к минимуму.

Вот пример реализации Appender — LogProxy. В каждом методе потребуется реализовать сохранение сообщения в какой-то абстрактный Storage.

/**
 * Класс копирующий структуру методов из [Log].
 * Используется для подмены вызовов к [Log] на уровне байт-кода.
 */
object LogProxy {
    @JvmStatic
    fun i(tag: String, message: String): Int {
        // todo: Тут нужно сохранить message в наш Storage
        return Log.i(tag, message)
    }

    @JvmStatic
    fun i(tag: String, message: String, throwable: Throwable): Int {
        //...
    }

    @JvmStatic
    fun d(tag: String, message: String): Int {
        //...
    }

    @JvmStatic
    fun d(tag: String, message: String, throwable: Throwable): Int {
        //...
    }

    @JvmStatic
    fun v(tag: String, message: String): Int {
        //...
    }

    @JvmStatic
    fun v(tag: String, message: String, throwable: Throwable): Int {
        //...
    }

    @JvmStatic
    fun w(tag: String, message: String): Int {
        //...
    }

    @JvmStatic
    fun w(tag: String, message: String, throwable: Throwable): Int {
        //...
    }

    @JvmStatic
    fun w(tag: String, throwable: Throwable): Int {
        //...
    }

    @JvmStatic
    fun e(tag: String, message: String): Int {
        //...
    }

    @JvmStatic
    fun e(tag: String, message: String, throwable: Throwable): Int {
        //...
    }
}

Storage

Сначала опишем наш Storage, пока на уровне интерфейса. Ну и заодно создадим сущность, представляющую единичную запись лога — LogEntry.

/**
 * Хранилище логов [LogEntry]
 *
 * Реализация должна учитывать:
 * 1) методы могут быть вызваны из разных потоков
 * 2) метод [append] не должен блокировать поток или сводить такие блокировки к минимуму
 */
interface Storage {
    /**
     * Добавить [logEntry]
     *
     * @param logEntry экземпляр [LogEntry], который необходимо сохранить
     */
    fun append(logEntry: LogEntry)

    /**
     * Снимок состояния хранилища логов.
     * Возвращает [Iterator]<[LogEntry]> по всем записям,
     * которые были добавлены методом [append] до вызова [snapshot]
     *
     * @return [Iterator]<[LogEntry]> копии содержимого буфера на момент вызова метода
     */
    fun snapshot(): Iterator<LogEntry>

    /**
     * Удалить все записи [LogEntry]
     */
    fun clear()
}

/**
 * Сущность представляющая элемент (строку) в системе журналирования - то, что логируется при вызове
 * `android.util.Log.println(...)`
 *
 * @property tag [String] строка для идентификации источника сообщения
 * @property message [String] логируемое сообщение. Может быть multiline
 * @property priority [Priority] приоритет.
 * @property throwable [Throwable]
 * @property timestamp [Long] временная метка, время создания записи
 */
data class LogEntry(
    val tag: String,
    val message: String,
    val priority: Priority,
    val throwable: Throwable? = null,
    val timestamp: Long = System.currentTimeMillis()
)

/**
 * Приоритет с которым логируется сообщение
 */
enum class Priority {
    VERBOSE,
    DEBUG,
    INFO,
    WARN,
    ERROR,
    ASSERT
}

С доменной моделью вроде бы все, давайте теперь вернемся к LogProxy. Мы там оставили todo.

На данный момент нет конкретной реализации Storage (мы ее еще не написали), да и хотелось бы, чтобы была возможность использовать разные реализации, чтобы прямо в run-time указать нужный Storage, а не хардкодить это на уровне LogProxy.

Для этого создадим StorageDispatcher, который будет делегировать все свои вызовы конкретной реализации Storage.

/**
 * [Storage], который делегирует методы в [storage]
 *
 * Используется для переопределения реализации [Storage] в run-time
 */
object StorageDispatcher : Storage {
    /**
     * [Storage] которому будут делегированы функции по добавлению [LogEntry], очистке и создания снимков.
     */
    var storage: Storage? = null

    override fun append(logEntry: LogEntry) {
        storage?.append(logEntry)
    }

    override fun snapshot(): Iterator<LogEntry> =
        storage?.snapshot() ?: Collections.emptyIterator()

    override fun clear() {
        storage?.clear()
    }
}

И теперь методы LogProxy принимают вот такой вид:

@JvmStatic
fun i(tag: String, message: String): Int {
    StorageDispatcher.storage?.append(
        LogEntry(
            tag = tag,
            message = message,
            priority = Priority.INFO
        )
    )
    return Log.i(tag, message)
}

Трансформация байт-кода

Теперь самое интересное — будем преобразовывать байт-код.

Начнем с реализации ClassVisitor. Напомню, что для этого потребуется в инструкции INVOKE_STATIC поменять method owner с andoid.util.log на наш LogProxy.

Если посмотреть на байт-код, то преобразование выглядит так:

До:

LINENUMBER 22 L0
LDC "Logging debug1"
LDC "Debug message"
INVOKESTATIC android.util.Log.d (Ljava/lang/String;Ljava/lang/String;)I
POP

После:

LINENUMBER 22 L0
LDC "Logging debug1"
LDC "Debug message"
INVOKESTATIC ru/sberbank/android/log/transformation/core/LogProxy.d (Ljava/lang/String;Ljava/lang/String;)I
POP

Т.е. поменять строку "android.util.Log" на ru/sberbank/android/log/transformation/core/LogProxy". В этом поможет прекрасный фреймворк ASM. Вот так, например:

class MethodOwnerTransformationClassVisitor(
    api: Int,
    classVisitor: ClassVisitor
) :
    ClassVisitor(api, classVisitor) {

    override fun visitMethod(
        access: Int,
        name: String?,
        descriptor: String?,
        signature: String?,
        exceptions: Array<out String>?
    ): MethodVisitor {
        return object :
            MethodVisitor(api, super.visitMethod(access, name, descriptor, signature, exceptions)) {
            override fun visitMethodInsn(
                opcode: Int,
                owner: String?,
                name: String?,
                descriptor: String?,
                isInterface: Boolean
            ) {
                if (owner == "android/util/Log" && name == "d" && opcode == Opcodes.INVOKESTATIC) {
                    mv.visitMethodInsn(opcode, "ru/sberbank/android/log/transformation/core/LogProxy", name, descriptor, isInterface)
                } else {
                    super.visitMethodInsn(opcode, owner, name, descriptor, isInterface)
                }
            }
        }
    }
}

Получается, что visitMethodInsn выполняется как только встречает в коде инструкцию, которая вызывает какой-то метод. Далее проверяем: если это статический метод android.util.Log.d(...), то вместо исходной инструкции записываем новую, точно такую же, но вызывающую метод LogProxy.d().

Для простоты изложения пока ограничимся только методом d() и оставим хардкод в виде строк дескрипторов (думаю, что написать полную реализацию несложно). А пока напишем AsmClassVisitorFactory и gradle плагин, который будет запускать  MethodOwnerTransformationClassVisitor.

abstract class LogTransformationFactory : AsmClassVisitorFactory<LogTransformationParameters> {

    override fun createClassVisitor(
        classContext: ClassContext,
        nextClassVisitor: ClassVisitor
    ): ClassVisitor {
        return if (isInstrumentable(classContext.currentClassData)) {
            MethodOwnerTransformationClassVisitor(
                api = instrumentationContext.apiVersion.get(),
                classVisitor = nextClassVisitor
            )
        } else {
            nextClassVisitor
        }
    }

// Так как в LogProxy мы оставили вызов методов android.util.Log, то исключим его из классов, которые подлежат трансформации
    override fun isInstrumentable(classData: ClassData): Boolean =
        classData.className != "ru.sberbank.android.log.transformation.core.LogProxy" 
}

// gradle plugin
description = "Convention-plugin для преобразования вызовов к android.util.Log"

project.plugins.withType(AndroidBasePlugin::class) {
    extensions.getByType(AndroidComponentsExtension::class).onVariants {
        if (it.buildType == "debug") {
            it.transformClassesWith(
                LogTransformationFactory::class.java,
                InstrumentationScope.ALL
            ) { params ->
                // todo
            }
        }
    }
}

Осталось сбилдить плагин и подключить его к приложению...

После декомпиляции собранного приложения можно видеть, что там, где раньше вызывался Log.d(), теперь вызывается LogProxy.d().

Осталось реализовать свой Storage. Он может быть in-memory, а может сохранять LogEntry на диск. Конкретная реализация Storage, как и компонентов для отображения его содержимого на экране устройства, уже не относится к теме этой статьи. Главное — не забывайте, что методы Storage могут быть вызваны из разных потоков. И помните, что логирование не должно ухудшать производительность приложения, даже в debug build type.

На этом все — если вдруг у вас возникли вопросы или предложения по теме, традиционно отписывайтесь в комментариях. Надеюсь, что статья окажется полезной для многих разработчиков.

Немного полезных ссылок

• ASM

• Logging system overview

• android.util.log

• transformClassesWith