Skip to content

Reproduction for sentry-java#5980 - #56

Open
markushi wants to merge 4 commits into
mainfrom
repro/sentry-java-5980
Open

markushi wants to merge 4 commits into
mainfrom
repro/sentry-java-5980

Conversation

@markushi

@markushi markushi commented Aug 26, 2026

Copy link
Copy Markdown
Member

Reproduction harness for getsentry/sentry-java#5980 — "SQLite writer connection timeout on Xiaomi Android 12".

What it builds

The reported setup, rebuilt exactly:

  • Room 3 (3.0.1) with two databases, androidx.sqlite 2.7.0 / BundledSQLiteDriver
  • the reporter's PragmaConfiguringDriver, verbatim from the issue
  • Sentry Android 8.53.0 + SAGP 6.19.0, so the runtime driver chain is
    SentrySQLiteDriver -> PragmaConfiguringDriver -> BundledSQLiteDriver

On top of that, three configurable workloads: a concurrent write burst against a cold database, a
probe over Room's file lock, and a contended replay of Room's first-open path.

Result: not reproduced

Zero writer-pool timeouts, on an Android 12 / API 32 emulator matching the report's platform
(~40 runs) and on an API 36 emulator.

Write burst, 16 writers x 200 inserts + 16 readers x 200 queries, cold database each run:

Emulator SAGP instrumentation run 1 run 2 run 3 pool timeouts
Android 12, API 32, arm64 on (all features) 2132 ms 1808 ms 1874 ms 0
Android 12, API 32, arm64 off 1591 ms 1328 ms 1245 ms 0
API 36, arm64 on (all features) 4461 ms 5095 ms 5062 ms 0
API 36, arm64 off 5041 ms 4534 ms 4114 ms 0

On Android 12 the instrumentation costs a consistent ~40%; on API 36 that was inside the noise.
Neither is close to the factor needed to exhaust Room's 30 second pool timeout.

The instrumentation was verified on the built APK rather than inferred from the Gradle config:
the dex contains one SentrySQLiteDriver.create call site inside
androidx.room3.RoomDatabase$Builder.setDriver (zero in the baseline build), the shipped manifest
carries io.sentry.gradle-plugin-integrations=…DatabaseInstrumentation,FileIOInstrumentation…,
and every worker thread logs a live parent span, so SentrySQLiteStatement is recording rather
than short-circuiting.

FILE_IO instrumentation on Room's file lock — tested, cleared

Room takes a multi-process file lock on a database's first open, and SAGP's FILE_IO feature
rewrites the FileOutputStream inside androidx.room3.concurrent.FileLock.lock() — confirmed in
the shipped dex. SentryFileOutputStream calls super(getFileDescriptor(delegate)), so two
streams share one file descriptor with the locking FileChannel on the outer one, directly on
Room's non-cancellable open path.

FileLockProbe replicates Room's FileLock so it receives the identical rewrite; FirstOpenRace
drives Room's real locked open path under contention. Three runs per configuration on Android 12:

-PsentryFeatures probe stream class OverlappingFileLockException first-open race, slowest round write burst
(instrumentation off) java.io.FileOutputStream 0 37 / 52 / 48 ms 502 / 1039 / 622 ms
DATABASE java.io.FileOutputStream 0 5266* / 85 / 46 ms 1462 / 658 / 577 ms
FILE_IO SentryFileOutputStream 0 50 / 37 / 21 ms 463 / 505 / 349 ms
DATABASE,FILE_IO SentryFileOutputStream 0 56 / 47 / 38 ms 570 / 632 / 559 ms
  • The lock is always released. OverlappingFileLockException is the decisive signal — a lock left
    in the JVM's lock table makes the next lock() on that file fail immediately — and it never
    fired over 500 sequential cycles with the wrapper active. FileChannelImpl.implCloseChannel()
    drains the lock table before calling parent.close().
  • No file descriptor leak: the /proc/self/fd delta is flat at 7–9 for both 300 and 2000 cycles.
  • FILE_IO alone is at or below baseline. The open-path cost comes from DATABASE.

* That single 5266 ms round was chased and does not hold up: 8 repeats with identical parameters
gave 37–47 ms, 10 repeats of a lighter configuration gave 40–154 ms, and 4 fresh-install runs gave
43–68 ms, during which the same emulator threw an unrelated 2531 ms burst outlier. Host noise,
kept in the table because it was observed.

