DEV Community

Cover image for Eleven tables, zero indices, and the observability I added afterwards found three more bugs
Arqam Waheed
Arqam Waheed Subscriber

Posted on

Eleven tables, zero indices, and the observability I added afterwards found three more bugs

Summer Bug Smash: Clear the Lineup ๐Ÿ›๐Ÿ›น

This is a submission for DEV's Summer Bug Smash: Clear the Lineup.

TL;DR. My app recomputes every coaching verdict from raw training logs on read. With a five-year history that took 119.1 ms per session, because eleven Room entities had zero indices between them. Adding indices took it to 6.8 ms, a 17.4x improvement, and one query got no faster at all. Then I instrumented the thing properly and Sentry found three bugs I did not know about, including one where Sentry had been silently discarding every trace I sent it. Zero accepted. Five invalid.


What I Built

I built WhyRep, a workout tracker that analyzes your training instead of just recording it. Log a session, get a verdict with a traceable reason: you are progressing, you have stalled, this is what to change. Every coaching decision traces back to a methodology document I signed off on, not to something a model invented in the moment.

The architecture choice that matters for this post is that nothing is precomputed. Verdicts are derived from raw set logs on read, every time. That keeps the coaching logic honest, because there is no cached judgement to go stale when the rules change. It also means every read walks the history.

Android is native Kotlin and Jetpack Compose. iOS is SwiftUI over a shared Kotlin Multiplatform core, so the engines have one implementation across both platforms. Storage is Room, local-first, and the tracker works offline with no account. The coach runs through a 235-line dependency-free Cloudflare Worker that holds the model key so it never ships in the APK.

Roughly 10,000 lines of Kotlin in the app module. Eleven Room entities. An 847-exercise catalog.

And, until the work in this post, no observability of any kind. No error reporting. No performance data. The Worker's top-level handler was console.error(e) followed by a generic 500, which in production means nothing is recorded anywhere.

I want to be precise about the order of events, because it matters for how you read the rest of this. The performance work came first and I found it by reading code, not by using Sentry. Sentry did not exist in this project yet. What Sentry found is a separate section, further down, and those are different bugs.


How Sentry got in

This is the first of four posts about that fortnight, so it is worth saying what the instrumentation actually is before I start quoting it at you. Three Sentry projects went in: the Android app, the Cloudflare Worker, and the landing site. All three were wired from nothing, and every finding in this series came out of that window.

The Android app uses the official SDK, gated on the DSN. SentryAndroid.init runs only if BuildConfig.SENTRY_DSN is non-blank, so a contributor can clone this repo with no Sentry account and the app behaves as though the dependency is not there. Making that guarantee actually true cost me a day and a 100% crash rate, which is post two.

The Worker could not use the SDK at all. Its deploy story is "paste one dependency-free file into the Cloudflare dashboard", and I was not giving that up for an npm install. So it speaks to Sentry's envelope endpoint through about 150 lines I wrote by hand: captureException, transaction and span envelopes, trace_id and parent_span_id threaded through from the app. Writing a protocol client instead of installing one is how I found the bug in section 5.

The coach call is traced as an AI span, not as a fetch. gen_ai.chat carries the model, and alongside it gen_ai.usage.input_tokens, output_tokens, cache_read_input_tokens, cache_creation_input_tokens, stop_reason, latency_ms, and a computed cost_usd. Around it sit auth.jwt, kv.get for the entitlement lookup and kv.rate_limit for the daily cap. One trace covers a tap on an Android phone, a Clerk JWT verified at the edge, two KV reads, and a Claude call, with the token and cache accounting sitting on the model span.

Nothing carrying training data leaves the device. sendDefaultPii is false everywhere. The Android beforeSend strips exercise names, weights, reps, RIR and notes. The landing site strips the URL fragment and the query string in beforeSend, beforeSendTransaction and beforeBreadcrumb, which is post four, and which I got wrong the first time.

Session Replay runs on the landing site only, and it is deliberately timid. maskAllText: true, blockAllMedia: true, replaysSessionSampleRate: 0.01, replaysOnErrorSampleRate: 1.0. I do not want a recording of every visitor. I want the one session where something broke.

The honest framing, once, up front: WhyRep is pre-release. The traffic behind every number in this series is my own device plus twelve closed testers, and I say so again each time it matters.

Bug Fix or Performance Improvement

The analyzer read path had four independent defects on it. I found them during a performance pass on 2026-07-25, reading the code that answers the question "how did this session go."

B3, the headline: eleven entities, zero indices. Every relation fetch full scanned set_logs, which is the table holding every set the lifter has ever performed. It is the largest table in the schema by a wide margin and it is the one on the hot path. This is invisible on a fresh install and gets worse every month, which means it punishes the most committed users first. That is exactly the wrong population to punish in a training app.

B1: reorderExercises wrote one row at a time. WorkoutRepository.kt:143 and :316 issued one UPDATE per row with no enclosing transaction. Finishing a 30-set workout was roughly 30 separate commits.

B2: cold start hydrated the entire catalog. seedIfEmpty at WorkoutRepository.kt:99 materialized all 847 catalog entities on every launch, purely to build a set of name and equipment pairs it then threw away.

B4: search allocated a string per row per keystroke. Three call sites built a joined lowercase string for every one of 847 exercises, on every keypress.

The interesting one is B3, and the interesting part of B3 is not the index. Everybody knows to add an index. The interesting part is the trap I nearly walked into while adding it.

Before and after: eleven Room tables with no indices full-scanning set_logs at 119.1 ms, versus seven indexed tables resolving in 6.8 ms

The read path, before and after. The analyzer recomputes every verdict from raw logs, so the scan was not a corner case, it was the main case.


Code

Here is the migration. The repo is private, so this post carries the diffs inline, which the rules explicitly allow.

// Db.kt, MIGRATION_11_12
database.execSQL(
    "CREATE INDEX IF NOT EXISTS `index_set_logs_exerciseLogId` " +
    "ON `set_logs` (`exerciseLogId`)"
)
database.execSQL(
    "CREATE INDEX IF NOT EXISTS `index_exercise_logs_sessionId` " +
    "ON `exercise_logs` (`sessionId`)"
)
// ...seven tables in total
Enter fullscreen mode Exit fullscreen mode

And the corresponding entity annotation:

@Entity(
    tableName = "set_logs",
    indices = [Index(value = ["exerciseLogId"])],
    // ...
)
Enter fullscreen mode Exit fullscreen mode

Now the trap, which is the part worth stealing. Room builds a fresh install from the @Entity annotations and an upgrade from the migration's raw SQL. Those are two independent sources of truth describing the same schema, and nothing in the framework checks them against each other at compile time.

Name that index index_set_logs_exerciseLogId in one place and anything else in the other, and you get the worst possible failure shape. Every new install works perfectly. Every existing install crashes on open with a schema validation error. You will not see it in development, because your development database gets recreated constantly.

It is a bug that only fires for users who already trust you.

So the test does not go on the annotation, and it does not go on the migration. It goes between them:

@Test
fun `migration produces the index names the annotations expect`() {
    val migrated = helper.runMigrationsAndValidate(TEST_DB, 12, true, MIGRATION_11_12)
    val names = migrated.query(
        "SELECT name FROM sqlite_master WHERE type='index' AND tbl_name='set_logs'"
    ).use { c -> generateSequence { if (c.moveToNext()) c.getString(0) else null }.toList() }

    assertTrue("index_set_logs_exerciseLogId" in names)
}

@Test
fun `the planner actually uses the index`() {
    val plan = db.query("EXPLAIN QUERY PLAN SELECT * FROM set_logs WHERE exerciseLogId = ?", arrayOf(1))
        .use { c -> c.moveToFirst(); c.getString(c.getColumnIndexOrThrow("detail")) }

    assertTrue(plan.contains("USING INDEX index_set_logs_exerciseLogId"))
}
Enter fullscreen mode Exit fullscreen mode

