1 /*
2  * Copyright (C) 2022 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.table
18 
19 import androidx.test.filters.SmallTest
20 import com.android.systemui.SysuiTestCase
21 import com.android.systemui.log.LogcatEchoTracker
22 import com.android.systemui.log.core.LogLevel
23 import com.android.systemui.log.table.TableChange.Companion.IS_INITIAL_PREFIX
24 import com.android.systemui.log.table.TableChange.Companion.MAX_STRING_LENGTH
25 import com.android.systemui.util.mockito.any
26 import com.android.systemui.util.mockito.eq
27 import com.android.systemui.util.mockito.mock
28 import com.android.systemui.util.mockito.whenever
29 import com.android.systemui.util.time.FakeSystemClock
30 import com.google.common.truth.Truth.assertThat
31 import java.io.PrintWriter
32 import java.io.StringWriter
33 import kotlinx.coroutines.ExperimentalCoroutinesApi
34 import kotlinx.coroutines.test.TestScope
35 import kotlinx.coroutines.test.UnconfinedTestDispatcher
36 import org.junit.Before
37 import org.junit.Test
38 
39 @OptIn(ExperimentalCoroutinesApi::class)
40 @SmallTest
41 class TableLogBufferTest : SysuiTestCase() {
42     private lateinit var underTest: TableLogBuffer
43 
44     private lateinit var systemClock: FakeSystemClock
45     private lateinit var outputWriter: StringWriter
46     private lateinit var logcatEchoTracker: LogcatEchoTracker
47     private lateinit var localLogcat: FakeLogProxy
48 
49     private val testDispatcher = UnconfinedTestDispatcher()
50     private val testScope = TestScope(testDispatcher)
51 
52     @Before
53     fun setup() {
54         localLogcat = FakeLogProxy()
55         logcatEchoTracker = mock()
56         systemClock = FakeSystemClock()
57         outputWriter = StringWriter()
58 
59         underTest =
60             TableLogBuffer(
61                 MAX_SIZE,
62                 NAME,
63                 systemClock,
64                 logcatEchoTracker,
65                 testDispatcher,
66                 testScope.backgroundScope,
67                 localLogcat = localLogcat,
68             )
69         underTest.init()
70     }
71 
72     @Test(expected = IllegalArgumentException::class)
73     fun maxSizeZero_throwsException() {
74         TableLogBuffer(
75             maxSize = 0,
76             "name",
77             systemClock,
78             logcatEchoTracker,
79             testDispatcher,
80             testScope.backgroundScope,
81             localLogcat = localLogcat,
82         )
83     }
84 
85     @Test
86     fun dumpChanges_hasHeader() {
87         val dumpedString = dumpChanges()
88 
89         assertThat(logLines(dumpedString)[0]).isEqualTo(HEADER_PREFIX + NAME)
90     }
91 
92     @Test
93     fun dumpChanges_hasVersion() {
94         val dumpedString = dumpChanges()
95 
96         assertThat(logLines(dumpedString)[1]).isEqualTo("version $VERSION")
97     }
98 
99     @Test
100     fun dumpChanges_hasFooter() {
101         val dumpedString = dumpChanges()
102 
103         assertThat(logLines(dumpedString).last()).isEqualTo(FOOTER_PREFIX + NAME)
104     }
105 
106     @Test(expected = IllegalArgumentException::class)
107     fun dumpChanges_str_separatorNotAllowedInPrefix() {
108         val next =
109             object : TestDiffable() {
110                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
111                     row.logChange("columnName", "stringValue")
112                 }
113             }
114         underTest.logDiffs("some${SEPARATOR}thing", TestDiffable(), next)
115     }
116 
117     @Test(expected = IllegalArgumentException::class)
118     fun dumpChanges_bool_separatorNotAllowedInPrefix() {
119         val next =
120             object : TestDiffable() {
121                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
122                     row.logChange("columnName", true)
123                 }
124             }
125         underTest.logDiffs("some${SEPARATOR}thing", TestDiffable(), next)
126     }
127 
128     @Test(expected = IllegalArgumentException::class)
129     fun dumpChanges_int_separatorNotAllowedInPrefix() {
130         val next =
131             object : TestDiffable() {
132                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
133                     row.logChange("columnName", 567)
134                 }
135             }
136         underTest.logDiffs("some${SEPARATOR}thing", TestDiffable(), next)
137     }
138 
139     @Test(expected = IllegalArgumentException::class)
140     fun dumpChanges_str_separatorNotAllowedInColumnName() {
141         val next =
142             object : TestDiffable() {
143                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
144                     row.logChange("column${SEPARATOR}Name", "stringValue")
145                 }
146             }
147         underTest.logDiffs("prefix", TestDiffable(), next)
148     }
149 
150     @Test(expected = IllegalArgumentException::class)
151     fun dumpChanges_bool_separatorNotAllowedInColumnName() {
152         val next =
153             object : TestDiffable() {
154                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
155                     row.logChange("column${SEPARATOR}Name", true)
156                 }
157             }
158         underTest.logDiffs("prefix", TestDiffable(), next)
159     }
160 
161     @Test(expected = IllegalArgumentException::class)
162     fun dumpChanges_int_separatorNotAllowedInColumnName() {
163         val next =
164             object : TestDiffable() {
165                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
166                     row.logChange("column${SEPARATOR}Name", 456)
167                 }
168             }
169         underTest.logDiffs("prefix", TestDiffable(), next)
170     }
171 
172     @Test
173     fun logChange_bool_dumpsCorrectly() {
174         systemClock.setCurrentTimeMillis(4000L)
175 
176         underTest.logChange("prefix", "columnName", true)
177 
178         val dumpedString = dumpChanges()
179         val expected =
180             TABLE_LOG_DATE_FORMAT.format(4000L) +
181                 SEPARATOR +
182                 "prefix.columnName" +
183                 SEPARATOR +
184                 "true"
185         assertThat(dumpedString).contains(expected)
186     }
187 
188     @Test
189     fun dumpChanges_strChange_logsFromNext() {
190         systemClock.setCurrentTimeMillis(100L)
191 
192         val prevDiffable =
193             object : TestDiffable() {
194                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
195                     row.logChange("stringValChange", "prevStringVal")
196                 }
197             }
198         val nextDiffable =
199             object : TestDiffable() {
200                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
201                     row.logChange("stringValChange", "newStringVal")
202                 }
203             }
204 
205         underTest.logDiffs("prefix", prevDiffable, nextDiffable)
206 
207         val dumpedString = dumpChanges()
208 
209         val expected =
210             TABLE_LOG_DATE_FORMAT.format(100L) +
211                 SEPARATOR +
212                 "prefix.stringValChange" +
213                 SEPARATOR +
214                 "newStringVal"
215         assertThat(dumpedString).contains(expected)
216         assertThat(dumpedString).doesNotContain("prevStringVal")
217     }
218 
219     @Test
220     fun dumpChanges_boolChange_logsFromNext() {
221         systemClock.setCurrentTimeMillis(100L)
222 
223         val prevDiffable =
224             object : TestDiffable() {
225                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
226                     row.logChange("booleanValChange", false)
227                 }
228             }
229         val nextDiffable =
230             object : TestDiffable() {
231                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
232                     row.logChange("booleanValChange", true)
233                 }
234             }
235 
236         underTest.logDiffs("prefix", prevDiffable, nextDiffable)
237 
238         val dumpedString = dumpChanges()
239 
240         val expected =
241             TABLE_LOG_DATE_FORMAT.format(100L) +
242                 SEPARATOR +
243                 "prefix.booleanValChange" +
244                 SEPARATOR +
245                 "true"
246         assertThat(dumpedString).contains(expected)
247         assertThat(dumpedString).doesNotContain("false")
248     }
249 
250     @Test
251     fun dumpChanges_intChange_logsFromNext() {
252         systemClock.setCurrentTimeMillis(100L)
253 
254         val prevDiffable =
255             object : TestDiffable() {
256                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
257                     row.logChange("intValChange", 12345)
258                 }
259             }
260         val nextDiffable =
261             object : TestDiffable() {
262                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
263                     row.logChange("intValChange", 67890)
264                 }
265             }
266 
267         underTest.logDiffs("prefix", prevDiffable, nextDiffable)
268 
269         val dumpedString = dumpChanges()
270 
271         val expected =
272             TABLE_LOG_DATE_FORMAT.format(100L) +
273                 SEPARATOR +
274                 "prefix.intValChange" +
275                 SEPARATOR +
276                 "67890"
277         assertThat(dumpedString).contains(expected)
278         assertThat(dumpedString).doesNotContain("12345")
279     }
280 
281     @Test
282     fun dumpChanges_noPrefix() {
283         systemClock.setCurrentTimeMillis(100L)
284 
285         val prevDiffable =
286             object : TestDiffable() {
287                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
288                     row.logChange("booleanValChange", false)
289                 }
290             }
291         val nextDiffable =
292             object : TestDiffable() {
293                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
294                     row.logChange("booleanValChange", true)
295                 }
296             }
297 
298         // WHEN there's a blank prefix
299         underTest.logDiffs("", prevDiffable, nextDiffable)
300 
301         val dumpedString = dumpChanges()
302 
303         // THEN the dump still works
304         val expected =
305             TABLE_LOG_DATE_FORMAT.format(100L) + SEPARATOR + "booleanValChange" + SEPARATOR + "true"
306         assertThat(dumpedString).contains(expected)
307     }
308 
309     @Test
310     fun dumpChanges_multipleChangesForSameColumn_logs() {
311         lateinit var valToDump: String
312 
313         val diffable =
314             object : TestDiffable() {
315                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
316                     row.logChange("valChange", valToDump)
317                 }
318             }
319 
320         systemClock.setCurrentTimeMillis(12000L)
321         valToDump = "stateValue12"
322         underTest.logDiffs(columnPrefix = "", diffable, diffable)
323 
324         systemClock.setCurrentTimeMillis(20000L)
325         valToDump = "stateValue20"
326         underTest.logDiffs(columnPrefix = "", diffable, diffable)
327 
328         systemClock.setCurrentTimeMillis(40000L)
329         valToDump = "stateValue40"
330         underTest.logDiffs(columnPrefix = "", diffable, diffable)
331 
332         systemClock.setCurrentTimeMillis(45000L)
333         valToDump = "stateValue45"
334         underTest.logDiffs(columnPrefix = "", diffable, diffable)
335 
336         val dumpedString = dumpChanges()
337 
338         val expected1 =
339             TABLE_LOG_DATE_FORMAT.format(12000L) +
340                 SEPARATOR +
341                 "valChange" +
342                 SEPARATOR +
343                 "stateValue12"
344         val expected2 =
345             TABLE_LOG_DATE_FORMAT.format(20000L) +
346                 SEPARATOR +
347                 "valChange" +
348                 SEPARATOR +
349                 "stateValue20"
350         val expected3 =
351             TABLE_LOG_DATE_FORMAT.format(40000L) +
352                 SEPARATOR +
353                 "valChange" +
354                 SEPARATOR +
355                 "stateValue40"
356         val expected4 =
357             TABLE_LOG_DATE_FORMAT.format(45000L) +
358                 SEPARATOR +
359                 "valChange" +
360                 SEPARATOR +
361                 "stateValue45"
362         assertThat(dumpedString).contains(expected1)
363         assertThat(dumpedString).contains(expected2)
364         assertThat(dumpedString).contains(expected3)
365         assertThat(dumpedString).contains(expected4)
366     }
367 
368     @Test
369     fun dumpChanges_multipleChangesAtOnce_logs() {
370         systemClock.setCurrentTimeMillis(100L)
371 
372         val prevDiffable = object : TestDiffable() {}
373         val nextDiffable =
374             object : TestDiffable() {
375                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
376                     row.logChange("status", "in progress")
377                     row.logChange("connected", false)
378                 }
379             }
380 
381         underTest.logDiffs(columnPrefix = "", prevDiffable, nextDiffable)
382 
383         val dumpedString = dumpChanges()
384 
385         val timestamp = TABLE_LOG_DATE_FORMAT.format(100L)
386         val expected1 = timestamp + SEPARATOR + "status" + SEPARATOR + "in progress"
387         val expected2 = timestamp + SEPARATOR + "connected" + SEPARATOR + "false"
388         assertThat(dumpedString).contains(expected1)
389         assertThat(dumpedString).contains(expected2)
390     }
391 
392     @Test
393     fun logChange_rowInitializer_notIsInitial_dumpsCorrectly() {
394         systemClock.setCurrentTimeMillis(100L)
395 
396         underTest.logChange(columnPrefix = "", isInitial = false) { row ->
397             row.logChange("column1", "val1")
398             row.logChange("column2", 2)
399             row.logChange("column3", true)
400         }
401 
402         val dumpedString = dumpChanges()
403 
404         val timestamp = TABLE_LOG_DATE_FORMAT.format(100L)
405         val expected1 = timestamp + SEPARATOR + "column1" + SEPARATOR + "val1"
406         val expected2 = timestamp + SEPARATOR + "column2" + SEPARATOR + "2"
407         val expected3 = timestamp + SEPARATOR + "column3" + SEPARATOR + "true"
408         assertThat(dumpedString).contains(expected1)
409         assertThat(dumpedString).contains(expected2)
410         assertThat(dumpedString).contains(expected3)
411     }
412 
413     @Test
414     fun logChange_rowInitializer_isInitial_dumpsCorrectly() {
415         systemClock.setCurrentTimeMillis(100L)
416 
417         underTest.logChange(columnPrefix = "", isInitial = true) { row ->
418             row.logChange("column1", "val1")
419             row.logChange("column2", 2)
420             row.logChange("column3", true)
421         }
422 
423         val dumpedString = dumpChanges()
424 
425         val timestamp = TABLE_LOG_DATE_FORMAT.format(100L)
426         val expected1 = timestamp + SEPARATOR + "column1" + SEPARATOR + IS_INITIAL_PREFIX + "val1"
427         val expected2 = timestamp + SEPARATOR + "column2" + SEPARATOR + IS_INITIAL_PREFIX + "2"
428         val expected3 = timestamp + SEPARATOR + "column3" + SEPARATOR + IS_INITIAL_PREFIX + "true"
429         assertThat(dumpedString).contains(expected1)
430         assertThat(dumpedString).contains(expected2)
431         assertThat(dumpedString).contains(expected3)
432     }
433 
434     @Test
435     fun logChange_rowInitializer_isInitialThenNotInitial_dumpsCorrectly() {
436         systemClock.setCurrentTimeMillis(100L)
437         underTest.logChange(columnPrefix = "", isInitial = true) { row ->
438             row.logChange("column1", "val1")
439             row.logChange("column2", 2)
440             row.logChange("column3", true)
441         }
442 
443         systemClock.setCurrentTimeMillis(200L)
444         underTest.logChange(columnPrefix = "", isInitial = false) { row ->
445             row.logChange("column1", "val11")
446             row.logChange("column2", 22)
447             row.logChange("column3", false)
448         }
449 
450         val dumpedString = dumpChanges()
451 
452         val timestamp = TABLE_LOG_DATE_FORMAT.format(100L)
453         val expected1 = timestamp + SEPARATOR + "column1" + SEPARATOR + IS_INITIAL_PREFIX + "val1"
454         val expected2 = timestamp + SEPARATOR + "column2" + SEPARATOR + IS_INITIAL_PREFIX + "2"
455         val expected3 = timestamp + SEPARATOR + "column3" + SEPARATOR + IS_INITIAL_PREFIX + "true"
456         val timestamp2 = TABLE_LOG_DATE_FORMAT.format(200L)
457         val expected4 = timestamp2 + SEPARATOR + "column1" + SEPARATOR + "val11"
458         val expected5 = timestamp2 + SEPARATOR + "column2" + SEPARATOR + "22"
459         val expected6 = timestamp2 + SEPARATOR + "column3" + SEPARATOR + "false"
460         assertThat(dumpedString).contains(expected1)
461         assertThat(dumpedString).contains(expected2)
462         assertThat(dumpedString).contains(expected3)
463         assertThat(dumpedString).contains(expected4)
464         assertThat(dumpedString).contains(expected5)
465         assertThat(dumpedString).contains(expected6)
466     }
467 
468     @Test
469     fun logDiffs_neverInitial() {
470         systemClock.setCurrentTimeMillis(100L)
471 
472         val prevDiffable =
473             object : TestDiffable() {
474                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
475                     row.logChange("stringValChange", "prevStringVal")
476                 }
477             }
478         val nextDiffable =
479             object : TestDiffable() {
480                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
481                     row.logChange("stringValChange", "newStringVal")
482                 }
483             }
484 
485         underTest.logDiffs("prefix", prevDiffable, nextDiffable)
486 
487         val dumpedString = dumpChanges()
488 
489         assertThat(dumpedString).doesNotContain(IS_INITIAL_PREFIX)
490     }
491 
492     @Test
493     fun logChange_variousPrimitiveValues_isInitialAlwaysUpdated() {
494         systemClock.setCurrentTimeMillis(100L)
495         underTest.logChange(prefix = "", columnName = "first", value = "val1", isInitial = true)
496         systemClock.setCurrentTimeMillis(200L)
497         underTest.logChange(prefix = "", columnName = "second", value = "val2", isInitial = true)
498         systemClock.setCurrentTimeMillis(300L)
499         underTest.logChange(prefix = "", columnName = "first", value = 11, isInitial = false)
500         systemClock.setCurrentTimeMillis(400L)
501         underTest.logChange(prefix = "", columnName = "first", value = false, isInitial = false)
502         systemClock.setCurrentTimeMillis(500L)
503         underTest.logChange(prefix = "", columnName = "third", value = 33, isInitial = true)
504 
505         val dumpedString = dumpChanges()
506 
507         val expected1 =
508             TABLE_LOG_DATE_FORMAT.format(100L) +
509                 SEPARATOR +
510                 "first" +
511                 SEPARATOR +
512                 IS_INITIAL_PREFIX +
513                 "val1"
514         val expected2 =
515             TABLE_LOG_DATE_FORMAT.format(200L) +
516                 SEPARATOR +
517                 "second" +
518                 SEPARATOR +
519                 IS_INITIAL_PREFIX +
520                 "val2"
521         val expected3 = TABLE_LOG_DATE_FORMAT.format(300L) + SEPARATOR + "first" + SEPARATOR + "11"
522         val expected4 =
523             TABLE_LOG_DATE_FORMAT.format(400L) + SEPARATOR + "first" + SEPARATOR + "false"
524         val expected5 =
525             TABLE_LOG_DATE_FORMAT.format(500L) +
526                 SEPARATOR +
527                 "third" +
528                 SEPARATOR +
529                 IS_INITIAL_PREFIX +
530                 "33"
531         assertThat(dumpedString).contains(expected1)
532         assertThat(dumpedString).contains(expected2)
533         assertThat(dumpedString).contains(expected3)
534         assertThat(dumpedString).contains(expected4)
535         assertThat(dumpedString).contains(expected5)
536     }
537 
538     @Test
539     fun logChangeAndLogDiffs_bothLogged() {
540         systemClock.setCurrentTimeMillis(100L)
541 
542         underTest.logChange("") { row ->
543             row.logChange("column1", "val1")
544             row.logChange("column2", 2)
545             row.logChange("column3", true)
546         }
547 
548         systemClock.setCurrentTimeMillis(200L)
549         val prevDiffable = object : TestDiffable() {}
550         val nextDiffable =
551             object : TestDiffable() {
552                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
553                     row.logChange("column1", "newVal1")
554                     row.logChange("column2", 222)
555                     row.logChange("column3", false)
556                 }
557             }
558 
559         underTest.logDiffs(columnPrefix = "", prevDiffable, nextDiffable)
560 
561         val dumpedString = dumpChanges()
562 
563         val timestamp1 = TABLE_LOG_DATE_FORMAT.format(100L)
564         val expected1 = timestamp1 + SEPARATOR + "column1" + SEPARATOR + "val1"
565         val expected2 = timestamp1 + SEPARATOR + "column2" + SEPARATOR + "2"
566         val expected3 = timestamp1 + SEPARATOR + "column3" + SEPARATOR + "true"
567         val timestamp2 = TABLE_LOG_DATE_FORMAT.format(200L)
568         val expected4 = timestamp2 + SEPARATOR + "column1" + SEPARATOR + "newVal1"
569         val expected5 = timestamp2 + SEPARATOR + "column2" + SEPARATOR + "222"
570         val expected6 = timestamp2 + SEPARATOR + "column3" + SEPARATOR + "false"
571         assertThat(dumpedString).contains(expected1)
572         assertThat(dumpedString).contains(expected2)
573         assertThat(dumpedString).contains(expected3)
574         assertThat(dumpedString).contains(expected4)
575         assertThat(dumpedString).contains(expected5)
576         assertThat(dumpedString).contains(expected6)
577     }
578 
579     @Test
580     fun dumpChanges_tooLongColumnPrefix_viaLogChange_truncated() {
581         underTest.logChange(
582             prefix = "P".repeat(MAX_STRING_LENGTH + 10),
583             columnName = "name",
584             value = true,
585         )
586 
587         val dumpedString = dumpChanges()
588 
589         assertThat(dumpedString).contains("P".repeat(MAX_STRING_LENGTH))
590         assertThat(dumpedString).doesNotContain("P".repeat(MAX_STRING_LENGTH + 1))
591     }
592 
593     @Test
594     fun dumpChanges_tooLongColumnPrefix_viaLogDiffs_truncated() {
595         val prevDiffable = object : TestDiffable() {}
596         val nextDiffable =
597             object : TestDiffable() {
598                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
599                     row.logChange("status", "value")
600                 }
601             }
602 
603         // WHEN the column prefix is too large
604         underTest.logDiffs(
605             columnPrefix = "P".repeat(MAX_STRING_LENGTH + 10),
606             prevDiffable,
607             nextDiffable,
608         )
609 
610         val dumpedString = dumpChanges()
611 
612         // THEN it's truncated to the max length
613         assertThat(dumpedString).contains("P".repeat(MAX_STRING_LENGTH))
614         assertThat(dumpedString).doesNotContain("P".repeat(MAX_STRING_LENGTH + 1))
615     }
616 
617     @Test
618     fun dumpChanges_tooLongColumnName_viaLogChange_truncated() {
619         underTest.logChange(
620             prefix = "prefix",
621             columnName = "N".repeat(MAX_STRING_LENGTH + 10),
622             value = 10,
623         )
624 
625         val dumpedString = dumpChanges()
626 
627         assertThat(dumpedString).contains("N".repeat(MAX_STRING_LENGTH))
628         assertThat(dumpedString).doesNotContain("N".repeat(MAX_STRING_LENGTH + 1))
629     }
630 
631     @Test
632     fun dumpChanges_tooLongColumnName_viaLogDiffs_truncated() {
633         val prevDiffable = object : TestDiffable() {}
634         val nextDiffable =
635             object : TestDiffable() {
636                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
637                     // WHEN the column name is too large
638                     row.logChange(columnName = "N".repeat(MAX_STRING_LENGTH + 10), "value")
639                 }
640             }
641 
642         underTest.logDiffs(columnPrefix = "prefix", prevDiffable, nextDiffable)
643 
644         val dumpedString = dumpChanges()
645 
646         // THEN it's truncated to the max length
647         assertThat(dumpedString).contains("N".repeat(MAX_STRING_LENGTH))
648         assertThat(dumpedString).doesNotContain("N".repeat(MAX_STRING_LENGTH + 1))
649     }
650 
651     @Test
652     fun dumpChanges_tooLongValue_viaLogChange_truncated() {
653         underTest.logChange(
654             prefix = "prefix",
655             columnName = "name",
656             value = "V".repeat(MAX_STRING_LENGTH + 10),
657         )
658 
659         val dumpedString = dumpChanges()
660 
661         assertThat(dumpedString).contains("V".repeat(MAX_STRING_LENGTH))
662         assertThat(dumpedString).doesNotContain("V".repeat(MAX_STRING_LENGTH + 1))
663     }
664 
665     @Test
666     fun dumpChanges_tooLongValue_viaLogDiffs_truncated() {
667         val prevDiffable = object : TestDiffable() {}
668         val nextDiffable =
669             object : TestDiffable() {
670                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
671                     // WHEN the value is too large
672                     row.logChange("columnName", value = "V".repeat(MAX_STRING_LENGTH + 10))
673                 }
674             }
675 
676         underTest.logDiffs(columnPrefix = "prefix", prevDiffable, nextDiffable)
677 
678         val dumpedString = dumpChanges()
679 
680         // THEN it's truncated to the max length
681         assertThat(dumpedString).contains("V".repeat(MAX_STRING_LENGTH))
682         assertThat(dumpedString).doesNotContain("V".repeat(MAX_STRING_LENGTH + 1))
683     }
684 
685     @Test
686     fun dumpChanges_rotatesIfBufferIsFull() {
687         lateinit var valToDump: String
688 
689         val prevDiffable = object : TestDiffable() {}
690         val nextDiffable =
691             object : TestDiffable() {
692                 override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {
693                     row.logChange("status", valToDump)
694                 }
695             }
696 
697         for (i in 0 until MAX_SIZE + 3) {
698             valToDump = "testString[$i]"
699             underTest.logDiffs(columnPrefix = "", prevDiffable, nextDiffable)
700         }
701 
702         val dumpedString = dumpChanges()
703 
704         assertThat(dumpedString).doesNotContain("testString[0]")
705         assertThat(dumpedString).doesNotContain("testString[1]")
706         // The buffer should contain [MAX_SIZE + 1] entries since we also save the most recently
707         // evicted value.
708         assertThat(dumpedString).contains("testString[2]")
709         assertThat(dumpedString).contains("testString[3]")
710         assertThat(dumpedString).contains("testString[${MAX_SIZE + 2}]")
711     }
712 
713     @Test
714     fun columnEvicted_lastKnownColumnValueInDump() {
715         systemClock.setCurrentTimeMillis(100L)
716         underTest.logChange(prefix = "", columnName = "willBeEvicted", value = "evictedValue")
717 
718         // Exactly fill the buffer so that "willBeEvicted" is evicted
719         for (i in 0 until MAX_SIZE) {
720             systemClock.advanceTime(100L)
721             val dumpString = "fillString[$i]"
722             underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
723         }
724 
725         val dumpedString = dumpChanges()
726 
727         // Expect that we'll have both the evicted column entry...
728         val evictedColumnLog =
729             TABLE_LOG_DATE_FORMAT.format(100L) +
730                 SEPARATOR +
731                 "willBeEvicted" +
732                 SEPARATOR +
733                 "evictedValue"
734         assertThat(dumpedString).contains(evictedColumnLog)
735 
736         // ... *and* all of the fillingColumn entries.
737         val firstFillingColumnLog =
738             TABLE_LOG_DATE_FORMAT.format(200L) +
739                 SEPARATOR +
740                 "fillingColumn" +
741                 SEPARATOR +
742                 "fillString[0]"
743         val lastFillingColumnLog =
744             TABLE_LOG_DATE_FORMAT.format(1100L) +
745                 SEPARATOR +
746                 "fillingColumn" +
747                 SEPARATOR +
748                 "fillString[9]"
749         assertThat(dumpedString).contains(firstFillingColumnLog)
750         assertThat(dumpedString).contains(lastFillingColumnLog)
751     }
752 
753     @Test
754     fun multipleColumnsEvicted_allColumnsInDump() {
755         systemClock.setCurrentTimeMillis(100L)
756         underTest.logChange(prefix = "", columnName = "willBeEvictedString", value = "evictedValue")
757         systemClock.advanceTime(100L)
758         underTest.logChange(prefix = "", columnName = "willBeEvictedInt", value = 45)
759         systemClock.advanceTime(100L)
760         underTest.logChange(prefix = "", columnName = "willBeEvictedBool", value = true)
761 
762         // Exactly fill the buffer so that all the above columns will be evicted
763         for (i in 0 until MAX_SIZE) {
764             systemClock.advanceTime(100L)
765             val dumpString = "fillString[$i]"
766             underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
767         }
768 
769         val dumpedString = dumpChanges()
770 
771         // Expect that we'll have all the evicted column entries...
772         val evictedColumnLogString =
773             TABLE_LOG_DATE_FORMAT.format(100L) +
774                 SEPARATOR +
775                 "willBeEvictedString" +
776                 SEPARATOR +
777                 "evictedValue"
778         val evictedColumnLogInt =
779             TABLE_LOG_DATE_FORMAT.format(200L) + SEPARATOR + "willBeEvictedInt" + SEPARATOR + "45"
780         val evictedColumnLogBool =
781             TABLE_LOG_DATE_FORMAT.format(300L) +
782                 SEPARATOR +
783                 "willBeEvictedBool" +
784                 SEPARATOR +
785                 "true"
786         assertThat(dumpedString).contains(evictedColumnLogString)
787         assertThat(dumpedString).contains(evictedColumnLogInt)
788         assertThat(dumpedString).contains(evictedColumnLogBool)
789 
790         // ... *and* all of the fillingColumn entries.
791         val firstFillingColumnLog =
792             TABLE_LOG_DATE_FORMAT.format(400) +
793                 SEPARATOR +
794                 "fillingColumn" +
795                 SEPARATOR +
796                 "fillString[0]"
797         val lastFillingColumnLog =
798             TABLE_LOG_DATE_FORMAT.format(1300) +
799                 SEPARATOR +
800                 "fillingColumn" +
801                 SEPARATOR +
802                 "fillString[9]"
803         assertThat(dumpedString).contains(firstFillingColumnLog)
804         assertThat(dumpedString).contains(lastFillingColumnLog)
805     }
806 
807     @Test
808     fun multipleColumnsEvicted_differentPrefixSameName_allColumnsInDump() {
809         systemClock.setCurrentTimeMillis(100L)
810         underTest.logChange(prefix = "prefix1", columnName = "sameName", value = "value1")
811         systemClock.advanceTime(100L)
812         underTest.logChange(prefix = "prefix2", columnName = "sameName", value = "value2")
813         systemClock.advanceTime(100L)
814         underTest.logChange(prefix = "prefix3", columnName = "sameName", value = "value3")
815 
816         // Exactly fill the buffer so that all the above columns will be evicted
817         for (i in 0 until MAX_SIZE) {
818             systemClock.advanceTime(100L)
819             val dumpString = "fillString[$i]"
820             underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
821         }
822 
823         val dumpedString = dumpChanges()
824 
825         // Expect that we'll have all the evicted column entries
826         val evictedColumn1 =
827             TABLE_LOG_DATE_FORMAT.format(100L) +
828                 SEPARATOR +
829                 "prefix1.sameName" +
830                 SEPARATOR +
831                 "value1"
832         val evictedColumn2 =
833             TABLE_LOG_DATE_FORMAT.format(200L) +
834                 SEPARATOR +
835                 "prefix2.sameName" +
836                 SEPARATOR +
837                 "value2"
838         val evictedColumn3 =
839             TABLE_LOG_DATE_FORMAT.format(300L) +
840                 SEPARATOR +
841                 "prefix3.sameName" +
842                 SEPARATOR +
843                 "value3"
844         assertThat(dumpedString).contains(evictedColumn1)
845         assertThat(dumpedString).contains(evictedColumn2)
846         assertThat(dumpedString).contains(evictedColumn3)
847     }
848 
849     @Test
850     fun multipleColumnsEvicted_dumpSortedByTimestamp() {
851         systemClock.setCurrentTimeMillis(100L)
852         underTest.logChange(prefix = "", columnName = "willBeEvictedFirst", value = "evictedValue")
853         systemClock.advanceTime(100L)
854         underTest.logChange(prefix = "", columnName = "willBeEvictedSecond", value = 45)
855         systemClock.advanceTime(100L)
856         underTest.logChange(prefix = "", columnName = "willBeEvictedThird", value = true)
857 
858         // Exactly fill the buffer with so that all the above columns will be evicted
859         for (i in 0 until MAX_SIZE) {
860             systemClock.advanceTime(100L)
861             val dumpString = "fillString[$i]"
862             underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
863         }
864 
865         val dumpedString = dumpChanges()
866 
867         // Expect that we'll have all the evicted column entries in timestamp order
868         val firstEvictedLog =
869             TABLE_LOG_DATE_FORMAT.format(100L) +
870                 SEPARATOR +
871                 "willBeEvictedFirst" +
872                 SEPARATOR +
873                 "evictedValue"
874         val secondEvictedLog =
875             TABLE_LOG_DATE_FORMAT.format(200L) +
876                 SEPARATOR +
877                 "willBeEvictedSecond" +
878                 SEPARATOR +
879                 "45"
880         val thirdEvictedLog =
881             TABLE_LOG_DATE_FORMAT.format(300L) +
882                 SEPARATOR +
883                 "willBeEvictedThird" +
884                 SEPARATOR +
885                 "true"
886         assertThat(dumpedString).contains(firstEvictedLog)
887         val stringAfterFirst = dumpedString.substringAfter(firstEvictedLog)
888         assertThat(stringAfterFirst).contains(secondEvictedLog)
889         val stringAfterSecond = stringAfterFirst.substringAfter(secondEvictedLog)
890         assertThat(stringAfterSecond).contains(thirdEvictedLog)
891     }
892 
893     @Test
894     fun sameColumnEvictedMultipleTimes_onlyLastEvictionInDump() {
895         systemClock.setCurrentTimeMillis(0L)
896 
897         for (i in 1 until 4) {
898             systemClock.advanceTime(100L)
899             val dumpString = "evicted[$i]"
900             underTest.logChange(prefix = "", columnName = "evictedColumn", value = dumpString)
901         }
902 
903         // Exactly fill the buffer so that all the entries for "evictedColumn" will be evicted.
904         for (i in 0 until MAX_SIZE) {
905             systemClock.advanceTime(100L)
906             val dumpString = "fillString[$i]"
907             underTest.logChange(prefix = "", columnName = "fillingColumn", value = dumpString)
908         }
909 
910         val dumpedString = dumpChanges()
911 
912         // Expect that we only have the most recent evicted column entry
913         val evictedColumnLog1 =
914             TABLE_LOG_DATE_FORMAT.format(100L) +
915                 SEPARATOR +
916                 "evictedColumn" +
917                 SEPARATOR +
918                 "evicted[1]"
919         val evictedColumnLog2 =
920             TABLE_LOG_DATE_FORMAT.format(200L) +
921                 SEPARATOR +
922                 "evictedColumn" +
923                 SEPARATOR +
924                 "evicted[2]"
925         val evictedColumnLog3 =
926             TABLE_LOG_DATE_FORMAT.format(300L) +
927                 SEPARATOR +
928                 "evictedColumn" +
929                 SEPARATOR +
930                 "evicted[3]"
931         assertThat(dumpedString).doesNotContain(evictedColumnLog1)
932         assertThat(dumpedString).doesNotContain(evictedColumnLog2)
933         assertThat(dumpedString).contains(evictedColumnLog3)
934     }
935 
936     @Test
937     fun logcat_bufferNotLoggable_tagNotLoggable_noEcho() {
938         whenever(logcatEchoTracker.isBufferLoggable(eq(NAME), any())).thenReturn(false)
939         whenever(logcatEchoTracker.isTagLoggable(eq("columnName"), any())).thenReturn(false)
940 
941         underTest.logChange("prefix", "columnName", true)
942 
943         assertThat(localLogcat.logs).isEmpty()
944     }
945 
946     @Test
947     fun logcat_bufferIsLoggable_tagNotLoggable_echoes() {
948         whenever(logcatEchoTracker.isBufferLoggable(eq(NAME), any())).thenReturn(true)
949         whenever(logcatEchoTracker.isTagLoggable(eq("columnName"), any())).thenReturn(false)
950 
951         underTest.logChange("prefix", "columnName", true)
952 
953         assertThat(localLogcat.logs).hasSize(1)
954     }
955 
956     @Test
957     fun logcat_bufferNotLoggable_tagIsLoggable_echoes() {
958         whenever(logcatEchoTracker.isBufferLoggable(eq(NAME), any())).thenReturn(false)
959         whenever(logcatEchoTracker.isTagLoggable(eq("columnName"), any())).thenReturn(true)
960 
961         underTest.logChange("prefix", "columnName", true)
962 
963         assertThat(localLogcat.logs).hasSize(1)
964     }
965 
966     @Test
967     fun logcat_echoesDebugLogs_debugDisabled_noEcho() {
968         // Allow any log other than debug
969         whenever(logcatEchoTracker.isBufferLoggable(eq(NAME), any())).thenAnswer { invocation ->
970             (invocation.getArgument(1) as LogLevel) != LogLevel.DEBUG
971         }
972 
973         underTest.logChange("prefix", "columnName", true)
974 
975         assertThat(localLogcat.logs).isEmpty()
976     }
977 
978     @Test
979     fun logcat_echoesDebugLogs_debugEnabled_echoes() {
980         // Only allow debug logs
981         whenever(logcatEchoTracker.isBufferLoggable(eq(NAME), eq(LogLevel.DEBUG))).thenReturn(true)
982 
983         underTest.logChange("prefix", "columnName", true)
984 
985         assertThat(localLogcat.logs).hasSize(1)
986     }
987 
988     @Test
989     fun logcat_bufferNotLoggable_tagIsLoggable_usesColNameForTagCheck() {
990         systemClock.setCurrentTimeMillis(1000L)
991 
992         val nonLoggingTag = "nonLoggingColName"
993         val loggingTag = "loggingColName"
994 
995         whenever(logcatEchoTracker.isBufferLoggable(eq(NAME), any())).thenReturn(false)
996         whenever(logcatEchoTracker.isTagLoggable(eq(loggingTag), eq(LogLevel.DEBUG)))
997             .thenReturn(true)
998         whenever(logcatEchoTracker.isTagLoggable(eq(nonLoggingTag), eq(LogLevel.DEBUG)))
999             .thenReturn(false)
1000 
1001         underTest.logChange("", nonLoggingTag, true)
1002         underTest.logChange("", loggingTag, true)
1003 
1004         assertThat(localLogcat.logs).hasSize(1)
1005 
1006         val timestamp = TABLE_LOG_DATE_FORMAT.format(1000L)
1007         val expectedMessage = "${timestamp}${SEPARATOR}${loggingTag}${SEPARATOR}true"
1008         val expectedLine = "D $NAME: $expectedMessage"
1009 
1010         assertThat(localLogcat.logs[0]).isEqualTo(expectedLine)
1011     }
1012 
1013     @Test
1014     fun logcat_bufferLoggable_multipleMessagesAreEchoed() {
1015         systemClock.setCurrentTimeMillis(1000L)
1016         whenever(logcatEchoTracker.isBufferLoggable(eq(NAME), any())).thenReturn(true)
1017 
1018         val col1 = "column1"
1019         val col2 = "column2"
1020 
1021         // Log a couple of columns that flip bits
1022         underTest.logChange("", col1, true)
1023         underTest.logChange("", col2, false)
1024         underTest.logChange("", col1, false)
1025         underTest.logChange("", col2, true)
1026 
1027         assertThat(localLogcat.logs).hasSize(4)
1028 
1029         val timestamp = TABLE_LOG_DATE_FORMAT.format(1000L)
1030         val msg1 = "${timestamp}${SEPARATOR}${col1}${SEPARATOR}true"
1031         val msg2 = "${timestamp}${SEPARATOR}${col2}${SEPARATOR}false"
1032         val msg3 = "${timestamp}${SEPARATOR}${col1}${SEPARATOR}false"
1033         val msg4 = "${timestamp}${SEPARATOR}${col2}${SEPARATOR}true"
1034         val expected = listOf(msg1, msg2, msg3, msg4).map { "D $NAME: $it" }
1035 
1036         // Logs use the same bg dispatcher for writing to logcat, they should be in order
1037         for ((msg, logLine) in expected zip localLogcat.logs) {
1038             assertThat(logLine).isEqualTo(msg)
1039         }
1040     }
1041 
1042     private fun dumpChanges(): String {
1043         underTest.dump(PrintWriter(outputWriter), arrayOf())
1044         return outputWriter.toString()
1045     }
1046 
1047     private fun logLines(string: String): List<String> {
1048         return string.split("\n").filter { it.isNotBlank() }
1049     }
1050 
1051     private open class TestDiffable : Diffable<TestDiffable> {
1052         override fun logDiffs(prevVal: TestDiffable, row: TableRowLogger) {}
1053     }
1054 }
1055 
1056 private const val NAME = "TestTableBuffer"
1057 private const val MAX_SIZE = 10
1058 
1059 // Copying these here from [TableLogBuffer] so that we catch any accidental versioning change
1060 private const val HEADER_PREFIX = "SystemUI StateChangeTableSection START: "
1061 private const val FOOTER_PREFIX = "SystemUI StateChangeTableSection END: "
1062 private const val SEPARATOR = "|" // TBD
1063 private const val VERSION = "1"
1064