Leads recorded in the README

  1. SentryTracer.startChild goes no-op after maxSpans (1000), bounding the instrumentation cost.
  2. DriverSpans.record captures a stack trace per statement only on the main thread — a path
    this harness never takes, and worth measuring on real hardware.
  3. Closest match to the report: PragmaConfiguringDriver sets busy_timeout = 30000 (Room's
    own default is 3000) and then re-runs journal_mode = WAL, which Room already does itself.
    Pool.acquire() calls the connection factory while holding a pool permit, so a connection
    stalling inside open() on first launch pins the single writer permit for the full 30 s.
  4. In ConnectionPoolImpl.useConnection, markRecycled() runs before pool.recycle(...). If it
    throws — it issues ROLLBACK TRANSACTION — the permit is lost for the life of the pool, which
    is what permits=0 looks like.

Also worth knowing: Room's pool logs the timeout and retries (onTimeout is always
LOG_TIMEOUT_EXCEPTION), so the message alone is not a failure.

Gotcha found while building this

SAGP skips any class whose name starts with io.sentry (ClassContext.isSentryClass(), only
io.sentry.samples and io.sentry.mobile exempted). The first version of this reproduction used
io.sentry.repro.issue5980 and its app code was silently left uninstrumented. The package is now
io.repro.issue5980.

Run it

cd sentry-java/5980
./gradlew :app:installDebug            # add -PsentryInstrumentation=false for the baseline,
                                       # or -PsentryFeatures=DATABASE to isolate one feature
adb shell pm clear io.repro.issue5980
adb logcat -c
adb shell am start -n io.repro.issue5980/.MainActivity --ei writers 16 --ei readers 16 --ei ops 200
adb logcat -d | grep Repro5980
adb logcat -d | grep "Timed out attempting to acquire a writer connection"

🤖 Generated with Claude Code

Rebuilds the reported setup: Room 3 + BundledSQLiteDriver behind a
user-supplied PRAGMA driver, wrapped by SentrySQLiteDriver through SAGP
bytecode instrumentation. Adds a configurable startup burst that puts
Room's single writer connection under pressure, plus an A/B switch to
build with and without the instrumentation.

The writer pool timeout does not reproduce on an API 36 emulator; the
README records the measurements and the analysis of the pool and
instrumentation code paths.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
emit("cold start: the burst below races Room's first open / schema creation")
}

var failures = 0

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bug: The failures counter is incremented from multiple coroutines without synchronization, which can lead to a data race and an inaccurate count of failures.
Severity: LOW

Suggested Fix

To ensure thread-safe increments, replace var failures = 0 with a thread-safe counter like val failures = java.util.concurrent.atomic.AtomicInteger(). Then, change the increment operation failures++ to failures.incrementAndGet().

Prompt for AI Agent
Review the code at the location below. A potential bug has been identified by an AI
agent. Verify if this is a real issue. If it is, propose a fix; if not, explain why it's
not valid.

Location:
sentry-java/5980/app/src/main/java/io/sentry/repro/issue5980/StartupWorkload.kt#L65

Potential issue: The `failures` variable is a standard integer that is incremented from
multiple coroutines running concurrently on `Dispatchers.IO`. The increment operation
(`failures++`) is not atomic. If multiple database operations throw exceptions at the
same time, their respective `catch` blocks will execute simultaneously, creating a race
condition. This will result in lost updates, causing the final reported `failures` count
to be unpredictably lower than the actual number of failures. An inaccurate failure
count in the diagnostic output could mislead developers analyzing the results of this
reproduction harness.

Also affects:

  • sentry-java/5980/app/src/main/java/io/sentry/repro/issue5980/StartupWorkload.kt:83~83
  • sentry-java/5980/app/src/main/java/io/sentry/repro/issue5980/StartupWorkload.kt:94~94

Did we get this right? 👍 / 👎 to inform future reviews.

Record that tracingInstrumentation defaults (enabled=true, features
includes DATABASE) are what make the Room 3 setDriver rewrite apply, and
add the APK-level evidence for both build variants: dex call-site counts
and the io.sentry.gradle-plugin-integrations manifest meta-data.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Comment on lines +48 to +54
echo. 1>&2
echo ERROR: JAVA_HOME is not set and no 'java' command could be found in your PATH. 1>&2
echo. 1>&2
echo Please set the JAVA_HOME variable in your environment to match the 1>&2
echo location of your Java installation. 1>&2

