Merge "Merge changes I48a0acc7,I57fbba0a into tm-qpr-dev am: 4a6855216f am:... (55af7ba0) · Commits · e / os / android_frameworks_base

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

+11 −0

Original line number	Diff line number	Diff line
		@@ -59,6 +59,17 @@ data class TableChange(
		int = value
		}

		/** Updates this to store the same value as [change]. */
		fun updateTo(change: TableChange) {
		reset(change.timestamp, change.columnPrefix, change.columnName)
		when (change.type) {
		DataType.STRING -> set(change.str)
		DataType.INT -> set(change.int)
		DataType.BOOLEAN -> set(change.bool)
		DataType.EMPTY -> {}
		}
		}

		/** Returns true if this object has a change. */
		fun hasData(): Boolean {
		return columnName.isNotBlank() && type != DataType.EMPTY

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

+36 −1

Original line number	Diff line number	Diff line
		@@ -16,13 +16,13 @@

		package com.android.systemui.log.table

		import android.os.Trace
		import com.android.systemui.Dumpable
		import com.android.systemui.plugins.util.RingBuffer
		import com.android.systemui.util.time.SystemClock
		import java.io.PrintWriter
		import java.text.SimpleDateFormat
		import java.util.Locale
		import kotlinx.coroutines.flow.Flow

		/**
		* A logger that logs changes in table format.
		@@ -82,6 +82,19 @@ class TableLogBuffer(

		private val buffer = RingBuffer(maxSize) { TableChange() }

		// Stores the most recently evicted value for each column name (indexed on column name).
		//
		// Why it's necessary: Because we use a RingBuffer of a fixed size, it's possible that a column
		// that's logged infrequently will eventually get pushed out by a different column that's
		// logged more frequently. Then, that infrequently-logged column isn't present in the RingBuffer
		// at all and we have no logs that the column ever existed. This is a problem because the
		// column's information is still relevant, valid, and may be critical to debugging issues.
		//
		// Fix: When a change is being evicted from the RingBuffer, we store it in this map (based on
		// its [TableChange.getName()]. This ensures that we always have at least one value for every
		// column ever logged. See b/272016422 for more details.
		private val lastEvictedValues = mutableMapOf<String, TableChange>()

		// A [TableRowLogger] object, re-used each time [logDiffs] is called.
		// (Re-used to avoid object allocation.)
		private val tempRow = TableRowLoggerImpl(0, columnPrefix = "", this)
		@@ -138,18 +151,24 @@ class TableLogBuffer(
		// timestamps.)

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

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

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

		// TODO(b/259454430): Add additional change types here.
		@@ -158,6 +177,9 @@ class TableLogBuffer(
		private fun obtain(timestamp: Long, prefix: String, columnName: String): TableChange {
		verifyValidName(prefix, columnName)
		val tableChange = buffer.advance()
		if (tableChange.hasData()) {
		saveEvictedValue(tableChange)
		}
		tableChange.reset(timestamp, prefix, columnName)
		return tableChange
		}
		@@ -173,10 +195,23 @@ class TableLogBuffer(
		}
		}

		private fun saveEvictedValue(change: TableChange) {
		Trace.beginSection("TableLogBuffer#saveEvictedValue")
		val name = change.getName()
		val previouslyEvicted =
		lastEvictedValues[name] ?: TableChange().also { lastEvictedValues[name] = it }
		// For recycling purposes, update the existing object in the map with the new information
		// instead of creating a new object.
		previouslyEvicted.updateTo(change)
		Trace.endSection()
		}

		@Synchronized
		override fun dump(pw: PrintWriter, args: Array<out String>) {
		pw.println(HEADER_PREFIX + name)
		pw.println("version $VERSION")

		lastEvictedValues.values.sortedBy { it.timestamp }.forEach { it.dump(pw) }
		for (i in 0 until buffer.size) {
		buffer[i].dump(pw)
		}

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

+88 −0

Original line number	Diff line number	Diff line
		@@ -121,4 +121,92 @@ class TableChangeTest : SysuiTestCase() {
		assertThat(underTest.getName()).doesNotContain("original")
		assertThat(underTest.getVal()).isEqualTo("8900")
		}

		@Test
		fun updateTo_emptyToString_isString() {
		val underTest = TableChange(columnPrefix = "fakePrefix", columnName = "fakeName")

		val new = TableChange(columnPrefix = "newPrefix", columnName = "newName")
		new.set("newString")
		underTest.updateTo(new)

		assertThat(underTest.hasData()).isTrue()
		assertThat(underTest.getName()).contains("newPrefix")
		assertThat(underTest.getName()).contains("newName")
		assertThat(underTest.getVal()).isEqualTo("newString")
		}

		@Test
		fun updateTo_intToEmpty_isEmpty() {
		val underTest = TableChange(columnPrefix = "fakePrefix", columnName = "fakeName")
		underTest.set(42)

		val new = TableChange(columnPrefix = "newPrefix", columnName = "newName")
		underTest.updateTo(new)

		assertThat(underTest.hasData()).isFalse()
		assertThat(underTest.getName()).contains("newPrefix")
		assertThat(underTest.getName()).contains("newName")
		assertThat(underTest.getVal()).isEqualTo("null")
		}

		@Test
		fun updateTo_stringToBool_isBool() {
		val underTest = TableChange(columnPrefix = "fakePrefix", columnName = "fakeName")
		underTest.set("oldString")

		val new = TableChange(columnPrefix = "newPrefix", columnName = "newName")
		new.set(true)
		underTest.updateTo(new)

		assertThat(underTest.hasData()).isTrue()
		assertThat(underTest.getName()).contains("newPrefix")
		assertThat(underTest.getName()).contains("newName")
		assertThat(underTest.getVal()).isEqualTo("true")
		}

		@Test
		fun updateTo_intToString_isString() {
		val underTest = TableChange(columnPrefix = "fakePrefix", columnName = "fakeName")
		underTest.set(43)

		val new = TableChange(columnPrefix = "newPrefix", columnName = "newName")
		new.set("newString")
		underTest.updateTo(new)

		assertThat(underTest.hasData()).isTrue()
		assertThat(underTest.getName()).contains("newPrefix")
		assertThat(underTest.getName()).contains("newName")
		assertThat(underTest.getVal()).isEqualTo("newString")
		}

		@Test
		fun updateTo_boolToInt_isInt() {
		val underTest = TableChange(columnPrefix = "fakePrefix", columnName = "fakeName")
		underTest.set(false)

		val new = TableChange(columnPrefix = "newPrefix", columnName = "newName")
		new.set(44)
		underTest.updateTo(new)

		assertThat(underTest.hasData()).isTrue()
		assertThat(underTest.getName()).contains("newPrefix")
		assertThat(underTest.getName()).contains("newName")
		assertThat(underTest.getVal()).isEqualTo("44")
		}

		@Test
		fun updateTo_boolToNewBool_isNewBool() {
		val underTest = TableChange(columnPrefix = "fakePrefix", columnName = "fakeName")
		underTest.set(false)

		val new = TableChange(columnPrefix = "newPrefix", columnName = "newName")
		new.set(true)
		underTest.updateTo(new)

		assertThat(underTest.hasData()).isTrue()
		assertThat(underTest.getName()).contains("newPrefix")
		assertThat(underTest.getName()).contains("newName")
		assertThat(underTest.getVal()).isEqualTo("true")
		}
		}

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

+226 −1

Original line number	Diff line number	Diff line
		@@ -435,11 +435,236 @@ class TableLogBufferTest : SysuiTestCase() {

		assertThat(dumpedString).doesNotContain("testString[0]")
		assertThat(dumpedString).doesNotContain("testString[1]")
		assertThat(dumpedString).doesNotContain("testString[2]")
		// The buffer should contain [MAX_SIZE + 1] entries since we also save the most recently
		// evicted value.
		assertThat(dumpedString).contains("testString[2]")
		assertThat(dumpedString).contains("testString[3]")
		assertThat(dumpedString).contains("testString[${MAX_SIZE + 2}]")
		}

		@Test
		fun columnEvicted_lastKnownColumnValueInDump() {
		systemClock.setCurrentTimeMillis(100L)
		underTest.logChange(prefix = "", columnName = "willBeEvicted", value = "evictedValue")

		// Exactly fill the buffer so that "willBeEvicted" is evicted
		for (i in 0 until MAX_SIZE) {
		systemClock.advanceTime(100L)
		val dumpString = "fillString[$i]"
		underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
		}

		val dumpedString = dumpChanges()

		// Expect that we'll have both the evicted column entry...
		val evictedColumnLog =
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		"willBeEvicted" +
		SEPARATOR +
		"evictedValue"
		assertThat(dumpedString).contains(evictedColumnLog)

		// ... and all of the fillingColumn entries.
		val firstFillingColumnLog =
		TABLE_LOG_DATE_FORMAT.format(200L) +
		SEPARATOR +
		"fillingColumn" +
		SEPARATOR +
		"fillString[0]"
		val lastFillingColumnLog =
		TABLE_LOG_DATE_FORMAT.format(1100L) +
		SEPARATOR +
		"fillingColumn" +
		SEPARATOR +
		"fillString[9]"
		assertThat(dumpedString).contains(firstFillingColumnLog)
		assertThat(dumpedString).contains(lastFillingColumnLog)
		}

		@Test
		fun multipleColumnsEvicted_allColumnsInDump() {
		systemClock.setCurrentTimeMillis(100L)
		underTest.logChange(prefix = "", columnName = "willBeEvictedString", value = "evictedValue")
		systemClock.advanceTime(100L)
		underTest.logChange(prefix = "", columnName = "willBeEvictedInt", value = 45)
		systemClock.advanceTime(100L)
		underTest.logChange(prefix = "", columnName = "willBeEvictedBool", value = true)

		// Exactly fill the buffer so that all the above columns will be evicted
		for (i in 0 until MAX_SIZE) {
		systemClock.advanceTime(100L)
		val dumpString = "fillString[$i]"
		underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
		}

		val dumpedString = dumpChanges()

		// Expect that we'll have all the evicted column entries...
		val evictedColumnLogString =
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		"willBeEvictedString" +
		SEPARATOR +
		"evictedValue"
		val evictedColumnLogInt =
		TABLE_LOG_DATE_FORMAT.format(200L) + SEPARATOR + "willBeEvictedInt" + SEPARATOR + "45"
		val evictedColumnLogBool =
		TABLE_LOG_DATE_FORMAT.format(300L) +
		SEPARATOR +
		"willBeEvictedBool" +
		SEPARATOR +
		"true"
		assertThat(dumpedString).contains(evictedColumnLogString)
		assertThat(dumpedString).contains(evictedColumnLogInt)
		assertThat(dumpedString).contains(evictedColumnLogBool)

		// ... and all of the fillingColumn entries.
		val firstFillingColumnLog =
		TABLE_LOG_DATE_FORMAT.format(400) +
		SEPARATOR +
		"fillingColumn" +
		SEPARATOR +
		"fillString[0]"
		val lastFillingColumnLog =
		TABLE_LOG_DATE_FORMAT.format(1300) +
		SEPARATOR +
		"fillingColumn" +
		SEPARATOR +
		"fillString[9]"
		assertThat(dumpedString).contains(firstFillingColumnLog)
		assertThat(dumpedString).contains(lastFillingColumnLog)
		}

		@Test
		fun multipleColumnsEvicted_differentPrefixSameName_allColumnsInDump() {
		systemClock.setCurrentTimeMillis(100L)
		underTest.logChange(prefix = "prefix1", columnName = "sameName", value = "value1")
		systemClock.advanceTime(100L)
		underTest.logChange(prefix = "prefix2", columnName = "sameName", value = "value2")
		systemClock.advanceTime(100L)
		underTest.logChange(prefix = "prefix3", columnName = "sameName", value = "value3")

		// Exactly fill the buffer so that all the above columns will be evicted
		for (i in 0 until MAX_SIZE) {
		systemClock.advanceTime(100L)
		val dumpString = "fillString[$i]"
		underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
		}

		val dumpedString = dumpChanges()

		// Expect that we'll have all the evicted column entries
		val evictedColumn1 =
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		"prefix1.sameName" +
		SEPARATOR +
		"value1"
		val evictedColumn2 =
		TABLE_LOG_DATE_FORMAT.format(200L) +
		SEPARATOR +
		"prefix2.sameName" +
		SEPARATOR +
		"value2"
		val evictedColumn3 =
		TABLE_LOG_DATE_FORMAT.format(300L) +
		SEPARATOR +
		"prefix3.sameName" +
		SEPARATOR +
		"value3"
		assertThat(dumpedString).contains(evictedColumn1)
		assertThat(dumpedString).contains(evictedColumn2)
		assertThat(dumpedString).contains(evictedColumn3)
		}

		@Test
		fun multipleColumnsEvicted_dumpSortedByTimestamp() {
		systemClock.setCurrentTimeMillis(100L)
		underTest.logChange(prefix = "", columnName = "willBeEvictedFirst", value = "evictedValue")
		systemClock.advanceTime(100L)
		underTest.logChange(prefix = "", columnName = "willBeEvictedSecond", value = 45)
		systemClock.advanceTime(100L)
		underTest.logChange(prefix = "", columnName = "willBeEvictedThird", value = true)

		// Exactly fill the buffer with so that all the above columns will be evicted
		for (i in 0 until MAX_SIZE) {
		systemClock.advanceTime(100L)
		val dumpString = "fillString[$i]"
		underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
		}

		val dumpedString = dumpChanges()

		// Expect that we'll have all the evicted column entries in timestamp order
		val firstEvictedLog =
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		"willBeEvictedFirst" +
		SEPARATOR +
		"evictedValue"
		val secondEvictedLog =
		TABLE_LOG_DATE_FORMAT.format(200L) +
		SEPARATOR +
		"willBeEvictedSecond" +
		SEPARATOR +
		"45"
		val thirdEvictedLog =
		TABLE_LOG_DATE_FORMAT.format(300L) +
		SEPARATOR +
		"willBeEvictedThird" +
		SEPARATOR +
		"true"
		assertThat(dumpedString).contains(firstEvictedLog)
		val stringAfterFirst = dumpedString.substringAfter(firstEvictedLog)
		assertThat(stringAfterFirst).contains(secondEvictedLog)
		val stringAfterSecond = stringAfterFirst.substringAfter(secondEvictedLog)
		assertThat(stringAfterSecond).contains(thirdEvictedLog)
		}

		@Test
		fun sameColumnEvictedMultipleTimes_onlyLastEvictionInDump() {
		systemClock.setCurrentTimeMillis(0L)

		for (i in 1 until 4) {
		systemClock.advanceTime(100L)
		val dumpString = "evicted[$i]"
		underTest.logChange(prefix = "", columnName = "evictedColumn", value = dumpString)
		}

		// Exactly fill the buffer so that all the entries for "evictedColumn" will be evicted.
		for (i in 0 until MAX_SIZE) {
		systemClock.advanceTime(100L)
		val dumpString = "fillString[$i]"
		underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
		}

		val dumpedString = dumpChanges()

		// Expect that we only have the most recent evicted column entry
		val evictedColumnLog1 =
		TABLE_LOG_DATE_FORMAT.format(100L) +
		SEPARATOR +
		"evictedColumn" +
		SEPARATOR +
		"evicted[1]"
		val evictedColumnLog2 =
		TABLE_LOG_DATE_FORMAT.format(200L) +
		SEPARATOR +
		"evictedColumn" +
		SEPARATOR +
		"evicted[2]"
		val evictedColumnLog3 =
		TABLE_LOG_DATE_FORMAT.format(300L) +
		SEPARATOR +
		"evictedColumn" +
		SEPARATOR +
		"evicted[3]"
		assertThat(dumpedString).doesNotContain(evictedColumnLog1)
		assertThat(dumpedString).doesNotContain(evictedColumnLog2)
		assertThat(dumpedString).contains(evictedColumnLog3)
		}

		private fun dumpChanges(): String {
		underTest.dump(PrintWriter(outputWriter), arrayOf())
		return outputWriter.toString()