chore(android-sqlite): Repair start times of spans generated by SentrySQLiteDriver (JAVA-275)

Repairs the nanoTimetamp of the SentryNanotimeDates used as start times for the spans generated by SentrySQLiteDriver. Without those repairs, all spans within a given wall clock millisecond are displayed by Sentry UI as starting at that same millisecond and are re-ordered arbitrarily. Often that's quite confusing as actual BEGIN -> EXECUTE STATEMENT -> END sequences can appear as EXECUTE STATEMENT -> END -> BEGIN (etc.).

For more details, see the discussion [here](#5504 (comment)).

Author: 0xadam-brown

sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SQLiteSpanManager.kt

@@ -41,10 +41,10 @@ internal class SQLiteSpanManager(
       if (result is CrossProcessCursor) {
         return SentryCrossProcessCursor(result, this, sql) as T
       }
-      spans.recordSpan(sql, startTimestamp, SpanStatus.OK)
+      spans.recordCoarseSpan(sql, startTimestamp, SpanStatus.OK)
       result
     } catch (e: Throwable) {
-      spans.recordSpan(sql, startTimestamp, SpanStatus.INTERNAL_ERROR, e)
+      spans.recordCoarseSpan(sql, startTimestamp, SpanStatus.INTERNAL_ERROR, e)
       throw e
     }
   }

sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt

@@ -1,10 +1,12 @@
 package io.sentry.sqlite
 
 import io.sentry.IScopes
+import io.sentry.ISpan
 import io.sentry.Instrumenter
 import io.sentry.ScopesAdapter
 import io.sentry.SentryDate
 import io.sentry.SentryLongDate
+import io.sentry.SentryNanotimeDate
 import io.sentry.SentryStackTraceFactory
 import io.sentry.SpanDataConvention
 import io.sentry.SpanStatus
@@ -28,36 +30,44 @@ internal class SQLiteSpanInstrumentation(
    */
   fun startTimestamp(): SentryDate = scopes.options.dateProvider.now()
 
-  /** Records a `db.sql.query` span from [startTimestamp] to the moment of invocation. */
+  /** Records a `db.sql.query` span from [startTimestamp] to [startTimestamp] + [durationNanos]. */
   fun recordSpan(
     sql: String,
     startTimestamp: SentryDate,
+    durationNanos: Long,
     status: SpanStatus,
     throwable: Throwable? = null,
   ) {
-    recordSpan(sql, startTimestamp, endTimestamp = null, status, throwable)
+    val parent = scopes.span ?: return
+    val nanoPrecisionStart = startTimestamp.repairPrecision(baseline = parent.startDate)
+    val endTimestamp = SentryLongDate(nanoPrecisionStart.nanoTimestamp() + durationNanos)
+    parent.recordChild(sql, nanoPrecisionStart, endTimestamp, status, throwable)
   }
 
-  /** Records a `db.sql.query` span from [startTimestamp] to [startTimestamp] + [durationNanos]. */
-  fun recordSpan(
+  /**
+   * Records a `db.sql.query` span from [startTimestamp] to the moment of invocation.
+   *
+   * "Coarse" in that it doesn't ensure nanosecond precision for [SentryNanotimeDate]
+   * [startTimestamp]s.
+   */
+  fun recordCoarseSpan(
     sql: String,
     startTimestamp: SentryDate,
-    durationNanos: Long,
     status: SpanStatus,
     throwable: Throwable? = null,
   ) {
-    val endTimestamp = SentryLongDate(startTimestamp.nanoTimestamp() + durationNanos)
-    recordSpan(sql, startTimestamp, endTimestamp, status, throwable)
+    val parent = scopes.span ?: return
+    parent.recordChild(sql, startTimestamp, endTimestamp = null, status, throwable)
   }
 
-  private fun recordSpan(
+  private fun ISpan.recordChild(
     sql: String,
     startTimestamp: SentryDate,
     endTimestamp: SentryDate?,
     status: SpanStatus,
     throwable: Throwable?,
   ) {
-    scopes.span?.startChild("db.sql.query", sql, startTimestamp, Instrumenter.SENTRY)?.apply {
+    startChild("db.sql.query", sql, startTimestamp, Instrumenter.SENTRY).apply {
       spanContext.origin = SQLITE_TRACE_ORIGIN
       throwable?.let { this.throwable = it }
 
@@ -74,6 +84,38 @@ internal class SQLiteSpanInstrumentation(
     }
   }
 
+  /**
+   * Repairs the receiver's [nanoTimestamp][SentryDate.nanoTimestamp] if needed so that it actually
+   * has nanosecond precision.
+   *
+   * Designed for use with spans whose start timestamps are [SentryNanotimeDate]s. Without repair,
+   * those timestamps will be aligned to the same millisecond at transport, and the Sentry UI will
+   * arbitrarily reorder them:
+   * ```
+   * Parent span                 ├█████████████┤
+   * END TRANSACTION              ├███┤          0.18 ms  ← (Wrong order)
+   * BEGIN IMMEDIATE TRANSACTION  ├████┤         0.25 ms
+   * INSERT INTO `my_db` …        ├██┤           0.10 ms
+   *                              ↑
+   *               (All spans share the same ms baseline
+   *             even though their execution was staggered)
+   * ```
+   *
+   * Repair ensures proper ordering and lets the spans stagger:
+   * ```
+   * Parent span                 ├█████████████┤
+   * BEGIN IMMEDIATE TRANSACTION  ├████┤         0.25 ms
+   * INSERT INTO `my_db` …              ├██┤     0.10 ms
+   * END TRANSACTION                     ├███┤   0.18 ms
+   * ```
+   */
+  private fun SentryDate.repairPrecision(baseline: SentryDate?): SentryDate =
+    if (baseline is SentryNanotimeDate) {
+      SentryLongDate(baseline.laterDateNanosTimestampByDiff(this))
+    } else {
+      this
+    }
+
   companion object {
 
     fun fromDatabaseName(databaseName: String?, scopes: IScopes = ScopesAdapter.getInstance()) =