Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit d4c12038 authored by Evan Laird's avatar Evan Laird
Browse files

[Sb refactor] Add local logcat echoing to TableLogBuffer

TableLogBuffer is a sibling of LogBuffer, so it needs to reimplement the
desirable behaviors of Logbuffer. In this CL, we're adding support for
local logcat echoing on every table. The logging happens only in the
background and can fail silently so that it never blocks the main
thread.

This implementation differs from the LogBuffer implementation which was
written before the coroutines library was available, so it doesn't use
a background thread-per-table like the LogBuffer implementation does.
Rather, this implementation uses a Channel + a background
CoroutineDispatcher to execute all logging in the background.

We do leverage the existing LogcatEchoTracker class, which implements a
generic settings listener + settings format for turning logcat echoing
on at the buffer or tag level. In our case, the buffer name is the name
of the table, and the tags are the column names.

Note that all TableLogBuffer logs are considered to be `LogLevel.DEBUG`
since the API for `logChange` does not let the caller decide on a log
level. Arguably this makes perfect sense since table logs are _not_
meant to be warning or error logs. We could probably make the case that
they are `info` or `verbose`, but that would be immaterial to this
overall change.

Test: existing tests in tests/src/com/android/systemui/statusbar/pipelinestyle
Test: TableLogBufferTest
Test: manual
Bug: 255951648
Change-Id: I930e4c7730117860ab22e8849c84f1f96f786b30
parent 66c3f036
Loading
Loading
Loading
Loading
+67 −0
Original line number Diff line number Diff line
/*
 * Copyright (C) 2023 The Android Open Source Project
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package com.android.systemui.log.table

import android.util.Log
import javax.inject.Inject

/** Dagger-friendly interface so we can inject a fake [android.util.Log] in tests */
interface LogProxy {
    /** verbose log */
    fun v(tag: String, message: String)

    /** debug log */
    fun d(tag: String, message: String)

    /** info log */
    fun i(tag: String, message: String)

    /** warning log */
    fun w(tag: String, message: String)

    /** error log */
    fun e(tag: String, message: String)

    /** wtf log */
    fun wtf(tag: String, message: String)
}

class LogProxyDefault @Inject constructor() : LogProxy {
    override fun v(tag: String, message: String) {
        Log.v(tag, message)
    }

    override fun d(tag: String, message: String) {
        Log.d(tag, message)
    }

    override fun i(tag: String, message: String) {
        Log.i(tag, message)
    }

    override fun w(tag: String, message: String) {
        Log.w(tag, message)
    }

    override fun e(tag: String, message: String) {
        Log.e(tag, message)
    }

    override fun wtf(tag: String, message: String) {
        Log.wtf(tag, message)
    }
}
+47 −0
Original line number Diff line number Diff line
@@ -19,10 +19,17 @@ package com.android.systemui.log.table
import android.os.Trace
import com.android.systemui.Dumpable
import com.android.systemui.common.buffer.RingBuffer
import com.android.systemui.dagger.qualifiers.Background
import com.android.systemui.plugins.log.LogLevel
import com.android.systemui.plugins.log.LogcatEchoTracker
import com.android.systemui.util.time.SystemClock
import java.io.PrintWriter
import java.text.SimpleDateFormat
import java.util.Locale
import kotlinx.coroutines.CoroutineDispatcher
import kotlinx.coroutines.CoroutineScope
import kotlinx.coroutines.channels.Channel
import kotlinx.coroutines.launch

