packages/SystemUI/plugin/src/com/android/systemui/plugins/log/LogBuffer.kt - platform/frameworks/base - Git at Google

 /*
  * 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.plugins.log

 import android.os.Trace
 import android.util.Log
 import com.android.systemui.plugins.util.RingBuffer
 import com.google.errorprone.annotations.CompileTimeConstant
 import java.io.PrintWriter
 import java.util.concurrent.ArrayBlockingQueue
 import java.util.concurrent.BlockingQueue
 import kotlin.concurrent.thread
 import kotlin.math.max

 /**
  * 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 <bufferName>
  * ```
  *
  * ...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/<bufferName> <level>
  * ```
  *
  * To enable logcat echoing for a specific tag:
  * ```
  * $ adb shell settings put global systemui/tag/<tag> <level>
  * ```
  *
  * In either case, `level` can be any of `verbose`, `debug`, `info`, `warn`, `error`, `assert`, or
  * the first letter of any of the previous.
  *
  * In SystemUI, buffers are provided by LogModule. Instances should be created using a SysUI
  * LogBufferFactory.
  *
  * @param name The name of this buffer, printed when the buffer is dumped and in some other
  *   situations.
  * @param maxSize The maximum number of messages to keep in memory at any one time. Buffers start
  *   out empty and grow up to [maxSize] as new messages are logged. Once the buffer's size reaches
  *   the maximum, it behaves like a ring buffer.
  */
 class LogBuffer
 @JvmOverloads
 constructor(
     private val name: String,
     private val maxSize: Int,
     private val logcatEchoTracker: LogcatEchoTracker,
     private val systrace: Boolean = true,
 ) {
     private val buffer = RingBuffer(maxSize) { LogMessageImpl.create() }

     private val echoMessageQueue: BlockingQueue<LogMessage>? =
         if (logcatEchoTracker.logInBackgroundThread) ArrayBlockingQueue(10) else null

     init {
         if (logcatEchoTracker.logInBackgroundThread && echoMessageQueue != null) {
             thread(start = true, name = "LogBuffer-$name", priority = Thread.NORM_PRIORITY) {
                 try {
                     while (true) {
                         echoToDesiredEndpoints(echoMessageQueue.take())
                     }
                 } catch (e: InterruptedException) {
                     Thread.currentThread().interrupt()
                 }
             }
         }
     }

     var frozen = false
         private set

     private val mutable
         get() = !frozen && maxSize > 0

     /**
      * 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 [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 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 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.
      * @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]
      */
     @JvmOverloads
     inline fun log(
         tag: String,
         level: LogLevel,
         messageInitializer: MessageInitializer,
         noinline messagePrinter: MessagePrinter,
         exception: Throwable? = null,
     ) {
         val message = obtain(tag, level, messagePrinter, exception)
         messageInitializer(message)
         commit(message)
     }

     /**
      * Logs a compile-time string constant [message] to the log buffer. Use sparingly.
      *
      * May also log the message to logcat if echoing is enabled for this buffer or tag. 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 [LogBuffer.log] overloaded method that takes in
      * an initializer and a message printer.
      *
      * Log buffers are limited by the number of entries, so logging more frequently will limit the
      * time window that the LogBuffer 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 detail to
      * every log may do more to improve overall logging than adding more logs with this method.
      */
     @JvmOverloads
     fun log(
         tag: String,
         level: LogLevel,
         @CompileTimeConstant message: String,
         exception: Throwable? = null,
     ) = log(tag, level, { str1 = message }, { str1!! }, exception)

     /**
      * You should call [log] instead of this method.
      *
      * Obtains the next [LogMessage] from the ring buffer. If the buffer is not yet at max size,
      * grows the buffer by one.
      *
      * After calling [obtain], the message will now be at the end of the buffer. The caller must
      * store any relevant data on the message and then call [commit].
      */
     @Synchronized
     fun obtain(
         tag: String,
         level: LogLevel,
         messagePrinter: MessagePrinter,
         exception: Throwable? = null,
     ): LogMessage {
         if (!mutable) {
             return FROZEN_MESSAGE
         }
         val message = buffer.advance()
         message.reset(tag, level, System.currentTimeMillis(), messagePrinter, exception)
         return message
     }

     /**
      * You should call [log] instead of this method.
      *
      * After acquiring a message via [obtain], call this method to signal to the buffer that you
      * have finished filling in its data fields. The message will be echoed to logcat if necessary.
      */
     @Synchronized
     fun commit(message: LogMessage) {
         if (!mutable) {
             return
         }
         // Log in the background thread only if echoMessageQueue exists and has capacity (checking
         // capacity avoids the possibility of blocking this thread)
         if (echoMessageQueue != null && echoMessageQueue.remainingCapacity() > 0) {
             try {
                 echoMessageQueue.put(message)
             } catch (e: InterruptedException) {
                 // the background thread has been shut down, so just log on this one
                 echoToDesiredEndpoints(message)
             }
         } else {
             echoToDesiredEndpoints(message)
         }
     }

     /** Sends message to echo after determining whether to use Logcat and/or systrace. */
     private fun echoToDesiredEndpoints(message: LogMessage) {
         val includeInLogcat =
             logcatEchoTracker.isBufferLoggable(name, message.level) ||
                 logcatEchoTracker.isTagLoggable(message.tag, message.level)
         echo(message, toLogcat = includeInLogcat, toSystrace = systrace)
     }

     /** Converts the entire buffer to a newline-delimited string */
     @Synchronized
     fun dump(pw: PrintWriter, tailLength: Int) {
         val iterationStart =
             if (tailLength <= 0) {
                 0
             } else {
                 max(0, buffer.size - tailLength)
             }

         for (i in iterationStart until buffer.size) {
             buffer[i].dump(pw)
         }
     }

     /**
      * "Freezes" the contents of the buffer, making it immutable until [unfreeze] is called. Calls
      * to [log], [obtain], and [commit] 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 echo(message: LogMessage, toLogcat: Boolean, toSystrace: Boolean) {
         if (toLogcat || toSystrace) {
             val strMessage = message.messagePrinter(message)
             if (toSystrace) {
                 echoToSystrace(message, strMessage)
             }
             if (toLogcat) {
                 echoToLogcat(message, strMessage)
             }
         }
     }

     private fun echoToSystrace(message: LogMessage, strMessage: String) {
         Trace.instantForTrack(
             Trace.TRACE_TAG_APP,
             "UI Events",
             "$name - ${message.level.shortString} ${message.tag}: $strMessage"
         )
     }

     private fun echoToLogcat(message: LogMessage, strMessage: String) {
         when (message.level) {
             LogLevel.VERBOSE -> Log.v(message.tag, strMessage, message.exception)
             LogLevel.DEBUG -> Log.d(message.tag, strMessage, message.exception)
             LogLevel.INFO -> Log.i(message.tag, strMessage, message.exception)
             LogLevel.WARNING -> Log.w(message.tag, strMessage, message.exception)
             LogLevel.ERROR -> Log.e(message.tag, strMessage, message.exception)
             LogLevel.WTF -> Log.wtf(message.tag, strMessage, message.exception)
         }
     }
 }

 /**
  * 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.
  */
 typealias MessageInitializer = LogMessage.() -> Unit

 private const val TAG = "LogBuffer"
 private val FROZEN_MESSAGE = LogMessageImpl.create()
	/*
	* 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.plugins.log

	import android.os.Trace
	import android.util.Log
	import com.android.systemui.plugins.util.RingBuffer
	import com.google.errorprone.annotations.CompileTimeConstant
	import java.io.PrintWriter
	import java.util.concurrent.ArrayBlockingQueue
	import java.util.concurrent.BlockingQueue
	import kotlin.concurrent.thread
	import kotlin.math.max

	/**
	* 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 <bufferName>
	* ```
	*
	* ...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/<bufferName> <level>
	* ```
	*
	* To enable logcat echoing for a specific tag:
	* ```
	* $ adb shell settings put global systemui/tag/<tag> <level>
	* ```
	*
	* In either case, `level` can be any of `verbose`, `debug`, `info`, `warn`, `error`, `assert`, or
	* the first letter of any of the previous.
	*
	* In SystemUI, buffers are provided by LogModule. Instances should be created using a SysUI
	* LogBufferFactory.
	*
	* @param name The name of this buffer, printed when the buffer is dumped and in some other
	* situations.
	* @param maxSize The maximum number of messages to keep in memory at any one time. Buffers start
	* out empty and grow up to [maxSize] as new messages are logged. Once the buffer's size reaches
	* the maximum, it behaves like a ring buffer.
	*/
	class LogBuffer
	@JvmOverloads
	constructor(
	private val name: String,
	private val maxSize: Int,
	private val logcatEchoTracker: LogcatEchoTracker,
	private val systrace: Boolean = true,
	) {
	private val buffer = RingBuffer(maxSize) { LogMessageImpl.create() }

	private val echoMessageQueue: BlockingQueue<LogMessage>? =
	if (logcatEchoTracker.logInBackgroundThread) ArrayBlockingQueue(10) else null

	init {
	if (logcatEchoTracker.logInBackgroundThread && echoMessageQueue != null) {
	thread(start = true, name = "LogBuffer-$name", priority = Thread.NORM_PRIORITY) {
	try {
	while (true) {
	echoToDesiredEndpoints(echoMessageQueue.take())
	}
	} catch (e: InterruptedException) {
	Thread.currentThread().interrupt()
	}
	}
	}
	}

	var frozen = false
	private set

	private val mutable
	get() = !frozen && maxSize > 0

	/**
	* 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 [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 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 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.
	* @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]
	*/
	@JvmOverloads
	inline fun log(
	tag: String,
	level: LogLevel,
	messageInitializer: MessageInitializer,
	noinline messagePrinter: MessagePrinter,
	exception: Throwable? = null,
	) {
	val message = obtain(tag, level, messagePrinter, exception)
	messageInitializer(message)
	commit(message)
	}

	/**
	* Logs a compile-time string constant [message] to the log buffer. Use sparingly.
	*
	* May also log the message to logcat if echoing is enabled for this buffer or tag. 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 [LogBuffer.log] overloaded method that takes in
	* an initializer and a message printer.
	*
	* Log buffers are limited by the number of entries, so logging more frequently will limit the
	* time window that the LogBuffer 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 detail to
	* every log may do more to improve overall logging than adding more logs with this method.
	*/
	@JvmOverloads
	fun log(
	tag: String,
	level: LogLevel,
	@CompileTimeConstant message: String,
	exception: Throwable? = null,
	) = log(tag, level, { str1 = message }, { str1!! }, exception)

	/**
	* You should call [log] instead of this method.
	*
	* Obtains the next [LogMessage] from the ring buffer. If the buffer is not yet at max size,
	* grows the buffer by one.
	*
	* After calling [obtain], the message will now be at the end of the buffer. The caller must
	* store any relevant data on the message and then call [commit].
	*/
	@Synchronized
	fun obtain(
	tag: String,
	level: LogLevel,
	messagePrinter: MessagePrinter,
	exception: Throwable? = null,
	): LogMessage {
	if (!mutable) {
	return FROZEN_MESSAGE
	}
	val message = buffer.advance()
	message.reset(tag, level, System.currentTimeMillis(), messagePrinter, exception)
	return message
	}

	/**
	* You should call [log] instead of this method.
	*
	* After acquiring a message via [obtain], call this method to signal to the buffer that you
	* have finished filling in its data fields. The message will be echoed to logcat if necessary.
	*/
	@Synchronized
	fun commit(message: LogMessage) {
	if (!mutable) {
	return
	}
	// Log in the background thread only if echoMessageQueue exists and has capacity (checking
	// capacity avoids the possibility of blocking this thread)
	if (echoMessageQueue != null && echoMessageQueue.remainingCapacity() > 0) {
	try {
	echoMessageQueue.put(message)
	} catch (e: InterruptedException) {
	// the background thread has been shut down, so just log on this one
	echoToDesiredEndpoints(message)
	}
	} else {
	echoToDesiredEndpoints(message)
	}
	}

	/** Sends message to echo after determining whether to use Logcat and/or systrace. */
	private fun echoToDesiredEndpoints(message: LogMessage) {
	val includeInLogcat =
	logcatEchoTracker.isBufferLoggable(name, message.level) \|\|
	logcatEchoTracker.isTagLoggable(message.tag, message.level)
	echo(message, toLogcat = includeInLogcat, toSystrace = systrace)
	}

	/** Converts the entire buffer to a newline-delimited string */
	@Synchronized
	fun dump(pw: PrintWriter, tailLength: Int) {
	val iterationStart =
	if (tailLength <= 0) {
	0
	} else {
	max(0, buffer.size - tailLength)
	}

	for (i in iterationStart until buffer.size) {
	buffer[i].dump(pw)
	}
	}

	/**
	* "Freezes" the contents of the buffer, making it immutable until [unfreeze] is called. Calls
	* to [log], [obtain], and [commit] 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 echo(message: LogMessage, toLogcat: Boolean, toSystrace: Boolean) {
	if (toLogcat \|\| toSystrace) {
	val strMessage = message.messagePrinter(message)
	if (toSystrace) {
	echoToSystrace(message, strMessage)
	}
	if (toLogcat) {
	echoToLogcat(message, strMessage)
	}
	}
	}

	private fun echoToSystrace(message: LogMessage, strMessage: String) {
	Trace.instantForTrack(
	Trace.TRACE_TAG_APP,
	"UI Events",
	"$name - ${message.level.shortString} ${message.tag}: $strMessage"
	)
	}

	private fun echoToLogcat(message: LogMessage, strMessage: String) {
	when (message.level) {
	LogLevel.VERBOSE -> Log.v(message.tag, strMessage, message.exception)
	LogLevel.DEBUG -> Log.d(message.tag, strMessage, message.exception)
	LogLevel.INFO -> Log.i(message.tag, strMessage, message.exception)
	LogLevel.WARNING -> Log.w(message.tag, strMessage, message.exception)
	LogLevel.ERROR -> Log.e(message.tag, strMessage, message.exception)
	LogLevel.WTF -> Log.wtf(message.tag, strMessage, message.exception)
	}
	}
	}

	/**
	* 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.
	*/
	typealias MessageInitializer = LogMessage.() -> Unit

	private const val TAG = "LogBuffer"
	private val FROZEN_MESSAGE = LogMessageImpl.create()