Skip to content

Commit dc37ab5

Browse files
bidetofevilbidetofevil
committed
Start app start up root span early to detect terminations
1 parent 88b9ab5 commit dc37ab5

File tree

4 files changed

+95
-109
lines changed

4 files changed

+95
-109
lines changed

‎embrace-android-core/src/main/kotlin/io/embrace/android/embracesdk/internal/spans/EmbraceSpanImpl.kt‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -45,10 +45,17 @@ internal class EmbraceSpanImpl(
4545
) : PersistableEmbraceSpan {
4646

4747
private val startedSpan: AtomicReference<io.opentelemetry.api.trace.Span?> = AtomicReference(null)
48+
49+
@Volatile
4850
private var spanStartTimeMs: Long? = null
51+
52+
@Volatile
4953
private var spanEndTimeMs: Long? = null
54+
55+
@Volatile
5056
private var status = Span.Status.UNSET
5157
private var updatedName: String? = null
58+
5259
private val systemEvents = ConcurrentLinkedQueue<EmbraceSpanEvent>()
5360
private val customEvents = ConcurrentLinkedQueue<EmbraceSpanEvent>()
5461
private val systemAttributes = ConcurrentHashMap<String, String>().apply {
@@ -230,6 +237,8 @@ internal class EmbraceSpanImpl(
230237
}
231238
}
232239

240+
override fun getStartTimeMs(): Long? = spanStartTimeMs
241+
233242
override fun addAttribute(key: String, value: String): Boolean {
234243
if (customAttributes.size < limits.getMaxCustomAttributeCount() && limits.isAttributeValid(key, value, spanBuilder.internal)) {
235244
synchronized(customAttributes) {

‎embrace-android-core/src/main/kotlin/io/embrace/android/embracesdk/internal/spans/PersistableEmbraceSpan.kt‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -70,6 +70,8 @@ interface PersistableEmbraceSpan : EmbraceSpan, ImplicitContextKeyed {
7070
*/
7171
fun setStatus(statusCode: StatusCode, description: String = "")
7272

73+
fun getStartTimeMs(): Long?
74+
7375
override fun storeInContext(context: Context): Context = context.with(embraceSpanContextKey, this)
7476
}
7577

‎embrace-android-features/src/main/kotlin/io/embrace/android/embracesdk/internal/capture/startup/AppStartupTraceEmitter.kt‎

Lines changed: 82 additions & 109 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@ import io.opentelemetry.sdk.common.Clock
1717
import java.util.concurrent.ConcurrentHashMap
1818
import java.util.concurrent.ConcurrentLinkedQueue
1919
import java.util.concurrent.atomic.AtomicBoolean
20+
import java.util.concurrent.atomic.AtomicReference
2021

2122
/**
2223
* Records startup traces based on the data that it is provided. It adjusts what it logs based on what data has been provided and
@@ -96,11 +97,9 @@ internal class AppStartupTraceEmitter(
9697
private var firstFrameRenderedMs: Long? = null
9798

9899
@Volatile
99-
private var sdkInitThreadName: String? = null
100-
101-
@Volatile
102-
private var sdkInitEndedInForeground: Boolean? = null
100+
private var recordColdStart = true
103101

102+
private val appStartupRootSpan = AtomicReference<PersistableEmbraceSpan?>(null)
104103
private val startupRecorded = AtomicBoolean(false)
105104
private val dataCollectionComplete = AtomicBoolean(false)
106105
private val endWithFrameDraw: Boolean = startupHasRenderEvent(versionChecker)
@@ -114,7 +113,21 @@ internal class AppStartupTraceEmitter(
114113
}
115114

116115
override fun firstActivityInit(timestampMs: Long?) {
117-
firstActivityInitStartMs = timestampMs ?: nowMs()
116+
val activityInitTimeMs = timestampMs ?: nowMs()
117+
firstActivityInitStartMs = activityInitTimeMs
118+
119+
val sdkInitStartMs = startupServiceProvider()?.getSdkInitStartMs()
120+
val sdkInitEndMs = startupServiceProvider()?.getSdkInitEndMs()
121+
if (sdkInitStartMs != null && sdkInitEndMs != null) {
122+
applicationActivityCreationGap(sdkInitEndMs)?.let { gap ->
123+
recordColdStart = gap <= SDK_AND_ACTIVITY_INIT_GAP
124+
startTrace(
125+
isColdStart = recordColdStart,
126+
sdkInitStartMs = sdkInitStartMs,
127+
activityInitTimeMs = activityInitTimeMs
128+
)
129+
}
130+
}
118131
}
119132

120133
override fun startupActivityPreCreated(timestampMs: Long?) {
@@ -124,7 +137,7 @@ internal class AppStartupTraceEmitter(
124137
override fun startupActivityInitStart(timestampMs: Long?) {
125138
startupActivityInitStartMs = (timestampMs ?: nowMs()).apply {
126139
if (firstActivityInitStartMs == null) {
127-
firstActivityInitStartMs = this
140+
firstActivityInit(this)
128141
}
129142
}
130143
}
@@ -140,7 +153,7 @@ internal class AppStartupTraceEmitter(
140153
override fun startupActivityResumed(
141154
activityName: String,
142155
collectionCompleteCallback: (() -> Unit)?,
143-
timestampMs: Long?
156+
timestampMs: Long?,
144157
) {
145158
startupActivityName = activityName
146159
startupActivityResumedMs = timestampMs ?: nowMs()
@@ -152,7 +165,7 @@ internal class AppStartupTraceEmitter(
152165
override fun firstFrameRendered(
153166
activityName: String,
154167
collectionCompleteCallback: (() -> Unit)?,
155-
timestampMs: Long?
168+
timestampMs: Long?,
156169
) {
157170
startupActivityName = activityName
158171
firstFrameRenderedMs = timestampMs ?: nowMs()
@@ -167,7 +180,7 @@ internal class AppStartupTraceEmitter(
167180
endTimeMs: Long,
168181
attributes: Map<String, String>,
169182
events: List<EmbraceSpanEvent>,
170-
errorCode: ErrorCode?
183+
errorCode: ErrorCode?,
171184
) {
172185
additionalTrackedIntervals.add(
173186
TrackedInterval(
@@ -208,59 +221,60 @@ internal class AppStartupTraceEmitter(
208221
}
209222
}
210223

211-
@Suppress("CyclomaticComplexMethod", "ComplexMethod")
224+
private fun startTrace(isColdStart: Boolean, sdkInitStartMs: Long, activityInitTimeMs: Long) {
225+
val rootSpan = if (isColdStart) {
226+
val processStartTimeMs =
227+
if (versionChecker.isAtLeast(VERSION_CODES.N)) {
228+
processCreatedMs
229+
} else if (applicationInitStartMs != null) {
230+
applicationInitStartMs
231+
} else {
232+
sdkInitStartMs
233+
}
234+
235+
spanService.startSpan(
236+
name = "app-startup-cold",
237+
startTimeMs = processStartTimeMs,
238+
)
239+
} else {
240+
spanService.startSpan(
241+
name = "app-startup-warm",
242+
startTimeMs = activityInitTimeMs,
243+
)
244+
}
245+
246+
if (rootSpan != null) {
247+
appStartupRootSpan.set(rootSpan)
248+
} else {
249+
logger.trackInternalError(
250+
type = InternalErrorType.APP_LAUNCH_TRACE_FAIL,
251+
throwable = IllegalStateException("App startup trace could not be started")
252+
)
253+
}
254+
}
255+
212256
private fun recordStartup() {
213257
val startupService = startupServiceProvider() ?: return
214-
val sdkInitStartMs = startupService.getSdkInitStartMs()
215258
val sdkInitEndMs = startupService.getSdkInitEndMs()
216-
val processStartTimeMs: Long? =
217-
if (versionChecker.isAtLeast(VERSION_CODES.N)) {
218-
processCreatedMs
219-
} else {
220-
applicationInitStartMs ?: sdkInitStartMs
221-
}
222-
223259
val traceEndTimeMs: Long? =
224260
if (endWithFrameDraw) {
225261
firstFrameRenderedMs
226262
} else {
227263
startupActivityResumedMs
228264
}
229265

230-
sdkInitEndedInForeground = startupService.endedInForeground()
231-
sdkInitThreadName = startupService.getInitThreadName()
232-
233-
if (processStartTimeMs != null && traceEndTimeMs != null && sdkInitEndMs != null) {
234-
val gap = applicationActivityCreationGap(sdkInitEndMs)
235-
if (gap != null) {
236-
val startupTrace: EmbraceSpan? = if (!spanService.initialized()) {
237-
null
238-
} else if (gap <= SDK_AND_ACTIVITY_INIT_GAP) {
239-
recordColdTtid(
240-
traceStartTimeMs = processStartTimeMs,
241-
applicationInitEndMs = applicationInitEndMs,
242-
sdkInitStartMs = sdkInitStartMs,
243-
sdkInitEndMs = sdkInitEndMs,
244-
firstActivityInitMs = firstActivityInitStartMs,
245-
activityInitStartMs = startupActivityInitStartMs,
246-
activityInitEndMs = startupActivityInitEndMs,
247-
traceEndTimeMs = traceEndTimeMs
248-
)
249-
} else {
250-
val warmStartTimeMs = firstActivityInitStartMs ?: startupActivityInitStartMs
251-
warmStartTimeMs?.let { startTime ->
252-
recordWarmTtid(
253-
traceStartTimeMs = startTime,
254-
activityInitStartMs = startupActivityInitStartMs,
255-
activityInitEndMs = startupActivityInitEndMs,
256-
traceEndTimeMs = traceEndTimeMs,
257-
)
258-
}
259-
}
260-
261-
if (startupTrace != null) {
262-
recordAdditionalIntervals(startupTrace)
263-
}
266+
if (traceEndTimeMs != null && sdkInitEndMs != null) {
267+
appStartupRootSpan.get()?.let { startupTrace ->
268+
recordTtid(
269+
applicationInitEndMs = if (recordColdStart) applicationInitEndMs else null,
270+
sdkInitStartMs = if (recordColdStart) startupService.getSdkInitStartMs() else null,
271+
sdkInitEndMs = if (recordColdStart) sdkInitEndMs else null,
272+
firstActivityInitMs = if (recordColdStart) firstActivityInitStartMs else null,
273+
activityInitStartMs = startupActivityInitStartMs,
274+
activityInitEndMs = startupActivityInitEndMs,
275+
traceEndTimeMs = traceEndTimeMs
276+
)
277+
recordAdditionalIntervals(startupTrace)
264278
}
265279
}
266280
}
@@ -283,8 +297,7 @@ internal class AppStartupTraceEmitter(
283297
}
284298

285299
@Suppress("CyclomaticComplexMethod", "ComplexMethod")
286-
private fun recordColdTtid(
287-
traceStartTimeMs: Long,
300+
private fun recordTtid(
288301
applicationInitEndMs: Long?,
289302
sdkInitStartMs: Long?,
290303
sdkInitEndMs: Long?,
@@ -294,24 +307,24 @@ internal class AppStartupTraceEmitter(
294307
traceEndTimeMs: Long,
295308
): EmbraceSpan? {
296309
return if (!startupRecorded.get()) {
297-
spanService.startSpan(
298-
name = "app-startup-cold",
299-
startTimeMs = traceStartTimeMs,
300-
)?.apply {
310+
appStartupRootSpan.get()?.apply {
301311
addTraceMetadata()
302312

303313
if (stop(endTimeMs = traceEndTimeMs)) {
304314
startupRecorded.set(true)
305315
}
306316

307-
if (applicationInitEndMs != null) {
308-
spanService.recordCompletedSpan(
309-
name = "process-init",
310-
parent = this,
311-
startTimeMs = traceStartTimeMs,
312-
endTimeMs = applicationInitEndMs,
313-
)
317+
getStartTimeMs()?.let { traceStartTimeMs ->
318+
if (applicationInitEndMs != null) {
319+
spanService.recordCompletedSpan(
320+
name = "process-init",
321+
parent = this,
322+
startTimeMs = traceStartTimeMs,
323+
endTimeMs = applicationInitEndMs,
324+
)
325+
}
314326
}
327+
315328
if (sdkInitStartMs != null && sdkInitEndMs != null) {
316329
spanService.recordCompletedSpan(
317330
name = "embrace-init",
@@ -320,16 +333,17 @@ internal class AppStartupTraceEmitter(
320333
endTimeMs = sdkInitEndMs,
321334
)
322335
}
336+
323337
val lastEventBeforeActivityInit = applicationInitEndMs ?: sdkInitEndMs
324-
val firstActivityInit = firstActivityInitMs ?: activityInitStartMs
325-
if (lastEventBeforeActivityInit != null && firstActivityInit != null) {
338+
if (lastEventBeforeActivityInit != null && firstActivityInitMs != null) {
326339
spanService.recordCompletedSpan(
327340
name = "activity-init-gap",
328341
parent = this,
329342
startTimeMs = lastEventBeforeActivityInit,
330-
endTimeMs = firstActivityInit,
343+
endTimeMs = firstActivityInitMs,
331344
)
332345
}
346+
333347
if (activityInitStartMs != null && activityInitEndMs != null) {
334348
spanService.recordCompletedSpan(
335349
name = "activity-create",
@@ -357,47 +371,6 @@ internal class AppStartupTraceEmitter(
357371
}
358372
}
359373

360-
private fun recordWarmTtid(
361-
traceStartTimeMs: Long,
362-
activityInitStartMs: Long?,
363-
activityInitEndMs: Long?,
364-
traceEndTimeMs: Long,
365-
): EmbraceSpan? {
366-
return if (!startupRecorded.get()) {
367-
spanService.startSpan(
368-
name = "app-startup-warm",
369-
startTimeMs = traceStartTimeMs,
370-
)?.apply {
371-
addTraceMetadata()
372-
373-
if (stop(endTimeMs = traceEndTimeMs)) {
374-
startupRecorded.set(true)
375-
}
376-
if (activityInitStartMs != null && activityInitEndMs != null) {
377-
spanService.recordCompletedSpan(
378-
name = "activity-create",
379-
parent = this,
380-
startTimeMs = activityInitStartMs,
381-
endTimeMs = activityInitEndMs,
382-
)
383-
val uiLoadSpanName = if (endWithFrameDraw) {
384-
"first-frame-render"
385-
} else {
386-
"activity-resume"
387-
}
388-
spanService.recordCompletedSpan(
389-
name = uiLoadSpanName,
390-
parent = this,
391-
startTimeMs = activityInitEndMs,
392-
endTimeMs = traceEndTimeMs,
393-
)
394-
}
395-
}
396-
} else {
397-
null
398-
}
399-
}
400-
401374
private fun applicationActivityCreationGap(sdkInitEndMs: Long): Long? =
402375
duration(applicationInitEndMs ?: sdkInitEndMs, firstActivityInitStartMs)
403376

‎embrace-test-fakes/src/main/kotlin/io/embrace/android/embracesdk/fakes/FakePersistableEmbraceSpan.kt‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -126,6 +126,8 @@ class FakePersistableEmbraceSpan(
126126
statusDescription = description
127127
}
128128

129+
override fun getStartTimeMs(): Long? = spanStartTimeMs
130+
129131
override fun addAttribute(key: String, value: String): Boolean {
130132
attributes[key] = value
131133
return true

0 commit comments

Comments
 (0)