The second test is the one I would not skip. Asserting an index exists proves you created an object. Asserting EXPLAIN QUERY PLAN names it proves the planner reaches for it, which is the thing you actually wanted. Those are not the same claim and I have written code where only the first one was true.

The lesson generalises past Room. When a framework generates the same artefact from two sources, the test belongs between the two sources, not on either one.


My Improvements

Measured on 2026-07-25 with PerformanceBenchmark.kt, run as:

./gradlew :app:testDebugUnitTest --tests '*PerformanceBenchmark*' -Dbenchmark=1
Enter fullscreen mode Exit fullscreen mode
Measurement Before After Change
Analyze one session, 300-session history 119.1 ms 6.8 ms 17.4x
20 keystrokes over 847 exercises 4.2 ms 566 us 7.5x
Mark 20 sets complete 2.4 ms 342 us 7.1x
Cold-start catalog identity check 2.8 ms 908 us 3.1x
Load the full history list 10.7 ms 11.4 ms no measurable change

The methodology, in full, because the numbers are worthless without it. The dataset is synthetic: 300 sessions by 5 exercises by 4 sets, which is 6,000 set rows and roughly a five-year training history. Measured on the JVM under Robolectric, not on a device. These are fair relative comparisons of two implementations against the same seeded database in the same process. They are not phone timings and I am not presenting them as phone timings. Median of 15 runs after 5 warmups, median rather than mean so one GC pause cannot move the figure. Where the old code no longer exists, the benchmark reimplements it inline so both sides run under identical conditions. The index rows are measured by dropping and recreating the real v12 indices on the same data.

The last row is the honest one and it stays in. Indices made no measurable difference to loading the full history list. That is correct, not a measurement error. That query returns nearly every row of sessions, so SQLite scans regardless and an index cannot help. Indices pay off on selective lookups, which is where the 17.4x came from.

I could have reported only the flattering row. A table with one negative result in it is more trustworthy than a table without one, and I would rather you believed the 17.4x.

Here is what I refused to do while fixing this:

  • Do not quote a device number I measured on the JVM.
  • Do not drop the row that did not improve.
  • Do not present a synthetic history as real user data.
  • Do not assert an index exists and call that a performance test.

Best Use of Sentry

Everything above was found by reading code. Sentry found different bugs, and this section is only about those. I am keeping the line hard because a submission that blurs it is not worth reading.

I wired Sentry into three projects: the Android app, the Cloudflare Worker, and the static landing site. The Worker could not use the official SDK, because its deploy story is "paste one dependency-free file into the Cloudflare dashboard" and I was not giving that up. So the Worker talks to Sentry's envelope endpoint through about 150 lines I wrote by hand.

That decision is how the first bug happened.

1. Sentry told me it was throwing away everything I sent it. Through a usage counter.

Found by: Settings, then Stats and Usage. Not an issue. Not an alert. Not Seer.

The Worker deployed clean. /health returned {"ok":true}. /chat correctly returned {"error":"unauthenticated"} on a bare request. wrangler tail showed outcome: ok with zero exceptions. Sentry's Traces view said "Waiting for this project's first trace."

Every one of those is exactly what a healthy Worker with no traffic looks like. That is the problem. I had sent it traffic.

The only place the truth appeared was a counter on a settings page:

Project Total Accepted Filtered Rate Limited Invalid
coach-worker 5 0 0 0 5
android 3 3 0 0 0

33 requests at a 0.2 sample rate produced 5 sampled transactions, which is the sampler working correctly. All 5 were rejected. The android row on the same screen, using the official SDK, accepted 3 of 3. That comparison is what made it a payload bug rather than a DSN, network, or config bug.

Root cause: one id generator doing two jobs.

function uuid() {
  return crypto.randomUUID().replace(/-/g, "");   // 32 hex chars
}
Enter fullscreen mode Exit fullscreen mode