/**
 * A logger that logs changes in table format.
@@ -73,12 +80,18 @@ class TableLogBuffer(
    maxSize: Int,
    private val name: String,
    private val systemClock: SystemClock,
    private val logcatEchoTracker: LogcatEchoTracker,
    @Background private val bgDispatcher: CoroutineDispatcher,
    private val coroutineScope: CoroutineScope,
    private val localLogcat: LogProxy = LogProxyDefault(),
) : Dumpable {
    init {
        if (maxSize <= 0) {
            throw IllegalArgumentException("maxSize must be > 0")
        }
    }
    // For local logcat, send messages across this channel so the background job can process them
    private val logMessageChannel = Channel<TableChange>(capacity = 10)

    private val buffer = RingBuffer(maxSize) { TableChange() }

@@ -105,6 +118,16 @@ class TableLogBuffer(
            tableLogBuffer = this,
        )

    /** Start this log buffer logging in the background */
    internal fun init() {
        coroutineScope.launch(bgDispatcher) {
            while (!logMessageChannel.isClosedForReceive) {
                val log = logMessageChannel.receive()
                echoToDesiredEndpoints(log)
            }
        }
    }

    /**
     * Log the differences between [prevVal] and [newVal].
     *
@@ -189,6 +212,7 @@ class TableLogBuffer(
        Trace.beginSection("TableLogBuffer#logChange(string)")
        val change = obtain(timestamp, prefix, columnName, isInitial)
        change.set(value)
        tryAddMessage(change)
        Trace.endSection()
    }

@@ -202,6 +226,7 @@ class TableLogBuffer(
        Trace.beginSection("TableLogBuffer#logChange(boolean)")
        val change = obtain(timestamp, prefix, columnName, isInitial)
        change.set(value)
        tryAddMessage(change)
        Trace.endSection()
    }

@@ -215,9 +240,14 @@ class TableLogBuffer(
        Trace.beginSection("TableLogBuffer#logChange(int)")
        val change = obtain(timestamp, prefix, columnName, isInitial)
        change.set(value)
        tryAddMessage(change)
        Trace.endSection()
    }

    private fun tryAddMessage(change: TableChange) {
        logMessageChannel.trySend(change)
    }

    // TODO(b/259454430): Add additional change types here.

    @Synchronized
@@ -258,6 +288,17 @@ class TableLogBuffer(
        Trace.endSection()
    }

    private fun echoToDesiredEndpoints(change: TableChange) {
        if (
            logcatEchoTracker.isBufferLoggable(bufferName = name, LogLevel.DEBUG) ||
                logcatEchoTracker.isTagLoggable(change.columnName, LogLevel.DEBUG)
        ) {
            if (change.hasData()) {
                localLogcat.d(name, change.logcatRepresentation())
            }
        }
    }

    @Synchronized
    override fun dump(pw: PrintWriter, args: Array<out String>) {
        pw.println(HEADER_PREFIX + name)
@@ -284,6 +325,12 @@ class TableLogBuffer(
        pw.println()
    }

    /** Transforms an individual [TableChange] into a String for logcat */
    private fun TableChange.logcatRepresentation(): String {
        val formattedTimestamp = TABLE_LOG_DATE_FORMAT.format(timestamp)
        return "$formattedTimestamp$SEPARATOR${getName()}$SEPARATOR${getVal()}"
    }

    /**
     * A private implementation of [TableRowLogger].
     *
+18 −1
Original line number Diff line number Diff line
@@ -17,10 +17,15 @@
package com.android.systemui.log.table

import com.android.systemui.dagger.SysUISingleton
import com.android.systemui.dagger.qualifiers.Application
import com.android.systemui.dagger.qualifiers.Background
import com.android.systemui.dump.DumpManager
import com.android.systemui.log.LogBufferHelper.Companion.adjustMaxSize
import com.android.systemui.plugins.log.LogcatEchoTracker
import com.android.systemui.util.time.SystemClock
import javax.inject.Inject
import kotlinx.coroutines.CoroutineDispatcher
import kotlinx.coroutines.CoroutineScope

@SysUISingleton
class TableLogBufferFactory
@@ -28,6 +33,9 @@ class TableLogBufferFactory
constructor(
    private val dumpManager: DumpManager,
    private val systemClock: SystemClock,
    private val logcatEchoTracker: LogcatEchoTracker,
    @Background private val bgDispatcher: CoroutineDispatcher,
    @Application private val coroutineScope: CoroutineScope,
) {
    private val existingBuffers = mutableMapOf<String, TableLogBuffer>()

@@ -44,8 +52,17 @@ constructor(
        name: String,
        maxSize: Int,
    ): TableLogBuffer {
        val tableBuffer = TableLogBuffer(adjustMaxSize(maxSize), name, systemClock)
        val tableBuffer =
            TableLogBuffer(
                adjustMaxSize(maxSize),
                name,
                systemClock,
                logcatEchoTracker,
                bgDispatcher,
                coroutineScope,
            )
        dumpManager.registerNormalDumpable(name, tableBuffer)
        tableBuffer.init()
        return tableBuffer
    }

+19 −2
Original line number Diff line number Diff line
@@ -65,6 +65,7 @@ import com.android.systemui.statusbar.phone.KeyguardBypassController
import com.android.systemui.user.data.repository.FakeUserRepository
import com.android.systemui.util.mockito.KotlinArgumentCaptor
import com.android.systemui.util.mockito.captureMany
import com.android.systemui.util.mockito.mock
import com.android.systemui.util.mockito.whenever
import com.android.systemui.util.time.FakeSystemClock
import com.android.systemui.util.time.SystemClock
@@ -191,8 +192,24 @@ class DeviceEntryFaceAuthRepositoryTest : SysuiTestCase() {
        bypassControllerOverride: KeyguardBypassController? = bypassController
    ): DeviceEntryFaceAuthRepositoryImpl {
        val systemClock = FakeSystemClock()
        val faceAuthBuffer = TableLogBuffer(10, "face auth", systemClock)
        val faceDetectBuffer = TableLogBuffer(10, "face detect", systemClock)
        val faceAuthBuffer =
            TableLogBuffer(
                10,
                "face auth",
                systemClock,
                mock(),
                testDispatcher,
                testScope.backgroundScope
            )
        val faceDetectBuffer =
            TableLogBuffer(
                10,
                "face detect",
                systemClock,
                mock(),
                testDispatcher,
                testScope.backgroundScope
            )
        keyguardTransitionRepository = FakeKeyguardTransitionRepository()
        val keyguardTransitionInteractor =
            KeyguardTransitionInteractor(keyguardTransitionRepository)
+56 −0
Original line number Diff line number Diff line
/*
 * Copyright (C) 2023 The Android Open Source Project
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package com.android.systemui.log.table

/**
 * Fake [LogProxy] that collects all lines sent to it. Mimics the ADB logcat format without the
 * timestamp. [FakeLogProxy.d] will write a log like so:
 * ```
 * logger.d("TAG", "message here")
 * // writes this to the [logs] field
 * "D TAG: message here"
 * ```
 *
 * Logs sent to this class are collected as a list of strings for simple test assertions.
 */
class FakeLogProxy : LogProxy {
    val logs: MutableList<String> = mutableListOf()

    override fun v(tag: String, message: String) {
        logs.add("V $tag: $message")
    }

    override fun d(tag: String, message: String) {
        logs.add("D $tag: $message")
    }

    override fun i(tag: String, message: String) {
        logs.add("I $tag: $message")
    }

    override fun w(tag: String, message: String) {
        logs.add("W $tag: $message")
    }

    override fun e(tag: String, message: String) {
        logs.add("E $tag: $message")
    }

    override fun wtf(tag: String, message: String) {
        logs.add("WTF $tag: $message")
    }
}
Loading