"%COMSPEC%" /c exit 1

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bug: The gradlew.bat script fails to exit properly after an error condition, causing it to fall through and execute subsequent commands, leading to confusing secondary errors.
Severity: LOW

Suggested Fix

Replace the exit command "%COMSPEC%" /c exit 1 with exit /b 1 to correctly terminate the batch script, or add goto :eof immediately after the command to prevent execution from continuing.

Prompt for AI Agent
Review the code at the location below. A potential bug has been identified by an AI
agent. Verify if this is a real issue. If it is, propose a fix; if not, explain why it's
not valid.

Location: sentry-java/5980/gradlew.bat#L48-L54

Potential issue: In the `gradlew.bat` script, if `JAVA_HOME` is not set and the `java`
command is not in the system's `PATH`, the script attempts to print an error and exit.
However, the command used, `"%COMSPEC%" /c exit 1`, only terminates a subprocess and
does not stop the main script's execution. This causes the script to fall through to
subsequent code blocks, leading to a second, confusing error message about an invalid
`JAVA_HOME` directory, and finally an attempt to execute an invalid Java path
(`/bin/java.exe`), causing the script to fail with an unclear error.

Also affects:

  • sentry-java/5980/gradlew.bat:62~68

Room takes a multi-process file lock on a database's first open, and
SAGP's FILE_IO feature rewrites the FileOutputStream inside
androidx.room3.concurrent.FileLock.lock(). SentryFileOutputStream calls
super(getFileDescriptor(delegate)), so two streams share one fd with the
locking FileChannel on the outer one, directly on Room's non-cancellable
open path.

Adds FileLockProbe (replicates Room's FileLock so it gets the identical
rewrite) and FirstOpenRace (drives Room's real locked open path under
contention), plus -PsentryFeatures to isolate individual features.

Result over three runs per configuration: the lock is always released
(no OverlappingFileLockException in 500 cycles), no fd leak, and FILE_IO
alone is within noise of the baseline. The open-path cost comes from
DATABASE. No failures in any configuration.

Also renames the app package away from io.sentry.*, which SAGP skips as
a Sentry class, leaving app code silently uninstrumented.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
eventDb.eventDao().insert(Event(payload = "w$worker-$op"))
} catch (t: Throwable) {
failures++
log("write failed: ${t::class.java.name}: ${t.message?.lineSequence()?.first()}")

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bug: Calling .first() on an exception's message line sequence can crash with NoSuchElementException if the message is an empty string, masking the original error.
Severity: LOW

Suggested Fix

Replace .first() with .firstOrNull() to safely handle cases where the exception message is empty or consists only of newlines. The corrected code would be log("write failed: ${t::class.java.name}: ${t.message?.lineSequence()?.firstOrNull()}"). This prevents the NoSuchElementException and ensures the original error context is not lost.

Prompt for AI Agent
Review the code at the location below. A potential bug has been identified by an AI
agent. Verify if this is a real issue. If it is, propose a fix; if not, explain why it's
not valid.

Location: sentry-java/5980/app/src/main/java/io/repro/issue5980/StartupWorkload.kt#L107

Potential issue: In the `catch` block, the code logs the first line of an exception's
message using `t.message?.lineSequence()?.first()`. If an exception is caught where
`t.message` is an empty string (`""`), `lineSequence()` will produce an empty sequence.
Calling `.first()` on this empty sequence will throw a `NoSuchElementException`, causing
a crash within the error handling logic and masking the original exception. While
standard library exceptions may not produce empty messages, this is a latent bug that
could be triggered by custom or unexpectedly formatted exceptions.

Also affects:

  • sentry-java/5980/app/src/main/java/io/repro/issue5980/StartupWorkload.kt:123
  • sentry-java/5980/app/src/main/java/io/repro/issue5980/FirstOpenRace.kt:63

Matches the platform in the report. Still no writer-pool timeout: zero
occurrences across roughly 40 runs, and the file lock is released in
every configuration.

Android 12 does show a consistent ~40% instrumentation cost on the write
burst, where API 36 kept it inside the noise. A single 5266 ms first-open
round appeared once with DATABASE only; 22 follow-up runs put it back at
37-154 ms, and the same emulator produced an unrelated burst outlier, so
it is recorded as host noise rather than a stall.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant