From 8d18e1c7a467559adcf6731f04f310f91a339ebc Mon Sep 17 00:00:00 2001 From: Adam Brown Date: Fri, 12 Jun 2026 12:07:15 +0200 Subject: [PATCH 1/4] 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](https://github.com/getsentry/sentry-java/pull/5504#issuecomment-4679631245). --- .../android/sqlite/SQLiteSpanManager.kt | 4 +- .../sqlite/SQLiteSpanInstrumentation.kt | 60 +++- .../sqlite/SQLiteSpanInstrumentationTest.kt | 279 +++++++++++++++++- 3 files changed, 325 insertions(+), 18 deletions(-) diff --git a/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SQLiteSpanManager.kt b/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SQLiteSpanManager.kt index 3495d3a71f..bed16fb57a 100644 --- a/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SQLiteSpanManager.kt +++ b/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 } } diff --git a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt index 4c925198bd..6180b6c033 100644 --- a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt +++ b/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 { /** diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt index ead123a190..c60446c2da 100644 --- a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt +++ b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt @@ -1,12 +1,15 @@ package io.sentry.sqlite import io.sentry.IScopes +import io.sentry.SentryDateProvider +import io.sentry.SentryNanotimeDate import io.sentry.SentryOptions import io.sentry.SentryTracer import io.sentry.SpanDataConvention import io.sentry.SpanStatus import io.sentry.TransactionContext import io.sentry.util.thread.IThreadChecker +import java.util.Date import kotlin.test.Test import kotlin.test.assertEquals import kotlin.test.assertFalse @@ -79,7 +82,6 @@ class SQLiteSpanInstrumentationTest { sut.recordSpan("SELECT 1", start, durationNanos, SpanStatus.OK) val span = fixture.sentryTracer.children.first() - assertEquals(start, span.startDate) assertEquals(span.startDate.nanoTimestamp() + durationNanos, span.finishDate!!.nanoTimestamp()) } @@ -147,11 +149,130 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `recordSpan without a duration finishes the span at the time of invocation`() { + fun `recordSpan repairs start precision when parent uses SentryNanotimeDate`() { + val sameMillis = Date(1_000_000L) + val parentNanos = 100_000_000L + val childNanos = 100_500_000L + + val sut = + setUpWithNanotimeDates( + SentryNanotimeDate(sameMillis, parentNanos), + SentryNanotimeDate(sameMillis, childNanos), + ) + val start = sut.startTimestamp() + val durationNanos = 42_000_000L + + sut.recordSpan("SELECT 1", start, durationNanos, SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + + val parentStart = fixture.sentryTracer.startDate + val expectedStart = parentStart.laterDateNanosTimestampByDiff(start) + assertEquals(expectedStart, span.startDate.nanoTimestamp()) + assertEquals(expectedStart + durationNanos, span.finishDate!!.nanoTimestamp()) + } + + @Test + fun `recordSpan gives distinct ordered starts within the same millisecond`() { + val sameMillis = Date(1_000_000L) + val parentNanos = 100_000_000L + val child1Nanos = 100_200_000L + val child2Nanos = 100_800_000L + + val sut = + setUpWithNanotimeDates( + SentryNanotimeDate(sameMillis, parentNanos), + SentryNanotimeDate(sameMillis, child1Nanos), + SentryNanotimeDate(sameMillis, child2Nanos), + ) + val start1 = sut.startTimestamp() + val start2 = sut.startTimestamp() + + assertEquals( + start1.nanoTimestamp(), + start2.nanoTimestamp(), + "Raw starts share the same ms-quantized timestamp", + ) + + sut.recordSpan("SELECT 1", start1, 1_000_000, SpanStatus.OK) + sut.recordSpan("SELECT 2", start2, 1_000_000, SpanStatus.OK) + + val span1 = fixture.sentryTracer.children[0] + val span2 = fixture.sentryTracer.children[1] + + assertTrue( + span1.startDate.nanoTimestamp() < span2.startDate.nanoTimestamp(), + "Repaired starts should be distinct and ordered", + ) + } + + @Test + fun `recordSpan preserves exact duration after precision repair`() { + val sameMillis = Date(1_000_000L) + val sut = + setUpWithNanotimeDates( + SentryNanotimeDate(sameMillis, 100_000_000L), + SentryNanotimeDate(sameMillis, 100_750_000L), + ) + val start = sut.startTimestamp() + val durationNanos = 123_456L + + sut.recordSpan("SELECT 1", start, durationNanos, SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + val actualDuration = span.finishDate!!.nanoTimestamp() - span.startDate.nanoTimestamp() + assertEquals(durationNanos, actualDuration) + } + + @Test + fun `recordSpan does not repair start when parent is not SentryNanotimeDate`() { + val sut = fixture.getSut(isTransactionActive = true) + val start = sut.startTimestamp() + val durationNanos = 1_000_000L + + sut.recordSpan("SELECT 1", start, durationNanos, SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + assertEquals(start.nanoTimestamp(), span.startDate.nanoTimestamp()) + assertEquals(start.nanoTimestamp() + durationNanos, span.finishDate!!.nanoTimestamp()) + } + + @Test + fun `recordCoarseSpan records a span if a transaction is active`() { + val sut = fixture.getSut(isTransactionActive = true) + sut.recordCoarseSpan("SELECT 1", sut.startTimestamp(), SpanStatus.OK) + assertEquals(1, fixture.sentryTracer.children.size) + } + + @Test + fun `recordCoarseSpan does not record a span if no transaction is active`() { + val sut = fixture.getSut(isTransactionActive = false) + val start = sut.startTimestamp() + sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) + assertEquals(0, fixture.sentryTracer.children.size) + } + + @Test + fun `recordCoarseSpan creates a span with correct properties`() { val sut = fixture.getSut() val start = sut.startTimestamp() + sut.recordCoarseSpan("SELECT * FROM users", start, SpanStatus.OK) - sut.recordSpan("SELECT 1", start, SpanStatus.OK) + val span = fixture.sentryTracer.children.firstOrNull() + assertNotNull(span) + assertEquals("db.sql.query", span.operation) + assertEquals("SELECT * FROM users", span.description) + assertEquals("auto.db.sqlite", span.spanContext.origin) + assertEquals(SpanStatus.OK, span.status) + assertTrue(span.isFinished) + } + + @Test + fun `recordCoarseSpan finishes the span at the time of invocation`() { + val sut = fixture.getSut() + val start = sut.startTimestamp() + + sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) val span = fixture.sentryTracer.children.first() assertTrue(span.isFinished) @@ -162,14 +283,144 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `fromFileName sets db name from fileName`() { + fun `recordCoarseSpan attaches throwable when provided`() { + val sut = fixture.getSut() + val start = sut.startTimestamp() + val exception = RuntimeException("disk I/O error") + + sut.recordCoarseSpan("INSERT INTO t VALUES(1)", start, SpanStatus.INTERNAL_ERROR, exception) + + val span = fixture.sentryTracer.children.first() + assertEquals(SpanStatus.INTERNAL_ERROR, span.status) + assertEquals(exception, span.throwable) + } + + @Test + fun `recordCoarseSpan sets db system and db name when fileName is not the in-memory sentinel`() { + val sut = fixture.getSut(fileName = "/data/data/com.example/databases/tracks.db") + val start = sut.startTimestamp() + sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) + assertEquals("tracks.db", span.data[SpanDataConvention.DB_NAME_KEY]) + } + + @Test + fun `recordCoarseSpan sets db system only when fileName is the in-memory sentinel`() { + val sut = fixture.getSut(fileName = ":memory:") + val start = sut.startTimestamp() + sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + assertEquals("in-memory", span.data[SpanDataConvention.DB_SYSTEM_KEY]) + assertNull(span.data[SpanDataConvention.DB_NAME_KEY]) + } + + @Test + fun `recordCoarseSpan sets blocked_main_thread to true and attaches call stack on main thread`() { + val sut = fixture.getSut() + fixture.options.threadChecker = mock() + whenever(fixture.options.threadChecker.isMainThread).thenReturn(true) + whenever(fixture.options.threadChecker.currentThreadName).thenReturn("main") + + sut.recordCoarseSpan("SELECT 1", sut.startTimestamp(), SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + assertTrue(span.getData(SpanDataConvention.BLOCKED_MAIN_THREAD_KEY) as Boolean) + assertNotNull(span.getData(SpanDataConvention.CALL_STACK_KEY)) + } + + @Test + fun `recordCoarseSpan sets blocked_main_thread to false and does not attach a call stack on background thread`() { + val sut = fixture.getSut() + fixture.options.threadChecker = mock() + whenever(fixture.options.threadChecker.isMainThread).thenReturn(false) + whenever(fixture.options.threadChecker.currentThreadName).thenReturn("worker") + + sut.recordCoarseSpan("SELECT 1", sut.startTimestamp(), SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + assertFalse(span.getData(SpanDataConvention.BLOCKED_MAIN_THREAD_KEY) as Boolean) + assertNull(span.getData(SpanDataConvention.CALL_STACK_KEY)) + } + + @Test + fun `recordCoarseSpan does not repair start precision when parent uses SentryNanotimeDate`() { + val sameMillis = Date(1_000_000L) + val parentNanos = 100_000_000L + val childNanos = 100_500_000L + + val finishNanos = 100_900_000L + val sut = + setUpWithNanotimeDates( + SentryNanotimeDate(sameMillis, parentNanos), + SentryNanotimeDate(sameMillis, childNanos), + SentryNanotimeDate(sameMillis, finishNanos), + ) + val start = sut.startTimestamp() + + sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + assertEquals(start.nanoTimestamp(), span.startDate.nanoTimestamp()) + assertTrue(span.finishDate!!.nanoTimestamp() >= span.startDate.nanoTimestamp()) + } + + @Test + fun `recordCoarseSpan does not repair start when parent is not SentryNanotimeDate`() { + val sut = fixture.getSut(isTransactionActive = true) + val start = sut.startTimestamp() + + sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + assertEquals(start.nanoTimestamp(), span.startDate.nanoTimestamp()) + assertTrue(span.finishDate!!.nanoTimestamp() >= start.nanoTimestamp()) + } + + @Test + fun `fromFileName sets db name from fileName when using recordSpan`() { + val options = SentryOptions().apply { dsn = "https://key@sentry.io/proj" } + whenever(fixture.scopes.options).thenReturn(options) + fixture.sentryTracer = SentryTracer(TransactionContext("name", "op"), fixture.scopes) + whenever(fixture.scopes.span).thenReturn(fixture.sentryTracer) + + val sut = SQLiteSpanInstrumentation.fromFileName("tracks.db", fixture.scopes) + val start = sut.startTimestamp() + sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) + assertEquals("tracks.db", span.data[SpanDataConvention.DB_NAME_KEY]) + } + + @Test + fun `fromDatabaseName sets db name from databaseName when using recordSpan`() { + val options = SentryOptions().apply { dsn = "https://key@sentry.io/proj" } + whenever(fixture.scopes.options).thenReturn(options) + fixture.sentryTracer = SentryTracer(TransactionContext("name", "op"), fixture.scopes) + whenever(fixture.scopes.span).thenReturn(fixture.sentryTracer) + + val sut = SQLiteSpanInstrumentation.fromDatabaseName("tracks.db", fixture.scopes) + val start = sut.startTimestamp() + sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) + + val span = fixture.sentryTracer.children.first() + assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) + assertEquals("tracks.db", span.data[SpanDataConvention.DB_NAME_KEY]) + } + + @Test + fun `fromFileName sets db name from fileName when using recordCoarseSpan`() { val options = SentryOptions().apply { dsn = "https://key@sentry.io/proj" } whenever(fixture.scopes.options).thenReturn(options) fixture.sentryTracer = SentryTracer(TransactionContext("name", "op"), fixture.scopes) whenever(fixture.scopes.span).thenReturn(fixture.sentryTracer) val sut = SQLiteSpanInstrumentation.fromFileName("tracks.db", fixture.scopes) - sut.recordSpan("SELECT 1", sut.startTimestamp(), SpanStatus.OK) + val start = sut.startTimestamp() + sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) val span = fixture.sentryTracer.children.first() assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) @@ -177,17 +428,31 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `fromDatabaseName sets db name from databaseName`() { + fun `fromDatabaseName sets db name from databaseName when using recordCoarseSpan`() { val options = SentryOptions().apply { dsn = "https://key@sentry.io/proj" } whenever(fixture.scopes.options).thenReturn(options) fixture.sentryTracer = SentryTracer(TransactionContext("name", "op"), fixture.scopes) whenever(fixture.scopes.span).thenReturn(fixture.sentryTracer) val sut = SQLiteSpanInstrumentation.fromDatabaseName("tracks.db", fixture.scopes) - sut.recordSpan("SELECT 1", sut.startTimestamp(), SpanStatus.OK) + val start = sut.startTimestamp() + sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) val span = fixture.sentryTracer.children.first() assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) assertEquals("tracks.db", span.data[SpanDataConvention.DB_NAME_KEY]) } + + private fun setUpWithNanotimeDates(vararg dates: SentryNanotimeDate): SQLiteSpanInstrumentation { + val dateQueue = ArrayDeque(dates.toList()) + val options = + SentryOptions().apply { + dsn = "https://key@sentry.io/proj" + dateProvider = SentryDateProvider { dateQueue.removeFirst() } + } + whenever(fixture.scopes.options).thenReturn(options) + fixture.sentryTracer = SentryTracer(TransactionContext("name", "op"), fixture.scopes) + whenever(fixture.scopes.span).thenReturn(fixture.sentryTracer) + return SQLiteSpanInstrumentation.fromFileName(":memory:", fixture.scopes) + } } From 3eb3a3f1efd9685a7228d6fdd31bc4dd658e6e63 Mon Sep 17 00:00:00 2001 From: Adam Brown Date: Tue, 16 Jun 2026 09:32:59 +0200 Subject: [PATCH 2/4] Make repair method internal + add unit tests --- .../sqlite/SQLiteSpanInstrumentation.kt | 75 ++++++++-------- .../io/sentry/sqlite/RepairPrecisionTest.kt | 90 +++++++++++++++++++ .../sqlite/SQLiteSpanInstrumentationTest.kt | 87 ++---------------- 3 files changed, 138 insertions(+), 114 deletions(-) create mode 100644 sentry-android-sqlite/src/test/java/io/sentry/sqlite/RepairPrecisionTest.kt diff --git a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt index 6180b6c033..18690b0f12 100644 --- a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt +++ b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt @@ -39,7 +39,7 @@ internal class SQLiteSpanInstrumentation( throwable: Throwable? = null, ) { val parent = scopes.span ?: return - val nanoPrecisionStart = startTimestamp.repairPrecision(baseline = parent.startDate) + val nanoPrecisionStart = startTimestamp.repairPrecision(anchor = parent.startDate) val endTimestamp = SentryLongDate(nanoPrecisionStart.nanoTimestamp() + durationNanos) parent.recordChild(sql, nanoPrecisionStart, endTimestamp, status, throwable) } @@ -47,8 +47,9 @@ internal class SQLiteSpanInstrumentation( /** * 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. + * "Coarse" in that it doesn't try to restore nanosecond precision for the start timestamp. Spans + * that start within the same wall clock millisecond will share the same start time and may be + * arbitrarily re-ordered by the Sentry UI. */ fun recordCoarseSpan( sql: String, @@ -84,38 +85,6 @@ 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 { /** @@ -139,3 +108,39 @@ internal class SQLiteSpanInstrumentation( SQLiteSpanInstrumentation(scopes, dbMetadataFromDatabaseName(databaseName)) } } + +/** + * 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: + * ``` + * (Relative start times out of order) + * ↓ + * Parent span ├█████████████┤ + * END TRANSACTION ├███┤ 0.33 ms + * BEGIN IMMEDIATE TRANSACTION ├████┤ 0.02 ms + * INSERT INTO `my_db` … ├██┤ 0.30 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.02 ms + * INSERT INTO `my_db` … ├██┤ 0.30 ms + * END TRANSACTION ├███┤ 0.33 ms + * ``` + */ +internal fun SentryDate.repairPrecision(anchor: SentryDate?): SentryDate = + if (anchor is SentryNanotimeDate) { + // Compute a new timestamp with nanosecond precision by using the anchor as the epoch instant + // and adding to it the diff of this.nanos - anchor.nanos. + SentryLongDate(anchor.laterDateNanosTimestampByDiff(this)) + } else { + this + } diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/RepairPrecisionTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/RepairPrecisionTest.kt new file mode 100644 index 0000000000..c0341bcdb4 --- /dev/null +++ b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/RepairPrecisionTest.kt @@ -0,0 +1,90 @@ +package io.sentry.sqlite + +import io.sentry.DateUtils +import io.sentry.SentryLongDate +import io.sentry.SentryNanotimeDate +import java.util.Date +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertIs +import kotlin.test.assertSame + +class RepairPrecisionTest { + + @Test + fun `repairs timestamp precision using nanotime diff from anchor`() { + val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) + val date = SentryNanotimeDate(Date(1_000_000L), 100_500_000L) + + val repaired = date.repairPrecision(anchor) + + assertIs(repaired) + val anchorNanoTimestamp = DateUtils.millisToNanos(1_000_000L) + assertEquals(anchorNanoTimestamp + 500_000L, repaired.nanoTimestamp()) + } + + @Test + fun `two dates in the same millisecond produce distinct ordered timestamps`() { + val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) + val earlier = SentryNanotimeDate(Date(1_000_000L), 100_200_000L) + val later = SentryNanotimeDate(Date(1_000_000L), 100_800_000L) + + assertEquals( + earlier.nanoTimestamp(), + later.nanoTimestamp(), + "Raw timestamps share the same ms-quantized value", + ) + + val anchorNanoTimestamp = DateUtils.millisToNanos(1_000_000L) + val repairedEarlier = earlier.repairPrecision(anchor) + val repairedLater = later.repairPrecision(anchor) + assertEquals(anchorNanoTimestamp + 200_000L, repairedEarlier.nanoTimestamp()) + assertEquals(anchorNanoTimestamp + 800_000L, repairedLater.nanoTimestamp()) + } + + @Test + fun `returns anchor nano timestamp when date matches anchor nanos`() { + val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) + val date = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) + + val repaired = date.repairPrecision(anchor) + + assertIs(repaired) + assertEquals(anchor.nanoTimestamp(), repaired.nanoTimestamp()) + } + + @Test + fun `repairs SentryLongDate receiver to anchor millisecond baseline`() { + val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) + val date = SentryLongDate(DateUtils.millisToNanos(1_000_000L)) + + val repaired = date.repairPrecision(anchor) + + assertIs(repaired) + assertEquals(anchor.nanoTimestamp(), repaired.nanoTimestamp()) + } + + @Test + fun `works when date and anchor span have different wall clock times`() { + val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) + val date = SentryNanotimeDate(Date(1_000_001L), 101_500_000L) + + val repaired = date.repairPrecision(anchor) + + val anchorNanoTimestamp = DateUtils.millisToNanos(1_000_000L) + assertEquals(anchorNanoTimestamp + 1_500_000L, repaired.nanoTimestamp()) + } + + @Test + fun `returns self when anchor is not SentryNanotimeDate`() { + val date = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) + val anchor = SentryLongDate(DateUtils.millisToNanos(1_000_000L)) + assertSame(date, date.repairPrecision(anchor = anchor)) + } + + @Test + fun `returns self when anchor is null`() { + val date = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) + assertSame(date, date.repairPrecision(anchor = null)) + } +} diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt index c60446c2da..6e4b6921cd 100644 --- a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt +++ b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt @@ -2,6 +2,7 @@ package io.sentry.sqlite import io.sentry.IScopes import io.sentry.SentryDateProvider +import io.sentry.SentryLongDate import io.sentry.SentryNanotimeDate import io.sentry.SentryOptions import io.sentry.SentryTracer @@ -13,6 +14,7 @@ import java.util.Date import kotlin.test.Test import kotlin.test.assertEquals import kotlin.test.assertFalse +import kotlin.test.assertIs import kotlin.test.assertNotNull import kotlin.test.assertNull import kotlin.test.assertTrue @@ -149,7 +151,7 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `recordSpan repairs start precision when parent uses SentryNanotimeDate`() { + fun `recordSpan repairs start precision`() { val sameMillis = Date(1_000_000L) val parentNanos = 100_000_000L val childNanos = 100_500_000L @@ -168,75 +170,14 @@ class SQLiteSpanInstrumentationTest { val parentStart = fixture.sentryTracer.startDate val expectedStart = parentStart.laterDateNanosTimestampByDiff(start) + // Child and parent share the same ms-quantized baseline; repair adds nanosecond offset. + assertEquals(parentStart.nanoTimestamp(), start.nanoTimestamp()) + assertTrue(start.nanoTimestamp() != expectedStart) + assertIs(span.startDate) assertEquals(expectedStart, span.startDate.nanoTimestamp()) assertEquals(expectedStart + durationNanos, span.finishDate!!.nanoTimestamp()) } - @Test - fun `recordSpan gives distinct ordered starts within the same millisecond`() { - val sameMillis = Date(1_000_000L) - val parentNanos = 100_000_000L - val child1Nanos = 100_200_000L - val child2Nanos = 100_800_000L - - val sut = - setUpWithNanotimeDates( - SentryNanotimeDate(sameMillis, parentNanos), - SentryNanotimeDate(sameMillis, child1Nanos), - SentryNanotimeDate(sameMillis, child2Nanos), - ) - val start1 = sut.startTimestamp() - val start2 = sut.startTimestamp() - - assertEquals( - start1.nanoTimestamp(), - start2.nanoTimestamp(), - "Raw starts share the same ms-quantized timestamp", - ) - - sut.recordSpan("SELECT 1", start1, 1_000_000, SpanStatus.OK) - sut.recordSpan("SELECT 2", start2, 1_000_000, SpanStatus.OK) - - val span1 = fixture.sentryTracer.children[0] - val span2 = fixture.sentryTracer.children[1] - - assertTrue( - span1.startDate.nanoTimestamp() < span2.startDate.nanoTimestamp(), - "Repaired starts should be distinct and ordered", - ) - } - - @Test - fun `recordSpan preserves exact duration after precision repair`() { - val sameMillis = Date(1_000_000L) - val sut = - setUpWithNanotimeDates( - SentryNanotimeDate(sameMillis, 100_000_000L), - SentryNanotimeDate(sameMillis, 100_750_000L), - ) - val start = sut.startTimestamp() - val durationNanos = 123_456L - - sut.recordSpan("SELECT 1", start, durationNanos, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - val actualDuration = span.finishDate!!.nanoTimestamp() - span.startDate.nanoTimestamp() - assertEquals(durationNanos, actualDuration) - } - - @Test - fun `recordSpan does not repair start when parent is not SentryNanotimeDate`() { - val sut = fixture.getSut(isTransactionActive = true) - val start = sut.startTimestamp() - val durationNanos = 1_000_000L - - sut.recordSpan("SELECT 1", start, durationNanos, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertEquals(start.nanoTimestamp(), span.startDate.nanoTimestamp()) - assertEquals(start.nanoTimestamp() + durationNanos, span.finishDate!!.nanoTimestamp()) - } - @Test fun `recordCoarseSpan records a span if a transaction is active`() { val sut = fixture.getSut(isTransactionActive = true) @@ -346,7 +287,7 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `recordCoarseSpan does not repair start precision when parent uses SentryNanotimeDate`() { + fun `recordCoarseSpan does not repair start precision`() { val sameMillis = Date(1_000_000L) val parentNanos = 100_000_000L val childNanos = 100_500_000L @@ -367,18 +308,6 @@ class SQLiteSpanInstrumentationTest { assertTrue(span.finishDate!!.nanoTimestamp() >= span.startDate.nanoTimestamp()) } - @Test - fun `recordCoarseSpan does not repair start when parent is not SentryNanotimeDate`() { - val sut = fixture.getSut(isTransactionActive = true) - val start = sut.startTimestamp() - - sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertEquals(start.nanoTimestamp(), span.startDate.nanoTimestamp()) - assertTrue(span.finishDate!!.nanoTimestamp() >= start.nanoTimestamp()) - } - @Test fun `fromFileName sets db name from fileName when using recordSpan`() { val options = SentryOptions().apply { dsn = "https://key@sentry.io/proj" } From 776deac39ba92a65ba8bd431c8aae3a043d8e665 Mon Sep 17 00:00:00 2001 From: Adam Brown Date: Tue, 16 Jun 2026 15:28:42 +0200 Subject: [PATCH 3/4] SQLiteSpanInstrumentation.startTimestamp() now returns Long + skips SentryDate allocation --- .../android/sqlite/SQLiteSpanManager.kt | 43 ++- .../main/java/io/sentry/sqlite/DbMetadata.kt | 11 - .../sqlite/SQLiteSpanInstrumentation.kt | 98 +++--- .../io/sentry/sqlite/SentrySQLiteStatement.kt | 13 +- .../sqlite/ChildStartTimestampOrNullTest.kt | 100 +++++++ .../java/io/sentry/sqlite/DbMetadataTest.kt | 8 - .../io/sentry/sqlite/RepairPrecisionTest.kt | 90 ------ .../sqlite/SQLiteSpanInstrumentationTest.kt | 278 ++++-------------- .../sqlite/SentrySQLiteStatementTest.kt | 9 +- 9 files changed, 240 insertions(+), 410 deletions(-) create mode 100644 sentry-android-sqlite/src/test/java/io/sentry/sqlite/ChildStartTimestampOrNullTest.kt delete mode 100644 sentry-android-sqlite/src/test/java/io/sentry/sqlite/RepairPrecisionTest.kt diff --git a/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SQLiteSpanManager.kt b/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SQLiteSpanManager.kt index bed16fb57a..1bdeb7d369 100644 --- a/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SQLiteSpanManager.kt +++ b/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SQLiteSpanManager.kt @@ -3,17 +3,21 @@ package io.sentry.android.sqlite import android.database.CrossProcessCursor import android.database.SQLException import io.sentry.IScopes +import io.sentry.ISpan +import io.sentry.Instrumenter import io.sentry.ScopesAdapter import io.sentry.SentryIntegrationPackageStorage +import io.sentry.SentryStackTraceFactory +import io.sentry.SpanDataConvention import io.sentry.SpanStatus -import io.sentry.sqlite.SQLiteSpanInstrumentation + +private const val TRACE_ORIGIN = "auto.db.sqlite" internal class SQLiteSpanManager( private val scopes: IScopes = ScopesAdapter.getInstance(), - databaseName: String? = null, + private val databaseName: String? = null, ) { - - private val spans = SQLiteSpanInstrumentation.fromDatabaseName(databaseName, scopes) + private val stackTraceFactory = SentryStackTraceFactory(scopes.options) init { SentryIntegrationPackageStorage.getInstance().addIntegration("SQLite") @@ -29,8 +33,8 @@ internal class SQLiteSpanManager( @Suppress("TooGenericExceptionCaught", "UNCHECKED_CAST") @Throws(SQLException::class) fun performSql(sql: String, operation: () -> T): T { - val startTimestamp = spans.startTimestamp() - + val startTimestamp = scopes.getOptions().dateProvider.now() + var span: ISpan? = null return try { val result = operation() /* @@ -41,11 +45,34 @@ internal class SQLiteSpanManager( if (result is CrossProcessCursor) { return SentryCrossProcessCursor(result, this, sql) as T } - spans.recordCoarseSpan(sql, startTimestamp, SpanStatus.OK) + span = scopes.span?.startChild("db.sql.query", sql, startTimestamp, Instrumenter.SENTRY) + span?.spanContext?.origin = TRACE_ORIGIN + span?.status = SpanStatus.OK result } catch (e: Throwable) { - spans.recordCoarseSpan(sql, startTimestamp, SpanStatus.INTERNAL_ERROR, e) + span = scopes.span?.startChild("db.sql.query", sql, startTimestamp, Instrumenter.SENTRY) + span?.spanContext?.origin = TRACE_ORIGIN + span?.status = SpanStatus.INTERNAL_ERROR + span?.throwable = e throw e + } finally { + span?.apply { + val isMainThread: Boolean = scopes.options.threadChecker.isMainThread + setData(SpanDataConvention.BLOCKED_MAIN_THREAD_KEY, isMainThread) + if (isMainThread) { + setData(SpanDataConvention.CALL_STACK_KEY, stackTraceFactory.inAppCallStack) + } + // if db name is null, then it's an in-memory database as per + // https://cs.android.com/androidx/platform/frameworks/support/+/androidx-main:sqlite/sqlite/src/main/java/androidx/sqlite/db/SupportSQLiteOpenHelper.kt;l=38-42 + if (databaseName != null) { + setData(SpanDataConvention.DB_SYSTEM_KEY, "sqlite") + setData(SpanDataConvention.DB_NAME_KEY, databaseName) + } else { + setData(SpanDataConvention.DB_SYSTEM_KEY, "in-memory") + } + + finish() + } } } } diff --git a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/DbMetadata.kt b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/DbMetadata.kt index aa3c186b6d..598dc524ed 100644 --- a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/DbMetadata.kt +++ b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/DbMetadata.kt @@ -36,14 +36,3 @@ internal fun dbMetadataFromFileName(fileName: String): DbMetadata { val basename = if (index >= 0) trimmed.substring(index + 1) else trimmed return DbMetadata(name = basename.ifEmpty { null }, system = DB_SYSTEM_SQLITE) } - -/** - * Returns metadata based on - * [SupportSQLiteOpenHelper.databaseName][androidx.sqlite.db.SupportSQLiteOpenHelper.databaseName]. - */ -internal fun dbMetadataFromDatabaseName(databaseName: String?): DbMetadata = - if (databaseName == null) { - DbMetadata(name = null, system = DB_SYSTEM_IN_MEMORY) - } else { - DbMetadata(name = databaseName, system = DB_SYSTEM_SQLITE) - } diff --git a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt index 18690b0f12..1dc07ae022 100644 --- a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt +++ b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt @@ -10,10 +10,17 @@ import io.sentry.SentryNanotimeDate import io.sentry.SentryStackTraceFactory import io.sentry.SpanDataConvention import io.sentry.SpanStatus +import java.util.Date private const val SQLITE_TRACE_ORIGIN = "auto.db.sqlite" -/** Shared span instrumentation for SQLite. */ +/** + * Sentinel for extracting a [SentryNanotimeDate]'s underlying [System.nanoTime] value via + * [SentryDate.diff]. + */ +private val EMPTY_NANO_TIME = SentryNanotimeDate(Date(0), 0L) + +/** Span instrumentation for [SentrySQLiteDriver]. */ internal class SQLiteSpanInstrumentation( private val scopes: IScopes, private val dbMetadata: DbMetadata, @@ -22,53 +29,32 @@ internal class SQLiteSpanInstrumentation( private val stackTraceFactory = SentryStackTraceFactory(scopes.options) /** - * Returns a start timestamp for a `db.sql.query` span. + * Returns a timestamp in nanoseconds for use with [recordSpan]. Timestamp is ns-precise if the + * active parent span uses a [SentryNanotimeDate] (the ordinary case); otherwise it's ms-precise. * - * Exposed so callers can capture a wall-clock start before accumulating database time. - * Internalizing the start time in [recordSpan] would shift spans to end-of-work on the trace - * timeline, which is less desirable. + * Note: Internalizing the start time in [recordSpan] would shift spans to end-of-work on the + * trace timeline, which is less desirable; callers capture the start before doing database work + * and pass it back to [recordSpan]. */ - fun startTimestamp(): SentryDate = scopes.options.dateProvider.now() + fun startTimestamp(): Long = + // Try to retain nanosecond precision + avoid SentryDate allocation... + scopes.span?.childStartTimestampOrNull() + // ...otherwise fall back to millisecond precision + allocate. + ?: scopes.options.dateProvider.now().nanoTimestamp() - /** Records a `db.sql.query` span from [startTimestamp] to [startTimestamp] + [durationNanos]. */ + /** Records a `db.sql.query` span. */ fun recordSpan( sql: String, - startTimestamp: SentryDate, + startTimestampNanos: Long, durationNanos: Long, status: SpanStatus, throwable: Throwable? = null, ) { val parent = scopes.span ?: return - val nanoPrecisionStart = startTimestamp.repairPrecision(anchor = parent.startDate) - val endTimestamp = SentryLongDate(nanoPrecisionStart.nanoTimestamp() + durationNanos) - parent.recordChild(sql, nanoPrecisionStart, endTimestamp, status, throwable) - } - - /** - * Records a `db.sql.query` span from [startTimestamp] to the moment of invocation. - * - * "Coarse" in that it doesn't try to restore nanosecond precision for the start timestamp. Spans - * that start within the same wall clock millisecond will share the same start time and may be - * arbitrarily re-ordered by the Sentry UI. - */ - fun recordCoarseSpan( - sql: String, - startTimestamp: SentryDate, - status: SpanStatus, - throwable: Throwable? = null, - ) { - val parent = scopes.span ?: return - parent.recordChild(sql, startTimestamp, endTimestamp = null, status, throwable) - } + val startTimestamp = SentryLongDate(startTimestampNanos) + val endTimestamp = SentryLongDate(startTimestampNanos + durationNanos) - private fun ISpan.recordChild( - sql: String, - startTimestamp: SentryDate, - endTimestamp: SentryDate?, - status: SpanStatus, - throwable: Throwable?, - ) { - startChild("db.sql.query", sql, startTimestamp, Instrumenter.SENTRY).apply { + parent.startChild("db.sql.query", sql, startTimestamp, Instrumenter.SENTRY).apply { spanContext.origin = SQLITE_TRACE_ORIGIN throwable?.let { this.throwable = it } @@ -96,26 +82,15 @@ internal class SQLiteSpanInstrumentation( scopes: IScopes = ScopesAdapter.getInstance(), ): SQLiteSpanInstrumentation = SQLiteSpanInstrumentation(scopes, dbMetadataFromFileName(fileName)) - - /** - * Returns [SQLiteSpanInstrumentation] based on - * [SupportSQLiteOpenHelper.databaseName][androidx.sqlite.db.SupportSQLiteOpenHelper.databaseName]. - */ - fun fromDatabaseName( - databaseName: String?, - scopes: IScopes = ScopesAdapter.getInstance(), - ): SQLiteSpanInstrumentation = - SQLiteSpanInstrumentation(scopes, dbMetadataFromDatabaseName(databaseName)) } } /** - * Repairs the receiver's [nanoTimestamp][SentryDate.nanoTimestamp] if needed so that it actually - * has nanosecond precision. + * Computes a start timestamp with nanosecond precision for the child of the receiver span. Returns + * null if nanosecond precision isn't possible. * - * 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: + * Lets us improve the display of spans in the Sentry UI. If timestamps are only ms-precise, the + * Sentry UI will left-align and arbitrarily reorder spans that share the same wall clock ms: * ``` * (Relative start times out of order) * ↓ @@ -128,7 +103,7 @@ internal class SQLiteSpanInstrumentation( * even though their execution was staggered) * ``` * - * Repair ensures proper ordering and lets the spans stagger: + * Nanosecond precision ensures proper ordering and lets the spans stagger: * ``` * Parent span ├█████████████┤ * BEGIN IMMEDIATE TRANSACTION ├████┤ 0.02 ms @@ -136,11 +111,14 @@ internal class SQLiteSpanInstrumentation( * END TRANSACTION ├███┤ 0.33 ms * ``` */ -internal fun SentryDate.repairPrecision(anchor: SentryDate?): SentryDate = - if (anchor is SentryNanotimeDate) { - // Compute a new timestamp with nanosecond precision by using the anchor as the epoch instant - // and adding to it the diff of this.nanos - anchor.nanos. - SentryLongDate(anchor.laterDateNanosTimestampByDiff(this)) - } else { - this +internal fun ISpan.childStartTimestampOrNull(): Long? { + if (startDate !is SentryNanotimeDate) { + return null } + + val parentWallClockNanos = startDate.nanoTimestamp() + val parentMonotonicNanos = startDate.diff(EMPTY_NANO_TIME) + val elapsedSinceParentStart = System.nanoTime() - parentMonotonicNanos + // Return the child's absolute start time. + return parentWallClockNanos + elapsedSinceParentStart +} diff --git a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SentrySQLiteStatement.kt b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SentrySQLiteStatement.kt index 41df37444b..a739a396bc 100644 --- a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SentrySQLiteStatement.kt +++ b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SentrySQLiteStatement.kt @@ -1,7 +1,6 @@ package io.sentry.sqlite import androidx.sqlite.SQLiteStatement -import io.sentry.SentryDate import io.sentry.SpanStatus /** @@ -22,7 +21,7 @@ internal class SentrySQLiteStatement( private val nanoTimeProvider: () -> Long = { System.nanoTime() }, ) : SQLiteStatement by delegate { - private var firstStepTimestamp: SentryDate? = null + private var firstStepTimestampNanos: Long? = null private var accumulatedDbNanos: Long = 0L private var stepsComplete = false private var closed = false @@ -35,8 +34,8 @@ internal class SentrySQLiteStatement( val beforeNanos = nanoTimeProvider() return try { - if (firstStepTimestamp == null) { - firstStepTimestamp = spans.startTimestamp() + if (firstStepTimestampNanos == null) { + firstStepTimestampNanos = spans.startTimestamp() } stepsComplete = !delegate.step() @@ -71,10 +70,10 @@ internal class SentrySQLiteStatement( } private fun recordSpan(status: SpanStatus, throwable: Throwable? = null) { - val start = firstStepTimestamp ?: return + val startNanos = firstStepTimestampNanos ?: return val duration = accumulatedDbNanos - firstStepTimestamp = null + firstStepTimestampNanos = null accumulatedDbNanos = 0L - spans.recordSpan(sql, start, duration, status, throwable) + spans.recordSpan(sql, startNanos, duration, status, throwable) } } diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ChildStartTimestampOrNullTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ChildStartTimestampOrNullTest.kt new file mode 100644 index 0000000000..7bf3b36f83 --- /dev/null +++ b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ChildStartTimestampOrNullTest.kt @@ -0,0 +1,100 @@ +package io.sentry.sqlite + +import io.sentry.DateUtils +import io.sentry.ISpan +import io.sentry.SentryLongDate +import io.sentry.SentryNanotimeDate +import java.util.Date +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertNull +import kotlin.test.assertTrue +import org.mockito.kotlin.mock +import org.mockito.kotlin.whenever + +class ChildStartTimestampOrNullTest { + + @Test + fun `returns parent wall clock plus elapsed monotonic time since parent started`() { + val wallClockMillis = 1_000_000L + val elapsedNanos = 500_000L + val parentMonotonicNanos = System.nanoTime() - elapsedNanos + val span = spanWithNanotimeStart(wallClockMillis, parentMonotonicNanos) + + val timestamp = span.childStartTimestampOrNull()!! + + val elapsedSinceParentStart = timestamp - DateUtils.millisToNanos(wallClockMillis) + assertTrue(elapsedSinceParentStart >= elapsedNanos) + assertTrue(elapsedSinceParentStart < elapsedNanos + TEST_SLACK_NANOS) + } + + @Test + fun `same millisecond wall clocks with different monotonic offsets produce distinct ordered timestamps`() { + val wallClockMillis = 1_000_000L + val wallClockNanos = DateUtils.millisToNanos(wallClockMillis) + val earlierParentMonotonicNanos = System.nanoTime() - 200_000L + val laterParentMonotonicNanos = System.nanoTime() - 800_000L + val earlierSpan = spanWithNanotimeStart(wallClockMillis, earlierParentMonotonicNanos) + val laterSpan = spanWithNanotimeStart(wallClockMillis, laterParentMonotonicNanos) + + assertEquals( + earlierSpan.startDate.nanoTimestamp(), + laterSpan.startDate.nanoTimestamp(), + "Raw parent timestamps share the same ms-quantized value", + ) + + val earlier = earlierSpan.childStartTimestampOrNull()!! + val later = laterSpan.childStartTimestampOrNull()!! + + assertTrue(earlier > wallClockNanos) + assertTrue(later > wallClockNanos) + assertTrue(earlier < later) + assertTrue(later - earlier >= 500_000L) + } + + @Test + fun `returns parent wall clock when no monotonic time has elapsed since parent started`() { + val wallClockMillis = 1_000_000L + val parentMonotonicNanos = System.nanoTime() + val span = spanWithNanotimeStart(wallClockMillis, parentMonotonicNanos) + + val elapsedSinceParentStart = + span.childStartTimestampOrNull()!! - DateUtils.millisToNanos(wallClockMillis) + assertTrue(elapsedSinceParentStart >= 0L) + assertTrue(elapsedSinceParentStart < TEST_SLACK_NANOS) + } + + @Test + fun `works when parent wall clock differs from millisecond baseline`() { + val wallClockMillis = 1_000_001L + val elapsedNanos = 1_500_000L + val parentMonotonicNanos = System.nanoTime() - elapsedNanos + val span = spanWithNanotimeStart(wallClockMillis, parentMonotonicNanos) + + val elapsedSinceParentStart = + span.childStartTimestampOrNull()!! - DateUtils.millisToNanos(wallClockMillis) + assertTrue(elapsedSinceParentStart >= elapsedNanos) + assertTrue(elapsedSinceParentStart < elapsedNanos + TEST_SLACK_NANOS) + } + + @Test + fun `returns null when start date is not SentryNanotimeDate`() { + val span = mock() + whenever(span.startDate).thenReturn(SentryLongDate(DateUtils.millisToNanos(1_000_000L))) + + assertNull(span.childStartTimestampOrNull()) + } + + private fun spanWithNanotimeStart(wallClockMillis: Long, parentMonotonicNanos: Long): ISpan { + val startDate = SentryNanotimeDate(Date(wallClockMillis), parentMonotonicNanos) + val span = mock() + whenever(span.startDate).thenReturn(startDate) + return span + } + + companion object { + + // Upper bound for monotonic drift while the test body runs. + private const val TEST_SLACK_NANOS = 50_000_000L + } +} diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/DbMetadataTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/DbMetadataTest.kt index 227b9d9558..09d80793ed 100644 --- a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/DbMetadataTest.kt +++ b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/DbMetadataTest.kt @@ -13,14 +13,6 @@ class DbMetadataTest { ) } - @Test - fun `dbMetadataFromDatabaseName returns in-memory system with no db name when databaseName is null`() { - assertEquals( - DbMetadata(name = null, system = DB_SYSTEM_IN_MEMORY), - dbMetadataFromDatabaseName(null), - ) - } - @Test fun `dbMetadataFromFileName returns sqlite system and db name for unix path`() { assertEquals( diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/RepairPrecisionTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/RepairPrecisionTest.kt deleted file mode 100644 index c0341bcdb4..0000000000 --- a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/RepairPrecisionTest.kt +++ /dev/null @@ -1,90 +0,0 @@ -package io.sentry.sqlite - -import io.sentry.DateUtils -import io.sentry.SentryLongDate -import io.sentry.SentryNanotimeDate -import java.util.Date -import kotlin.test.Test -import kotlin.test.assertEquals -import kotlin.test.assertIs -import kotlin.test.assertSame - -class RepairPrecisionTest { - - @Test - fun `repairs timestamp precision using nanotime diff from anchor`() { - val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) - val date = SentryNanotimeDate(Date(1_000_000L), 100_500_000L) - - val repaired = date.repairPrecision(anchor) - - assertIs(repaired) - val anchorNanoTimestamp = DateUtils.millisToNanos(1_000_000L) - assertEquals(anchorNanoTimestamp + 500_000L, repaired.nanoTimestamp()) - } - - @Test - fun `two dates in the same millisecond produce distinct ordered timestamps`() { - val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) - val earlier = SentryNanotimeDate(Date(1_000_000L), 100_200_000L) - val later = SentryNanotimeDate(Date(1_000_000L), 100_800_000L) - - assertEquals( - earlier.nanoTimestamp(), - later.nanoTimestamp(), - "Raw timestamps share the same ms-quantized value", - ) - - val anchorNanoTimestamp = DateUtils.millisToNanos(1_000_000L) - val repairedEarlier = earlier.repairPrecision(anchor) - val repairedLater = later.repairPrecision(anchor) - assertEquals(anchorNanoTimestamp + 200_000L, repairedEarlier.nanoTimestamp()) - assertEquals(anchorNanoTimestamp + 800_000L, repairedLater.nanoTimestamp()) - } - - @Test - fun `returns anchor nano timestamp when date matches anchor nanos`() { - val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) - val date = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) - - val repaired = date.repairPrecision(anchor) - - assertIs(repaired) - assertEquals(anchor.nanoTimestamp(), repaired.nanoTimestamp()) - } - - @Test - fun `repairs SentryLongDate receiver to anchor millisecond baseline`() { - val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) - val date = SentryLongDate(DateUtils.millisToNanos(1_000_000L)) - - val repaired = date.repairPrecision(anchor) - - assertIs(repaired) - assertEquals(anchor.nanoTimestamp(), repaired.nanoTimestamp()) - } - - @Test - fun `works when date and anchor span have different wall clock times`() { - val anchor = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) - val date = SentryNanotimeDate(Date(1_000_001L), 101_500_000L) - - val repaired = date.repairPrecision(anchor) - - val anchorNanoTimestamp = DateUtils.millisToNanos(1_000_000L) - assertEquals(anchorNanoTimestamp + 1_500_000L, repaired.nanoTimestamp()) - } - - @Test - fun `returns self when anchor is not SentryNanotimeDate`() { - val date = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) - val anchor = SentryLongDate(DateUtils.millisToNanos(1_000_000L)) - assertSame(date, date.repairPrecision(anchor = anchor)) - } - - @Test - fun `returns self when anchor is null`() { - val date = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) - assertSame(date, date.repairPrecision(anchor = null)) - } -} diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt index 6e4b6921cd..a38be242ec 100644 --- a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt +++ b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SQLiteSpanInstrumentationTest.kt @@ -1,6 +1,7 @@ package io.sentry.sqlite import io.sentry.IScopes +import io.sentry.ISpan import io.sentry.SentryDateProvider import io.sentry.SentryLongDate import io.sentry.SentryNanotimeDate @@ -46,158 +47,82 @@ class SQLiteSpanInstrumentationTest { private val fixture = Fixture() @Test - fun `recordSpan records a span if a transaction is active`() { - val sut = fixture.getSut(isTransactionActive = true) - sut.recordSpan("SELECT 1", sut.startTimestamp(), 1_000_000, SpanStatus.OK) - assertEquals(1, fixture.sentryTracer.children.size) - } - - @Test - fun `recordSpan does not record a span if no transaction is active`() { - val sut = fixture.getSut(isTransactionActive = false) - val start = sut.startTimestamp() - sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) - assertEquals(0, fixture.sentryTracer.children.size) - } + fun `startTimestamp is ns-precise and skips date provider when parent uses SentryNanotimeDate`() { + // Only the parent date is queued. If startTimestamp() were to call dateProvider.now(), + // the queue would underflow and the test would fail loudly — this is what verifies the + // optimization is in effect. + val parentDate = SentryNanotimeDate(Date(1_000_000L), 100_000_000L) + val sut = setUpWithNanotimeDates(parentDate) - @Test - fun `recordSpan creates a span with correct properties`() { - val sut = fixture.getSut() val start = sut.startTimestamp() - sut.recordSpan("SELECT * FROM users", start, 1_000_000, SpanStatus.OK) - val span = fixture.sentryTracer.children.firstOrNull() - assertNotNull(span) - assertEquals("db.sql.query", span.operation) - assertEquals("SELECT * FROM users", span.description) - assertEquals("auto.db.sqlite", span.spanContext.origin) - assertEquals(SpanStatus.OK, span.status) - assertTrue(span.isFinished) - } - - @Test - fun `recordSpan sets finishDate equal to startDate + durationNanos`() { - val sut = fixture.getSut() - val start = sut.startTimestamp() val durationNanos = 42_000_000L - sut.recordSpan("SELECT 1", start, durationNanos, SpanStatus.OK) val span = fixture.sentryTracer.children.first() - assertEquals(span.startDate.nanoTimestamp() + durationNanos, span.finishDate!!.nanoTimestamp()) - } - @Test - fun `recordSpan attaches throwable when provided`() { - val sut = fixture.getSut() - val start = sut.startTimestamp() - val exception = RuntimeException("disk I/O error") - - sut.recordSpan("INSERT INTO t VALUES(1)", start, 500_000, SpanStatus.INTERNAL_ERROR, exception) - - val span = fixture.sentryTracer.children.first() - assertEquals(SpanStatus.INTERNAL_ERROR, span.status) - assertEquals(exception, span.throwable) - } - - @Test - fun `recordSpan sets db system and db name when fileName is not the in-memory sentinel`() { - val sut = fixture.getSut(fileName = "/data/data/com.example/databases/tracks.db") - val start = sut.startTimestamp() - sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) - assertEquals("tracks.db", span.data[SpanDataConvention.DB_NAME_KEY]) - } - - @Test - fun `recordSpan sets db system only when fileName is the in-memory sentinel`() { - val sut = fixture.getSut(fileName = ":memory:") - val start = sut.startTimestamp() - sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertEquals("in-memory", span.data[SpanDataConvention.DB_SYSTEM_KEY]) - assertNull(span.data[SpanDataConvention.DB_NAME_KEY]) + // startTimestamp returns an already-ns-precise value, anchored to the parent's wall clock and + // offset by elapsed System.nanoTime(). The exact ns-math is unit-tested in + // ChildStartTimestampOrNullTest; here we verify the integration shape. + assertIs(span.startDate) + assertEquals(start, span.startDate.nanoTimestamp()) + assertEquals(start + durationNanos, span.finishDate!!.nanoTimestamp()) } @Test - fun `recordSpan sets blocked_main_thread to true and attaches call stack on main thread`() { - val sut = fixture.getSut() - fixture.options.threadChecker = mock() - whenever(fixture.options.threadChecker.isMainThread).thenReturn(true) - whenever(fixture.options.threadChecker.currentThreadName).thenReturn("main") + fun `startTimestamp falls back to date provider when parent does not use SentryNanotimeDate`() { + val providerDate = SentryNanotimeDate(Date(2_000_000L), 200_000_000L) + val parentSpan = mock() + whenever(parentSpan.startDate).thenReturn(SentryLongDate(1_000_000_000_000_000L)) + val options = + SentryOptions().apply { + dsn = "https://key@sentry.io/proj" + dateProvider = SentryDateProvider { providerDate } + } + whenever(fixture.scopes.options).thenReturn(options) + whenever(fixture.scopes.span).thenReturn(parentSpan) - sut.recordSpan("SELECT 1", sut.startTimestamp(), 1_000_000, SpanStatus.OK) + val sut = SQLiteSpanInstrumentation.fromFileName(":memory:", fixture.scopes) - val span = fixture.sentryTracer.children.first() - assertTrue(span.getData(SpanDataConvention.BLOCKED_MAIN_THREAD_KEY) as Boolean) - assertNotNull(span.getData(SpanDataConvention.CALL_STACK_KEY)) + assertEquals(providerDate.nanoTimestamp(), sut.startTimestamp()) } @Test - fun `recordSpan sets blocked_main_thread to false and does not attach a call stack on background thread`() { - val sut = fixture.getSut() - fixture.options.threadChecker = mock() - whenever(fixture.options.threadChecker.isMainThread).thenReturn(false) - whenever(fixture.options.threadChecker.currentThreadName).thenReturn("worker") - - sut.recordSpan("SELECT 1", sut.startTimestamp(), 1_000_000, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertFalse(span.getData(SpanDataConvention.BLOCKED_MAIN_THREAD_KEY) as Boolean) - assertNull(span.getData(SpanDataConvention.CALL_STACK_KEY)) - } - - @Test - fun `recordSpan repairs start precision`() { - val sameMillis = Date(1_000_000L) - val parentNanos = 100_000_000L - val childNanos = 100_500_000L - - val sut = - setUpWithNanotimeDates( - SentryNanotimeDate(sameMillis, parentNanos), - SentryNanotimeDate(sameMillis, childNanos), - ) - val start = sut.startTimestamp() - val durationNanos = 42_000_000L - - sut.recordSpan("SELECT 1", start, durationNanos, SpanStatus.OK) + fun `startTimestamp falls back to date provider when no transaction is active`() { + val providerDate = SentryNanotimeDate(Date(2_000_000L), 200_000_000L) + val options = + SentryOptions().apply { + dsn = "https://key@sentry.io/proj" + dateProvider = SentryDateProvider { providerDate } + } + whenever(fixture.scopes.options).thenReturn(options) + whenever(fixture.scopes.span).thenReturn(null) - val span = fixture.sentryTracer.children.first() + val sut = SQLiteSpanInstrumentation.fromFileName(":memory:", fixture.scopes) - val parentStart = fixture.sentryTracer.startDate - val expectedStart = parentStart.laterDateNanosTimestampByDiff(start) - // Child and parent share the same ms-quantized baseline; repair adds nanosecond offset. - assertEquals(parentStart.nanoTimestamp(), start.nanoTimestamp()) - assertTrue(start.nanoTimestamp() != expectedStart) - assertIs(span.startDate) - assertEquals(expectedStart, span.startDate.nanoTimestamp()) - assertEquals(expectedStart + durationNanos, span.finishDate!!.nanoTimestamp()) + assertEquals(providerDate.nanoTimestamp(), sut.startTimestamp()) } @Test - fun `recordCoarseSpan records a span if a transaction is active`() { + fun `recordSpan records a span if a transaction is active`() { val sut = fixture.getSut(isTransactionActive = true) - sut.recordCoarseSpan("SELECT 1", sut.startTimestamp(), SpanStatus.OK) + sut.recordSpan("SELECT 1", sut.startTimestamp(), 1_000_000, SpanStatus.OK) assertEquals(1, fixture.sentryTracer.children.size) } @Test - fun `recordCoarseSpan does not record a span if no transaction is active`() { + fun `recordSpan does not record a span if no transaction is active`() { val sut = fixture.getSut(isTransactionActive = false) val start = sut.startTimestamp() - sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) + sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) assertEquals(0, fixture.sentryTracer.children.size) } @Test - fun `recordCoarseSpan creates a span with correct properties`() { + fun `recordSpan creates a span with correct properties`() { val sut = fixture.getSut() val start = sut.startTimestamp() - sut.recordCoarseSpan("SELECT * FROM users", start, SpanStatus.OK) + sut.recordSpan("SELECT * FROM users", start, 1_000_000, SpanStatus.OK) val span = fixture.sentryTracer.children.firstOrNull() assertNotNull(span) @@ -209,27 +134,24 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `recordCoarseSpan finishes the span at the time of invocation`() { + fun `recordSpan sets finishDate equal to startDate + durationNanos`() { val sut = fixture.getSut() val start = sut.startTimestamp() + val durationNanos = 42_000_000L - sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) + sut.recordSpan("SELECT 1", start, durationNanos, SpanStatus.OK) val span = fixture.sentryTracer.children.first() - assertTrue(span.isFinished) - assertEquals(SpanStatus.OK, span.status) - // Unlike the duration overload, no synthetic end timestamp is supplied; the span finishes at - // "now", i.e. at or after its start. - assertTrue(span.finishDate!!.nanoTimestamp() >= start.nanoTimestamp()) + assertEquals(span.startDate.nanoTimestamp() + durationNanos, span.finishDate!!.nanoTimestamp()) } @Test - fun `recordCoarseSpan attaches throwable when provided`() { + fun `recordSpan attaches throwable when provided`() { val sut = fixture.getSut() val start = sut.startTimestamp() val exception = RuntimeException("disk I/O error") - sut.recordCoarseSpan("INSERT INTO t VALUES(1)", start, SpanStatus.INTERNAL_ERROR, exception) + sut.recordSpan("INSERT INTO t VALUES(1)", start, 500_000, SpanStatus.INTERNAL_ERROR, exception) val span = fixture.sentryTracer.children.first() assertEquals(SpanStatus.INTERNAL_ERROR, span.status) @@ -237,10 +159,10 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `recordCoarseSpan sets db system and db name when fileName is not the in-memory sentinel`() { + fun `recordSpan sets db system and db name when fileName is not the in-memory sentinel`() { val sut = fixture.getSut(fileName = "/data/data/com.example/databases/tracks.db") val start = sut.startTimestamp() - sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) + sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) val span = fixture.sentryTracer.children.first() assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) @@ -248,10 +170,10 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `recordCoarseSpan sets db system only when fileName is the in-memory sentinel`() { + fun `recordSpan sets db system only when fileName is the in-memory sentinel`() { val sut = fixture.getSut(fileName = ":memory:") val start = sut.startTimestamp() - sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) + sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) val span = fixture.sentryTracer.children.first() assertEquals("in-memory", span.data[SpanDataConvention.DB_SYSTEM_KEY]) @@ -259,13 +181,13 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `recordCoarseSpan sets blocked_main_thread to true and attaches call stack on main thread`() { + fun `recordSpan sets blocked_main_thread to true and attaches call stack on main thread`() { val sut = fixture.getSut() fixture.options.threadChecker = mock() whenever(fixture.options.threadChecker.isMainThread).thenReturn(true) whenever(fixture.options.threadChecker.currentThreadName).thenReturn("main") - sut.recordCoarseSpan("SELECT 1", sut.startTimestamp(), SpanStatus.OK) + sut.recordSpan("SELECT 1", sut.startTimestamp(), 1_000_000, SpanStatus.OK) val span = fixture.sentryTracer.children.first() assertTrue(span.getData(SpanDataConvention.BLOCKED_MAIN_THREAD_KEY) as Boolean) @@ -273,105 +195,19 @@ class SQLiteSpanInstrumentationTest { } @Test - fun `recordCoarseSpan sets blocked_main_thread to false and does not attach a call stack on background thread`() { + fun `recordSpan sets blocked_main_thread to false and does not attach a call stack on background thread`() { val sut = fixture.getSut() fixture.options.threadChecker = mock() whenever(fixture.options.threadChecker.isMainThread).thenReturn(false) whenever(fixture.options.threadChecker.currentThreadName).thenReturn("worker") - sut.recordCoarseSpan("SELECT 1", sut.startTimestamp(), SpanStatus.OK) + sut.recordSpan("SELECT 1", sut.startTimestamp(), 1_000_000, SpanStatus.OK) val span = fixture.sentryTracer.children.first() assertFalse(span.getData(SpanDataConvention.BLOCKED_MAIN_THREAD_KEY) as Boolean) assertNull(span.getData(SpanDataConvention.CALL_STACK_KEY)) } - @Test - fun `recordCoarseSpan does not repair start precision`() { - val sameMillis = Date(1_000_000L) - val parentNanos = 100_000_000L - val childNanos = 100_500_000L - - val finishNanos = 100_900_000L - val sut = - setUpWithNanotimeDates( - SentryNanotimeDate(sameMillis, parentNanos), - SentryNanotimeDate(sameMillis, childNanos), - SentryNanotimeDate(sameMillis, finishNanos), - ) - val start = sut.startTimestamp() - - sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertEquals(start.nanoTimestamp(), span.startDate.nanoTimestamp()) - assertTrue(span.finishDate!!.nanoTimestamp() >= span.startDate.nanoTimestamp()) - } - - @Test - fun `fromFileName sets db name from fileName when using recordSpan`() { - val options = SentryOptions().apply { dsn = "https://key@sentry.io/proj" } - whenever(fixture.scopes.options).thenReturn(options) - fixture.sentryTracer = SentryTracer(TransactionContext("name", "op"), fixture.scopes) - whenever(fixture.scopes.span).thenReturn(fixture.sentryTracer) - - val sut = SQLiteSpanInstrumentation.fromFileName("tracks.db", fixture.scopes) - val start = sut.startTimestamp() - sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) - assertEquals("tracks.db", span.data[SpanDataConvention.DB_NAME_KEY]) - } - - @Test - fun `fromDatabaseName sets db name from databaseName when using recordSpan`() { - val options = SentryOptions().apply { dsn = "https://key@sentry.io/proj" } - whenever(fixture.scopes.options).thenReturn(options) - fixture.sentryTracer = SentryTracer(TransactionContext("name", "op"), fixture.scopes) - whenever(fixture.scopes.span).thenReturn(fixture.sentryTracer) - - val sut = SQLiteSpanInstrumentation.fromDatabaseName("tracks.db", fixture.scopes) - val start = sut.startTimestamp() - sut.recordSpan("SELECT 1", start, 1_000_000, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) - assertEquals("tracks.db", span.data[SpanDataConvention.DB_NAME_KEY]) - } - - @Test - fun `fromFileName sets db name from fileName when using recordCoarseSpan`() { - val options = SentryOptions().apply { dsn = "https://key@sentry.io/proj" } - whenever(fixture.scopes.options).thenReturn(options) - fixture.sentryTracer = SentryTracer(TransactionContext("name", "op"), fixture.scopes) - whenever(fixture.scopes.span).thenReturn(fixture.sentryTracer) - - val sut = SQLiteSpanInstrumentation.fromFileName("tracks.db", fixture.scopes) - val start = sut.startTimestamp() - sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) - assertEquals("tracks.db", span.data[SpanDataConvention.DB_NAME_KEY]) - } - - @Test - fun `fromDatabaseName sets db name from databaseName when using recordCoarseSpan`() { - val options = SentryOptions().apply { dsn = "https://key@sentry.io/proj" } - whenever(fixture.scopes.options).thenReturn(options) - fixture.sentryTracer = SentryTracer(TransactionContext("name", "op"), fixture.scopes) - whenever(fixture.scopes.span).thenReturn(fixture.sentryTracer) - - val sut = SQLiteSpanInstrumentation.fromDatabaseName("tracks.db", fixture.scopes) - val start = sut.startTimestamp() - sut.recordCoarseSpan("SELECT 1", start, SpanStatus.OK) - - val span = fixture.sentryTracer.children.first() - assertEquals("sqlite", span.data[SpanDataConvention.DB_SYSTEM_KEY]) - assertEquals("tracks.db", span.data[SpanDataConvention.DB_NAME_KEY]) - } - private fun setUpWithNanotimeDates(vararg dates: SentryNanotimeDate): SQLiteSpanInstrumentation { val dateQueue = ArrayDeque(dates.toList()) val options = diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SentrySQLiteStatementTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SentrySQLiteStatementTest.kt index 6691910e35..ce2c3f00cd 100644 --- a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SentrySQLiteStatementTest.kt +++ b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/SentrySQLiteStatementTest.kt @@ -1,7 +1,6 @@ package io.sentry.sqlite import androidx.sqlite.SQLiteStatement -import io.sentry.SentryLongDate import io.sentry.SpanStatus import java.util.concurrent.atomic.AtomicLong import kotlin.test.Test @@ -21,11 +20,11 @@ class SentrySQLiteStatementTest { private class Fixture { val mockStatement = mock() val mockSpans = mock() - val startDate = SentryLongDate(1_000_000_000_000L) + val startTimestampNanos = 1_000_000_000_000L val fakeClock = AtomicLong(0L) fun getSut(sql: String): SentrySQLiteStatement { - whenever(mockSpans.startTimestamp()).thenReturn(startDate) + whenever(mockSpans.startTimestamp()).thenReturn(startTimestampNanos) return SentrySQLiteStatement(mockStatement, mockSpans, sql, fakeClock::getAndIncrement) } } @@ -43,7 +42,7 @@ class SentrySQLiteStatementTest { verify(fixture.mockSpans) .recordSpan( eq("SELECT * FROM users"), - eq(fixture.startDate), + eq(fixture.startTimestampNanos), any(), eq(SpanStatus.OK), anyOrNull(), @@ -61,7 +60,7 @@ class SentrySQLiteStatementTest { verify(fixture.mockSpans) .recordSpan( eq("BAD SQL"), - eq(fixture.startDate), + eq(fixture.startTimestampNanos), any(), eq(SpanStatus.INTERNAL_ERROR), eq(exception), From fee24613dcf5d516f43f2e27e5d9bf606a9acd17 Mon Sep 17 00:00:00 2001 From: Adam Brown Date: Wed, 17 Jun 2026 13:13:06 +0200 Subject: [PATCH 4/4] Rename childStartTimestampOrNull() -> computeNanoStartTimestampForChild() --- .../io/sentry/sqlite/SQLiteSpanInstrumentation.kt | 4 ++-- ...kt => ComputeNanoStartTimestampForChildTest.kt} | 14 +++++++------- 2 files changed, 9 insertions(+), 9 deletions(-) rename sentry-android-sqlite/src/test/java/io/sentry/sqlite/{ChildStartTimestampOrNullTest.kt => ComputeNanoStartTimestampForChildTest.kt} (87%) diff --git a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt index 1dc07ae022..5099f38f69 100644 --- a/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt +++ b/sentry-android-sqlite/src/main/java/io/sentry/sqlite/SQLiteSpanInstrumentation.kt @@ -38,7 +38,7 @@ internal class SQLiteSpanInstrumentation( */ fun startTimestamp(): Long = // Try to retain nanosecond precision + avoid SentryDate allocation... - scopes.span?.childStartTimestampOrNull() + scopes.span?.computeNanoStartTimestampForChild() // ...otherwise fall back to millisecond precision + allocate. ?: scopes.options.dateProvider.now().nanoTimestamp() @@ -111,7 +111,7 @@ internal class SQLiteSpanInstrumentation( * END TRANSACTION ├███┤ 0.33 ms * ``` */ -internal fun ISpan.childStartTimestampOrNull(): Long? { +internal fun ISpan.computeNanoStartTimestampForChild(): Long? { if (startDate !is SentryNanotimeDate) { return null } diff --git a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ChildStartTimestampOrNullTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ComputeNanoStartTimestampForChildTest.kt similarity index 87% rename from sentry-android-sqlite/src/test/java/io/sentry/sqlite/ChildStartTimestampOrNullTest.kt rename to sentry-android-sqlite/src/test/java/io/sentry/sqlite/ComputeNanoStartTimestampForChildTest.kt index 7bf3b36f83..92a98b6e56 100644 --- a/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ChildStartTimestampOrNullTest.kt +++ b/sentry-android-sqlite/src/test/java/io/sentry/sqlite/ComputeNanoStartTimestampForChildTest.kt @@ -12,7 +12,7 @@ import kotlin.test.assertTrue import org.mockito.kotlin.mock import org.mockito.kotlin.whenever -class ChildStartTimestampOrNullTest { +class ComputeNanoStartTimestampForChildTest { @Test fun `returns parent wall clock plus elapsed monotonic time since parent started`() { @@ -21,7 +21,7 @@ class ChildStartTimestampOrNullTest { val parentMonotonicNanos = System.nanoTime() - elapsedNanos val span = spanWithNanotimeStart(wallClockMillis, parentMonotonicNanos) - val timestamp = span.childStartTimestampOrNull()!! + val timestamp = span.computeNanoStartTimestampForChild()!! val elapsedSinceParentStart = timestamp - DateUtils.millisToNanos(wallClockMillis) assertTrue(elapsedSinceParentStart >= elapsedNanos) @@ -43,8 +43,8 @@ class ChildStartTimestampOrNullTest { "Raw parent timestamps share the same ms-quantized value", ) - val earlier = earlierSpan.childStartTimestampOrNull()!! - val later = laterSpan.childStartTimestampOrNull()!! + val earlier = earlierSpan.computeNanoStartTimestampForChild()!! + val later = laterSpan.computeNanoStartTimestampForChild()!! assertTrue(earlier > wallClockNanos) assertTrue(later > wallClockNanos) @@ -59,7 +59,7 @@ class ChildStartTimestampOrNullTest { val span = spanWithNanotimeStart(wallClockMillis, parentMonotonicNanos) val elapsedSinceParentStart = - span.childStartTimestampOrNull()!! - DateUtils.millisToNanos(wallClockMillis) + span.computeNanoStartTimestampForChild()!! - DateUtils.millisToNanos(wallClockMillis) assertTrue(elapsedSinceParentStart >= 0L) assertTrue(elapsedSinceParentStart < TEST_SLACK_NANOS) } @@ -72,7 +72,7 @@ class ChildStartTimestampOrNullTest { val span = spanWithNanotimeStart(wallClockMillis, parentMonotonicNanos) val elapsedSinceParentStart = - span.childStartTimestampOrNull()!! - DateUtils.millisToNanos(wallClockMillis) + span.computeNanoStartTimestampForChild()!! - DateUtils.millisToNanos(wallClockMillis) assertTrue(elapsedSinceParentStart >= elapsedNanos) assertTrue(elapsedSinceParentStart < elapsedNanos + TEST_SLACK_NANOS) } @@ -82,7 +82,7 @@ class ChildStartTimestampOrNullTest { val span = mock() whenever(span.startDate).thenReturn(SentryLongDate(DateUtils.millisToNanos(1_000_000L))) - assertNull(span.childStartTimestampOrNull()) + assertNull(span.computeNanoStartTimestampForChild()) } private fun spanWithNanotimeStart(wallClockMillis: Long, parentMonotonicNanos: Long): ISpan {