Skip to content

Commit

Permalink
Add Conditional Extraction of ApplicationExitInfo Trace Data for Enha…
Browse files Browse the repository at this point in the history 
…nced Logging from getTraceInputStream
  • Loading branch information
@jaredsburrows
jaredsburrows committed Nov 5, 2024
1 parent 1c77b4a commit 20801e1
Show file tree
Hide file tree
Showing 2 changed files with 321 additions and 12 deletions.
48 changes: 36 additions & 12 deletions platform/jvm/capture/src/main/kotlin/io/bitdrift/capture/events/lifecycle/AppExitLogger.kt
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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 {
Expand Down
285 changes: 285 additions & 0 deletions platform/jvm/capture/src/test/kotlin/io/bitdrift/capture/AppExitLoggerTest.kt
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand Down Expand Up @@ -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<ApplicationExitInfo>(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<ApplicationExitInfo>(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<ApplicationExitInfo>(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<ApplicationExitInfo>(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<ApplicationExitInfo>(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<ApplicationExitInfo>(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
Expand Down

0 comments on commit 20801e1

Please sign in to comment.