32 hex characters is correct for event_id and correct for trace_id. It is wrong for a span id. A Sentry trace id is 16 bytes and a span id is 8, exactly as in W3C trace-context where parent-id is 16 hex characters. I was calling uuid() at three span-id sites, and Relay discards a transaction whose span id is the wrong width.

Why it survived to production. Ingest accepts the envelope and answers 200. The rejection happens later, inside Relay, after the Worker's request is long over. So it cannot appear in the response, in ctx.waitUntil, in wrangler tail, or in the issue stream. My send() even has a .catch() that logs sentry send failed. It never fired, because the send genuinely succeeded.

The fix separates the widths and makes the distinction impossible to un-learn:

/** 32 hex chars. Correct for `event_id` and `trace_id`, and WRONG for a span id. */
function uuid() {
  return crypto.randomUUID().replace(/-/g, "");
}

/**
 * 16 hex chars, which is what a Sentry span id is: 8 bytes, the same width as
 * W3C trace-context's `parent-id`. A trace id is 16 bytes and a span id is 8,
 * and they are NOT interchangeable.
 */
function spanId() {
  return crypto.randomUUID().replace(/-/g, "").slice(0, 16);
}
Enter fullscreen mode Exit fullscreen mode

I considered a single id(bytes) helper taking a width argument and rejected it. A call site reading id(8) still lets someone pass the wrong number. spanId() has no argument to get wrong.

Metric Before After
Transactions accepted 0 8
Rejected as Invalid 5 (100%) 0
Traces view "Waiting for this project's first trace" 8 spans, all POST /chat

The guard is scripts/check-sentry-ids.mjs, six checks, running in CI. I verified it goes red before trusting it: reverting the three spanId() calls fails 2 of 6 with span_id is 16 lowercase hex chars: got 32 chars. It carries a behavioural check and a static one, because the behavioural check alone only covers startSpan, and two of the three original offenders minted their ids inline.

The deeper cause is not the character class. backend/coach-worker/ had no tests and no CI workflow at all. A hand-rolled protocol client with no test against the protocol is the actual defect. The workflow landed in the same commit, because adding a guard without adding the thing that runs it recreates the exact conditions that let this live.

Four-box chain from Worker to Sentry Ingest to Relay to Traces view, showing the 200 OK returned before Relay discards the span

The failure lives past the 200. That is why no signal on the Worker side could ever have shown it, and why a usage counter could.

2. Performance Issues found a database open on the main thread. It sat unread for thirteen days.

Found by: Sentry's "DB on Main Thread" detector, on the MainActivity ui.load transaction. Issue ANDROID-1, 16 events, 1 user.

DB on Main Thread
INSERT OR IGNORE INTO room_table_modification_log VALUES(1, 0)
transaction: MainActivity ยท start_type: cold ยท ui.load 6.43s
Enter fullscreen mode Exit fullscreen mode

AppViewModel registered an invalidation observer from an init block:

init {
    db.invalidationTracker.addObserver(cacheInvalidator)
}
Enter fullscreen mode Exit fullscreen mode

That reads like bookkeeping. Hand Room an object, get told when tables change. It is not bookkeeping. Decompiled from room-runtime 2.8.4 rather than recalled:

9:  invokespecial addObserverOnly:(InvalidationTracker$Observer;)Z
29: invokestatic  RunBlockingUninterruptible_androidKt.runBlockingUninterruptible:(...)
Enter fullscreen mode Exit fullscreen mode

It blocks the calling thread, uninterruptibly, to sync the invalidation triggers. Syncing opens the database if it is not open and writes one row per observed table. A ViewModel is constructed on the main thread, so every cold start paid a database open plus four writes in front of the first frame.

Why it hid for thirteen days. It throws nothing, so it is a performance issue rather than an error and never triggered an alert. Sentry filed it Low, under two High items. And the API that causes it has a signature promising nothing about blocking, so it survived a code review that had already been over this exact file for the index work above.

The fix moves registration to Dispatchers.IO, and because that makes registration asynchronous, it keeps removal ordered behind it:

