Merge "Introduce Logger" into udc-qpr-dev

packages/SystemUI/log/src/com/android/systemui/log/LogBuffer.kt

@@ -21,6 +21,7 @@ import android.util.Log
 import com.android.systemui.common.buffer.RingBuffer
 import com.android.systemui.log.core.LogLevel
 import com.android.systemui.log.core.LogMessage
+import com.android.systemui.log.core.MessageBuffer
 import com.android.systemui.log.core.MessageInitializer
 import com.android.systemui.log.core.MessagePrinter
 import com.google.errorprone.annotations.CompileTimeConstant
@@ -77,7 +78,7 @@ constructor(
     private val maxSize: Int,
     private val logcatEchoTracker: LogcatEchoTracker,
     private val systrace: Boolean = true,
-) {
+) : MessageBuffer {
     private val buffer = RingBuffer(maxSize) { LogMessageImpl.create() }
 
     private val echoMessageQueue: BlockingQueue<LogMessage>? =
@@ -178,11 +179,11 @@ constructor(
      * store any relevant data on the message and then call [commit].
      */
     @Synchronized
-    fun obtain(
+    override fun obtain(
         tag: String,
         level: LogLevel,
         messagePrinter: MessagePrinter,
-        exception: Throwable? = null,
+        exception: Throwable?,
     ): LogMessage {
         if (!mutable) {
             return FROZEN_MESSAGE
@@ -199,7 +200,7 @@ constructor(
      * have finished filling in its data fields. The message will be echoed to logcat if necessary.
      */
     @Synchronized
-    fun commit(message: LogMessage) {
+    override fun commit(message: LogMessage) {
         if (!mutable) {
             return
         }

packages/SystemUI/log/src/com/android/systemui/log/core/Logger.kt

@@ -0,0 +1,224 @@
+/*
+ * 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.core
+
+import com.google.errorprone.annotations.CompileTimeConstant
+
+/** Logs messages to the [MessageBuffer] with [tag]. */
+open class Logger(val buffer: MessageBuffer, val tag: String) {
+    /**
+     * Logs a message to the buffer.
+     *
+     * The actual string of the log message is not constructed until it is needed. To accomplish
+     * this, logging a message is a two-step process. First, a fresh instance of [LogMessage] is
+     * obtained and is passed to the [messageInitializer]. The initializer stores any relevant data
+     * on the message's fields. The message is then inserted into the buffer where it waits until it
+     * is either pushed out by newer messages or it needs to printed. If and when this latter moment
+     * occurs, the [messagePrinter] function is called on the message. It reads whatever data the
+     * initializer stored and converts it to a human-readable log message.
+     *
+     * @param level Which level to log the message at, both to the buffer and to logcat if it's
+     *   echoed. In general, a module should split most of its logs into either INFO or DEBUG level.
+     *   INFO level should be reserved for information that other parts of the system might care
+     *   about, leaving the specifics of code's day-to-day operations to DEBUG.
+     * @param messagePrinter A function that will be called if and when the message needs to be
+     *   dumped to logcat or a bug report. It should read the data stored by the initializer and
+     *   convert it to a human-readable string. The value of `this` will be the [LogMessage] to be
+     *   printed. **IMPORTANT:** The printer should ONLY ever reference fields on the [LogMessage]
+     *   and NEVER any variables in its enclosing scope. Otherwise, the runtime will need to
+     *   allocate a new instance of the printer for each call, thwarting our attempts at avoiding
+     *   any sort of allocation.
+     * @param exception Provide any exception that need to be logged. This is saved as
+     *   [LogMessage.exception]
+     * @param messageInitializer A function that will be called immediately to store relevant data
+     *   on the log message. The value of `this` will be the [LogMessage] to be initialized.
+     */
+    @JvmOverloads
+    inline fun log(
+        level: LogLevel,
+        noinline messagePrinter: MessagePrinter,
+        exception: Throwable? = null,
+        messageInitializer: MessageInitializer,
+    ) {
+        val message = buffer.obtain(tag, level, messagePrinter, exception)
+        messageInitializer(message)
+        buffer.commit(message)
+    }
+
+    /**
+     * Logs a compile-time string constant [message] to the log buffer. Use sparingly.
+     *
+     * This is for simpler use-cases where [message] is a compile time string constant. For
+     * use-cases where the log message is built during runtime, use the [log] overloaded method that
+     * takes in an initializer and a message printer.
+     *
+     * Buffers are limited by the number of entries, so logging more frequently will limit the time
+     * window that the [MessageBuffer] covers in a bug report. Richer logs, on the other hand, make
+     * a bug report more actionable, so using the [log] with a [MessagePrinter] to add more details
+     * to every log may do more to improve overall logging than adding more logs with this method.
+     */
+    @JvmOverloads
+    fun log(
+        level: LogLevel,
+        @CompileTimeConstant message: String,
+        exception: Throwable? = null,
+    ) = log(level, { str1!! }, exception) { str1 = message }
+
+    /**
+     * Logs a message to the buffer at [LogLevel.VERBOSE].
+     *
+     * @see log
+     */
+    @JvmOverloads
+    inline fun v(
+        noinline messagePrinter: MessagePrinter,
+        exception: Throwable? = null,
+        messageInitializer: MessageInitializer,
+    ) = log(LogLevel.VERBOSE, messagePrinter, exception, messageInitializer)
+
+    /**
+     * Logs a compile-time string constant [message] to the log buffer at [LogLevel.VERBOSE]. Use
+     * sparingly.
+     *
+     * @see log
+     */
+    @JvmOverloads
+    fun v(
+        @CompileTimeConstant message: String,
+        exception: Throwable? = null,
+    ) = log(LogLevel.VERBOSE, message, exception)
+
+    /**
+     * Logs a message to the buffer at [LogLevel.DEBUG].
+     *
+     * @see log
+     */
+    @JvmOverloads
+    inline fun d(
+        noinline messagePrinter: MessagePrinter,
+        exception: Throwable? = null,
+        messageInitializer: MessageInitializer,
+    ) = log(LogLevel.DEBUG, messagePrinter, exception, messageInitializer)
+
+    /**
+     * Logs a compile-time string constant [message] to the log buffer at [LogLevel.DEBUG]. Use
+     * sparingly.
+     *
+     * @see log
+     */
+    @JvmOverloads
+    fun d(
+        @CompileTimeConstant message: String,
+        exception: Throwable? = null,
+    ) = log(LogLevel.DEBUG, message, exception)
+
+    /**
+     * Logs a message to the buffer at [LogLevel.INFO].
+     *
+     * @see log
+     */
+    @JvmOverloads
+    inline fun i(
+        noinline messagePrinter: MessagePrinter,
+        exception: Throwable? = null,
+        messageInitializer: MessageInitializer,
+    ) = log(LogLevel.INFO, messagePrinter, exception, messageInitializer)
+
+    /**
+     * Logs a compile-time string constant [message] to the log buffer at [LogLevel.INFO]. Use
+     * sparingly.
+     *
+     * @see log
+     */
+    @JvmOverloads
+    fun i(
+        @CompileTimeConstant message: String,
+        exception: Throwable? = null,
+    ) = log(LogLevel.INFO, message, exception)
+
+    /**
+     * Logs a message to the buffer at [LogLevel.WARNING].
+     *
+     * @see log
+     */
+    @JvmOverloads
+    inline fun w(
+        noinline messagePrinter: MessagePrinter,
+        exception: Throwable? = null,
+        messageInitializer: MessageInitializer,
+    ) = log(LogLevel.WARNING, messagePrinter, exception, messageInitializer)
+
+    /**
+     * Logs a compile-time string constant [message] to the log buffer at [LogLevel.WARNING]. Use
+     * sparingly.
+     *
+     * @see log
+     */
+    @JvmOverloads
+    fun w(
+        @CompileTimeConstant message: String,
+        exception: Throwable? = null,
+    ) = log(LogLevel.WARNING, message, exception)
+
+    /**
+     * Logs a message to the buffer at [LogLevel.ERROR].
+     *
+     * @see log
+     */
+    @JvmOverloads
+    inline fun e(
+        noinline messagePrinter: MessagePrinter,
+        exception: Throwable? = null,
+        messageInitializer: MessageInitializer,
+    ) = log(LogLevel.ERROR, messagePrinter, exception, messageInitializer)
+
+    /**
+     * Logs a compile-time string constant [message] to the log buffer at [LogLevel.ERROR]. Use
+     * sparingly.
+     *
+     * @see log
+     */
+    @JvmOverloads
+    fun e(
+        @CompileTimeConstant message: String,
+        exception: Throwable? = null,
+    ) = log(LogLevel.ERROR, message, exception)
+
+    /**
+     * Logs a message to the buffer at [LogLevel.WTF].
+     *
+     * @see log
+     */
+    @JvmOverloads
+    inline fun wtf(
+        noinline messagePrinter: MessagePrinter,
+        exception: Throwable? = null,
+        messageInitializer: MessageInitializer,
+    ) = log(LogLevel.WTF, messagePrinter, exception, messageInitializer)
+
+    /**
+     * Logs a compile-time string constant [message] to the log buffer at [LogLevel.WTF]. Use
+     * sparingly.
+     *
+     * @see log
+     */
+    @JvmOverloads
+    fun wtf(
+        @CompileTimeConstant message: String,
+        exception: Throwable? = null,
+    ) = log(LogLevel.WTF, message, exception)
+}

packages/SystemUI/log/src/com/android/systemui/log/core/MessageBuffer.kt

@@ -0,0 +1,42 @@
+/*
+ * 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.core
+
+/**
+ * [MessageBuffer] is an interface that represents a buffer of log messages, and provides methods to
+ * [obtain] a log message and [commit] it to the buffer.
+ */
+interface MessageBuffer {
+    /**
+     * Obtains the next [LogMessage] from the buffer.
+     *
+     * After calling [obtain], the caller must store any relevant data on the message and then call
+     * [commit].
+     */
+    fun obtain(
+        tag: String,
+        level: LogLevel,
+        messagePrinter: MessagePrinter,
+        exception: Throwable? = null,
+    ): LogMessage
+
+    /**
+     * After acquiring a log message via [obtain], call this method to signal to the buffer that
+     * data fields have been filled.
+     */
+    fun commit(message: LogMessage)
+}

packages/SystemUI/tests/src/com/android/systemui/log/LogBufferTest.kt

@@ -2,7 +2,7 @@ package com.android.systemui.log
 
 import androidx.test.filters.SmallTest
 import com.android.systemui.SysuiTestCase
-import com.android.systemui.log.core.LogLevel
+import com.android.systemui.log.core.Logger
 import com.google.common.truth.Truth.assertThat
 import java.io.PrintWriter
 import java.io.StringWriter
@@ -33,7 +33,8 @@ class LogBufferTest : SysuiTestCase() {
 
     @Test
     fun log_shouldSaveLogToBuffer() {
-        buffer.log("Test", LogLevel.INFO, "Some test message")
+        val logger = Logger(buffer, "Test")
+        logger.i("Some test message")
 
         val dumpedString = dumpBuffer()
 
@@ -42,8 +43,9 @@ class LogBufferTest : SysuiTestCase() {
 
     @Test
     fun log_shouldRotateIfLogBufferIsFull() {
-        buffer.log("Test", LogLevel.INFO, "This should be rotated")
-        buffer.log("Test", LogLevel.INFO, "New test message")
+        val logger = Logger(buffer, "Test")
+        logger.i("This should be rotated")
+        logger.i("New test message")
 
         val dumpedString = dumpBuffer()
 
@@ -54,7 +56,8 @@ class LogBufferTest : SysuiTestCase() {
     fun dump_writesExceptionAndStacktrace() {
         buffer = createBuffer()
         val exception = createTestException("Exception message", "TestClass")
-        buffer.log("Tag", LogLevel.ERROR, { str1 = "Extra message" }, { str1!! }, exception)
+        val logger = Logger(buffer, "Test")
+        logger.e("Extra message", exception)
 
         val dumpedString = dumpBuffer()
 
@@ -73,7 +76,8 @@ class LogBufferTest : SysuiTestCase() {
                 "TestClass",
                 cause = createTestException("The real cause!", "TestClass")
             )
-        buffer.log("Tag", LogLevel.ERROR, { str1 = "Extra message" }, { str1!! }, exception)
+        val logger = Logger(buffer, "Test")
+        logger.e("Extra message", exception)
 
         val dumpedString = dumpBuffer()
 
@@ -94,7 +98,8 @@ class LogBufferTest : SysuiTestCase() {
             )
         )
         exception.addSuppressed(createTestException("Second suppressed exception", "SecondClass"))
-        buffer.log("Tag", LogLevel.ERROR, { str1 = "Extra message" }, { str1!! }, exception)
+        val logger = Logger(buffer, "Test")
+        logger.e("Extra message", exception)
 
         val dumpedStr = dumpBuffer()
 

packages/SystemUI/tests/src/com/android/systemui/log/core/LoggerTest.kt

@@ -0,0 +1,140 @@
+package com.android.systemui.log.core
+
+import androidx.test.filters.SmallTest
+import com.android.systemui.SysuiTestCase
+import com.android.systemui.log.LogMessageImpl
+import com.android.systemui.util.mockito.any
+import com.android.systemui.util.mockito.eq
+import com.android.systemui.util.mockito.nullable
+import com.android.systemui.util.mockito.whenever
+import com.google.common.truth.Truth.assertThat
+import org.junit.Before
+import org.junit.Test
+import org.junit.runner.RunWith
+import org.mockito.Mock
+import org.mockito.Mockito.anyString
+import org.mockito.Mockito.isNull
+import org.mockito.Mockito.verify
+import org.mockito.MockitoAnnotations
+import org.mockito.junit.MockitoJUnitRunner
+
+@SmallTest
+@RunWith(MockitoJUnitRunner::class)
+class LoggerTest : SysuiTestCase() {
+    @Mock private lateinit var buffer: MessageBuffer
+    private lateinit var message: LogMessage
+
+    @Before
+    fun setup() {
+        MockitoAnnotations.initMocks(this)
+        whenever(buffer.obtain(any(), any(), any(), isNull())).thenAnswer {
+            message = LogMessageImpl.Factory.create()
+            return@thenAnswer message
+        }
+    }
+
+    @Test
+    fun log_shouldCommitLogMessage() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.log(LogLevel.DEBUG, { "count=$int1" }) {
+            int1 = 1
+            str1 = "test"
+            bool1 = true
+        }
+
+        assertThat(message.int1).isEqualTo(1)
+        assertThat(message.str1).isEqualTo("test")
+        assertThat(message.bool1).isEqualTo(true)
+    }
+
+    @Test
+    fun log_shouldUseCorrectLoggerTag() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.log(LogLevel.DEBUG, { "count=$int1" }) { int1 = 1 }
+        verify(buffer).obtain(eq("LoggerTest"), any(), any(), nullable())
+    }
+
+    @Test
+    fun v_withMessageInitializer_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.v({ "count=$int1" }) { int1 = 1 }
+        verify(buffer).obtain(anyString(), eq(LogLevel.VERBOSE), any(), nullable())
+    }
+
+    @Test
+    fun v_withCompileTimeMessage_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.v("Message")
+        verify(buffer).obtain(anyString(), eq(LogLevel.VERBOSE), any(), nullable())
+    }
+
+    @Test
+    fun d_withMessageInitializer_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.d({ "count=$int1" }) { int1 = 1 }
+        verify(buffer).obtain(anyString(), eq(LogLevel.DEBUG), any(), nullable())
+    }
+
+    @Test
+    fun d_withCompileTimeMessage_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.d("Message")
+        verify(buffer).obtain(anyString(), eq(LogLevel.DEBUG), any(), nullable())
+    }
+
+    @Test
+    fun i_withMessageInitializer_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.i({ "count=$int1" }) { int1 = 1 }
+        verify(buffer).obtain(anyString(), eq(LogLevel.INFO), any(), nullable())
+    }
+
+    @Test
+    fun i_withCompileTimeMessage_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.i("Message")
+        verify(buffer).obtain(anyString(), eq(LogLevel.INFO), any(), nullable())
+    }
+
+    @Test
+    fun w_withMessageInitializer_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.w({ "count=$int1" }) { int1 = 1 }
+        verify(buffer).obtain(anyString(), eq(LogLevel.WARNING), any(), nullable())
+    }
+
+    @Test
+    fun w_withCompileTimeMessage_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.w("Message")
+        verify(buffer).obtain(anyString(), eq(LogLevel.WARNING), any(), nullable())
+    }
+
+    @Test
+    fun e_withMessageInitializer_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.e({ "count=$int1" }) { int1 = 1 }
+        verify(buffer).obtain(anyString(), eq(LogLevel.ERROR), any(), nullable())
+    }
+
+    @Test
+    fun e_withCompileTimeMessage_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.e("Message")
+        verify(buffer).obtain(anyString(), eq(LogLevel.ERROR), any(), nullable())
+    }
+
+    @Test
+    fun wtf_withMessageInitializer_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.wtf({ "count=$int1" }) { int1 = 1 }
+        verify(buffer).obtain(anyString(), eq(LogLevel.WTF), any(), nullable())
+    }
+
+    @Test
+    fun wtf_withCompileTimeMessage_shouldLogAtCorrectLevel() {
+        val logger = Logger(buffer, "LoggerTest")
+        logger.wtf("Message")
+        verify(buffer).obtain(anyString(), eq(LogLevel.WTF), any(), nullable())
+    }
+}