-
Notifications
You must be signed in to change notification settings - Fork 11
Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
Add component that adds traces to track app launches (#500)
## Goal POC of a component that takes in some event times to produce startup traces when requested, along with an activity lifecycle callback listener that feeds it the appropriate startup events. ## Testing Added basic testing to verify that core functionality
- Loading branch information
1 parent
e10ad04
commit 648acf6
Showing
6 changed files
with
899 additions
and
0 deletions.
There are no files selected for viewing
320 changes: 320 additions & 0 deletions
320
...sdk/src/main/java/io/embrace/android/embracesdk/capture/startup/AppStartupTraceEmitter.kt
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,320 @@ | ||
package io.embrace.android.embracesdk.capture.startup | ||
|
||
import android.os.Build.VERSION_CODES | ||
import android.os.Process | ||
import io.embrace.android.embracesdk.internal.clock.nanosToMillis | ||
import io.embrace.android.embracesdk.internal.spans.SpanService | ||
import io.embrace.android.embracesdk.internal.spans.toEmbraceAttributeName | ||
import io.embrace.android.embracesdk.internal.utils.Provider | ||
import io.embrace.android.embracesdk.internal.utils.VersionChecker | ||
import io.embrace.android.embracesdk.logging.InternalEmbraceLogger | ||
import io.embrace.android.embracesdk.worker.BackgroundWorker | ||
import io.opentelemetry.sdk.common.Clock | ||
import java.util.concurrent.atomic.AtomicBoolean | ||
|
||
/** | ||
* Records startup traces based on the data that it is provided. It adjusts what it logs based on what data has been provided and | ||
* and which Android version the app is running. | ||
* | ||
* For the start of cold launch traces, the start time is determined by the following: | ||
* | ||
* - Android 13 onwards, it is determined by when the app process is specialized from the zygote process, which could be some time after the | ||
* the zygote process is created, depending on, perhaps among other things, the manufacturer of the device. If this value is used, | ||
* it value will be captured in an attribute on the root span of the trace. | ||
* | ||
* - Android 7.0 to 12 (inclusive), it is determined by when the app process is created. Some OEMs on some versions of Android are known to | ||
* pre-created a bunch of zygotes in order to speed up startup time, to mixed success. The fact that Pixel devices don't do this should | ||
* tell you how effectively that strategy overall is. | ||
* | ||
* - Older Android version that are supported, if provided, the application object creation time. Otherwise, we fall back to | ||
* SDK startup time (for now) | ||
* | ||
* For the start of warm launch traces, we use the creation time for the first activity that we want to consider for startup | ||
* | ||
*/ | ||
internal class AppStartupTraceEmitter( | ||
private val clock: Clock, | ||
private val startupServiceProvider: Provider<StartupService?>, | ||
private val spanService: SpanService, | ||
private val backgroundWorker: BackgroundWorker, | ||
private val versionChecker: VersionChecker, | ||
private val logger: InternalEmbraceLogger | ||
) { | ||
private val processCreateRequestedMs: Long? | ||
private val processCreatedMs: Long? | ||
|
||
init { | ||
val timestampAtDeviceStart = nowMs() - clock.nanoTime().nanosToMillis() | ||
processCreateRequestedMs = if (versionChecker.isAtLeast(VERSION_CODES.N)) { | ||
timestampAtDeviceStart + Process.getStartElapsedRealtime() | ||
} else { | ||
null | ||
} | ||
processCreatedMs = if (versionChecker.isAtLeast(VERSION_CODES.TIRAMISU)) { | ||
timestampAtDeviceStart + Process.getStartRequestedElapsedRealtime() | ||
} else { | ||
null | ||
} | ||
} | ||
|
||
@Volatile | ||
private var applicationInitStartMs: Long? = null | ||
|
||
@Volatile | ||
private var applicationInitEndMs: Long? = null | ||
|
||
@Volatile | ||
private var startupActivityInitStartMs: Long? = null | ||
|
||
@Volatile | ||
private var startupActivityInitEndMs: Long? = null | ||
|
||
@Volatile | ||
private var startupActivityResumedMs: Long? = null | ||
|
||
@Volatile | ||
private var firstFrameRenderedMs: Long? = null | ||
|
||
private val startupRecorded = AtomicBoolean(false) | ||
private val endWithFrameDraw: Boolean = versionChecker.isAtLeast(VERSION_CODES.Q) | ||
|
||
fun applicationInitStart(timestampMs: Long? = null) { | ||
applicationInitStartMs = timestampMs ?: nowMs() | ||
} | ||
|
||
fun applicationInitEnd(timestampMs: Long? = null) { | ||
applicationInitEndMs = timestampMs ?: nowMs() | ||
} | ||
|
||
fun startupActivityInitStart(timestampMs: Long? = null) { | ||
if (startupActivityInitStartMs == null) { | ||
startupActivityInitStartMs = timestampMs ?: nowMs() | ||
} | ||
} | ||
|
||
fun startupActivityInitEnd(timestampMs: Long? = null) { | ||
startupActivityInitEndMs = timestampMs ?: nowMs() | ||
} | ||
|
||
fun startupActivityResumed(timestampMs: Long? = null) { | ||
startupActivityResumedMs = timestampMs ?: nowMs() | ||
if (!endWithFrameDraw) { | ||
dataCollectionComplete() | ||
} | ||
} | ||
|
||
fun firstFrameRendered(timestampMs: Long? = null) { | ||
firstFrameRenderedMs = timestampMs ?: nowMs() | ||
if (endWithFrameDraw) { | ||
dataCollectionComplete() | ||
} | ||
} | ||
|
||
private fun dataCollectionComplete() { | ||
if (!startupRecorded.get()) { | ||
synchronized(startupRecorded) { | ||
if (!startupRecorded.get()) { | ||
backgroundWorker.submit { | ||
recordStartup() | ||
if (!startupRecorded.get()) { | ||
logger.logWarning("App startup trace recording attempted but did not succeed") | ||
} | ||
} | ||
} | ||
} | ||
} | ||
} | ||
|
||
private fun recordStartup() { | ||
val startupService = startupServiceProvider() ?: return | ||
val sdkInitStartMs = startupService.getSdkInitStartMs() | ||
val sdkInitEndMs = startupService.getSdkInitEndMs() | ||
val sdkStartupDuration = duration(sdkInitStartMs, sdkInitEndMs) | ||
val processStartTimeMs: Long? = | ||
if (versionChecker.isAtLeast(VERSION_CODES.N)) { | ||
processCreatedMs | ||
} else { | ||
applicationInitStartMs ?: sdkInitStartMs | ||
} | ||
|
||
val traceEndTimeMs: Long? = | ||
if (versionChecker.isAtLeast(VERSION_CODES.Q)) { | ||
firstFrameRenderedMs | ||
} else { | ||
startupActivityResumedMs | ||
} | ||
|
||
if (processStartTimeMs != null && traceEndTimeMs != null) { | ||
val gap = applicationActivityCreationGap() ?: duration(sdkInitEndMs, startupActivityInitStartMs) | ||
if (gap != null) { | ||
if (!spanService.initialized()) { | ||
logger.logWarning("Startup trace not recorded because the spans service is not initialized") | ||
} else if (gap <= SDK_AND_ACTIVITY_INIT_GAP) { | ||
recordColdTtid( | ||
traceStartTimeMs = processStartTimeMs, | ||
applicationInitEndMs = applicationInitEndMs, | ||
sdkInitStartMs = sdkInitStartMs, | ||
sdkInitEndMs = sdkInitEndMs, | ||
activityInitStartMs = startupActivityInitStartMs, | ||
activityInitEndMs = startupActivityInitEndMs, | ||
traceEndTimeMs = traceEndTimeMs, | ||
processCreateDelay = processCreateDelay(), | ||
) | ||
} else { | ||
startupActivityInitStartMs?.let { startTime -> | ||
recordWarmTtid( | ||
traceStartTimeMs = startTime, | ||
activityInitEndMs = startupActivityInitEndMs, | ||
traceEndTimeMs = traceEndTimeMs, | ||
processCreateDelay = processCreateDelay(), | ||
processToActivityCreateGap = gap, | ||
sdkStartupDuration = sdkStartupDuration | ||
) | ||
} | ||
} | ||
} | ||
} | ||
} | ||
|
||
@Suppress("CyclomaticComplexMethod", "ComplexMethod") | ||
private fun recordColdTtid( | ||
traceStartTimeMs: Long, | ||
applicationInitEndMs: Long?, | ||
sdkInitStartMs: Long?, | ||
sdkInitEndMs: Long?, | ||
activityInitStartMs: Long?, | ||
activityInitEndMs: Long?, | ||
traceEndTimeMs: Long, | ||
processCreateDelay: Long?, | ||
) { | ||
if (!startupRecorded.get()) { | ||
spanService.startSpan( | ||
name = "cold-time-to-initial-display", | ||
startTimeMs = traceStartTimeMs, | ||
)?.run { | ||
processCreateDelay?.let { delay -> | ||
addAttribute("process-create-delay-ms".toEmbraceAttributeName(), delay.toString()) | ||
} | ||
if (stop(endTimeMs = traceEndTimeMs)) { | ||
startupRecorded.set(true) | ||
} | ||
|
||
if (applicationInitEndMs != null) { | ||
spanService.recordCompletedSpan( | ||
name = "process-init", | ||
parent = this, | ||
startTimeMs = traceStartTimeMs, | ||
endTimeMs = applicationInitEndMs, | ||
) | ||
} | ||
if (sdkInitStartMs != null && sdkInitEndMs != null) { | ||
spanService.recordCompletedSpan( | ||
name = "embrace-init", | ||
parent = this, | ||
startTimeMs = sdkInitStartMs, | ||
endTimeMs = sdkInitEndMs, | ||
) | ||
} | ||
val lastEventBeforeActivityInit = applicationInitEndMs ?: sdkInitEndMs | ||
if (lastEventBeforeActivityInit != null && activityInitStartMs != null) { | ||
spanService.recordCompletedSpan( | ||
name = "activity-init-gap", | ||
parent = this, | ||
startTimeMs = lastEventBeforeActivityInit, | ||
endTimeMs = activityInitStartMs, | ||
) | ||
} | ||
if (activityInitStartMs != null && activityInitEndMs != null) { | ||
spanService.recordCompletedSpan( | ||
name = "activity-create", | ||
parent = this, | ||
startTimeMs = activityInitStartMs, | ||
endTimeMs = activityInitEndMs, | ||
) | ||
} | ||
if (activityInitEndMs != null) { | ||
val uiLoadSpanName = if (endWithFrameDraw) { | ||
"first-frame-render" | ||
} else { | ||
"activity-resume" | ||
} | ||
spanService.recordCompletedSpan( | ||
name = uiLoadSpanName, | ||
parent = this, | ||
startTimeMs = activityInitEndMs, | ||
endTimeMs = traceEndTimeMs, | ||
) | ||
} | ||
} | ||
} | ||
} | ||
|
||
private fun recordWarmTtid( | ||
traceStartTimeMs: Long, | ||
activityInitEndMs: Long?, | ||
traceEndTimeMs: Long, | ||
processCreateDelay: Long?, | ||
processToActivityCreateGap: Long?, | ||
sdkStartupDuration: Long?, | ||
) { | ||
if (!startupRecorded.get()) { | ||
spanService.startSpan( | ||
name = "warm-time-to-initial-display", | ||
startTimeMs = traceStartTimeMs, | ||
)?.run { | ||
processCreateDelay?.let { delay -> | ||
addAttribute("process-create-delay-ms".toEmbraceAttributeName(), delay.toString()) | ||
} | ||
processToActivityCreateGap?.let { gap -> | ||
addAttribute("activity-init-gap-ms".toEmbraceAttributeName(), gap.toString()) | ||
} | ||
sdkStartupDuration?.let { duration -> | ||
addAttribute("embrace-init-duration-ms".toEmbraceAttributeName(), duration.toString()) | ||
} | ||
if (stop(endTimeMs = traceEndTimeMs)) { | ||
startupRecorded.set(true) | ||
} | ||
if (activityInitEndMs != null) { | ||
spanService.recordCompletedSpan( | ||
name = "activity-create", | ||
parent = this, | ||
startTimeMs = traceStartTimeMs, | ||
endTimeMs = activityInitEndMs, | ||
) | ||
val uiLoadSpanName = if (endWithFrameDraw) { | ||
"first-frame-render" | ||
} else { | ||
"activity-resume" | ||
} | ||
spanService.recordCompletedSpan( | ||
name = uiLoadSpanName, | ||
parent = this, | ||
startTimeMs = activityInitEndMs, | ||
endTimeMs = traceEndTimeMs, | ||
) | ||
} | ||
} | ||
} | ||
} | ||
|
||
private fun processCreateDelay(): Long? = duration(processCreateRequestedMs, processCreatedMs) | ||
|
||
private fun applicationActivityCreationGap(): Long? = duration(applicationInitEndMs, startupActivityInitStartMs) | ||
|
||
private fun nowMs(): Long = clock.now().nanosToMillis() | ||
|
||
companion object { | ||
/** | ||
* The gap between the end of the Embrace SDK initialization to when the first activity loaded after startup happens. | ||
* If this gap is greater than 1 minute, it's likely that the app process was not created because the user tapped on the app icon, | ||
* so we track this app launch as a warm start. | ||
*/ | ||
const val SDK_AND_ACTIVITY_INIT_GAP = 60000L | ||
|
||
fun duration(start: Long?, end: Long?): Long? = if (start != null && end != null) { | ||
end - start | ||
} else { | ||
null | ||
} | ||
} | ||
} |
Oops, something went wrong.