internal class TableObserverRegistration(
    dispatcher: CoroutineDispatcher = Dispatchers.IO,
    private val register: () -> Unit,
    private val unregister: () -> Unit,
) {
    private val scope = CoroutineScope(SupervisorJob() + dispatcher)
    private val registered: Job = scope.launch { register() }

    fun dispose() {
        scope.launch {
            registered.join()
            unregister()
        }.invokeOnCompletion { scope.cancel() }
    }
}
Enter fullscreen mode Exit fullscreen mode

Two things a bare viewModelScope.launch { } would have got wrong, which is why this is a class and not one line. First, viewModelScope cannot own the removal, because onCleared runs after that scope is cancelled, so a removal launched there never executes and the observer leaks for the life of the process. Second, once registration is asynchronous the pair can invert: a ViewModel cleared quickly by rotation or a fast back-out reaches dispose() while registration is still in flight, and a removeObserver that overtakes its own addObserver silently does nothing and leaks identically. registered.join() is what holds the order regardless of interleaving.

The honest caveat on impact. The win is a main-thread-blocking removal, not a measured millisecond count. Sentry's detector reports that the span ran on the main thread, not how long it took. I am not quoting a cold-start delta this fix has not measured.

There is a second honest note here, about my own test. unregisterCannotOvertakeRegister originally blocked forever against the reverted code instead of failing, because its fake register awaited a latch with no timeout. ./gradlew test hung. A regression test that deadlocks when the bug returns hands CI a timeout instead of a signal, and a timeout is the one failure mode people retry rather than read. The await is bounded now and both tests fail in 28 seconds against the reverted code.

"I verified the test goes red" is itself a claim. Hanging is not red.

3. Error Monitoring caught a fatal on the sign-in screen

Found by: Error Monitoring. Unhandled IllegalStateException, fatal, handled: no, mechanism: UncaughtExceptionHandler. 3 events, 1 user, all inside 20 minutes.

IllegalStateException: Size(948 x 2147483647) is out of range.
Each dimension must be between 0 and 16777215.
Enter fullscreen mode Exit fullscreen mode

2147483647 is Int.MAX_VALUE, which is Compose's Constraints.Infinity. Two individually reasonable requirements that cannot both hold: Modifier.verticalScroll measures its child with an unbounded main axis, which is the entire point of a scroll container. And material3 Scaffold measures through a SubcomposeLayout, which rejects any dimension above 16777215.

My onboarding put all four steps inside one shared scrolling column. Three are plain forms. The fourth renders Clerk's AuthView, and AuthView renders its own material3 Scaffold. So the sign-in step handed a Scaffold an infinite height.

The 948 is what located it before I changed a line. The device is 1080px wide at density 2.75, and 1080 minus 948 is 132px, which is 48dp, which is exactly the .padding(horizontal = 24.dp) on that column and on no other column in the app.

The breadcrumbs made it look like a lifecycle bug: the activity paused, stopped and restarted three seconds before the crash. It was neither rotation nor a return from background. AuthView renders a placeholder until Clerk's network calls return. Both returned at 04:55:14.05 and the crash is at 04:55:15.40. The app crashed when the real sign-in form first composed, so the trigger was a round trip completing.

The fix narrows the scroll to the steps that need it rather than deleting it, because the form steps genuinely do overflow with the keyboard up.

A concession about this one: the event is tagged environment: debug, on my own device. It is real traffic on real hardware and it is not production traffic, and I am not going to describe it as production traffic.

4. Seer was right about the numbers and wrong about the cause

This is the section I expect to be least popular and I think it is the most useful.

Sentry filed ANDROID-3 with a Seer-authored description:

"The application performs a large number of synchronous database trigger creations and insertions on the main thread during the 'seedIfEmpty' operation, which blocks the UI during the cold start process."

Stated impact: 383 ms of a 1831 ms cold start. Evidence: span 2b74f84036ca48b6 containing 38 sequential sqlite queries.

