From 20801e109cafb616a59fa6d5507b0a040a3534d5 Mon Sep 17 00:00:00 2001 From: Jared Burrows Date: Mon, 4 Nov 2024 03:04:30 -0500 Subject: [PATCH] Add Conditional Extraction of ApplicationExitInfo Trace Data for Enhanced Logging from getTraceInputStream --- .../capture/events/lifecycle/AppExitLogger.kt | 48 ++- .../io/bitdrift/capture/AppExitLoggerTest.kt | 285 ++++++++++++++++++ 2 files changed, 321 insertions(+), 12 deletions(-) diff --git a/platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/events/lifecycle/AppExitLogger.kt b/platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/events/lifecycle/AppExitLogger.kt index b32d4ec8..cf7f9e50 100644 --- a/platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/events/lifecycle/AppExitLogger.kt +++ b/platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/events/lifecycle/AppExitLogger.kt @@ -25,6 +25,7 @@ import io.bitdrift.capture.providers.toFields import io.bitdrift.capture.utils.BuildVersionChecker import java.lang.reflect.InvocationTargetException import java.nio.charset.StandardCharsets +import java.util.Base64 internal class AppExitLogger( private val logger: LoggerImpl, @@ -140,18 +141,41 @@ internal class AppExitLogger( @TargetApi(Build.VERSION_CODES.R) private fun ApplicationExitInfo.toFields(): InternalFieldsMap { - // https://developer.android.com/reference/kotlin/android/app/ApplicationExitInfo - return mapOf( - "_app_exit_source" to "ApplicationExitInfo", - "_app_exit_process_name" to this.processName, - "_app_exit_reason" to this.reason.toReasonText(), - "_app_exit_importance" to this.importance.toImportanceText(), - "_app_exit_status" to this.status.toString(), - "_app_exit_pss" to this.pss.toString(), - "_app_exit_rss" to this.rss.toString(), - "_app_exit_description" to this.description.orEmpty(), - // TODO(murki): Extract getTraceInputStream() for REASON_ANR or REASON_CRASH_NATIVE - ).toFields() + // Initialize the fields map with basic application exit information + return buildMap { + put("_app_exit_source", "ApplicationExitInfo") + put("_app_exit_process_name", processName) + put("_app_exit_reason", reason.toReasonText()) + put("_app_exit_importance", importance.toImportanceText()) + put("_app_exit_status", status.toString()) + put("_app_exit_pss", pss.toString()) + put("_app_exit_rss", rss.toString()) + put("_app_exit_description", description.orEmpty()) + + // Add trace data as binary if available for REASON_ANR or REASON_CRASH_NATIVE + if (reason == ApplicationExitInfo.REASON_ANR || reason == ApplicationExitInfo.REASON_CRASH_NATIVE) { + runCatching { + getTraceInputStream()?.takeIf { it.available() > 0 }?.use { traceStream -> + traceStream.readBytes().takeIf { it.isNotEmpty() } + } + }.onSuccess { traceData -> + // TODO(jaredsburrows): Add a way to decode this on the backend + // See https://developer.android.com/ndk/guides/debug#tombstone-traces + traceData?.let { put("_app_exit_trace", Base64.getEncoder().encodeToString(it)) } + }.onFailure { e -> + // Log or handle the exception as needed + logger.log( + LogType.LIFECYCLE, + LogLevel.ERROR, + mapOf( + "_app_exit_source" to "ApplicationExitInfo", + "_app_exit_reason" to "TraceReadFailure", + "_app_exit_details" to e.message.orEmpty(), + ).toFields(), + ) { APP_EXIT_EVENT_NAME } + } + } + }.toFields() } private fun Int.toReasonText(): String { diff --git a/platform/jvm/capture/src/test/kotlin/io/bitdrift/capture/AppExitLoggerTest.kt b/platform/jvm/capture/src/test/kotlin/io/bitdrift/capture/AppExitLoggerTest.kt index 2cedde83..3acc2f7d 100644 --- a/platform/jvm/capture/src/test/kotlin/io/bitdrift/capture/AppExitLoggerTest.kt +++ b/platform/jvm/capture/src/test/kotlin/io/bitdrift/capture/AppExitLoggerTest.kt @@ -29,8 +29,10 @@ import org.junit.Test import org.mockito.ArgumentMatchers.anyInt import org.mockito.Mockito import org.mockito.Mockito.RETURNS_DEEP_STUBS +import java.io.ByteArrayInputStream import java.io.IOException import java.nio.charset.StandardCharsets +import java.util.Base64 class AppExitLoggerTest { private val logger: LoggerImpl = mock() @@ -168,6 +170,289 @@ class AppExitLoggerTest { ) } + @Test + fun testLogPreviousExitReasonIfAnyWithTrace() { + // ARRANGE + val sessionId = "test-session-id" + val timestamp = 123L + val traceData = "Test trace data" + val base64TraceData = Base64.getEncoder().encodeToString(traceData.toByteArray()) // Encode expected data + + val mockExitInfo = mock(defaultAnswer = RETURNS_DEEP_STUBS) + whenever(mockExitInfo.processStateSummary).thenReturn(sessionId.toByteArray(StandardCharsets.UTF_8)) + whenever(mockExitInfo.timestamp).thenReturn(timestamp) + whenever(mockExitInfo.processName).thenReturn("test-process-name") + whenever(mockExitInfo.reason).thenReturn(ApplicationExitInfo.REASON_ANR) + whenever(mockExitInfo.importance).thenReturn(RunningAppProcessInfo.IMPORTANCE_FOREGROUND) + whenever(mockExitInfo.status).thenReturn(0) + whenever(mockExitInfo.pss).thenReturn(1) + whenever(mockExitInfo.rss).thenReturn(2) + whenever(mockExitInfo.description).thenReturn("test-description") + whenever(mockExitInfo.getTraceInputStream()).thenReturn(ByteArrayInputStream(traceData.toByteArray())) + + whenever(activityManager.getHistoricalProcessExitReasons(anyOrNull(), any(), any())).thenReturn(listOf(mockExitInfo)) + + // ACT + appExitLogger.logPreviousExitReasonIfAny() + + // ASSERT + val expectedFields = mapOf( + "_app_exit_source" to "ApplicationExitInfo", + "_app_exit_process_name" to "test-process-name", + "_app_exit_reason" to "ANR", + "_app_exit_importance" to "FOREGROUND", + "_app_exit_status" to "0", + "_app_exit_pss" to "1", + "_app_exit_rss" to "2", + "_app_exit_description" to "test-description", + "_app_exit_trace" to base64TraceData, // Use the Base64 encoded expected value + ).toFields() + + verify(logger).log( + eq(LogType.LIFECYCLE), + eq(LogLevel.ERROR), + eq(expectedFields), + eq(null), + eq(LogAttributesOverrides(sessionId, timestamp)), + eq(false), + argThat { i: () -> String -> i.invoke() == "AppExit" }, + ) + } + + @Test + fun testLogPreviousExitReasonIfAnyWithoutTrace() { + // ARRANGE + val sessionId = "test-session-id" + val timestamp = 123L + + val mockExitInfo = mock(defaultAnswer = RETURNS_DEEP_STUBS) + whenever(mockExitInfo.processStateSummary).thenReturn(sessionId.toByteArray(StandardCharsets.UTF_8)) + whenever(mockExitInfo.timestamp).thenReturn(timestamp) + whenever(mockExitInfo.processName).thenReturn("test-process-name") + whenever(mockExitInfo.reason).thenReturn(ApplicationExitInfo.REASON_ANR) + whenever(mockExitInfo.importance).thenReturn(RunningAppProcessInfo.IMPORTANCE_FOREGROUND) + whenever(mockExitInfo.status).thenReturn(0) + whenever(mockExitInfo.pss).thenReturn(1) + whenever(mockExitInfo.rss).thenReturn(2) + whenever(mockExitInfo.description).thenReturn("test-description") + whenever(mockExitInfo.getTraceInputStream()).thenReturn(null) // Simulate no trace data available + + whenever(activityManager.getHistoricalProcessExitReasons(anyOrNull(), any(), any())).thenReturn(listOf(mockExitInfo)) + + // ACT + appExitLogger.logPreviousExitReasonIfAny() + + // ASSERT + val expectedFields = mapOf( + "_app_exit_source" to "ApplicationExitInfo", + "_app_exit_process_name" to "test-process-name", + "_app_exit_reason" to "ANR", + "_app_exit_importance" to "FOREGROUND", + "_app_exit_status" to "0", + "_app_exit_pss" to "1", + "_app_exit_rss" to "2", + "_app_exit_description" to "test-description", + // _app_exit_trace is not present + ).toFields() + + verify(logger).log( + eq(LogType.LIFECYCLE), + eq(LogLevel.ERROR), + eq(expectedFields), + eq(null), + eq(LogAttributesOverrides(sessionId, timestamp)), + eq(false), + argThat { i: () -> String -> i.invoke() == "AppExit" }, + ) + } + + @Test + fun testLogPreviousExitReasonIfAnyWithEmptyTrace() { + // ARRANGE + val sessionId = "test-session-id" + val timestamp = 123L + val emptyTraceData = ByteArray(0) + + val mockExitInfo = mock(defaultAnswer = RETURNS_DEEP_STUBS) + whenever(mockExitInfo.processStateSummary).thenReturn(sessionId.toByteArray(StandardCharsets.UTF_8)) + whenever(mockExitInfo.timestamp).thenReturn(timestamp) + whenever(mockExitInfo.processName).thenReturn("test-process-name") + whenever(mockExitInfo.reason).thenReturn(ApplicationExitInfo.REASON_ANR) + whenever(mockExitInfo.importance).thenReturn(RunningAppProcessInfo.IMPORTANCE_FOREGROUND) + whenever(mockExitInfo.status).thenReturn(0) + whenever(mockExitInfo.pss).thenReturn(1) + whenever(mockExitInfo.rss).thenReturn(2) + whenever(mockExitInfo.description).thenReturn("test-description") + whenever(mockExitInfo.getTraceInputStream()).thenReturn(ByteArrayInputStream(emptyTraceData)) + + whenever(activityManager.getHistoricalProcessExitReasons(anyOrNull(), any(), any())).thenReturn(listOf(mockExitInfo)) + + // ACT + appExitLogger.logPreviousExitReasonIfAny() + + // ASSERT + val expectedFields = mapOf( + "_app_exit_source" to "ApplicationExitInfo", + "_app_exit_process_name" to "test-process-name", + "_app_exit_reason" to "ANR", + "_app_exit_importance" to "FOREGROUND", + "_app_exit_status" to "0", + "_app_exit_pss" to "1", + "_app_exit_rss" to "2", + "_app_exit_description" to "test-description", + // _app_exit_trace is not present since trace data is empty + ).toFields() + + verify(logger).log( + eq(LogType.LIFECYCLE), + eq(LogLevel.ERROR), + eq(expectedFields), + eq(null), + eq(LogAttributesOverrides(sessionId, timestamp)), + eq(false), + argThat { i: () -> String -> i.invoke() == "AppExit" }, + ) + } + + @Test + fun testLogPreviousExitReasonIfAnyWithBinaryTrace() { + // ARRANGE + val sessionId = "test-session-id" + val timestamp = 123L + val traceData = "Binary trace data".toByteArray() + val base64TraceData = Base64.getEncoder().encodeToString(traceData) + + val mockExitInfo = mock(defaultAnswer = RETURNS_DEEP_STUBS) + whenever(mockExitInfo.processStateSummary).thenReturn(sessionId.toByteArray(StandardCharsets.UTF_8)) + whenever(mockExitInfo.timestamp).thenReturn(timestamp) + whenever(mockExitInfo.processName).thenReturn("test-process-name") + whenever(mockExitInfo.reason).thenReturn(ApplicationExitInfo.REASON_ANR) + whenever(mockExitInfo.importance).thenReturn(RunningAppProcessInfo.IMPORTANCE_FOREGROUND) + whenever(mockExitInfo.status).thenReturn(0) + whenever(mockExitInfo.pss).thenReturn(1) + whenever(mockExitInfo.rss).thenReturn(2) + whenever(mockExitInfo.description).thenReturn("test-description") + whenever(mockExitInfo.getTraceInputStream()).thenReturn(ByteArrayInputStream(traceData)) + + whenever(activityManager.getHistoricalProcessExitReasons(anyOrNull(), any(), any())).thenReturn(listOf(mockExitInfo)) + + // ACT + appExitLogger.logPreviousExitReasonIfAny() + + // ASSERT + val expectedFields = mapOf( + "_app_exit_source" to "ApplicationExitInfo", + "_app_exit_process_name" to "test-process-name", + "_app_exit_reason" to "ANR", + "_app_exit_importance" to "FOREGROUND", + "_app_exit_status" to "0", + "_app_exit_pss" to "1", + "_app_exit_rss" to "2", + "_app_exit_description" to "test-description", + "_app_exit_trace" to base64TraceData, + ).toFields() + + verify(logger).log( + eq(LogType.LIFECYCLE), + eq(LogLevel.ERROR), + eq(expectedFields), + eq(null), + eq(LogAttributesOverrides(sessionId, timestamp)), + eq(false), + argThat { i: () -> String -> i.invoke() == "AppExit" }, + ) + } + + @Test + fun testLogPreviousExitReasonIfAnyWithIOException() { + // ARRANGE + val sessionId = "test-session-id" + val timestamp = 123L + val ioException = IOException("Test IO exception") + + val mockExitInfo = mock(defaultAnswer = RETURNS_DEEP_STUBS) + whenever(mockExitInfo.processStateSummary).thenReturn(sessionId.toByteArray(StandardCharsets.UTF_8)) + whenever(mockExitInfo.timestamp).thenReturn(timestamp) + whenever(mockExitInfo.processName).thenReturn("test-process-name") + whenever(mockExitInfo.reason).thenReturn(ApplicationExitInfo.REASON_ANR) + whenever(mockExitInfo.importance).thenReturn(RunningAppProcessInfo.IMPORTANCE_FOREGROUND) + whenever(mockExitInfo.status).thenReturn(0) + whenever(mockExitInfo.pss).thenReturn(1) + whenever(mockExitInfo.rss).thenReturn(2) + whenever(mockExitInfo.description).thenReturn("test-description") + + // Simulate an IOException when accessing the trace input stream + whenever(mockExitInfo.getTraceInputStream()).thenThrow(ioException) + + whenever(activityManager.getHistoricalProcessExitReasons(anyOrNull(), any(), any())).thenReturn(listOf(mockExitInfo)) + + // ACT + appExitLogger.logPreviousExitReasonIfAny() + + // ASSERT + val errorFields = mapOf( + "_app_exit_source" to "ApplicationExitInfo", + "_app_exit_reason" to "TraceReadFailure", + "_app_exit_details" to ioException.message.orEmpty(), + ).toFields() + + verify(logger).log( + eq(LogType.LIFECYCLE), + eq(LogLevel.ERROR), + eq(errorFields), + eq(null), + eq(null), + eq(false), + argThat { i: () -> String -> i.invoke() == "AppExit" }, + ) + } + + @Test + fun testLogPreviousExitReasonIfAnyWithNonRelevantReason() { + // ARRANGE + val sessionId = "test-session-id" + val timestamp = 123L + + val mockExitInfo = mock(defaultAnswer = RETURNS_DEEP_STUBS) + whenever(mockExitInfo.processStateSummary).thenReturn(sessionId.toByteArray(StandardCharsets.UTF_8)) + whenever(mockExitInfo.timestamp).thenReturn(timestamp) + whenever(mockExitInfo.processName).thenReturn("test-process-name") + whenever(mockExitInfo.reason).thenReturn(ApplicationExitInfo.REASON_EXIT_SELF) // Non-relevant reason + whenever(mockExitInfo.importance).thenReturn(RunningAppProcessInfo.IMPORTANCE_FOREGROUND) + whenever(mockExitInfo.status).thenReturn(0) + whenever(mockExitInfo.pss).thenReturn(1) + whenever(mockExitInfo.rss).thenReturn(2) + whenever(mockExitInfo.description).thenReturn("test-description") + + whenever(activityManager.getHistoricalProcessExitReasons(anyOrNull(), any(), any())).thenReturn(listOf(mockExitInfo)) + + // ACT + appExitLogger.logPreviousExitReasonIfAny() + + // ASSERT + val expectedFields = mapOf( + "_app_exit_source" to "ApplicationExitInfo", + "_app_exit_process_name" to "test-process-name", + "_app_exit_reason" to "EXIT_SELF", + "_app_exit_importance" to "FOREGROUND", + "_app_exit_status" to "0", + "_app_exit_pss" to "1", + "_app_exit_rss" to "2", + "_app_exit_description" to "test-description", + // _app_exit_trace is not present since reason is not REASON_ANR or REASON_CRASH_NATIVE + ).toFields() + + verify(logger).log( + eq(LogType.LIFECYCLE), + eq(LogLevel.INFO), // Use INFO instead of ERROR + eq(expectedFields), + eq(null), + eq(LogAttributesOverrides(sessionId, timestamp)), + eq(false), + argThat { i: () -> String -> i.invoke() == "AppExit" }, + ) + } + @Test fun testLogPreviousExitReasonIfAnyReportsError() { // ARRANGE