fix(am): fix parsing of failed test runs

should emit TestRunEnded with time if applicable and attach a shortMsg to the failure reason

adam/src/main/kotlin/com/malinskiy/adam/request/testrunner/transform/InstrumentationResponseTransformer.kt

@@ -228,14 +228,26 @@ class InstrumentationResponseTransformer : ProgressiveResponseTransformer<List<T
             }
             else -> {
                 finishReported = true
-                listOf(TestRunFailed("Unexpected INSTRUMENTATION_CODE: $code"))
+                var shortMessage: String? = null
+                var time = 0L
+                atom.forEach { line ->
+                    when {
+                        line.startsWith("INSTRUMENTATION_RESULT: shortMsg=") -> {
+                            shortMessage = line.substring(33)
+                        }
+                        line.startsWith("Time: ") -> {
+                            time = line.substring(6).toDoubleOrNull()?.times(1000)?.toLong() ?: 0L
+                        }
+                    }
+                }
+                listOf(TestRunFailed(shortMessage ?: "Unexpected INSTRUMENTATION_CODE: $code"), TestRunEnded(time, emptyMap()))
             }
         }
     }
 }
 
-private fun List<String>.toMap(): Map<String, String> {
-    return this.filter { it.isNotEmpty() }.joinToString(separator = "\n").split("INSTRUMENTATION_STATUS: ").mapNotNull {
+private fun List<String>.toMap(delimiter: String = "INSTRUMENTATION_STATUS: "): Map<String, String> {
+    return this.filter { it.isNotEmpty() }.joinToString(separator = "\n").split(delimiter).mapNotNull {
         /**
          * Generally, the stacktrace field will have only a single = sign.
          * But as observed on Sony Xperia D5833, it can contain multiple `=` signs (because stacktrace value is equal to the stream)

adam/src/test/kotlin/com/malinskiy/adam/request/testrunner/transform/InstrumentationResponseTransformerTest.kt

@@ -117,7 +117,7 @@ class InstrumentationResponseTransformerTest {
             transformer.transform()?.let { events.addAll(it) }
 
             assertThat(events.map { it.toString() }.reduce { acc, s -> acc + "\n" + s })
-                .isEqualTo(javaClass.getResourceAsStream("/instrumentation/log_4.expected").reader().readText())
+                .isEqualTo(javaClass.getResourceAsStream("/instrumentation/log_4.expected").reader().readText().trimEnd())
         }
     }
 
@@ -161,7 +161,7 @@ class InstrumentationResponseTransformerTest {
         transformer.transform()?.let { events.addAll(it) }
 
         assertThat(events.map { it.toString() }.reduce { acc, s -> acc + "\n" + s })
-            .isEqualTo(javaClass.getResourceAsStream("/instrumentation/log_6.expected").reader().readText())
+            .isEqualTo(javaClass.getResourceAsStream("/instrumentation/log_6.expected").reader().readText().trimEnd())
     }
 
     @Test
@@ -186,7 +186,7 @@ class InstrumentationResponseTransformerTest {
         transformer.transform()?.let { events.addAll(it) }
 
         assertThat(events.map { it.toString() }.reduce { acc, s -> acc + "\n" + s })
-            .isEqualTo(javaClass.getResourceAsStream("/instrumentation/log_6.expected").reader().readText())
+            .isEqualTo(javaClass.getResourceAsStream("/instrumentation/log_6.expected").reader().readText().trimEnd())
     }
 
     /**
@@ -226,4 +226,20 @@ class InstrumentationResponseTransformerTest {
         assertThat(events.map { it.toString() }.reduce { acc, s -> acc + "\n" + s })
             .isEqualTo(javaClass.getResourceAsStream("/instrumentation/log_7.expected").reader().readText().trimEnd())
     }
+
+    @Test
+    fun testFailureHandling() = runBlocking {
+        val transformer = InstrumentationResponseTransformer()
+        val lines = javaClass.getResourceAsStream("/instrumentation/log_8.input").reader().readText()
+
+        val events = mutableListOf<TestEvent>()
+        val bytes = (lines).toByteArray(Const.DEFAULT_TRANSPORT_ENCODING)
+        transformer.process(bytes, 0, bytes.size)?.let {
+            events.addAll(it)
+        }
+        transformer.transform()?.let { events.addAll(it) }
+
+        assertThat(events.map { it.toString() }.reduce { acc, s -> acc + "\n" + s })
+            .isEqualTo(javaClass.getResourceAsStream("/instrumentation/log_8.expected").reader().readText().trimEnd())
+    }
 }

adam/src/test/resources/instrumentation/log_4.expected

@@ -118,4 +118,4 @@ TestFailed(id=TestIdentifier(className=com.example.MainActivityFlakyTest, testNa
 	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1932))
 TestEnded(id=TestIdentifier(className=com.example.MainActivityFlakyTest, testName=testTextFlaky7), metrics={})
 TestStarted(id=TestIdentifier(className=com.example.MainActivityFlakyTest, testName=testTextFlaky8))
-TestRunFailed(error=Test run failed to complete. Expected 9 tests, executed 8)
+TestRunFailed(error=Test run failed to complete. Expected 9 tests, executed 8)

adam/src/test/resources/instrumentation/log_6.expected

@@ -119,4 +119,5 @@ TestFailed(id=TestIdentifier(className=com.example.MainActivityFlakyTest, testNa
 TestEnded(id=TestIdentifier(className=com.example.MainActivityFlakyTest, testName=testTextFlaky7), metrics={})
 TestStarted(id=TestIdentifier(className=com.example.MainActivityFlakyTest, testName=testTextFlaky8))
 TestEnded(id=TestIdentifier(className=com.example.MainActivityFlakyTest, testName=testTextFlaky8), metrics={})
-TestRunFailed(error=Unexpected INSTRUMENTATION_CODE: 0)
+TestRunFailed(error=Unexpected INSTRUMENTATION_CODE: 0)
+TestRunEnded(elapsedTimeMillis=5832, metrics={})

adam/src/test/resources/instrumentation/log_8.expected

@@ -0,0 +1,30 @@
+TestRunStartedEvent(testCount=9)
+TestStarted(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AddAdvertToFavoritesTest, testName=addAdvertToFavorite))
+TestEnded(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AddAdvertToFavoritesTest, testName=addAdvertToFavorite), metrics={})
+TestStarted(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AdvertDetailsTest, testName=checkHeaderIsShown))
+TestEnded(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AdvertDetailsTest, testName=checkHeaderIsShown), metrics={})
+TestStarted(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AdvertDetailsTest, testName=checkCommentButtonIsShown))
+TestEnded(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AdvertDetailsTest, testName=checkCommentButtonIsShown), metrics={})
+TestStarted(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AdvertDetailsTest, testName=checkUnAuthClickOnMessageButton))
+TestEnded(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AdvertDetailsTest, testName=checkUnAuthClickOnMessageButton), metrics={})
+TestStarted(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AdvertDetailsTest, testName=checkEmptyPhotoViewIsShown))
+TestEnded(id=TestIdentifier(className=kz.kolesa.tests.advertdetails.AdvertDetailsTest, testName=checkEmptyPhotoViewIsShown), metrics={})
+TestStarted(id=TestIdentifier(className=kz.kolesa.tests.report.ReportBugTest, testName=emptyMessageFieldTest))
+TestEnded(id=TestIdentifier(className=kz.kolesa.tests.report.ReportBugTest, testName=emptyMessageFieldTest), metrics={})
+TestStarted(id=TestIdentifier(className=kz.kolesa.tests.report.ReportBugTest, testName=sendReportTest))
+TestEnded(id=TestIdentifier(className=kz.kolesa.tests.report.ReportBugTest, testName=sendReportTest), metrics={})
+TestStarted(id=TestIdentifier(className=kz.kolesa.tests.login.SignInEmptyDataTest, testName=signInWithEmptyPassword[0]))
+TestEnded(id=TestIdentifier(className=kz.kolesa.tests.login.SignInEmptyDataTest, testName=signInWithEmptyPassword[0]), metrics={})
+TestStarted(id=TestIdentifier(className=kz.kolesa.tests.login.SignInEmptyDataTest, testName=signInWithEmptyPassword[1]))
+TestFailed(id=TestIdentifier(className=kz.kolesa.tests.login.SignInEmptyDataTest, testName=signInWithEmptyPassword[1]), stackTrace=java.lang.NullPointerException: Attempt to read from field 'java.lang.Object kz.library.network.model.Response.result' on a null object reference
+        at kz.library.auth.domain.AuthInteractor.login(AuthInteractor.kt:43)
+        at kz.library.auth.presentation.AuthViewModel$onLoginClicked$1$invokeSuspend$$inlined$let$lambda$1.invokeSuspend(AuthViewModel.kt:152)
+        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
+        at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:571)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:738)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:678)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:665))
+TestEnded(id=TestIdentifier(className=kz.kolesa.tests.login.SignInEmptyDataTest, testName=signInWithEmptyPassword[1]), metrics={})
+TestRunFailed(error=Process crashed.)
+TestRunEnded(elapsedTimeMillis=0, metrics={})

adam/src/test/resources/instrumentation/log_8.input

@@ -0,0 +1,151 @@
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AddAdvertToFavoritesTest
+INSTRUMENTATION_STATUS: current=1
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=
+kz.kolesa.tests.advertdetails.AddAdvertToFavoritesTest:
+INSTRUMENTATION_STATUS: test=addAdvertToFavorite
+INSTRUMENTATION_STATUS_CODE: 1
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AddAdvertToFavoritesTest
+INSTRUMENTATION_STATUS: current=1
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=.
+INSTRUMENTATION_STATUS: test=addAdvertToFavorite
+INSTRUMENTATION_STATUS_CODE: 0
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AdvertDetailsTest
+INSTRUMENTATION_STATUS: current=2
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=
+kz.kolesa.tests.advertdetails.AdvertDetailsTest:
+INSTRUMENTATION_STATUS: test=checkHeaderIsShown
+INSTRUMENTATION_STATUS_CODE: 1
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AdvertDetailsTest
+INSTRUMENTATION_STATUS: current=2
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=.
+INSTRUMENTATION_STATUS: test=checkHeaderIsShown
+INSTRUMENTATION_STATUS_CODE: 0
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AdvertDetailsTest
+INSTRUMENTATION_STATUS: current=3
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=
+INSTRUMENTATION_STATUS: test=checkCommentButtonIsShown
+INSTRUMENTATION_STATUS_CODE: 1
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AdvertDetailsTest
+INSTRUMENTATION_STATUS: current=3
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=.
+INSTRUMENTATION_STATUS: test=checkCommentButtonIsShown
+INSTRUMENTATION_STATUS_CODE: 0
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AdvertDetailsTest
+INSTRUMENTATION_STATUS: current=4
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=
+INSTRUMENTATION_STATUS: test=checkUnAuthClickOnMessageButton
+INSTRUMENTATION_STATUS_CODE: 1
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AdvertDetailsTest
+INSTRUMENTATION_STATUS: current=4
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=.
+INSTRUMENTATION_STATUS: test=checkUnAuthClickOnMessageButton
+INSTRUMENTATION_STATUS_CODE: 0
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AdvertDetailsTest
+INSTRUMENTATION_STATUS: current=5
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=
+INSTRUMENTATION_STATUS: test=checkEmptyPhotoViewIsShown
+INSTRUMENTATION_STATUS_CODE: 1
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.advertdetails.AdvertDetailsTest
+INSTRUMENTATION_STATUS: current=5
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=.
+INSTRUMENTATION_STATUS: test=checkEmptyPhotoViewIsShown
+INSTRUMENTATION_STATUS_CODE: 0
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.report.ReportBugTest
+INSTRUMENTATION_STATUS: current=6
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=
+kz.kolesa.tests.report.ReportBugTest:
+INSTRUMENTATION_STATUS: test=emptyMessageFieldTest
+INSTRUMENTATION_STATUS_CODE: 1
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.report.ReportBugTest
+INSTRUMENTATION_STATUS: current=6
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=.
+INSTRUMENTATION_STATUS: test=emptyMessageFieldTest
+INSTRUMENTATION_STATUS_CODE: 0
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.report.ReportBugTest
+INSTRUMENTATION_STATUS: current=7
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=
+INSTRUMENTATION_STATUS: test=sendReportTest
+INSTRUMENTATION_STATUS_CODE: 1
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.report.ReportBugTest
+INSTRUMENTATION_STATUS: current=7
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=.
+INSTRUMENTATION_STATUS: test=sendReportTest
+INSTRUMENTATION_STATUS_CODE: 0
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.login.SignInEmptyDataTest
+INSTRUMENTATION_STATUS: current=8
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=
+kz.kolesa.tests.login.SignInEmptyDataTest:
+INSTRUMENTATION_STATUS: test=signInWithEmptyPassword[0]
+INSTRUMENTATION_STATUS_CODE: 1
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.login.SignInEmptyDataTest
+INSTRUMENTATION_STATUS: current=8
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=.
+INSTRUMENTATION_STATUS: test=signInWithEmptyPassword[0]
+INSTRUMENTATION_STATUS_CODE: 0
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.login.SignInEmptyDataTest
+INSTRUMENTATION_STATUS: current=9
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stream=
+INSTRUMENTATION_STATUS: test=signInWithEmptyPassword[1]
+INSTRUMENTATION_STATUS_CODE: 1
+INSTRUMENTATION_STATUS: class=kz.kolesa.tests.login.SignInEmptyDataTest
+INSTRUMENTATION_STATUS: current=9
+INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
+INSTRUMENTATION_STATUS: numtests=9
+INSTRUMENTATION_STATUS: stack=java.lang.NullPointerException: Attempt to read from field 'java.lang.Object kz.library.network.model.Response.result' on a null object reference
+        at kz.library.auth.domain.AuthInteractor.login(AuthInteractor.kt:43)
+        at kz.library.auth.presentation.AuthViewModel$onLoginClicked$1$invokeSuspend$$inlined$let$lambda$1.invokeSuspend(AuthViewModel.kt:152)
+        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
+        at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:571)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:738)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:678)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:665)
+INSTRUMENTATION_STATUS: stream=
+Process crashed while executing signInWithEmptyPassword[1](kz.kolesa.tests.login.SignInEmptyDataTest):
+java.lang.NullPointerException: Attempt to read from field 'java.lang.Object kz.library.network.model.Response.result' on a null object reference
+        at kz.library.auth.domain.AuthInteractor.login(AuthInteractor.kt:43)
+        at kz.library.auth.presentation.AuthViewModel$onLoginClicked$1$invokeSuspend$$inlined$let$lambda$1.invokeSuspend(AuthViewModel.kt:152)
+        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
+        at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:571)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:738)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:678)
+        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:665)
+INSTRUMENTATION_STATUS: test=signInWithEmptyPassword[1]
+INSTRUMENTATION_STATUS_CODE: -2
+INSTRUMENTATION_RESULT: shortMsg=Process crashed.
+INSTRUMENTATION_CODE: 0