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-6033 Add telemetry and logs related with RumMonitor#addViewLoadigTime API #2267

Merged
merged 2 commits into from
Sep 19, 2024
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
2 changes: 1 addition & 1 deletion dd-sdk-android-core/api/apiSurface
Original file line number Diff line number Diff line change
Expand Up @@ -44,7 +44,7 @@ interface com.datadog.android.api.InternalLogger
fun log(Level, List<Target>, () -> String, Throwable? = null, Boolean = false, Map<String, Any?>? = null)
fun logMetric(() -> String, Map<String, Any?>, Float)
fun startPerformanceMeasure(String, com.datadog.android.core.metrics.TelemetryMetricType, Float, String): com.datadog.android.core.metrics.PerformanceMetric?
fun logApiUsage(com.datadog.android.internal.telemetry.InternalTelemetryEvent.ApiUsage, Float)
fun logApiUsage(com.datadog.android.internal.telemetry.InternalTelemetryEvent.ApiUsage, Float = 15f)
companion object
val UNBOUND: InternalLogger
interface com.datadog.android.api.SdkCore
Expand Down
1 change: 1 addition & 0 deletions dd-sdk-android-core/api/dd-sdk-android-core.api
Original file line number Diff line number Diff line change
Expand Up @@ -89,6 +89,7 @@ public final class com/datadog/android/api/InternalLogger$Companion {
public final class com/datadog/android/api/InternalLogger$DefaultImpls {
public static synthetic fun log$default (Lcom/datadog/android/api/InternalLogger;Lcom/datadog/android/api/InternalLogger$Level;Lcom/datadog/android/api/InternalLogger$Target;Lkotlin/jvm/functions/Function0;Ljava/lang/Throwable;ZLjava/util/Map;ILjava/lang/Object;)V
public static synthetic fun log$default (Lcom/datadog/android/api/InternalLogger;Lcom/datadog/android/api/InternalLogger$Level;Ljava/util/List;Lkotlin/jvm/functions/Function0;Ljava/lang/Throwable;ZLjava/util/Map;ILjava/lang/Object;)V
public static synthetic fun logApiUsage$default (Lcom/datadog/android/api/InternalLogger;Lcom/datadog/android/internal/telemetry/InternalTelemetryEvent$ApiUsage;FILjava/lang/Object;)V
}

public final class com/datadog/android/api/InternalLogger$Level : java/lang/Enum {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -137,12 +137,12 @@ interface InternalLogger {
* Logs an API usage from the internal implementation.
* @param apiUsageEvent the API event being tracked
* @param samplingRate value between 0-100 for sampling the event. Note that the sampling rate applied to this
* event will be applied in addition to the global telemetry sampling rate.
* event will be applied in addition to the global telemetry sampling rate. By default, the sampling rate is 15%.
*/
@InternalApi
fun logApiUsage(
apiUsageEvent: InternalTelemetryEvent.ApiUsage,
samplingRate: Float
samplingRate: Float = 15f
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note

Nitpick, this should be a constant and not a hardcoded Magic Number

)

companion object {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ import com.datadog.android.rum.model.ViewEvent
import com.datadog.android.telemetry.model.TelemetryConfigurationEvent
import com.datadog.android.telemetry.model.TelemetryDebugEvent
import com.datadog.android.telemetry.model.TelemetryErrorEvent
import com.datadog.android.telemetry.model.TelemetryUsageEvent
import com.google.gson.JsonObject

internal class RumEventSerializer(
Expand Down Expand Up @@ -55,6 +56,9 @@ internal class RumEventSerializer(
is TelemetryConfigurationEvent -> {
model.toJson().toString()
}
is TelemetryUsageEvent -> {
model.toJson().toString()
}
is JsonObject -> {
model.toString()
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ 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.core.metrics.MethodCallSamplingRate
import com.datadog.android.internal.telemetry.InternalTelemetryEvent
import com.datadog.android.rum.DdRumContentProvider
import com.datadog.android.rum.internal.anr.ANRException
import com.datadog.android.rum.internal.domain.RumContext
Expand Down Expand Up @@ -144,7 +145,24 @@ internal class RumViewManagerScope(
val importanceForeground = ActivityManager.RunningAppProcessInfo.IMPORTANCE_FOREGROUND
val isForegroundProcess = processFlag == importanceForeground

if (applicationDisplayed || !isForegroundProcess) {
if (event is RumRawEvent.AddViewLoadingTime) {

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

/question

do you need to add checks like this in future if you any other usage telemetry like setTrackingConsent ?

if yes, then we should change it to more generic else these if-else will explode.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not anticipating that but this whole part will need re - factory soon but not planned for now.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

a backlog item would be fine here so we don't forget.

val internalLogger = sdkCore.internalLogger
internalLogger.log(
InternalLogger.Level.WARN,
InternalLogger.Target.USER,
{ MESSAGE_MISSING_VIEW }
)
internalLogger.logApiUsage(
InternalTelemetryEvent.ApiUsage.AddViewLoadingTime(
overwrite = event.overwrite,
noView = true,
noActiveView = false
)
)
// we should return here and not add the event to the session ended metric missed events as we already
// send the API usage telemetry
return
} else if (applicationDisplayed || !isForegroundProcess) {
handleBackgroundEvent(event, writer)
} else {
val isSilentOrphanEvent = event.javaClass in silentOrphanEventTypes
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ import com.datadog.android.api.storage.EventType
import com.datadog.android.core.InternalSdkCore
import com.datadog.android.core.internal.net.FirstPartyHostHeaderTypeResolver
import com.datadog.android.core.internal.utils.loggableStackTrace
import com.datadog.android.internal.telemetry.InternalTelemetryEvent
import com.datadog.android.rum.GlobalRumMonitor
import com.datadog.android.rum.RumActionType
import com.datadog.android.rum.RumAttributes
Expand Down Expand Up @@ -240,14 +241,72 @@ internal open class RumViewScope(

@WorkerThread
private fun onAddViewLoadingTime(event: RumRawEvent.AddViewLoadingTime, writer: DataWriter<Any>) {
if (stopped) return
val canAddViewLoadingTime = event.overwrite || viewLoadingTime == null
if (canAddViewLoadingTime) {
viewLoadingTime = event.eventTime.nanoTime - startedNanos
sendViewUpdate(event, writer)
} else {
// TODO RUM-6031 Add logs and telemetry here
val internalLogger = sdkCore.internalLogger
val canUpdateViewLoadingTime = !stopped && (viewLoadingTime == null || event.overwrite)
if (stopped) {
internalLogger.log(
InternalLogger.Level.WARN,
InternalLogger.Target.USER,
{ NO_ACTIVE_VIEW_FOR_LOADING_TIME_WARNING_MESSAGE }
)
internalLogger.logApiUsage(
InternalTelemetryEvent.ApiUsage.AddViewLoadingTime(
overwrite = event.overwrite,
noView = false,
noActiveView = true
)
)
}

if (canUpdateViewLoadingTime) {
updateViewLoadingTime(event, internalLogger, writer)
}
}

private fun updateViewLoadingTime(
event: RumRawEvent.AddViewLoadingTime,
internalLogger: InternalLogger,
writer: DataWriter<Any>
) {
val viewName = key.name
val previousViewLoadingTime = viewLoadingTime
val newLoadingTime = event.eventTime.nanoTime - startedNanos
if (previousViewLoadingTime == null) {
internalLogger.log(
InternalLogger.Level.DEBUG,
InternalLogger.Target.USER,
{ ADDING_VIEW_LOADING_TIME_DEBUG_MESSAGE_FORMAT.format(Locale.US, viewLoadingTime, viewName) }
)
internalLogger.logApiUsage(
InternalTelemetryEvent.ApiUsage.AddViewLoadingTime(
overwrite = false,
noView = false,
noActiveView = false
)
)
} else if (event.overwrite) {
internalLogger.log(
InternalLogger.Level.WARN,
InternalLogger.Target.USER,
{
OVERWRITING_VIEW_LOADING_TIME_WARNING_MESSAGE_FORMAT.format(
Locale.US,
viewName,
previousViewLoadingTime,
newLoadingTime
)
}
)
internalLogger.logApiUsage(
InternalTelemetryEvent.ApiUsage.AddViewLoadingTime(
overwrite = true,
noView = false,
noActiveView = false
)
)
}
viewLoadingTime = newLoadingTime
sendViewUpdate(event, writer)
}

@WorkerThread
Expand Down Expand Up @@ -1249,6 +1308,13 @@ internal open class RumViewScope(
internal const val SLOW_RENDERED_THRESHOLD_FPS = 55
internal const val NEGATIVE_DURATION_WARNING_MESSAGE = "The computed duration for the " +
"view: %s was 0 or negative. In order to keep the view we forced it to 1ns."
internal const val NO_ACTIVE_VIEW_FOR_LOADING_TIME_WARNING_MESSAGE =
"No active view found to add the loading time."
internal const val ADDING_VIEW_LOADING_TIME_DEBUG_MESSAGE_FORMAT =
"View loading time %dns added to the view %s"
internal const val OVERWRITING_VIEW_LOADING_TIME_WARNING_MESSAGE_FORMAT =
"View loading time already exists for the view %s. Replacing the existing %d ns " +
"view loading time with the new %d ns loading time."

internal fun fromEvent(
parentScope: RumScope,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -137,7 +137,7 @@ internal class TelemetryEventHandler(

val eventIdentity = event.identity

if (event !is InternalTelemetryEvent.Metric && eventIDsSeenInCurrentSession.contains(eventIdentity)) {
if (isLog(event) && eventIDsSeenInCurrentSession.contains(eventIdentity)) {
sdkCore.internalLogger.log(
InternalLogger.Level.INFO,
InternalLogger.Target.MAINTAINER,
Expand All @@ -158,6 +158,10 @@ internal class TelemetryEventHandler(
return true
}

private fun isLog(event: InternalTelemetryEvent): Boolean {
return event is InternalTelemetryEvent.Log
}

private fun createDebugEvent(
datadogContext: DatadogContext,
timestamp: Long,
Expand Down Expand Up @@ -351,7 +355,7 @@ internal class TelemetryEventHandler(
datadogContext.source,
sdkCore.internalLogger
) ?: TelemetryUsageEvent.Source.ANDROID,
service = datadogContext.service,
service = TELEMETRY_SERVICE_NAME,
version = datadogContext.sdkVersion,
application = TelemetryUsageEvent.Application(rumContext.applicationId),
session = TelemetryUsageEvent.Session(rumContext.sessionId),
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ import com.datadog.android.rum.utils.forge.Configurator
import com.datadog.android.telemetry.model.TelemetryConfigurationEvent
import com.datadog.android.telemetry.model.TelemetryDebugEvent
import com.datadog.android.telemetry.model.TelemetryErrorEvent
import com.datadog.android.telemetry.model.TelemetryUsageEvent
import com.datadog.tools.unit.assertj.JsonObjectAssert.Companion.assertThat
import com.datadog.tools.unit.forge.anException
import com.google.gson.JsonObject
Expand All @@ -33,6 +34,7 @@ import org.junit.jupiter.api.RepeatedTest
import org.junit.jupiter.api.Test
import org.junit.jupiter.api.extension.ExtendWith
import org.junit.jupiter.api.extension.Extensions
import org.junit.jupiter.api.fail
import org.mockito.Mock
import org.mockito.junit.jupiter.MockitoExtension
import org.mockito.junit.jupiter.MockitoSettings
Expand Down Expand Up @@ -748,6 +750,110 @@ internal class RumEventSerializerTest {
}
}

@RepeatedTest(8)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we should use @Test to reduce CI load after making repeating test in local.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

in this case we need a repeated test as this model has multiple variables variation. Is good to have repetitive tests in order to make sure we cover more cases in this variation.

fun `M serialize RUM event W serialize() with TelemetryUsageEvent`(
@Forgery event: TelemetryUsageEvent
) {
val serialized = testedSerializer.serialize(event)
val jsonObject = JsonParser.parseString(serialized).asJsonObject
assertThat(jsonObject)
.hasField("type", "telemetry")
.hasField("_dd") {
hasField("format_version", 2L)
}
.hasField("date", event.date)
.hasField("source", event.source.name.lowercase(Locale.US).replace('_', '-'))
.hasField("service", event.service)
.hasField("version", event.version)
.hasField("telemetry") {
hasField("usage") {
when (event.telemetry.usage) {
is TelemetryUsageEvent.Usage.AddViewLoadingTime -> {
val usage = event.telemetry.usage as TelemetryUsageEvent.Usage.AddViewLoadingTime
hasField("no_view", usage.noView)
hasField("no_active_view", usage.noActiveView)
hasField("overwritten", usage.overwritten)
}

else -> {
fail("Usage type not covered in assertions")
}
}
}
if (event.telemetry.device != null) {
hasField("device") {
val device = event.telemetry.device
checkNotNull(device)
if (device.architecture != null) {
hasField("architecture", device.architecture!!)
}
if (device.brand != null) {
hasField("brand", device.brand!!)
}
if (device.model != null) {
hasField("model", device.model!!)
}
}
}
if (event.telemetry.os != null) {
hasField("os") {
val os = event.telemetry.os
checkNotNull(os)
if (os.build != null) {
hasField("build", os.build!!)
}
if (os.name != null) {
hasField("name", os.name!!)
}
if (os.version != null) {
hasField("version", os.version!!)
}
}
}
containsAttributes(event.telemetry.additionalProperties)
}

val application = event.application
if (application != null) {
assertThat(jsonObject)
.hasField("application") {
hasField("id", application.id)
}
} else {
assertThat(jsonObject).doesNotHaveField("application")
}

val session = event.session
if (session != null) {
assertThat(jsonObject)
.hasField("session") {
hasField("id", session.id)
}
} else {
assertThat(jsonObject).doesNotHaveField("session")
}

val view = event.view
if (view != null) {
assertThat(jsonObject)
.hasField("view") {
hasField("id", view.id)
}
} else {
assertThat(jsonObject).doesNotHaveField("view")
}

val action = event.action
if (action != null) {
assertThat(jsonObject)
.hasField("action") {
hasField("id", action.id)
}
} else {
assertThat(jsonObject).doesNotHaveField("action")
}
}

@Test
fun `M serialize RUM event W serialize() with unknown event`(
@Forgery unknownEvent: UserInfo
Expand Down Expand Up @@ -1451,25 +1557,29 @@ internal class RumEventSerializerTest {
usr = (it.usr ?: ViewEvent.Usr()).copy(additionalProperties = userAttributes)
)
}

2 -> this.getForgery(ActionEvent::class.java).let {
it.copy(
context = ActionEvent.Context(additionalProperties = attributes),
usr = (it.usr ?: ActionEvent.Usr()).copy(additionalProperties = userAttributes)
)
}

3 -> this.getForgery(ErrorEvent::class.java).let {
it.copy(
context = ErrorEvent.Context(additionalProperties = attributes),
usr = (it.usr ?: ErrorEvent.Usr()).copy(additionalProperties = userAttributes)
)
}

4 -> this.getForgery(ResourceEvent::class.java).let {
it.copy(
context = ResourceEvent.Context(additionalProperties = attributes),
usr = (it.usr ?: ResourceEvent.Usr())
.copy(additionalProperties = userAttributes)
)
}

else -> this.getForgery(LongTaskEvent::class.java).let {
it.copy(
context = LongTaskEvent.Context(additionalProperties = attributes),
Expand Down
Loading