/* * Copyright (C) 2020 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 import android.util.Log import com.android.systemui.dump.DumpManager import com.android.systemui.log.dagger.LogModule import java.io.PrintWriter import java.text.SimpleDateFormat import java.util.ArrayDeque import java.util.Locale /** * A simple ring buffer of recyclable log messages * * The goal of this class is to enable logging that is both extremely chatty and extremely * lightweight. If done properly, logging a message will not result in any heap allocations or * string generation. Messages are only converted to strings if the log is actually dumped (usually * as the result of taking a bug report). * * You can dump the entire buffer at any time by running: * * ``` * $ adb shell dumpsys activity service com.android.systemui/.SystemUIService * ``` * * ...where `bufferName` is the (case-sensitive) [name] passed to the constructor. * * By default, only messages of WARN level or higher are echoed to logcat, but this can be adjusted * locally (usually for debugging purposes). * * To enable logcat echoing for an entire buffer: * * ``` * $ adb shell settings put global systemui/buffer/ * ``` * * To enable logcat echoing for a specific tag: * * ``` * $ adb shell settings put global systemui/tag/ * ``` * * In either case, `level` can be any of `verbose`, `debug`, `info`, `warn`, `error`, `assert`, or * the first letter of any of the previous. * * Buffers are provided by [LogModule]. * * @param name The name of this buffer * @param maxLogs The maximum number of messages to keep in memory at any one time, including the * unused pool. * @param poolSize The maximum amount that the size of the buffer is allowed to flex in response to * sequential calls to [document] that aren't immediately followed by a matching call to [push]. */ class LogBuffer( private val name: String, private val maxLogs: Int, private val poolSize: Int, private val logcatEchoTracker: LogcatEchoTracker ) { private val buffer: ArrayDeque = ArrayDeque() var frozen = false private set fun attach(dumpManager: DumpManager) { dumpManager.registerBuffer(name, this) } /** * Logs a message to the log buffer * * May also log the message to logcat if echoing is enabled for this buffer or tag. * * 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 [initializer]. 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 [printer] function is called on the message. It reads whatever data the * initializer stored and converts it to a human-readable log message. * * @param tag A string of at most 23 characters, used for grouping logs into categories or * subjects. If this message is echoed to logcat, this will be the tag that is used. * @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 initializer 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. * @param printer 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. */ inline fun log( tag: String, level: LogLevel, initializer: LogMessage.() -> Unit, noinline printer: LogMessage.() -> String ) { if (!frozen) { val message = obtain(tag, level, printer) initializer(message) push(message) } } /** * Same as [log], but doesn't push the message to the buffer. Useful if you need to supply a * "reason" for doing something (the thing you supply the reason to will presumably call [push] * on that message at some point). */ inline fun document( tag: String, level: LogLevel, initializer: LogMessage.() -> Unit, noinline printer: LogMessage.() -> String ): LogMessage { val message = obtain(tag, level, printer) initializer(message) return message } /** * Obtains an instance of [LogMessageImpl], usually from the object pool. If the pool has been * exhausted, creates a new instance. * * In general, you should call [log] or [document] instead of this method. */ @Synchronized fun obtain( tag: String, level: LogLevel, printer: (LogMessage) -> String ): LogMessageImpl { val message = when { frozen -> LogMessageImpl.create() buffer.size > maxLogs - poolSize -> buffer.removeFirst() else -> LogMessageImpl.create() } message.reset(tag, level, System.currentTimeMillis(), printer) return message } /** * Pushes a message into buffer, possibly evicting an older message if the buffer is full. */ @Synchronized fun push(message: LogMessage) { if (frozen) { return } if (buffer.size == maxLogs) { Log.e(TAG, "LogBuffer $name has exceeded its pool size") buffer.removeFirst() } buffer.add(message as LogMessageImpl) if (logcatEchoTracker.isBufferLoggable(name, message.level) || logcatEchoTracker.isTagLoggable(message.tag, message.level)) { echoToLogcat(message) } } /** Converts the entire buffer to a newline-delimited string */ @Synchronized fun dump(pw: PrintWriter, tailLength: Int) { val start = if (tailLength <= 0) { 0 } else { buffer.size - tailLength } for ((i, message) in buffer.withIndex()) { if (i >= start) { dumpMessage(message, pw) } } } /** * "Freezes" the contents of the buffer, making them immutable until [unfreeze] is called. * Calls to [log], [document], [obtain], and [push] will not affect the buffer and will return * dummy values if necessary. */ @Synchronized fun freeze() { if (!frozen) { log(TAG, LogLevel.DEBUG, { str1 = name }, { "$str1 frozen" }) frozen = true } } /** * Undoes the effects of calling [freeze]. */ @Synchronized fun unfreeze() { if (frozen) { log(TAG, LogLevel.DEBUG, { str1 = name }, { "$str1 unfrozen" }) frozen = false } } private fun dumpMessage(message: LogMessage, pw: PrintWriter) { pw.print(DATE_FORMAT.format(message.timestamp)) pw.print(" ") pw.print(message.level) pw.print(" ") pw.print(message.tag) pw.print(" ") pw.println(message.printer(message)) } private fun echoToLogcat(message: LogMessage) { val strMessage = message.printer(message) when (message.level) { LogLevel.VERBOSE -> Log.v(message.tag, strMessage) LogLevel.DEBUG -> Log.d(message.tag, strMessage) LogLevel.INFO -> Log.i(message.tag, strMessage) LogLevel.WARNING -> Log.w(message.tag, strMessage) LogLevel.ERROR -> Log.e(message.tag, strMessage) LogLevel.WTF -> Log.wtf(message.tag, strMessage) } } } private const val TAG = "LogBuffer" private val DATE_FORMAT = SimpleDateFormat("MM-dd HH:mm:ss.SSS", Locale.US)