Only log startup moment span if it's not triggered by a lateness timer (

#46) ## Goal Only log a span for the startup moment if it's not "late" ## Testing Restored functional tests and add unit test
embrace-io · Nov 7, 2023 · 5b97785 · 5b97785
2 parents ce8a627 + 8afa208
commit 5b97785
Show file tree

Hide file tree

Showing 3 changed files with 84 additions and 10 deletions.
diff --git a/embrace-android-sdk/src/androidTest/assets/golden-files/session-end.json b/embrace-android-sdk/src/androidTest/assets/golden-files/session-end.json
@@ -105,6 +105,59 @@
     "un": "John Doe",
     "per": ["first_day"]
   },
-  "spans": "__EMBRACE_TEST_IGNORE__",
+  "spans": [
+    {
+      "attributes": {
+        "emb.sequence_id": "2",
+        "emb.private": "true",
+        "emb.key": "true",
+        "emb.type": "PERFORMANCE"
+      },
+      "end_time_unix_nano": "__EMBRACE_TEST_IGNORE__",
+      "events": [
+        {
+          "attributes": {},
+          "name": "start-time",
+          "time_unix_nano": "__EMBRACE_TEST_IGNORE__"
+        }
+      ],
+      "name": "emb-sdk-init",
+      "parent_span_id": "0000000000000000",
+      "span_id": "__EMBRACE_TEST_IGNORE__",
+      "start_time_unix_nano": "__EMBRACE_TEST_IGNORE__",
+      "status": "OK",
+      "trace_id": "__EMBRACE_TEST_IGNORE__"
+    },
+    {
+      "attributes": {
+        "emb.sequence_id": "3",
+        "emb.key": "true",
+        "emb.type": "PERFORMANCE"
+      },
+      "end_time_unix_nano": "__EMBRACE_TEST_IGNORE__",
+      "events": [],
+      "name": "emb-startup-moment",
+      "parent_span_id": "0000000000000000",
+      "span_id": "__EMBRACE_TEST_IGNORE__",
+      "start_time_unix_nano": "__EMBRACE_TEST_IGNORE__",
+      "status": "OK",
+      "trace_id": "__EMBRACE_TEST_IGNORE__"
+    },
+    {
+      "attributes": {
+        "emb.sequence_id": "1",
+        "emb.private": "true",
+        "emb.type": "SESSION"
+      },
+      "end_time_unix_nano": "__EMBRACE_TEST_IGNORE__",
+      "events": [],
+      "name": "emb-session-span",
+      "parent_span_id": "0000000000000000",
+      "span_id": "__EMBRACE_TEST_IGNORE__",
+      "start_time_unix_nano": "__EMBRACE_TEST_IGNORE__",
+      "status": "OK",
+      "trace_id": "__EMBRACE_TEST_IGNORE__"
+    }
+  ],
   "v": 13
 }
diff --git a/embrace-android-sdk/src/main/java/io/embrace/android/embracesdk/event/EmbraceEventService.kt b/embrace-android-sdk/src/main/java/io/embrace/android/embracesdk/event/EmbraceEventService.kt
@@ -234,7 +234,9 @@ internal class EmbraceEventService(
                 sessionProperties
             )
             if (isStartupEvent(name)) {
-                logStartupSpan()
+                if (!late) {
+                    logStartupSpan()
+                }
                 logDeveloper("EmbraceEventService", "Ending Startup Ending")
                 startupEventInfo = eventHandler.buildStartupEventInfo(
                     originEventDescription.event,

diff --git a/...-android-sdk/src/test/java/io/embrace/android/embracesdk/event/EmbraceEventServiceTest.kt b/...-android-sdk/src/test/java/io/embrace/android/embracesdk/event/EmbraceEventServiceTest.kt
@@ -115,7 +115,7 @@ internal class EmbraceEventServiceTest {
             configService
         )
         gatingService = FakeGatingService(configService)
-        fakeWorkerThreadModule = FakeWorkerThreadModule(blockingMode = true)
+        fakeWorkerThreadModule = FakeWorkerThreadModule(clock = fakeClock, blockingMode = true)
         spansService = EmbraceSpansService(clock = OpenTelemetryClock(embraceClock = fakeClock))
         configService.addListener(spansService)
         eventHandler = EventHandler(
@@ -431,9 +431,9 @@ internal class EmbraceEventServiceTest {
         eventService.applicationStartupComplete()
         val executor = fakeWorkerThreadModule.backgroundExecutor(ExecutorName.BACKGROUND_REGISTRATION)
         executor.runCurrentlyBlocked()
-        assertEquals(1, spansService.completedSpans()?.size)
-        val startupSpan = spansService.completedSpans()!![0]
-        with(startupSpan) {
+        val completedSpans = checkNotNull(spansService.completedSpans())
+        assertEquals(1, completedSpans.size)
+        with(completedSpans[0]) {
             assertEquals("emb-startup-moment", name)
             assertEquals(TimeUnit.MILLISECONDS.toNanos(1), startTimeNanos)
             assertEquals(TimeUnit.MILLISECONDS.toNanos(10), endTimeNanos)
@@ -453,18 +453,37 @@ internal class EmbraceEventServiceTest {
         eventService.applicationStartupComplete()
         val executor = fakeWorkerThreadModule.backgroundExecutor(ExecutorName.BACKGROUND_REGISTRATION)
         executor.runCurrentlyBlocked()
-        assertEquals(0, spansService.completedSpans()?.size)
+        val completedSpans = checkNotNull(spansService.completedSpans())
+        assertEquals(0, completedSpans.size)
 
         fakeClock.setCurrentTime(20L)
         eventService.endEvent(STARTUP_EVENT_NAME)
         executor.runCurrentlyBlocked()
-        assertEquals(1, spansService.completedSpans()?.size)
+        val completedSpansAgain = checkNotNull(spansService.completedSpans())
+        assertEquals(1, completedSpansAgain.size)
 
-        val startupSpan = spansService.completedSpans()!![0]
-        with(startupSpan) {
+        with(completedSpansAgain[0]) {
             assertEquals("emb-startup-moment", name)
             assertEquals(TimeUnit.MILLISECONDS.toNanos(1), startTimeNanos)
             assertEquals(TimeUnit.MILLISECONDS.toNanos(20), endTimeNanos)
         }
     }
+
+    @Test
+    fun `startup not logged as span if startup moment is ended via a timeout`() {
+        spansService.initializeService(
+            sdkInitStartTimeNanos = TimeUnit.MILLISECONDS.toNanos(1),
+            sdkInitEndTimeNanos = TimeUnit.MILLISECONDS.toNanos(3)
+        )
+        configService.updateListeners()
+        spansService.flushSpans()
+        eventService.sendStartupMoment()
+        assertNull(eventService.getStartupMomentInfo())
+        fakeClock.tick(10000L)
+        fakeWorkerThreadModule.backgroundExecutor(ExecutorName.BACKGROUND_REGISTRATION).runCurrentlyBlocked()
+        fakeWorkerThreadModule.scheduledExecutor(ExecutorName.SCHEDULED_REGISTRATION).runCurrentlyBlocked()
+        assertNotNull(eventService.getStartupMomentInfo())
+        val completedSpans = checkNotNull(spansService.completedSpans())
+        assertEquals(0, completedSpans.size)
+    }
 }