What is true: the numbers. There is a db.seed span, it does contain 38 sequential queries, and it is inside the MainActivity load. All of that checks out against the trace.

What is false: the load-bearing half. The queries are not on the main thread.

That needs a more careful argument than it looks like, because the obvious argument is one this same project already falsified. I could say allowMainThreadQueries() appears nowhere in WhyRepDb.get() so the guard would have thrown. But bug 2 above was a genuine main-thread database write that sailed straight past that guard, because addObserver blocks through runBlockingUninterruptible instead of going down the guarded query path.

So I checked both sites instead. The addObserver path is still fixed and goes through TableObserverRegistration on Dispatchers.IO, confirmed in the file rather than remembered, which rules out a regression of bug 2. And seedIfEmpty is DAO calls only, where Room's generated suspend methods dispatch to the query executor, so it starts on Main.immediate, suspends at the first DAO call, and never resumes on main. Those are on the guarded path, so there the guard argument does hold.

What the 38 queries actually are. Eleven entities, three temp triggers per table installed by InvalidationTracker on first database access, which is 33, plus the open, the version check, one identity read and the insert. That is 38. It is Room's fixed first-open cost, and it is charged to db.seed only because seedIfEmpty happens to be the first thing to touch the database. Rename the span and the cost moves with it.

Expanding the span in Sentry's own trace view confirms it:

db.sql.query โ€” CREATE TEMP TRIGGER IF NOT EXISTS `room_table_modification_trig...   0.16ms
db.sql.query โ€” CREATE TEMP TRIGGER IF NOT EXISTS `room_table_modification_trig...   0.20ms
db.sql.query โ€” INSERT OR IGNORE INTO room_table_modification_log VALUES(2, 0)       0.07ms
                                                                    32 hidden spans
Enter fullscreen mode Exit fullscreen mode

So the claim "38 sequential sqlite queries" and the claim "insertions on the main thread" came from the same trace, and one of them was reading it correctly.

I left the issue open with a comment rather than resolving it. Nothing was fixed and the 383 ms is genuine, so resolving would assert something untrue about a real measurement. The comment ends with "do not code against the title."

Why I am telling you this in a Sentry category submission. Because the alternative is a paragraph saying Seer is great, and you have read that paragraph already. A tool that is precisely right about measurements and confidently wrong about mechanism is more interesting than a tool that is right, and it is the failure mode you actually need to plan for. Seer got me to the span. I still had to read the bytecode.

Sentry's own Suspect Commit was also wrong on this issue. It blamed a commit that had nothing to do with the span.

Two columns comparing what Seer claimed against what the span actually contained, with the main-thread claim marked wrong

The honest version of an AI root cause analysis. Measurements and mechanism are separate claims and they fail separately.


What I Learned

A green signal reports on the part of the trip it can see. The Worker's .catch() never fired because the send succeeded. Everything past the 200 was invisible to every check I had.

A performance test asserts the plan, not the object. An index that exists and an index the planner reaches for are two different claims, and only one of them is the one you wanted.

The negative result is what makes the positive one credible. One query got no faster. Saying so costs nothing and buys the rest of the table.

A guard that has never been observed to fire is a guess. check-sentry-ids.mjs is trustworthy because I broke the code and watched it go red. unregisterCannotOvertakeRegister was not trustworthy until I found out it hung instead of failing.

Instrumentation is a protocol client, and protocol clients need tests. Mine was 150 hand-written lines against a wire format, shipped with no test against that wire format. The character class was where it surfaced. The missing test was the bug.

I added observability to find bugs in my app. The first thing it found was a bug in my observability.


One thing I would genuinely like an answer to, if you have one. The EXPLAIN QUERY PLAN assertion is the most useful test in this whole repo, and I have never seen it in anyone else's Android codebase. Is there a reason for that I have not thought of, or is it just that nobody bothers? I would rather find out now than in a year.

WhyRep is in closed testing on Play and launches in September. If you lift, I will take testers.

Top comments (0)