Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

RUM-3430: Fix application startup time regression #1935

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -6,15 +6,21 @@

package com.datadog.android.rum.internal.domain.scope

import android.app.ActivityManager
import androidx.annotation.WorkerThread
import com.datadog.android.api.InternalLogger
import com.datadog.android.api.feature.Feature
import com.datadog.android.api.storage.DataWriter
import com.datadog.android.core.InternalSdkCore
import com.datadog.android.core.internal.net.FirstPartyHostHeaderTypeResolver
import com.datadog.android.rum.DdRumContentProvider
import com.datadog.android.rum.RumSessionListener
import com.datadog.android.rum.internal.AppStartTimeProvider
import com.datadog.android.rum.internal.DefaultAppStartTimeProvider
import com.datadog.android.rum.internal.domain.RumContext
import com.datadog.android.rum.internal.domain.Time
import com.datadog.android.rum.internal.vitals.VitalMonitor
import java.util.concurrent.TimeUnit

@Suppress("LongParameterList")
internal class RumApplicationScope(
Expand All @@ -27,7 +33,8 @@ internal class RumApplicationScope(
private val cpuVitalMonitor: VitalMonitor,
private val memoryVitalMonitor: VitalMonitor,
private val frameRateVitalMonitor: VitalMonitor,
private val sessionListener: RumSessionListener?
private val sessionListener: RumSessionListener?,
private val appStartTimeProvider: AppStartTimeProvider = DefaultAppStartTimeProvider()
) : RumScope, RumViewChangedListener {

private var rumContext = RumContext(applicationId = applicationId)
Expand Down Expand Up @@ -55,6 +62,7 @@ internal class RumApplicationScope(
}

private var lastActiveViewInfo: RumViewInfo? = null
private var isAppStartedEventSent = false

// region RumScope

Expand All @@ -79,6 +87,10 @@ internal class RumApplicationScope(
}
}

if (event !is RumRawEvent.SdkInit && !isAppStartedEventSent) {
sendApplicationStartEvent(event.eventTime, writer)
}

delegateToChildren(event, writer)

return this
Expand Down Expand Up @@ -154,6 +166,32 @@ internal class RumApplicationScope(
}
}

@WorkerThread
private fun sendApplicationStartEvent(eventTime: Time, writer: DataWriter<Any>) {
val processImportance = DdRumContentProvider.processImportance
val isForegroundProcess = processImportance ==
ActivityManager.RunningAppProcessInfo.IMPORTANCE_FOREGROUND
if (isForegroundProcess) {
val processStartTimeNs = appStartTimeProvider.appStartTimeNs
// processStartTime is the time in nanoseconds since VM start. To get a timestamp, we want
// to convert it to milliseconds since epoch provided by System.currentTimeMillis.
// To do so, we take the offset of those times in the event time, which should be consistent,
// then add that to our processStartTime to get the correct value.
val timestampNs = (
TimeUnit.MILLISECONDS.toNanos(eventTime.timestamp) - eventTime.nanoTime
) + processStartTimeNs
val applicationLaunchViewTime = Time(
timestamp = TimeUnit.NANOSECONDS.toMillis(timestampNs),
nanoTime = processStartTimeNs
)
val startupTime = eventTime.nanoTime - processStartTimeNs
val appStartedEvent =
RumRawEvent.ApplicationStarted(applicationLaunchViewTime, startupTime)
delegateToChildren(appStartedEvent, writer)
isAppStartedEventSent = true
}
}

// endregion

companion object {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -220,7 +220,6 @@ internal sealed class RumRawEvent {

internal data class SdkInit(
val isAppInForeground: Boolean,
val appStartTimeNs: Long,
override val eventTime: Time = Time()
) : RumRawEvent()
}
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,6 @@ import com.datadog.android.core.InternalSdkCore
import com.datadog.android.core.internal.net.FirstPartyHostHeaderTypeResolver
import com.datadog.android.rum.RumSessionListener
import com.datadog.android.rum.internal.domain.RumContext
import com.datadog.android.rum.internal.domain.Time
import com.datadog.android.rum.internal.storage.NoOpDataWriter
import com.datadog.android.rum.internal.vitals.VitalMonitor
import com.datadog.android.rum.utils.percent
Expand Down Expand Up @@ -119,19 +118,8 @@ internal class RumSessionScope(

val actualWriter = if (sessionState == State.TRACKED) writer else noOpWriter

val downStreamEvent = if (event is RumRawEvent.SdkInit) {
if (event.isAppInForeground) {
createApplicationStartEvent(event)
} else {
// stop here, we initialized the session, no need to go down
null
}
} else {
event
}

if (downStreamEvent != null) {
childScope = childScope?.handleEvent(downStreamEvent, actualWriter)
if (event !is RumRawEvent.SdkInit) {
childScope = childScope?.handleEvent(event, actualWriter)
}

return if (isSessionComplete()) {
Expand Down Expand Up @@ -228,26 +216,6 @@ internal class RumSessionScope(
)
}

private fun createApplicationStartEvent(
sdkInitEvent: RumRawEvent.SdkInit
): RumRawEvent.ApplicationStarted {
val processStartTimeNs = sdkInitEvent.appStartTimeNs
val eventTime = sdkInitEvent.eventTime
// processStartTime is the time in nanoseconds since VM start. To get a timestamp, we want
// to convert it to milliseconds since epoch provided by System.currentTimeMillis.
// To do so, we take the offset of those times in the event time, which should be consistent,
// then add that to our processStartTime to get the correct value.
val timestampNs = (
TimeUnit.MILLISECONDS.toNanos(eventTime.timestamp) - eventTime.nanoTime
) + processStartTimeNs
val applicationLaunchViewTime = Time(
timestamp = TimeUnit.NANOSECONDS.toMillis(timestampNs),
nanoTime = processStartTimeNs
)
val startupTime = sdkInitEvent.eventTime.nanoTime - processStartTimeNs
return RumRawEvent.ApplicationStarted(applicationLaunchViewTime, startupTime)
}

// endregion

companion object {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -26,9 +26,7 @@ import com.datadog.android.rum.RumResourceKind
import com.datadog.android.rum.RumResourceMethod
import com.datadog.android.rum.RumSessionListener
import com.datadog.android.rum._RumInternalProxy
import com.datadog.android.rum.internal.AppStartTimeProvider
import com.datadog.android.rum.internal.CombinedRumSessionListener
import com.datadog.android.rum.internal.DefaultAppStartTimeProvider
import com.datadog.android.rum.internal.RumErrorSourceType
import com.datadog.android.rum.internal.RumFeature
import com.datadog.android.rum.internal.debug.RumDebugListener
Expand Down Expand Up @@ -71,7 +69,6 @@ internal class DatadogRumMonitor(
memoryVitalMonitor: VitalMonitor,
frameRateVitalMonitor: VitalMonitor,
sessionListener: RumSessionListener,
private val appStartTimeProvider: AppStartTimeProvider = DefaultAppStartTimeProvider(),
internal val executorService: ExecutorService = Executors.newSingleThreadExecutor()
) : RumMonitor, AdvancedRumMonitor {

Expand Down Expand Up @@ -413,9 +410,8 @@ internal class DatadogRumMonitor(
val processImportance = DdRumContentProvider.processImportance
val isAppInForeground = processImportance ==
ActivityManager.RunningAppProcessInfo.IMPORTANCE_FOREGROUND
val processStartTimeNs = appStartTimeProvider.appStartTimeNs
handleEvent(
RumRawEvent.SdkInit(isAppInForeground, processStartTimeNs)
RumRawEvent.SdkInit(isAppInForeground)
)
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,15 +6,18 @@

package com.datadog.android.rum.internal.domain.scope

import android.app.ActivityManager
import com.datadog.android.api.context.DatadogContext
import com.datadog.android.api.context.TimeInfo
import com.datadog.android.api.feature.Feature
import com.datadog.android.api.feature.FeatureScope
import com.datadog.android.api.storage.DataWriter
import com.datadog.android.core.InternalSdkCore
import com.datadog.android.core.internal.net.FirstPartyHostHeaderTypeResolver
import com.datadog.android.rum.DdRumContentProvider
import com.datadog.android.rum.RumActionType
import com.datadog.android.rum.RumSessionListener
import com.datadog.android.rum.internal.AppStartTimeProvider
import com.datadog.android.rum.internal.domain.RumContext
import com.datadog.android.rum.internal.vitals.VitalMonitor
import com.datadog.android.rum.utils.forge.Configurator
Expand Down Expand Up @@ -44,6 +47,7 @@ import org.mockito.kotlin.verify
import org.mockito.kotlin.verifyNoInteractions
import org.mockito.kotlin.whenever
import org.mockito.quality.Strictness
import java.util.concurrent.TimeUnit

@Extensions(
ExtendWith(MockitoExtension::class),
Expand All @@ -67,6 +71,9 @@ internal class RumApplicationScopeTest {
@Mock
lateinit var mockResolver: FirstPartyHostHeaderTypeResolver

@Mock
lateinit var mockAppStartTimeProvider: AppStartTimeProvider

@Mock
lateinit var mockCpuVitalMonitor: VitalMonitor

Expand Down Expand Up @@ -119,7 +126,8 @@ internal class RumApplicationScopeTest {
mockCpuVitalMonitor,
mockMemoryVitalMonitor,
mockFrameRateVitalMonitor,
mockSessionListener
mockSessionListener,
mockAppStartTimeProvider
)
}

Expand Down Expand Up @@ -362,4 +370,133 @@ internal class RumApplicationScopeTest {
assertThat(rumContext["view_id"]).isNotNull
}
}

@Test
fun `M send ApplicationStarted event once W handleEvent { app is in foreground }`(
forge: Forge
) {
// Given
val fakeEvents = forge.aList {
forge.anyRumEvent(
excluding = listOf(
RumRawEvent.ApplicationStarted::class.java,
RumRawEvent.SdkInit::class.java
)
)
}
val firstEvent = fakeEvents.first()
val appStartTimeNs = forge.aLong(min = 0, max = fakeEvents.first().eventTime.nanoTime)
whenever(mockAppStartTimeProvider.appStartTimeNs) doReturn appStartTimeNs
DdRumContentProvider.processImportance =
ActivityManager.RunningAppProcessInfo.IMPORTANCE_FOREGROUND
val mockSessionScope = mock<RumScope>()
testedScope.childScopes.clear()
testedScope.childScopes += mockSessionScope

val expectedEventTimestamp =
TimeUnit.NANOSECONDS.toMillis(
TimeUnit.MILLISECONDS.toNanos(firstEvent.eventTime.timestamp) -
firstEvent.eventTime.nanoTime + appStartTimeNs
)

// When
fakeEvents.forEach {
testedScope.handleEvent(it, mockWriter)
}

// Then
argumentCaptor<RumRawEvent> {
verify(mockSessionScope).handleEvent(capture(), eq(mockWriter))
assertThat(firstValue).isInstanceOf(RumRawEvent.ApplicationStarted::class.java)
val appStartEventTime = (firstValue as RumRawEvent.ApplicationStarted).eventTime
assertThat(appStartEventTime.timestamp).isEqualTo(expectedEventTimestamp)
assertThat(appStartEventTime.nanoTime).isEqualTo(appStartTimeNs)

val processStartTimeNs =
(firstValue as RumRawEvent.ApplicationStarted).applicationStartupNanos
assertThat(processStartTimeNs).isEqualTo(firstEvent.eventTime.nanoTime - appStartTimeNs)

assertThat(allValues.filterIsInstance<RumRawEvent.ApplicationStarted>()).hasSize(1)
}
}

@Test
fun `M not send ApplicationStarted event W handleEvent { app is not in foreground }`(
forge: Forge
) {
// Given
val fakeEvents = forge.aList {
forge.anyRumEvent(
excluding = listOf(
RumRawEvent.ApplicationStarted::class.java,
RumRawEvent.SdkInit::class.java
)
)
}
val appStartTimeNs = forge.aLong(min = 0, max = fakeEvents.first().eventTime.nanoTime)
whenever(mockAppStartTimeProvider.appStartTimeNs) doReturn appStartTimeNs
DdRumContentProvider.processImportance = forge.anElementFrom(
ActivityManager.RunningAppProcessInfo.IMPORTANCE_FOREGROUND_SERVICE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_TOP_SLEEPING,
@Suppress("DEPRECATION")
ActivityManager.RunningAppProcessInfo.IMPORTANCE_TOP_SLEEPING_PRE_28,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_VISIBLE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_PERCEPTIBLE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_PERCEPTIBLE_PRE_26,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_CANT_SAVE_STATE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_SERVICE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_CACHED,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_GONE
)
val mockSessionScope = mock<RumScope>()
testedScope.childScopes.clear()
testedScope.childScopes += mockSessionScope

// When
fakeEvents.forEach {
testedScope.handleEvent(it, mockWriter)
}

// Then
argumentCaptor<RumRawEvent> {
verify(mockSessionScope).handleEvent(capture(), eq(mockWriter))
assertThat(allValues).doesNotHaveSameClassAs(RumRawEvent.ApplicationStarted::class.java)
}
}

@Test
fun `M not send ApplicationStarted event W handleEvent { SdkInit event }`(
forge: Forge
) {
// Given
val fakeSdkInitEvent = forge.sdkInitEvent()
val appStartTimeNs = forge.aLong(min = 0, max = fakeSdkInitEvent.eventTime.nanoTime)
whenever(mockAppStartTimeProvider.appStartTimeNs) doReturn appStartTimeNs
DdRumContentProvider.processImportance = forge.anElementFrom(
ActivityManager.RunningAppProcessInfo.IMPORTANCE_FOREGROUND,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_FOREGROUND_SERVICE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_TOP_SLEEPING,
@Suppress("DEPRECATION")
ActivityManager.RunningAppProcessInfo.IMPORTANCE_TOP_SLEEPING_PRE_28,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_VISIBLE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_PERCEPTIBLE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_PERCEPTIBLE_PRE_26,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_CANT_SAVE_STATE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_SERVICE,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_CACHED,
ActivityManager.RunningAppProcessInfo.IMPORTANCE_GONE
)
val mockSessionScope = mock<RumScope>()
testedScope.childScopes.clear()
testedScope.childScopes += mockSessionScope

// When
testedScope.handleEvent(fakeSdkInitEvent, mockWriter)

// Then
argumentCaptor<RumRawEvent> {
verify(mockSessionScope).handleEvent(capture(), eq(mockWriter))
assertThat(allValues).doesNotHaveSameClassAs(RumRawEvent.ApplicationStarted::class.java)
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -130,7 +130,6 @@ internal fun Forge.sdkInitEvent(): RumRawEvent.SdkInit {
val time = Time()
return RumRawEvent.SdkInit(
isAppInForeground = aBool(),
appStartTimeNs = aLong(min = 0L, max = time.nanoTime),
eventTime = time
)
}
Expand Down
Loading
Loading