1 /* 2 * Copyright (C) 2020 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17 package com.android.systemui.log 18 19 import android.os.Trace 20 import android.util.Log 21 import com.android.systemui.common.buffer.RingBuffer 22 import com.android.systemui.log.core.LogLevel 23 import com.android.systemui.log.core.LogMessage 24 import com.android.systemui.log.core.MessageBuffer 25 import com.android.systemui.log.core.MessageInitializer 26 import com.android.systemui.log.core.MessagePrinter 27 import com.google.errorprone.annotations.CompileTimeConstant 28 import java.io.PrintWriter 29 import kotlin.math.max 30 31 /** 32 * A simple ring buffer of recyclable log messages 33 * 34 * The goal of this class is to enable logging that is both extremely chatty and extremely 35 * lightweight. If done properly, logging a message will not result in any heap allocations or 36 * string generation. Messages are only converted to strings if the log is actually dumped (usually 37 * as the result of taking a bug report). 38 * 39 * You can dump the entire buffer at any time by running: 40 * ``` 41 * $ adb shell dumpsys activity service com.android.systemui/.SystemUIService <bufferName> 42 * ``` 43 * 44 * ...where `bufferName` is the (case-sensitive) [name] passed to the constructor. 45 * 46 * By default, only messages of WARN level or higher are echoed to logcat, but this can be adjusted 47 * locally (usually for debugging purposes). 48 * 49 * To enable logcat echoing for an entire buffer: 50 * ``` 51 * $ adb shell cmd statusbar echo -b <bufferName>:<level> 52 * ``` 53 * 54 * To enable logcat echoing for a specific tag: 55 * ``` 56 * $ adb shell cmd statusbar echo -t <tagName>:<level> 57 * ``` 58 * 59 * In either case, `level` can be any of `verbose`, `debug`, `info`, `warn`, `error`, `assert`, or 60 * the first letter of any of the previous. 61 * 62 * In SystemUI, buffers are provided by LogModule. Instances should be created using a SysUI 63 * LogBufferFactory. 64 * 65 * @param name The name of this buffer, printed when the buffer is dumped and in some other 66 * situations. 67 * @param maxSize The maximum number of messages to keep in memory at any one time. Buffers start 68 * out empty and grow up to [maxSize] as new messages are logged. Once the buffer's size reaches 69 * the maximum, it behaves like a ring buffer. 70 */ 71 class LogBuffer 72 @JvmOverloads 73 constructor( 74 private val name: String, 75 private val maxSize: Int, 76 private val logcatEchoTracker: LogcatEchoTracker, 77 private val systrace: Boolean = true, 78 ) : MessageBuffer { <lambda>null79 private val buffer = RingBuffer(maxSize) { LogMessageImpl.create() } 80 81 var frozen = false 82 private set 83 84 private val mutable 85 get() = !frozen && maxSize > 0 86 87 /** 88 * Logs a message to the log buffer 89 * 90 * May also log the message to logcat if echoing is enabled for this buffer or tag. 91 * 92 * The actual string of the log message is not constructed until it is needed. To accomplish 93 * this, logging a message is a two-step process. First, a fresh instance of [LogMessage] is 94 * obtained and is passed to the [messageInitializer]. The initializer stores any relevant data 95 * on the message's fields. The message is then inserted into the buffer where it waits until it 96 * is either pushed out by newer messages or it needs to printed. If and when this latter moment 97 * occurs, the [messagePrinter] function is called on the message. It reads whatever data the 98 * initializer stored and converts it to a human-readable log message. 99 * 100 * @param tag A string of at most 23 characters, used for grouping logs into categories or 101 * subjects. If this message is echoed to logcat, this will be the tag that is used. 102 * @param level Which level to log the message at, both to the buffer and to logcat if it's 103 * echoed. In general, a module should split most of its logs into either INFO or DEBUG level. 104 * INFO level should be reserved for information that other parts of the system might care 105 * about, leaving the specifics of code's day-to-day operations to DEBUG. 106 * @param messageInitializer A function that will be called immediately to store relevant data 107 * on the log message. The value of `this` will be the LogMessage to be initialized. 108 * @param messagePrinter A function that will be called if and when the message needs to be 109 * dumped to logcat or a bug report. It should read the data stored by the initializer and 110 * convert it to a human-readable string. The value of `this` will be the LogMessage to be 111 * printed. **IMPORTANT:** The printer should ONLY ever reference fields on the LogMessage and 112 * NEVER any variables in its enclosing scope. Otherwise, the runtime will need to allocate a 113 * new instance of the printer for each call, thwarting our attempts at avoiding any sort of 114 * allocation. 115 * @param exception Provide any exception that need to be logged. This is saved as 116 * [LogMessage.exception] 117 */ 118 @JvmOverloads lognull119 inline fun log( 120 tag: String, 121 level: LogLevel, 122 messageInitializer: MessageInitializer, 123 noinline messagePrinter: MessagePrinter, 124 exception: Throwable? = null, 125 ) { 126 val message = obtain(tag, level, messagePrinter, exception) 127 messageInitializer(message) 128 commit(message) 129 } 130 131 /** 132 * Logs a compile-time string constant [message] to the log buffer. Use sparingly. 133 * 134 * May also log the message to logcat if echoing is enabled for this buffer or tag. This is for 135 * simpler use-cases where [message] is a compile time string constant. For use-cases where the 136 * log message is built during runtime, use the [LogBuffer.log] overloaded method that takes in 137 * an initializer and a message printer. 138 * 139 * Log buffers are limited by the number of entries, so logging more frequently will limit the 140 * time window that the LogBuffer covers in a bug report. Richer logs, on the other hand, make a 141 * bug report more actionable, so using the [log] with a messagePrinter to add more detail to 142 * every log may do more to improve overall logging than adding more logs with this method. 143 */ 144 @JvmOverloads lognull145 fun log( 146 tag: String, 147 level: LogLevel, 148 @CompileTimeConstant message: String, 149 exception: Throwable? = null, 150 ) = log(tag, level, { str1 = message }, { str1!! }, exception) 151 152 /** 153 * You should call [log] instead of this method. 154 * 155 * Obtains the next [LogMessage] from the ring buffer. If the buffer is not yet at max size, 156 * grows the buffer by one. 157 * 158 * After calling [obtain], the message will now be at the end of the buffer. The caller must 159 * store any relevant data on the message and then call [commit]. 160 */ 161 @Synchronized obtainnull162 override fun obtain( 163 tag: String, 164 level: LogLevel, 165 messagePrinter: MessagePrinter, 166 exception: Throwable?, 167 ): LogMessage { 168 if (!mutable) { 169 return FROZEN_MESSAGE 170 } 171 val message = buffer.advance() 172 message.reset(tag, level, System.currentTimeMillis(), messagePrinter, exception) 173 return message 174 } 175 176 /** 177 * You should call [log] instead of this method. 178 * 179 * After acquiring a message via [obtain], call this method to signal to the buffer that you 180 * have finished filling in its data fields. The message will be echoed to logcat if necessary. 181 */ 182 @Synchronized commitnull183 override fun commit(message: LogMessage) { 184 if (!mutable) { 185 return 186 } 187 echoToDesiredEndpoints(message) 188 } 189 190 /** Sends message to echo after determining whether to use Logcat and/or systrace. */ echoToDesiredEndpointsnull191 private fun echoToDesiredEndpoints(message: LogMessage) { 192 val includeInLogcat = 193 logcatEchoTracker.isBufferLoggable(name, message.level) || 194 logcatEchoTracker.isTagLoggable(message.tag, message.level) 195 196 val includeInSystrace = systrace && Trace.isTagEnabled(Trace.TRACE_TAG_APP) 197 198 if (includeInLogcat || includeInSystrace) { 199 val strMessage = message.messagePrinter(message) 200 if (includeInLogcat) { 201 echoToLogcat(message, strMessage) 202 } 203 if (includeInSystrace) { 204 echoToSystrace(message.level, message.tag, strMessage) 205 } 206 } 207 } 208 209 /** Converts the entire buffer to a newline-delimited string */ 210 @Synchronized dumpnull211 fun dump(pw: PrintWriter, tailLength: Int) { 212 val iterationStart = 213 if (tailLength <= 0) { 214 0 215 } else { 216 max(0, buffer.size - tailLength) 217 } 218 219 for (i in iterationStart until buffer.size) { 220 buffer[i].dump(pw) 221 } 222 } 223 224 /** 225 * "Freezes" the contents of the buffer, making it immutable until [unfreeze] is called. Calls 226 * to [log], [obtain], and [commit] will not affect the buffer and will return dummy values if 227 * necessary. 228 */ 229 @Synchronized freezenull230 fun freeze() { 231 if (!frozen) { 232 log(TAG, LogLevel.DEBUG, { str1 = name }, { "$str1 frozen" }) 233 frozen = true 234 } 235 } 236 237 /** Undoes the effects of calling [freeze]. */ 238 @Synchronized unfreezenull239 fun unfreeze() { 240 if (frozen) { 241 frozen = false 242 log(TAG, LogLevel.DEBUG, { str1 = name }, { "$str1 unfrozen" }) 243 } 244 } 245 echoToSystracenull246 private fun echoToSystrace(level: LogLevel, tag: String, strMessage: String) { 247 Trace.instantForTrack( 248 Trace.TRACE_TAG_APP, 249 "UI Events", 250 "$name - ${level.shortString} $tag: $strMessage" 251 ) 252 } 253 echoToLogcatnull254 private fun echoToLogcat(message: LogMessage, strMessage: String) { 255 when (message.level) { 256 LogLevel.VERBOSE -> Log.v(message.tag, strMessage, message.exception) 257 LogLevel.DEBUG -> Log.d(message.tag, strMessage, message.exception) 258 LogLevel.INFO -> Log.i(message.tag, strMessage, message.exception) 259 LogLevel.WARNING -> Log.w(message.tag, strMessage, message.exception) 260 LogLevel.ERROR -> Log.e(message.tag, strMessage, message.exception) 261 LogLevel.WTF -> Log.wtf(message.tag, strMessage, message.exception) 262 } 263 } 264 } 265 266 private const val TAG = "LogBuffer" 267 private val FROZEN_MESSAGE = LogMessageImpl.create() 268