From 8fe9881fdd4edc3cecd3c57bc9d2862fda06b879 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Thu, 25 Jul 2024 13:30:06 +0200 Subject: [PATCH 1/2] added SentryCrossProcessCursor wrapper SQLiteSpanManager now wraps CrossProcessCursors to start a span only when the cursor is filled with data --- .../android/sqlite/SQLiteSpanManager.kt | 21 ++- .../sqlite/SentryCrossProcessCursor.kt | 51 +++++++ .../android/sqlite/SQLiteSpanManagerTest.kt | 15 +++ .../sqlite/SentryCrossProcessCursorTest.kt | 124 ++++++++++++++++++ 4 files changed, 208 insertions(+), 3 deletions(-) create mode 100644 sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SentryCrossProcessCursor.kt create mode 100644 sentry-android-sqlite/src/test/java/io/sentry/android/sqlite/SentryCrossProcessCursorTest.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 3bfa855d535..c45d31aa171 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 @@ -1,8 +1,11 @@ package io.sentry.android.sqlite +import android.database.CrossProcessCursor import android.database.SQLException import io.sentry.HubAdapter import io.sentry.IHub +import io.sentry.ISpan +import io.sentry.Instrumenter import io.sentry.SentryIntegrationPackageStorage import io.sentry.SentryStackTraceFactory import io.sentry.SpanDataConvention @@ -27,16 +30,28 @@ internal class SQLiteSpanManager( * @param operation The sql operation to execute. * In case of an error the surrounding span will have its status set to INTERNAL_ERROR */ - @Suppress("TooGenericExceptionCaught") + @Suppress("TooGenericExceptionCaught", "UNCHECKED_CAST") @Throws(SQLException::class) fun performSql(sql: String, operation: () -> T): T { - val span = hub.span?.startChild("db.sql.query", sql) - span?.spanContext?.origin = TRACE_ORIGIN + val startTimestamp = hub.getOptions().dateProvider.now() + var span: ISpan? = null return try { val result = operation() + /* + * SQLiteCursor - that extends CrossProcessCursor - executes the query lazily, when one of + * getCount() or onMove() is called. In this case we don't have to start the span here. + * Otherwise we start the span with the timestamp taken before the operation started. + */ + if (result is CrossProcessCursor) { + return SentryCrossProcessCursor(result, this, sql) as T + } + span = hub.span?.startChild("db.sql.query", sql, startTimestamp, Instrumenter.SENTRY) + span?.spanContext?.origin = TRACE_ORIGIN span?.status = SpanStatus.OK result } catch (e: Throwable) { + span = hub.span?.startChild("db.sql.query", sql, startTimestamp, Instrumenter.SENTRY) + span?.spanContext?.origin = TRACE_ORIGIN span?.status = SpanStatus.INTERNAL_ERROR span?.throwable = e throw e diff --git a/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SentryCrossProcessCursor.kt b/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SentryCrossProcessCursor.kt new file mode 100644 index 00000000000..962e8bbb71c --- /dev/null +++ b/sentry-android-sqlite/src/main/java/io/sentry/android/sqlite/SentryCrossProcessCursor.kt @@ -0,0 +1,51 @@ +package io.sentry.android.sqlite + +import android.database.CrossProcessCursor +import android.database.CursorWindow + +/* + * SQLiteCursor executes the query lazily, when one of getCount() and onMove() is called. + * Also, by docs, fillWindow() can be used to fill the cursor with data. + * So we wrap these methods to create a span. + * SQLiteCursor is never used directly in the code, but only the Cursor interface. + * This means we can use CrossProcessCursor - that extends Cursor - as wrapper, since + * CrossProcessCursor is an interface and we can use Kotlin delegation. + */ +internal class SentryCrossProcessCursor( + private val delegate: CrossProcessCursor, + private val spanManager: SQLiteSpanManager, + private val sql: String +) : CrossProcessCursor by delegate { + // We have to start the span only the first time, regardless of how many times its methods get called. + private var isSpanStarted = false + + override fun getCount(): Int { + if (isSpanStarted) { + return delegate.count + } + isSpanStarted = true + return spanManager.performSql(sql) { + delegate.count + } + } + + override fun onMove(oldPosition: Int, newPosition: Int): Boolean { + if (isSpanStarted) { + return delegate.onMove(oldPosition, newPosition) + } + isSpanStarted = true + return spanManager.performSql(sql) { + delegate.onMove(oldPosition, newPosition) + } + } + + override fun fillWindow(position: Int, window: CursorWindow?) { + if (isSpanStarted) { + return delegate.fillWindow(position, window) + } + isSpanStarted = true + return spanManager.performSql(sql) { + delegate.fillWindow(position, window) + } + } +} diff --git a/sentry-android-sqlite/src/test/java/io/sentry/android/sqlite/SQLiteSpanManagerTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/android/sqlite/SQLiteSpanManagerTest.kt index e2fa0c2e4de..425932113cd 100644 --- a/sentry-android-sqlite/src/test/java/io/sentry/android/sqlite/SQLiteSpanManagerTest.kt +++ b/sentry-android-sqlite/src/test/java/io/sentry/android/sqlite/SQLiteSpanManagerTest.kt @@ -1,5 +1,6 @@ package io.sentry.android.sqlite +import android.database.CrossProcessCursor import android.database.SQLException import io.sentry.IHub import io.sentry.SentryIntegrationPackageStorage @@ -15,6 +16,7 @@ import org.mockito.kotlin.whenever 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 @@ -140,4 +142,17 @@ class SQLiteSpanManagerTest { assertEquals(span.data[SpanDataConvention.DB_SYSTEM_KEY], "in-memory") } + + @Test + fun `when performSql returns a CrossProcessCursor, does not start a span and returns a SentryCrossProcessCursor`() { + val sut = fixture.getSut() + + // When performSql returns a CrossProcessCursor + val result = sut.performSql("sql") { mock() } + + // Returns a SentryCrossProcessCursor + assertIs(result) + // And no span is started + assertNull(fixture.sentryTracer.children.firstOrNull()) + } } diff --git a/sentry-android-sqlite/src/test/java/io/sentry/android/sqlite/SentryCrossProcessCursorTest.kt b/sentry-android-sqlite/src/test/java/io/sentry/android/sqlite/SentryCrossProcessCursorTest.kt new file mode 100644 index 00000000000..13ddf4500cc --- /dev/null +++ b/sentry-android-sqlite/src/test/java/io/sentry/android/sqlite/SentryCrossProcessCursorTest.kt @@ -0,0 +1,124 @@ +package io.sentry.android.sqlite + +import android.database.CrossProcessCursor +import io.sentry.IHub +import io.sentry.ISpan +import io.sentry.SentryOptions +import io.sentry.SentryTracer +import io.sentry.SpanStatus +import io.sentry.TransactionContext +import org.mockito.kotlin.any +import org.mockito.kotlin.eq +import org.mockito.kotlin.mock +import org.mockito.kotlin.verify +import org.mockito.kotlin.whenever +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertNotNull +import kotlin.test.assertTrue + +class SentryCrossProcessCursorTest { + private class Fixture { + private val hub = mock() + private val spanManager = SQLiteSpanManager(hub) + val mockCursor = mock() + lateinit var options: SentryOptions + lateinit var sentryTracer: SentryTracer + + fun getSut(sql: String, isSpanActive: Boolean = true): SentryCrossProcessCursor { + options = SentryOptions().apply { + dsn = "https://key@sentry.io/proj" + } + whenever(hub.options).thenReturn(options) + sentryTracer = SentryTracer(TransactionContext("name", "op"), hub) + + if (isSpanActive) { + whenever(hub.span).thenReturn(sentryTracer) + } + return SentryCrossProcessCursor(mockCursor, spanManager, sql) + } + } + + private val fixture = Fixture() + + @Test + fun `all calls are propagated to the delegate`() { + val sql = "sql" + val cursor = fixture.getSut(sql) + + cursor.onMove(0, 1) + verify(fixture.mockCursor).onMove(eq(0), eq(1)) + + cursor.count + verify(fixture.mockCursor).count + + cursor.fillWindow(0, mock()) + verify(fixture.mockCursor).fillWindow(eq(0), any()) + + // Let's verify other methods are delegated, even if not explicitly + cursor.close() + verify(fixture.mockCursor).close() + + cursor.getString(1) + verify(fixture.mockCursor).getString(eq(1)) + } + + @Test + fun `getCount creates a span if a span is running`() { + val sql = "execute" + val sut = fixture.getSut(sql) + assertEquals(0, fixture.sentryTracer.children.size) + sut.count + val span = fixture.sentryTracer.children.firstOrNull() + assertSqlSpanCreated(sql, span) + } + + @Test + fun `getCount does not create a span if no span is running`() { + val sut = fixture.getSut("execute", isSpanActive = false) + sut.count + assertEquals(0, fixture.sentryTracer.children.size) + } + + @Test + fun `onMove creates a span if a span is running`() { + val sql = "execute" + val sut = fixture.getSut(sql) + assertEquals(0, fixture.sentryTracer.children.size) + sut.onMove(0, 5) + val span = fixture.sentryTracer.children.firstOrNull() + assertSqlSpanCreated(sql, span) + } + + @Test + fun `onMove does not create a span if no span is running`() { + val sut = fixture.getSut("execute", isSpanActive = false) + sut.onMove(0, 5) + assertEquals(0, fixture.sentryTracer.children.size) + } + + @Test + fun `fillWindow creates a span if a span is running`() { + val sql = "execute" + val sut = fixture.getSut(sql) + assertEquals(0, fixture.sentryTracer.children.size) + sut.fillWindow(0, mock()) + val span = fixture.sentryTracer.children.firstOrNull() + assertSqlSpanCreated(sql, span) + } + + @Test + fun `fillWindow does not create a span if no span is running`() { + val sut = fixture.getSut("execute", isSpanActive = false) + sut.fillWindow(0, mock()) + assertEquals(0, fixture.sentryTracer.children.size) + } + + private fun assertSqlSpanCreated(sql: String, span: ISpan?) { + assertNotNull(span) + assertEquals("db.sql.query", span.operation) + assertEquals(sql, span.description) + assertEquals(SpanStatus.OK, span.status) + assertTrue(span.isFinished) + } +} From 4ffeb7dd8780f362ce2f13ffe658d551d6981b55 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Thu, 25 Jul 2024 13:35:01 +0200 Subject: [PATCH 2/2] updated changelog --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index cac75859581..b2ba6fe6128 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,7 @@ ### Fixes +- Fix lazy select queries instrumentation ([#3604](https://github.com/getsentry/sentry-java/pull/3604)) - Check app start spans time and ignore background app starts ([#3550](https://github.com/getsentry/sentry-java/pull/3550)) - This should eliminate long-lasting App Start transactions