[Table logging] Add "**" to logs that were generated when a flow (397da934) · Commits · e / os / android_frameworks_base

packages/SystemUI/src/com/android/systemui/log/table/Diffable.kt

+13 −6

Original line number	Diff line number	Diff line
		@@ -70,7 +70,9 @@ fun <T : Diffable<T>> Flow<T>.logDiffsForTable(
		): Flow<T> {
		// Fully log the initial value to the table.
		val getInitialValue = {
		tableLogBuffer.logChange(columnPrefix) { row -> initialValue.logFull(row) }
		tableLogBuffer.logChange(columnPrefix, isInitial = true) { row ->
		initialValue.logFull(row)
		}
		initialValue
		}
		return this.pairwiseBy(getInitialValue) { prevVal: T, newVal: T ->
		@@ -90,7 +92,7 @@ fun Flow<Boolean>.logDiffsForTable(
		initialValue: Boolean,
		): Flow<Boolean> {
		val initialValueFun = {
		tableLogBuffer.logChange(columnPrefix, columnName, initialValue)
		tableLogBuffer.logChange(columnPrefix, columnName, initialValue, isInitial = true)
		initialValue
		}
		return this.pairwiseBy(initialValueFun) { prevVal, newVal: Boolean ->
		@@ -109,7 +111,7 @@ fun Flow<Int>.logDiffsForTable(
		initialValue: Int,
		): Flow<Int> {
		val initialValueFun = {
		tableLogBuffer.logChange(columnPrefix, columnName, initialValue)
		tableLogBuffer.logChange(columnPrefix, columnName, initialValue, isInitial = true)
		initialValue
		}
		return this.pairwiseBy(initialValueFun) { prevVal, newVal: Int ->
		@@ -128,7 +130,7 @@ fun Flow<Int?>.logDiffsForTable(
		initialValue: Int?,
		): Flow<Int?> {
		val initialValueFun = {
		tableLogBuffer.logChange(columnPrefix, columnName, initialValue)
		tableLogBuffer.logChange(columnPrefix, columnName, initialValue, isInitial = true)
		initialValue
		}
		return this.pairwiseBy(initialValueFun) { prevVal, newVal: Int? ->
		@@ -147,7 +149,7 @@ fun Flow<String?>.logDiffsForTable(
		initialValue: String?,
		): Flow<String?> {
		val initialValueFun = {
		tableLogBuffer.logChange(columnPrefix, columnName, initialValue)
		tableLogBuffer.logChange(columnPrefix, columnName, initialValue, isInitial = true)
		initialValue
		}
		return this.pairwiseBy(initialValueFun) { prevVal, newVal: String? ->
		@@ -166,7 +168,12 @@ fun <T> Flow<List<T>>.logDiffsForTable(
		initialValue: List<T>,
		): Flow<List<T>> {
		val initialValueFun = {
		tableLogBuffer.logChange(columnPrefix, columnName, initialValue.toString())
		tableLogBuffer.logChange(
		columnPrefix,
		columnName,
		initialValue.toString(),
		isInitial = true,
		)
		initialValue
		}
		return this.pairwiseBy(initialValueFun) { prevVal, newVal: List<T> ->

packages/SystemUI/src/com/android/systemui/log/table/TableChange.kt

+20 −8

Original line number	Diff line number	Diff line
		@@ -16,25 +16,31 @@

		package com.android.systemui.log.table

		import androidx.annotation.VisibleForTesting

		/**
		* A object used with [TableLogBuffer] to store changes in variables over time. Is recyclable.
		*
		* Each message represents a change to exactly 1 type, specified by [DataType].
		*
		* @property isInitial see [TableLogBuffer.logChange(String, Boolean, (TableRowLogger) -> Unit].
		*/
		data class TableChange(
		var timestamp: Long = 0,
		var columnPrefix: String = "",
		var columnName: String = "",
		var isInitial: Boolean = false,
		var type: DataType = DataType.EMPTY,
		var bool: Boolean = false,
		var int: Int? = null,
		var str: String? = null,
		) {
		/** Resets to default values so that the object can be recycled. */
		fun reset(timestamp: Long, columnPrefix: String, columnName: String) {
		fun reset(timestamp: Long, columnPrefix: String, columnName: String, isInitial: Boolean) {
		this.timestamp = timestamp
		this.columnPrefix = columnPrefix
		this.columnName = columnName
		this.isInitial = isInitial
		this.type = DataType.EMPTY
		this.bool = false
		this.int = 0
		@@ -61,7 +67,7 @@ data class TableChange(

		/** Updates this to store the same value as [change]. */
		fun updateTo(change: TableChange) {
		reset(change.timestamp, change.columnPrefix, change.columnName)
		reset(change.timestamp, change.columnPrefix, change.columnName, change.isInitial)
		when (change.type) {
		DataType.STRING -> set(change.str)
		DataType.INT -> set(change.int)
		@@ -84,12 +90,14 @@ data class TableChange(
		}

		fun getVal(): String {
		return when (type) {
		val value =
		when (type) {
		DataType.EMPTY -> null
		DataType.STRING -> str
		DataType.INT -> int
		DataType.BOOLEAN -> bool
		}.toString()
		return "${if (isInitial) IS_INITIAL_PREFIX else ""}$value"
		}

		enum class DataType {
		@@ -98,4 +106,8 @@ data class TableChange(
		INT,
		EMPTY,
		}

		companion object {
		@VisibleForTesting const val IS_INITIAL_PREFIX = "**"
		}
		}

packages/SystemUI/src/com/android/systemui/log/table/TableLogBuffer.kt

+75 −22

Original line number	Diff line number	Diff line
		@@ -97,7 +97,13 @@ class TableLogBuffer(

		// A [TableRowLogger] object, re-used each time [logDiffs] is called.
		// (Re-used to avoid object allocation.)
		private val tempRow = TableRowLoggerImpl(0, columnPrefix = "", this)
		private val tempRow =
		TableRowLoggerImpl(
		timestamp = 0,
		columnPrefix = "",
		isInitial = false,
		tableLogBuffer = this,
		)

		/**
		* Log the differences between [prevVal] and [newVal].
		@@ -115,6 +121,8 @@ class TableLogBuffer(
		val row = tempRow
		row.timestamp = systemClock.currentTimeMillis()
		row.columnPrefix = columnPrefix
		// Because we have a prevVal and a newVal, we know that this isn't the initial log.
		row.isInitial = false
		newVal.logDiffs(prevVal, row)
		}

		@@ -123,50 +131,89 @@ class TableLogBuffer(
		*
		* @param rowInitializer a function that will be called immediately to store relevant data on
		* the row.
		* @param isInitial true if this change represents the starting value for a particular column
		* (as opposed to a value that was updated after receiving new information). This is used to
		* help us identify which values were just default starting values, and which values were
		* derived from updated information. Most callers should use false for this value.
		*/
		@Synchronized
		fun logChange(columnPrefix: String, rowInitializer: (TableRowLogger) -> Unit) {
		fun logChange(
		columnPrefix: String,
		isInitial: Boolean = false,
		rowInitializer: (TableRowLogger) -> Unit
		) {
		val row = tempRow
		row.timestamp = systemClock.currentTimeMillis()
		row.columnPrefix = columnPrefix
		row.isInitial = isInitial
		rowInitializer(row)
		}

		/** Logs a String? change. */
		fun logChange(prefix: String, columnName: String, value: String?) {
		logChange(systemClock.currentTimeMillis(), prefix, columnName, value)
		/**
		* Logs a String? change.
		*
		* @param isInitial see [TableLogBuffer.logChange(String, Boolean, (TableRowLogger) -> Unit].
		*/
		fun logChange(prefix: String, columnName: String, value: String?, isInitial: Boolean = false) {
		logChange(systemClock.currentTimeMillis(), prefix, columnName, value, isInitial)
		}

		/** Logs a boolean change. */
		fun logChange(prefix: String, columnName: String, value: Boolean) {
		logChange(systemClock.currentTimeMillis(), prefix, columnName, value)
		/**
		* Logs a boolean change.
		*
		* @param isInitial see [TableLogBuffer.logChange(String, Boolean, (TableRowLogger) -> Unit].
		*/
		fun logChange(prefix: String, columnName: String, value: Boolean, isInitial: Boolean = false) {
		logChange(systemClock.currentTimeMillis(), prefix, columnName, value, isInitial)
		}

		/** Logs a Int change. */
		fun logChange(prefix: String, columnName: String, value: Int?) {
		logChange(systemClock.currentTimeMillis(), prefix, columnName, value)
		/**
		* Logs a Int change.
		*
		* @param isInitial see [TableLogBuffer.logChange(String, Boolean, (TableRowLogger) -> Unit].
		*/
		fun logChange(prefix: String, columnName: String, value: Int?, isInitial: Boolean = false) {
		logChange(systemClock.currentTimeMillis(), prefix, columnName, value, isInitial)
		}

		// Keep these individual [logChange] methods private (don't let clients give us their own
		// timestamps.)

		private fun logChange(timestamp: Long, prefix: String, columnName: String, value: String?) {
		private fun logChange(
		timestamp: Long,
		prefix: String,
		columnName: String,
		value: String?,
		isInitial: Boolean,
		) {
		Trace.beginSection("TableLogBuffer#logChange(string)")
		val change = obtain(timestamp, prefix, columnName)
		val change = obtain(timestamp, prefix, columnName, isInitial)
		change.set(value)
		Trace.endSection()
		}

		private fun logChange(timestamp: Long, prefix: String, columnName: String, value: Boolean) {
		private fun logChange(
		timestamp: Long,
		prefix: String,
		columnName: String,
		value: Boolean,
		isInitial: Boolean,
		) {
		Trace.beginSection("TableLogBuffer#logChange(boolean)")
		val change = obtain(timestamp, prefix, columnName)
		val change = obtain(timestamp, prefix, columnName, isInitial)
		change.set(value)
		Trace.endSection()
		}

		private fun logChange(timestamp: Long, prefix: String, columnName: String, value: Int?) {
		private fun logChange(
		timestamp: Long,
		prefix: String,
		columnName: String,
		value: Int?,
		isInitial: Boolean,
		) {
		Trace.beginSection("TableLogBuffer#logChange(int)")
		val change = obtain(timestamp, prefix, columnName)
		val change = obtain(timestamp, prefix, columnName, isInitial)
		change.set(value)
		Trace.endSection()
		}
		@@ -174,13 +221,18 @@ class TableLogBuffer(
		// TODO(b/259454430): Add additional change types here.

		@Synchronized
		private fun obtain(timestamp: Long, prefix: String, columnName: String): TableChange {
		private fun obtain(
		timestamp: Long,
		prefix: String,
		columnName: String,
		isInitial: Boolean,
		): TableChange {
		verifyValidName(prefix, columnName)
		val tableChange = buffer.advance()
		if (tableChange.hasData()) {
		saveEvictedValue(tableChange)
		}
		tableChange.reset(timestamp, prefix, columnName)
		tableChange.reset(timestamp, prefix, columnName, isInitial)
		return tableChange
		}

		@@ -240,21 +292,22 @@ class TableLogBuffer(
		private class TableRowLoggerImpl(
		var timestamp: Long,
		var columnPrefix: String,
		var isInitial: Boolean,
		val tableLogBuffer: TableLogBuffer,
		) : TableRowLogger {
		/** Logs a change to a string value. */
		override fun logChange(columnName: String, value: String?) {
		tableLogBuffer.logChange(timestamp, columnPrefix, columnName, value)
		tableLogBuffer.logChange(timestamp, columnPrefix, columnName, value, isInitial)
		}

		/** Logs a change to a boolean value. */
		override fun logChange(columnName: String, value: Boolean) {
		tableLogBuffer.logChange(timestamp, columnPrefix, columnName, value)
		tableLogBuffer.logChange(timestamp, columnPrefix, columnName, value, isInitial)
		}

		/** Logs a change to an int value. */
		override fun logChange(columnName: String, value: Int) {
		tableLogBuffer.logChange(timestamp, columnPrefix, columnName, value)
		tableLogBuffer.logChange(timestamp, columnPrefix, columnName, value, isInitial)
		}
		}
		}

packages/SystemUI/tests/src/com/android/systemui/keyguard/data/repository/KeyguardBouncerRepositoryTest.kt

+3 −1

Original line number	Diff line number	Diff line
		@@ -21,6 +21,8 @@ import androidx.test.filters.SmallTest
		import com.android.keyguard.ViewMediatorCallback
		import com.android.systemui.SysuiTestCase
		import com.android.systemui.log.table.TableLogBuffer
		import com.android.systemui.util.mockito.any
		import com.android.systemui.util.mockito.eq
		import com.android.systemui.util.time.SystemClock
		import kotlinx.coroutines.runBlocking
		import kotlinx.coroutines.ExperimentalCoroutinesApi
		@@ -58,6 +60,6 @@ class KeyguardBouncerRepositoryTest : SysuiTestCase() {
		@Test
		fun changingFlowValueTriggersLogging() = runBlocking {
		underTest.setPrimaryShow(true)
		verify(bouncerLogger).logChange("", "PrimaryBouncerShow", false)
		verify(bouncerLogger).logChange(eq(""), eq("PrimaryBouncerShow"), value = eq(false), any())
		}
		}

packages/SystemUI/tests/src/com/android/systemui/log/table/LogDiffsForTableTest.kt

+81 −11

Original line number	Diff line number	Diff line
		@@ -18,6 +18,7 @@ package com.android.systemui.log.table

		import androidx.test.filters.SmallTest
		import com.android.systemui.SysuiTestCase
		import com.android.systemui.log.table.TableChange.Companion.IS_INITIAL_PREFIX
		import com.android.systemui.util.time.FakeSystemClock
		import com.google.common.truth.Truth.assertThat
		import java.io.PrintWriter
		@@ -91,6 +92,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"false"
		)

		@@ -121,7 +123,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		val logs = dumpLog()
		assertThat(logs)
		.contains(
		TABLE_LOG_DATE_FORMAT.format(100L) + SEPARATOR + FULL_NAME + SEPARATOR + "false"
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"false"
		)
		assertThat(logs)
		.contains(
		@@ -164,7 +171,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		// Input flow: true@100, true@200, true@300, false@400, false@500, true@600
		// Output log: true@100, --------, --------, false@400, ---------, true@600
		val expected1 =
		TABLE_LOG_DATE_FORMAT.format(100L) + SEPARATOR + FULL_NAME + SEPARATOR + "true"
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"true"
		val expected4 =
		TABLE_LOG_DATE_FORMAT.format(400L) + SEPARATOR + FULL_NAME + SEPARATOR + "false"
		val expected6 =
		@@ -203,7 +215,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		val job = launch { flowWithLogging.collect() }
		assertThat(dumpLog())
		.contains(
		TABLE_LOG_DATE_FORMAT.format(50L) + SEPARATOR + FULL_NAME + SEPARATOR + "false"
		TABLE_LOG_DATE_FORMAT.format(50L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"false"
		)

		systemClock.setCurrentTimeMillis(100L)
		@@ -269,7 +286,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		val logs = dumpLog()
		assertThat(logs)
		.contains(
		TABLE_LOG_DATE_FORMAT.format(3000L) + SEPARATOR + FULL_NAME + SEPARATOR + "1234"
		TABLE_LOG_DATE_FORMAT.format(3000L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"1234"
		)

		job.cancel()
		@@ -299,7 +321,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		val logs = dumpLog()
		assertThat(logs)
		.contains(
		TABLE_LOG_DATE_FORMAT.format(100L) + SEPARATOR + FULL_NAME + SEPARATOR + "1234"
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"1234"
		)
		assertThat(logs)
		.contains(
		@@ -345,7 +372,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		val logs = dumpLog()
		assertThat(logs)
		.contains(
		TABLE_LOG_DATE_FORMAT.format(100L) + SEPARATOR + FULL_NAME + SEPARATOR + "1"
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"1"
		)
		assertThat(logs)
		.contains(
		@@ -388,7 +420,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		// Input flow: 1@100, 2@200, 3@300, 3@400, 3@500, 2@600, 6@700, 6@800
		// Output log: 1@100, 2@200, 3@300, -----, -----, 2@600, 6@700, -----
		val expected1 =
		TABLE_LOG_DATE_FORMAT.format(100L) + SEPARATOR + FULL_NAME + SEPARATOR + "1"
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"1"
		val expected2 =
		TABLE_LOG_DATE_FORMAT.format(200L) + SEPARATOR + FULL_NAME + SEPARATOR + "2"
		val expected3 =
		@@ -432,7 +469,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		val job = launch { flowWithLogging.collect() }
		assertThat(dumpLog())
		.contains(
		TABLE_LOG_DATE_FORMAT.format(50L) + SEPARATOR + FULL_NAME + SEPARATOR + "1111"
		TABLE_LOG_DATE_FORMAT.format(50L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"1111"
		)

		systemClock.setCurrentTimeMillis(100L)
		@@ -502,6 +544,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"val1234"
		)

		@@ -532,7 +575,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		val logs = dumpLog()
		assertThat(logs)
		.contains(
		TABLE_LOG_DATE_FORMAT.format(100L) + SEPARATOR + FULL_NAME + SEPARATOR + "val1"
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"val1"
		)
		assertThat(logs)
		.contains(
		@@ -574,7 +622,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		val logs = dumpLog()
		assertThat(logs)
		.contains(
		TABLE_LOG_DATE_FORMAT.format(100L) + SEPARATOR + FULL_NAME + SEPARATOR + "start"
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"start"
		)
		assertThat(logs)
		.contains(
		@@ -621,7 +674,12 @@ class LogDiffsForTableTest : SysuiTestCase() {
		// Input flow: start@100, start@200, new@300, new@400, newer@500, newest@600, newest@700
		// Output log: start@100, ---------, new@300, -------, newer@500, newest@600, ----------
		val expected1 =
		TABLE_LOG_DATE_FORMAT.format(100L) + SEPARATOR + FULL_NAME + SEPARATOR + "start"
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"start"
		val expected3 =
		TABLE_LOG_DATE_FORMAT.format(300L) + SEPARATOR + FULL_NAME + SEPARATOR + "new"
		val expected5 =
		@@ -667,6 +725,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"initial"
		)

		@@ -761,6 +820,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		"." +
		TestDiffable.COL_FULL +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"true"
		)
		assertThat(logs)
		@@ -771,6 +831,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		"." +
		TestDiffable.COL_INT +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"1234"
		)
		assertThat(logs)
		@@ -781,6 +842,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		"." +
		TestDiffable.COL_STRING +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"string1234"
		)
		assertThat(logs)
		@@ -791,6 +853,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		"." +
		TestDiffable.COL_BOOLEAN +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"false"
		)
		job.cancel()
		@@ -979,6 +1042,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		"." +
		TestDiffable.COL_INT +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"0"
		)
		assertThat(logs)
		@@ -989,6 +1053,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		"." +
		TestDiffable.COL_STRING +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"string0"
		)
		assertThat(logs)
		@@ -999,6 +1064,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		"." +
		TestDiffable.COL_BOOLEAN +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		"false"
		)

		@@ -1118,6 +1184,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		listOf(1234).toString()
		)

		@@ -1155,6 +1222,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		listOf("val0", "val00").toString()
		)
		assertThat(logs)
		@@ -1221,6 +1289,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		listOf("val0", "val00").toString()
		val expected3 =
		TABLE_LOG_DATE_FORMAT.format(300L) +
		@@ -1276,6 +1345,7 @@ class LogDiffsForTableTest : SysuiTestCase() {
		SEPARATOR +
		FULL_NAME +
		SEPARATOR +
		IS_INITIAL_PREFIX +
		listOf(1111).toString()
		)