Add tests to validate time and change impl to make that possible

embrace-android-okhttp3/src/main/java/io/embrace/android/embracesdk/okhttp3/EmbraceOkHttp3NetworkInterceptor.java

@@ -10,6 +10,8 @@
 
 import io.embrace.android.embracesdk.Embrace;
 import io.embrace.android.embracesdk.InternalApi;
+import io.embrace.android.embracesdk.clock.Clock;
+import io.embrace.android.embracesdk.clock.SystemClock;
 import io.embrace.android.embracesdk.internal.ApkToolsConfig;
 import io.embrace.android.embracesdk.network.EmbraceNetworkRequest;
 import io.embrace.android.embracesdk.network.http.EmbraceHttpPathOverride;
@@ -59,12 +61,16 @@ public final class EmbraceOkHttp3NetworkInterceptor implements Interceptor {
 
     final Embrace embrace;
 
+    // A clock that mirrors the one used by OkHttp to get timestamps
+    final Clock systemClock;
+
     public EmbraceOkHttp3NetworkInterceptor() {
-        this(Embrace.getInstance());
+        this(Embrace.getInstance(), new SystemClock());
     }
 
-    EmbraceOkHttp3NetworkInterceptor(Embrace embrace) {
+    EmbraceOkHttp3NetworkInterceptor(Embrace embrace, Clock systemClock) {
         this.embrace = embrace;
+        this.systemClock = systemClock;
     }
 
     @Override
@@ -75,7 +81,7 @@ public Response intercept(Chain chain) throws IOException {
             return chain.proceed(originalRequest);
         }
 
-        long preRequestClockOffset = sdkClockOffset();
+        long offset = sdkClockOffset();
         boolean networkSpanForwardingEnabled = embrace.getInternalInterface().isNetworkSpanForwardingEnabled();
 
         String traceparent = null;
@@ -87,7 +93,6 @@ public Response intercept(Chain chain) throws IOException {
             originalRequest : originalRequest.newBuilder().header(TRACEPARENT_HEADER_NAME, traceparent).build();
 
         Response networkResponse = chain.proceed(request);
-        long postResponseClockOffset = sdkClockOffset();
         Response.Builder responseBuilder = networkResponse.newBuilder().request(request);
 
         Long contentLength = null;
@@ -154,14 +159,12 @@ public Response intercept(Chain chain) throws IOException {
             networkCaptureData = getNetworkCaptureData(request, response);
         }
 
-
-
         embrace.recordNetworkRequest(
             EmbraceNetworkRequest.fromCompletedRequest(
                 EmbraceHttpPathOverride.getURLString(new EmbraceOkHttp3PathOverrideRequest(request)),
                 HttpMethod.fromString(request.method()),
-                response.sentRequestAtMillis() + preRequestClockOffset,
-                response.receivedResponseAtMillis() + postResponseClockOffset,
+                response.sentRequestAtMillis() + offset,
+                response.receivedResponseAtMillis() + offset,
                 request.body() != null ? request.body().contentLength() : 0,
                 contentLength,
                 response.code(),
@@ -259,6 +262,6 @@ private byte[] getRequestBody(final Request request) {
      * determining client-side timestamps.
      */
     private long sdkClockOffset() {
-        return embrace.getInternalInterface().getSdkCurrentTime() - System.currentTimeMillis();
+        return embrace.getInternalInterface().getSdkCurrentTime() - systemClock.now();
     }
 }

embrace-android-okhttp3/src/test/kotlin/io/embrace/android/embracesdk/okhttp3/EmbraceOkHttp3InterceptorsTest.kt

@@ -1,6 +1,7 @@
 package io.embrace.android.embracesdk.okhttp3
 
 import io.embrace.android.embracesdk.Embrace
+import io.embrace.android.embracesdk.clock.Clock
 import io.embrace.android.embracesdk.internal.EmbraceInternalInterface
 import io.embrace.android.embracesdk.network.EmbraceNetworkRequest
 import io.embrace.android.embracesdk.network.http.NetworkCaptureData
@@ -56,6 +57,9 @@ internal class EmbraceOkHttp3InterceptorsTest {
         private const val TRACEPARENT_HEADER = "traceparent"
         private const val CUSTOM_TRACEPARENT = "00-b583a45b2c7c813e0ebc6aa0835b9d98-b5475c618bb98e67-01"
         private const val GENERATED_TRACEPARENT = "00-3c72a77a7b51af6fb3778c06d4c165ce-4c1d710fffc88e35-01"
+        private const val FAKE_SDK_TIME = 1692201601000L
+        private const val CLOCK_DRIFT = 5000L
+        private const val FAKE_SYSTEM_TIME = FAKE_SDK_TIME + CLOCK_DRIFT
     }
 
     private lateinit var server: MockWebServer
@@ -69,6 +73,7 @@ internal class EmbraceOkHttp3InterceptorsTest {
     private lateinit var getRequestBuilder: Request.Builder
     private lateinit var postRequestBuilder: Request.Builder
     private lateinit var capturedEmbraceNetworkRequest: CapturingSlot<EmbraceNetworkRequest>
+    private lateinit var mockSystemClock: Clock
     private var preNetworkInterceptorBeforeRequestSupplier: (Request) -> Request = { request -> request }
     private var preNetworkInterceptorAfterResponseSupplier: (Response) -> Response = { response -> response }
     private var postNetworkInterceptorBeforeRequestSupplier: (Request) -> Request = { request -> request }
@@ -84,13 +89,15 @@ internal class EmbraceOkHttp3InterceptorsTest {
         every { mockInternalInterface.shouldCaptureNetworkBody(any(), "POST") } answers { true }
         every { mockInternalInterface.shouldCaptureNetworkBody(any(), "GET") } answers { false }
         every { mockInternalInterface.isNetworkSpanForwardingEnabled() } answers { isNetworkSpanForwardingEnabled }
-        every { mockInternalInterface.getSdkCurrentTime() } answers { System.currentTimeMillis() }
+        every { mockInternalInterface.getSdkCurrentTime() } answers { FAKE_SDK_TIME }
         applicationInterceptor = EmbraceOkHttp3ApplicationInterceptor(mockEmbrace)
         preNetworkInterceptorTestInterceptor = TestInspectionInterceptor(
             beforeRequestSent = { request -> preNetworkInterceptorBeforeRequestSupplier.invoke(request) },
             afterResponseReceived = { response -> preNetworkInterceptorAfterResponseSupplier.invoke(response) }
         )
-        networkInterceptor = EmbraceOkHttp3NetworkInterceptor(mockEmbrace)
+        mockSystemClock = mockk(relaxed = true)
+        every { mockSystemClock.now() } answers { FAKE_SYSTEM_TIME }
+        networkInterceptor = EmbraceOkHttp3NetworkInterceptor(mockEmbrace, mockSystemClock)
         postNetworkInterceptorTestInterceptor = TestInspectionInterceptor(
             beforeRequestSent = { request -> postNetworkInterceptorBeforeRequestSupplier.invoke(request) },
             afterResponseReceived = { response -> postNetworkInterceptorAfterResponseSupplier.invoke(response) }
@@ -114,6 +121,8 @@ internal class EmbraceOkHttp3InterceptorsTest {
         every { mockEmbrace.recordNetworkRequest(capture(capturedEmbraceNetworkRequest)) } answers { }
         every { mockEmbrace.generateW3cTraceparent() } answers { GENERATED_TRACEPARENT }
         every { mockEmbrace.internalInterface } answers { mockInternalInterface }
+        isSDKStarted = true
+        isNetworkSpanForwardingEnabled = false
     }
 
     @After
@@ -423,35 +432,44 @@ internal class EmbraceOkHttp3InterceptorsTest {
         expectedPath: String = defaultPath,
         expectedHttpStatus: Int = 200
     ) {
+        val realSystemClockStartTime = System.currentTimeMillis()
         runPostRequest()
+        val realSystemClockEndTime = System.currentTimeMillis()
         validateWholeRequest(
             path = expectedPath,
             httpStatus = expectedHttpStatus,
             responseBodySize = expectedResponseBodySize,
             httpMethod = "POST",
             requestSize = requestBodySize,
-            responseBody = responseBody
+            responseBody = responseBody,
+            realSystemClockStartTime = realSystemClockStartTime,
+            realSystemClockEndTime = realSystemClockEndTime
         )
     }
 
     private fun runAndValidateGetRequest(
         expectedResponseBodySize: Int
     ) {
+        val realSystemClockStartTime = System.currentTimeMillis()
         runGetRequest()
+        val realSystemClockEndTime = System.currentTimeMillis()
         validateWholeRequest(
             path = defaultPath,
             httpStatus = 200,
             httpMethod = "GET",
             requestSize = 0,
             responseBodySize = expectedResponseBodySize,
-            responseBody = null
+            responseBody = null,
+            realSystemClockStartTime = realSystemClockStartTime,
+            realSystemClockEndTime = realSystemClockEndTime
         )
     }
 
     private fun runPostRequest() = assertNotNull(okHttpClient.newCall(postRequestBuilder.build()).execute())
 
     private fun runGetRequest() = assertNotNull(okHttpClient.newCall(getRequestBuilder.build()).execute())
 
+    @Suppress("LongParameterList")
     private fun validateWholeRequest(
         path: String,
         httpMethod: String,
@@ -462,16 +480,17 @@ internal class EmbraceOkHttp3InterceptorsTest {
         errorMessage: String? = null,
         traceId: String? = null,
         w3cTraceparent: String? = null,
-        responseBody: String?
+        responseBody: String?,
+        realSystemClockStartTime: Long,
+        realSystemClockEndTime: Long
     ) {
         with(capturedEmbraceNetworkRequest) {
             assertTrue(captured.url.endsWith("$path?$defaultQueryString"))
             assertEquals(httpMethod, captured.httpMethod)
-
-            // assert expected start/end times when we fix the issue of not using a custom clock instance.
-            assertTrue(captured.startTime > 0)
-            assertTrue(captured.endTime > 0)
-
+            assertTrue(realSystemClockStartTime - CLOCK_DRIFT <= captured.startTime)
+            assertTrue(realSystemClockStartTime > captured.startTime)
+            assertTrue(realSystemClockEndTime - CLOCK_DRIFT >= captured.endTime)
+            assertTrue(realSystemClockEndTime > captured.endTime)
             assertEquals(httpStatus, captured.responseCode)
             assertEquals(requestSize.toLong(), captured.bytesOut)
             assertEquals(responseBodySize.toLong(), captured.bytesIn)

embrace-android-sdk/api/embrace-android-sdk.api

@@ -177,6 +177,15 @@ public final class io/embrace/android/embracesdk/WebViewClientSwazzledHooks {
 public abstract interface annotation class io/embrace/android/embracesdk/annotation/StartupActivity : java/lang/annotation/Annotation {
 }
 
+public abstract interface class io/embrace/android/embracesdk/clock/Clock {
+	public abstract fun now ()J
+}
+
+public final class io/embrace/android/embracesdk/clock/SystemClock : io/embrace/android/embracesdk/clock/Clock {
+	public fun <init> ()V
+	public fun now ()J
+}
+
 public abstract interface class io/embrace/android/embracesdk/internal/EmbraceInternalInterface {
 	public abstract fun getSdkCurrentTime ()J
 	public abstract fun isNetworkSpanForwardingEnabled ()Z

embrace-android-sdk/src/integrationTest/kotlin/io/embrace/android/embracesdk/IntegrationTestRule.kt

@@ -190,7 +190,7 @@ internal class IntegrationTestRule(
     )
 
     companion object {
-        const val DEFAULT_SDK_START_TIME_MS = 1692201600L
+        const val DEFAULT_SDK_START_TIME_MS = 169220160000L
 
         fun newHarness(startImmediately: Boolean) = Harness(startImmediately = startImmediately)
 

embrace-android-sdk/src/integrationTest/kotlin/io/embrace/android/embracesdk/testcases/EmbraceInternalInterfaceTest.kt

@@ -254,7 +254,7 @@ internal class EmbraceInternalInterfaceTest {
 
     companion object {
         private const val URL = "https://embrace.io"
-        private const val START_TIME = 1692201601L
-        private const val END_TIME = 1692202600L
+        private const val START_TIME = 1692201601000L
+        private const val END_TIME = 1692201603000L
     }
 }

embrace-android-sdk/src/integrationTest/kotlin/io/embrace/android/embracesdk/testcases/NetworkRequestApiTest.kt

@@ -343,8 +343,8 @@ internal class NetworkRequestApiTest {
     companion object {
         private const val URL = "https://embrace.io"
         private const val DISABLED_URL = "https://dontlogmebro.pizza/yum"
-        private const val START_TIME = 1692201601L
-        private const val END_TIME = 1692202600L
+        private const val START_TIME = 1692201601000L
+        private const val END_TIME = 1692201603000L
         private const val BYTES_SENT = 100L
         private const val BYTES_RECEIVED = 500L
         private const val TRACE_ID = "rAnDoM-traceId"

embrace-android-sdk/src/main/java/io/embrace/android/embracesdk/clock/Clock.kt

@@ -1,9 +1,12 @@
 package io.embrace.android.embracesdk.clock
 
-internal fun interface Clock {
+import io.embrace.android.embracesdk.InternalApi
+
+@InternalApi
+public fun interface Clock {
 
     /**
      * Returns the current milliseconds from epoch.
      */
-    fun now(): Long
+    public fun now(): Long
 }

embrace-android-sdk/src/main/java/io/embrace/android/embracesdk/clock/SystemClock.kt

@@ -1,6 +1,9 @@
 package io.embrace.android.embracesdk.clock
 
-internal class SystemClock : Clock {
+import io.embrace.android.embracesdk.InternalApi
+
+@InternalApi
+public class SystemClock : Clock {
     override fun now(): Long {
         return System.currentTimeMillis()
     }

embrace-android-sdk/src/test/java/io/embrace/android/embracesdk/network/http/EmbraceUrlConnectionOverrideTest.kt

@@ -31,13 +31,15 @@ internal class EmbraceUrlConnectionOverrideTest {
     private lateinit var capturedEmbraceNetworkRequest: CapturingSlot<EmbraceNetworkRequest>
     private lateinit var embraceUrlConnectionOverride: EmbraceUrlConnectionOverride<HttpsURLConnection>
     private lateinit var embraceUrlConnectionOverrideUnwrapped: EmbraceUrlConnectionOverride<HttpsURLConnection>
+    private var fakeTimeMs = REQUEST_TIME
     private var shouldCaptureNetworkBody = false
     private var isNetworkSpanForwardingEnabled = false
 
     @Before
     fun setup() {
         mockEmbrace = mockk(relaxed = true)
         every { mockEmbrace.internalInterface } answers { mockInternalInterface }
+        fakeTimeMs = REQUEST_TIME
         shouldCaptureNetworkBody = false
         isNetworkSpanForwardingEnabled = false
         capturedCallId = mutableListOf()
@@ -48,6 +50,7 @@ internal class EmbraceUrlConnectionOverrideTest {
             mockInternalInterface.recordAndDeduplicateNetworkRequest(capture(capturedCallId), capture(capturedEmbraceNetworkRequest))
         } answers { }
         every { mockInternalInterface.isNetworkSpanForwardingEnabled() } answers { isNetworkSpanForwardingEnabled }
+        every { mockInternalInterface.getSdkCurrentTime() } answers { fakeTimeMs }
         mockConnection = createMockConnection()
         embraceUrlConnectionOverride = EmbraceUrlConnectionOverride(mockConnection, true, mockEmbrace)
         embraceUrlConnectionOverrideUnwrapped = EmbraceUrlConnectionOverride(mockConnection, false, mockEmbrace)
@@ -59,6 +62,8 @@ internal class EmbraceUrlConnectionOverrideTest {
         verifyTwoCallsRecordedWithSameCallId()
         with(capturedEmbraceNetworkRequest.captured) {
             assertEquals(HttpMethod.POST.name, httpMethod)
+            assertEquals(REQUEST_TIME, startTime)
+            assertEquals(REQUEST_TIME, endTime)
             assertEquals(HTTP_OK, responseCode)
             assertEquals(requestBodySize.toLong(), bytesSent)
             assertEquals(responseBodySize.toLong(), bytesReceived)
@@ -248,6 +253,7 @@ internal class EmbraceUrlConnectionOverrideTest {
     companion object {
         private const val TRACEPARENT = "00-3c72a77a7b51af6fb3778c06d4c165ce-4c1d710fffc88e35-01"
         private const val HTTP_OK = 200
+        private const val REQUEST_TIME = 1692201601000L
         private val requestBody = "test".toByteArray()
         private val requestBodySize = requestBody.size
         private val responseBody = "responseresponse".toByteArray()