|
| 1 | +# GTFS-RT Matching CPU Investigation — Design |
| 2 | + |
| 3 | +**Date:** 2026-07-10 |
| 4 | +**Branch:** `perf/gtfsrt-matching-investigation` |
| 5 | +**Status:** Design — approved, revised after adversarial spec review |
| 6 | + |
| 7 | +## Problem |
| 8 | + |
| 9 | +A production OBA deployment (2 GB RAM / 1 vCPU) runs with one GTFS-realtime feed |
| 10 | +wired (~840 trips, polled every ~30 s). Memory is flat (~50%) but CPU is pegged |
| 11 | +near 85% of the single core. A prior assessment claimed this is "mostly |
| 12 | +legitimate work" — that matching 840 trips every 30 s is inherently enough to |
| 13 | +saturate a core. |
| 14 | + |
| 15 | +We doubt that claim. 840 trips every 30 s is ~28 trips/sec of matching work; |
| 16 | +saturating a modern core with that implies large per-trip constant factors, i.e. |
| 17 | +algorithmic waste, not inherent load. |
| 18 | + |
| 19 | +## Goal |
| 20 | + |
| 21 | +Produce **evidence**, not a fix: |
| 22 | + |
| 23 | +1. A committed, repeatable performance harness that reproduces the production |
| 24 | + **poll path** at scale. |
| 25 | +2. A CPU flamegraph + an allocation profile + a wall-clock baseline |
| 26 | + (ms/refresh, refreshes/sec) captured with King County Metro (KCM) GTFS + |
| 27 | + GTFS-RT data. |
| 28 | +3. An attribution of where the cycles actually go, and evidence (not just |
| 29 | + assertion) for the quadratic-cost hypothesis. |
| 30 | +4. A prioritized list of next-step optimizations ranked by cost / risk / reward. |
| 31 | +5. A regression safety net so any *future* optimization is provably |
| 32 | + behavior-preserving. |
| 33 | + |
| 34 | +**Out of scope this session:** changing the matching engine itself. The |
| 35 | +deliverable ends at the prioritized task list. |
| 36 | + |
| 37 | +## Findings that motivate the design (from code exploration, verified in review) |
| 38 | + |
| 39 | +Pipeline: `GtfsRealtimeSource.refresh()` (public; scheduled every |
| 40 | +`_refreshInterval`, default 30 s) → `handleUpdates()` (`synchronized`) → |
| 41 | +`GtfsRealtimeTripLibrary` matching → (gated by dedup) → `VehicleLocationListener` |
| 42 | +→ `BlockLocationServiceImpl` position inference → caches. |
| 43 | + |
| 44 | +**Two distinct cost stages, gated differently — this distinction is load-bearing |
| 45 | +for the harness:** |
| 46 | + |
| 47 | +- **Matching stage (paid every poll):** |
| 48 | + `handleCombinedUpdates` calls `createVehicleLocationRecordForUpdate` for all |
| 49 | + ~840 updates (`GtfsRealtimeSource.java:711`) **before** the `_lastVehicleUpdate` |
| 50 | + timestamp dedup (`GtfsRealtimeSource.java:741-742`). So the full O(feed) match |
| 51 | + cost is paid on every poll even when nothing changed. |
| 52 | + - `GtfsRealtimeTripLibrary.applyTripUpdatesToRecord` — outer loop over |
| 53 | + `stopTimeUpdateList` (line 958); `getBlockStopTimeForStopTimeUpdate` rebuilds |
| 54 | + a `MappingLibrary.mapToValue(stopTimes, "stopTime.gtfsSequence")` index on |
| 55 | + *every* stop-time update (line 1132); plus a second inner loop over all |
| 56 | + `blockTrip.getStopTimes()` per update (lines 964-970) → ≈ O(stops²) per trip. |
| 57 | + |
| 58 | +- **Block-location write stage (gated by dedup):** |
| 59 | + the downstream `_vehicleLocationListener.handleVehicleLocationRecord(record)` |
| 60 | + (`GtfsRealtimeSource.java:744`) only runs when |
| 61 | + `prev.before(timestamp)` — i.e. when the feed timestamp has advanced. This is |
| 62 | + the entry to `VehicleStatusServiceImpl.handleVehicleLocationRecord` → |
| 63 | + `BlockLocationServiceImpl.handleVehicleLocationRecord` (`:228`) → |
| 64 | + `ScheduledBlockLocationServiceImpl` interpolation. In production the feed |
| 65 | + timestamp advances every 30 s, so this **also runs every poll**. A naïve |
| 66 | + harness that replays one static `.pb` would run it only on iteration 1 — see |
| 67 | + Component 2, which corrects for this. |
| 68 | + |
| 69 | +**Read-path, NOT on the poll path:** |
| 70 | +`AbstractBlockLocationServiceImpl.getBlockLocation` is invoked on API |
| 71 | +arrivals/departures *queries*, not by `refresh()`. The poll path calls |
| 72 | +`handleVehicleLocationRecord` (a cache *write*). The primary harness measures the |
| 73 | +poll path; read-path cost is a **secondary, optional** measurement (see |
| 74 | +Component 2b) and is not conflated with the poll suspects. |
| 75 | + |
| 76 | +What is *not* a full-bundle rescan: `getActiveBlocks` / `getBlockInstance` are |
| 77 | +per-blockId and `@Cacheable`; `BlockFinder` is cached (30-min TTL); shape points |
| 78 | +and block indices are prebuilt. So the matching-stage suspects above are the |
| 79 | +target. |
| 80 | + |
| 81 | +## Design |
| 82 | + |
| 83 | +### Principle: decouple the slow/fragile build from the fast profiled loop |
| 84 | + |
| 85 | +The existing `onebusaway-gtfsrt-integration-tests` module is slow and fragile |
| 86 | +because it rebuilds bundles and stands up Spring contexts inside a parallel-fork |
| 87 | +test lifecycle. We reuse its proven building blocks |
| 88 | +(`FederatedTransitDataBundleConventionMain` bundle builder; the |
| 89 | +`GtfsRealtimeSource` DI wiring from `BundleLoader` **and its test subclasses**) |
| 90 | +but run them from a **standalone `main()`**, never as tests in that module. |
| 91 | + |
| 92 | +### Component 1 — Bundle build + pinned feed snapshot (slow, once, off to the side) |
| 93 | + |
| 94 | +- Download KCM GTFS (`google_transit.zip`) into scratchpad and build the KCM |
| 95 | + bundle **once** into a persisted scratchpad directory via |
| 96 | + `FederatedTransitDataBundleConventionMain`. |
| 97 | +- Download the 3 KCM `.pb` feeds **once** into scratchpad and **pin that |
| 98 | + snapshot** (do not re-download per run). Rationale: live KCM feeds drift — |
| 99 | + matched counts and service dates change run-to-run and eventually expire |
| 100 | + against a fixed bundle, destroying comparability. One pinned snapshot + the |
| 101 | + fixed bundle = reproducible numbers. |
| 102 | +- This step is slow, runs outside the measured loop, and never touches CI. KCM |
| 103 | + data + the built bundle are git-ignored (no large binaries committed). |
| 104 | + |
| 105 | +### Component 2 — Perf harness (new committed module `onebusaway-gtfsrt-perf`) |
| 106 | + |
| 107 | +- New isolated Maven module depending on `onebusaway-transit-data-federation` |
| 108 | + (+ the federation-builder for bundle build if needed). |
| 109 | +- **Reactor + test-run mechanics (concrete):** the module IS added to root |
| 110 | + `<modules>` so CI compiles it, but the driver is a `public static void main` |
| 111 | + class (**not** a `*Test`), so root `mvn install` compiles it and never |
| 112 | + executes it. (The root surefire `<excludes>` only covers |
| 113 | + `org/onebusaway/integration/**`; adding a `*Test` would otherwise run in the |
| 114 | + default unit phase.) No reliance on implicit exclusion. |
| 115 | +- The driver `GtfsRtRefreshBenchmark` (main class): |
| 116 | + 1. **Stand up the source with the full collaborator set** the poll path needs |
| 117 | + (replicating `BundleLoader` **plus** what |
| 118 | + `AbstractGtfsRealtimeIntegrationTest` wires — `BundleLoader` alone is |
| 119 | + insufficient): |
| 120 | + - blocking bundle load via `ContainerLibrary.createContext(...)`, waiting |
| 121 | + for `BundleManagementService.bundleIsReady()`, with the pre-built bundle |
| 122 | + mounted via the `bundle.root`/`bundlePath` system properties; |
| 123 | + - `setRefreshInterval(0)` so **no background `RefreshTask` is scheduled** — |
| 124 | + we drive `refresh()` synchronously and avoid the `synchronized |
| 125 | + handleUpdates` interleaving that a live scheduler + manual loop would |
| 126 | + cause; |
| 127 | + - a **non-null `VehicleLocationListener`** that delegates to the real |
| 128 | + `VehicleStatusServiceImpl` bean (mirroring |
| 129 | + `TestVehicleLocationListener`) — without it, `refresh()` NPEs at |
| 130 | + `cacheVehicleLocations` (line 662) and the block-location write path is |
| 131 | + never measured; |
| 132 | + - the cancel service and feed `file://` URLs |
| 133 | + (`setTripUpdatesUrl`/`setVehiclePositionsUrl`/`setAlertsUrl`) pointed at |
| 134 | + the pinned local `.pb` files. |
| 135 | + 2. **Reset dedup per measured iteration.** Call `source.reset()` (public, |
| 136 | + `GtfsRealtimeSource.java:574` — clears `_lastVehicleUpdate`) at the top of |
| 137 | + every iteration so **both** stages run every iteration, matching |
| 138 | + production where the feed timestamp advances each poll. Without this, only |
| 139 | + iteration 1 exercises the block-location write path and the baseline |
| 140 | + understates real cost. (Log matched/unmatched + per-refresh ms — the source |
| 141 | + already logs these at lines 785-791 — to confirm both stages fire each |
| 142 | + iteration.) |
| 143 | + 3. **Warmup:** ~20 `source.refresh()` calls (each with `reset()`), so **both** |
| 144 | + the matching and block-location paths are JIT-warm before measurement. |
| 145 | + 4. **Measure:** ~100 `source.refresh()` calls, recording per-call ms → |
| 146 | + mean / p50 / p95, refreshes/sec. |
| 147 | + 5. **Profile only the measure phase** (start the profiler after warmup, stop |
| 148 | + before teardown): |
| 149 | + - async-profiler `event=cpu` → CPU flamegraph HTML (primary); |
| 150 | + - async-profiler `event=alloc` → allocation flamegraph — directly tests the |
| 151 | + "index rebuilt on every stop-time update" hypothesis, which a CPU-only |
| 152 | + graph can mis-attribute to GC threads; |
| 153 | + - JVM flags for accurate stacks: |
| 154 | + `-XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints` (both |
| 155 | + async-profiler and JFR are safepoint-biased without it); pinned |
| 156 | + `-Xmx`/GC; `-Xlog:gc` for GC overhead. |
| 157 | + - **Fallback:** JDK-builtin **JFR** (`-XX:StartFlightRecording`) if |
| 158 | + async-profiler won't attach on macOS. |
| 159 | + 6. Optionally dump the produced records to a local KCM snapshot for |
| 160 | + (non-committed) confidence. |
| 161 | + |
| 162 | +Measuring `refresh()` in a `reset()`-per-iteration loop is faithful: production |
| 163 | +does the identical `refresh()` → `handleUpdates` → match → listener work each |
| 164 | +poll; we remove only the 30 s sleep. |
| 165 | + |
| 166 | +### Component 2b — Optional read-path measurement (secondary) |
| 167 | + |
| 168 | +The production symptom described (CPU pegged "importing and matching") points at |
| 169 | +the poll path, which is the primary target. If poll-path cost does **not** |
| 170 | +account for the observed saturation, add a secondary measured step that drives |
| 171 | +API reads (`BlockLocationService.getScheduledLocationForBlockInstance` / |
| 172 | +arrivals-and-departures) to exercise `getBlockLocation`, and profile that |
| 173 | +separately. Kept out of the primary baseline so the two paths are never |
| 174 | +conflated. |
| 175 | + |
| 176 | +### Component 3 — Regression golden test (committed, unit-level, CI-friendly) |
| 177 | + |
| 178 | +- A characterization test at the **unit level** on |
| 179 | + `GtfsRealtimeTripLibrary.createVehicleLocationRecordForUpdate` — constructed |
| 180 | + inputs, snapshot of the produced `VehicleLocationRecord` / predictions — |
| 181 | + consistent with the existing `GtfsRealtimeTripLibraryTest` (Mockito-based, no |
| 182 | + bundle/Spring lifecycle). |
| 183 | +- Rationale (revised from the first draft): a *real* `source.refresh()` golden |
| 184 | + needs the same bundle build + Spring context + `BundleManagementService` as |
| 185 | + the fragile integration module, and the `cut.zip` fixtures live in that |
| 186 | + module's `src/test/resources` (not visible elsewhere without a test-jar or |
| 187 | + duplication). A unit-level golden covers the exact refactor target |
| 188 | + deterministically, fast, in CI, with zero lifecycle entanglement. |
| 189 | +- Regeneratable via a flag (e.g. `-Dupdate.golden=true`). |
| 190 | +- Purpose: any *future* optimization of the hot methods must reproduce identical |
| 191 | + output. This is the behavior-preserving safety net for step 1. |
| 192 | +- Full-`refresh()` characterization is deferred to the integration module if ever |
| 193 | + wanted; not built this session. |
| 194 | + |
| 195 | +### Components 4–5 — Analysis |
| 196 | + |
| 197 | +- Attribute CPU **self-time** (poll path) to `applyTripUpdatesToRecord`, |
| 198 | + `getBlockStopTimeForStopTimeUpdate` (the map rebuild), |
| 199 | + `handleCombinedUpdates`, `handleVehicleLocationRecord`/ |
| 200 | + `ScheduledBlockLocationServiceImpl` (block-location write), and feed parsing. |
| 201 | +- Corroborate with the **allocation** profile and GC logs. |
| 202 | +- **Demonstrate the complexity class, not just self-time:** capture per-trip |
| 203 | + stop-count distribution from the KCM bundle so the O(stops²) claim is |
| 204 | + evidence-backed (self-time correlated with stop count), rather than asserted |
| 205 | + from the flamegraph alone. |
| 206 | + |
| 207 | +### Component 6 — Deliverable report |
| 208 | + |
| 209 | +Written findings under `docs/`: baseline numbers, CPU + allocation attribution, |
| 210 | +the quadratic-scaling evidence, and a ranked fix list (each entry: expected |
| 211 | +reward, implementation cost, regression risk, and which existing/added test |
| 212 | +covers it). |
| 213 | + |
| 214 | +## Testing strategy |
| 215 | + |
| 216 | +- **Unit-level golden** (Component 3) is the regression net for the hot path — |
| 217 | + committed, fast, deterministic, CI-safe. |
| 218 | +- Existing coverage relied on as-is: `GtfsRealtimeTripLibraryTest` (12), |
| 219 | + `ScheduledBlockLocationServiceImplTest` (14), 16 end-to-end integration tests. |
| 220 | +- The harness itself is validated by: it builds, it completes N refreshes |
| 221 | + without error, both stages fire each iteration (matched-count logging), and it |
| 222 | + emits non-empty CPU + alloc flamegraphs plus timing numbers. |
| 223 | + |
| 224 | +## Risks & mitigations |
| 225 | + |
| 226 | +- **Static-feed dedup hides half the pipeline** → `source.reset()` per measured |
| 227 | + iteration (Blocker fix); confirm via per-iteration matched-count logging. |
| 228 | +- **Poll-path vs read-path confusion** → primary harness measures the poll path |
| 229 | + only; `getBlockLocation` (read-path) is a separate optional measurement. |
| 230 | +- **async-profiler attach on macOS may fail** → JFR fallback (ships with JDK 11). |
| 231 | +- **KCM bundle build is slow/heavy; live feed drifts** → build once, pin one |
| 232 | + `.pb` snapshot, persist, exclude from CI. |
| 233 | +- **New module slowing/altering the default build** → added to the reactor as a |
| 234 | + `main()` class (no `*Test`), so `mvn install` compiles but never runs it. |
| 235 | +- **`refresh()` NPE / missing collaborators** → enumerate and wire the full set |
| 236 | + (listener delegating to real `VehicleStatusServiceImpl`, cancel service, feed |
| 237 | + URLs, `refreshInterval=0`, blocking bundle load) per |
| 238 | + `AbstractGtfsRealtimeIntegrationTest`, not just `BundleLoader`. |
| 239 | +- **Safepoint-biased stacks / single-run variance** → `DebugNonSafepoints`; |
| 240 | + report mean/p50/p95; profile only the measure phase. |
| 241 | + |
| 242 | +## Non-goals |
| 243 | + |
| 244 | +- No changes to `GtfsRealtimeTripLibrary` / `BlockLocationServiceImpl` / any |
| 245 | + matching code this session. |
| 246 | +- No committing of KCM data or built bundles (large binaries). |
| 247 | +- No modification to the fragile `onebusaway-gtfsrt-integration-tests` lifecycle. |
0 commit comments