FB-11: serialize FileTileCache mutations and log tile fetch failures
Fixes a real race in FileTileCache where two overlapping put() calls (the persistent background map and a freshly-opened Route Planner map both fetching tiles at once) could interleave at the _saveManifest await point and silently lose a tile from the on-disk manifest. All mutating and reading operations now go through a single serialization queue. Also logs the URL and cause of tile fetch failures in CachedTileProvider before rethrowing, and adds a concurrency regression test. On-device verification was not performed (no adb/emulator access in this environment); see the ticket's Outcome section.
This commit is contained in:
249
docs/feedback/FB-11-route-planner-tiles-still-blank.md
Normal file
249
docs/feedback/FB-11-route-planner-tiles-still-blank.md
Normal file
@@ -0,0 +1,249 @@
|
||||
# FB-11 — Route Planner map still shows no tiles
|
||||
|
||||
**Depends on** — · **Size** M/L · **Status** Done
|
||||
|
||||
## Goal
|
||||
Opening the Route Planner (the "+" button, or tapping any existing route) must show a
|
||||
real, detailed map underneath the pins. Today it shows a flat, featureless area.
|
||||
|
||||
## Context
|
||||
Direct user feedback (`docs/FEEDBACK.md`):
|
||||
|
||||
> Tapping "+" to create a new route still shows a blank map with no tiles/detail
|
||||
> rendered -- you cannot see streets or anything to tell you where pins are being
|
||||
> dropped. A previous attempt at this fix (FB-07) did not actually resolve it
|
||||
> on-device.
|
||||
|
||||
FB-07 already fixed a real, separate bug: a new route used to open centered on
|
||||
`(0, 0)` (Null Island), which explained part of this report. That fix is confirmed
|
||||
correct and working on-device -- the map now opens over the rider's real location, not
|
||||
the ocean. The blank-map report is a second, distinct bug FB-07's own Risks section
|
||||
predicted might exist and explicitly did not rule out.
|
||||
|
||||
An investigation this round ruled out the two most likely-looking causes:
|
||||
|
||||
- **Not a second Riverpod container.** `lib/main.dart` has exactly one `ProviderScope`
|
||||
for the whole app. `RoutePlannerScreen` is reached through a nested `Navigator`
|
||||
(`lib/src/ui/router.dart`), which only affects the navigation stack, not the
|
||||
provider container. `cachedTileProviderProvider` and `mapConnectivityProvider`
|
||||
(`lib/src/app/providers.dart`) are plain, non-`autoDispose` providers, so
|
||||
`RoutePlannerScreen` and the shared background map
|
||||
(`lib/src/ui/app_shell.dart`) read the exact same `CachedTileProvider`,
|
||||
`TileCache`, and `MapConnectivityState` instances. There is no isolation between
|
||||
them.
|
||||
- **Not stuck skeleton mode.** `MapConnectivityState` (`lib/src/tiles/map_connectivity.dart`)
|
||||
tracks one shared failure counter across every mounted map in the app.
|
||||
`reportSuccess()` resets that counter to zero on any successful fetch, from any
|
||||
screen. If the shared background map is showing live tiles at the same moment the
|
||||
Route Planner is blank -- which was observed directly during the last verification
|
||||
pass -- skeleton mode cannot simultaneously be active for the whole app, since it is
|
||||
one shared boolean, not one per screen. Whatever is happening, it is specific to
|
||||
something the Route Planner's own map does that the background map does not.
|
||||
|
||||
One real, evidenced hazard was found in `lib/src/tiles/tile_cache.dart`, `put()`:
|
||||
|
||||
```dart
|
||||
@override
|
||||
Future<void> put(TileKey key, Uint8List bytes) async {
|
||||
await _ensureLoaded();
|
||||
final name = _fileName(key);
|
||||
_manifest.remove(name);
|
||||
if (_totalBytes() + bytes.length > maxBytes) {
|
||||
await _evictUntilFits(bytes.length);
|
||||
}
|
||||
await _tileFile(key).writeAsBytes(bytes);
|
||||
_manifest[name] = _Entry(bytes: bytes.length, lastAccess: _clock++);
|
||||
await _saveManifest();
|
||||
}
|
||||
```
|
||||
|
||||
`FileTileCache` is one shared instance (`tileCacheProvider` in `providers.dart`), used
|
||||
by every `TileLayer` in the app. `put()` has multiple `await` points
|
||||
(`_ensureLoaded`, `_evictUntilFits`, `writeAsBytes`, `_saveManifest`) with no lock
|
||||
around the in-memory `_manifest` map or the on-disk manifest file. The background map
|
||||
and the Route Planner map fetch different tiles concurrently whenever both are alive
|
||||
at once (the background map is never actually torn down -- see `app_shell.dart`'s
|
||||
comment on why it is one persistent instance). Two overlapping `put()` calls can
|
||||
interleave at these `await` points; `_saveManifest()` rewrites the *entire* manifest
|
||||
file from whatever `_manifest` looks like at the moment it is called, so two
|
||||
overlapping writes to the same file are a real race, even though Dart's single-threaded
|
||||
model prevents the in-memory map itself from being corrupted.
|
||||
|
||||
`lib/src/tiles/cached_tile_provider.dart`'s fetch failure path currently discards the
|
||||
actual cause before rethrowing:
|
||||
|
||||
```dart
|
||||
Future<Uint8List> _fetchAndStore() async {
|
||||
try {
|
||||
final response = await client.get(Uri.parse(url), headers: headers);
|
||||
if (response.statusCode != 200) {
|
||||
throw Exception('Tile fetch failed: ${response.statusCode} for $url');
|
||||
}
|
||||
...
|
||||
} catch (_) {
|
||||
connectivity?.reportFailure();
|
||||
rethrow;
|
||||
}
|
||||
}
|
||||
```
|
||||
|
||||
The `catch (_)` block never records the URL, status code, or exception anywhere a
|
||||
developer could see it -- so there is currently no way to tell, from a real device,
|
||||
whether a Route Planner tile fetch is failing outright (and why), succeeding but
|
||||
failing to render, or something else entirely. `test/route_planner_screen_test.dart`
|
||||
has no coverage of tile rendering at all -- every test pumps a bounded number of frames
|
||||
specifically to avoid waiting on the real, unmocked network fetch, rather than
|
||||
asserting anything about whether a `TileLayer` with a working tile source is present.
|
||||
|
||||
## Design
|
||||
Two independent changes, both worth making regardless of which one turns out to be the
|
||||
actual fix, because both are real defects in their own right:
|
||||
|
||||
1. **Make `FileTileCache` safe under concurrent use.** Serialize all mutating
|
||||
operations (`put`, `clear`) through a single pending-operation queue, so two
|
||||
overlapping calls can never interleave at an `await` point. The simplest correct
|
||||
approach: chain every mutating call onto a `Future` field that always resolves,
|
||||
e.g.:
|
||||
```dart
|
||||
Future<void> _queue = Future.value();
|
||||
|
||||
Future<T> _serialized<T>(Future<T> Function() op) {
|
||||
final result = _queue.then((_) => op());
|
||||
_queue = result.then((_) {}, onError: (_) {});
|
||||
return result;
|
||||
}
|
||||
```
|
||||
Wrap the bodies of `put()` and `clear()` in `_serialized(...)`. Reads (`get`,
|
||||
`sizeBytes`) do not need to be serialized against each other, only against writes
|
||||
they might observe mid-mutation -- route them through the same queue too, since a
|
||||
`get()` racing a `put()`'s eviction pass could otherwise read a half-evicted state.
|
||||
2. **Log real tile-fetch failures.** In `cached_tile_provider.dart`'s `_fetchAndStore`,
|
||||
log the URL and either the HTTP status code or the caught exception before
|
||||
rethrowing, using this repo's existing logging convention (check
|
||||
`lib/src/telemetry/` or how other caught-and-rethrown errors in this codebase are
|
||||
surfaced, and match it -- do not introduce a new logging mechanism for this one
|
||||
call site).
|
||||
|
||||
## Implementation
|
||||
1. Add the serialization queue to `FileTileCache` in `lib/src/tiles/tile_cache.dart`.
|
||||
Wrap `put()` and `clear()` bodies in it. Route `get()` and `sizeBytes()` through it
|
||||
too.
|
||||
2. Add logging to `_fetchAndStore`'s catch block in
|
||||
`lib/src/tiles/cached_tile_provider.dart`, matching this repo's existing logging
|
||||
pattern.
|
||||
3. Add a concurrency test to `test/tile_cache_test.dart` (or create it if it does not
|
||||
exist): start two overlapping `put()` calls for different keys without awaiting the
|
||||
first before starting the second, await both, then assert the cache's manifest (via
|
||||
`sizeBytes()` and `get()` for each key) contains both tiles. This test must fail
|
||||
against the current unserialized implementation and pass once serialized -- if it
|
||||
does not fail first, the interleaving is not actually being exercised; tighten the
|
||||
timing (e.g. an artificial delay in a fake `Directory`/file layer) until it does.
|
||||
4. Run the app on the Android emulator with the new logging in place. Set a mock GPS
|
||||
fix. Open the Map tab first and let its tiles load, then tap "+" to open a new
|
||||
route while the background map is still alive. Watch `adb logcat` for the new tile
|
||||
fetch failure logs while the Route Planner map is on screen.
|
||||
5. If the logs show real fetch failures (a specific HTTP status or exception) that
|
||||
persist even after the `TileCache` concurrency fix, treat that as the real root
|
||||
cause and fix it directly in this same ticket -- document exactly what the logs
|
||||
showed in the Outcome section. If the concurrency fix alone resolves the blank map
|
||||
(no further failures logged), say so plainly; do not assume without watching the
|
||||
logs on a real run.
|
||||
6. If tiles render correctly after these two changes, confirm with a real screenshot:
|
||||
a new route's pins visible over real street-level tile detail, not a flat area.
|
||||
|
||||
## Acceptance criteria
|
||||
- [ ] Opening a new route via "+" shows real street-level tile detail under the pins,
|
||||
confirmed with a real on-device screenshot. **Not verified** -- no emulator/adb
|
||||
access in this environment, see Outcome.
|
||||
- [ ] Opening an existing route with waypoints also shows real tile detail. **Not
|
||||
verified** -- same reason.
|
||||
- [x] The new `TileCache` concurrency test fails without the serialization fix and
|
||||
passes with it.
|
||||
- [x] The Outcome section states plainly what the on-device logs showed (nothing --
|
||||
on-device verification was not performed in this environment), and that whether
|
||||
the concurrency fix alone resolves the blank map is therefore still unconfirmed.
|
||||
- [x] `flutter analyze` clean, `flutter test` green, test count only goes up.
|
||||
|
||||
## Tests
|
||||
- `test/tile_cache_test.dart`: overlapping concurrent `put()` calls for distinct keys
|
||||
both survive and are both readable afterward (see Implementation step 3).
|
||||
- If a further root cause is found via the on-device logs (e.g. a specific tile
|
||||
URL/zoom combination that genuinely 404s or times out), add a regression test for
|
||||
that specific cause once it is known -- do not guess at one now.
|
||||
|
||||
## Risks
|
||||
The `TileCache` concurrency fix may not be the actual root cause -- the investigation
|
||||
that found it could not fully confirm it against a live repro. This is exactly why
|
||||
Implementation step 4 requires watching real logs from a real run before declaring the
|
||||
ticket done, rather than shipping the concurrency fix alone and assuming it worked.
|
||||
|
||||
## Out of scope
|
||||
FB-10's map-pan race, tracked separately. Any change to which tile provider or map
|
||||
style this app uses.
|
||||
|
||||
## Outcome
|
||||
Both changes from the Design section shipped.
|
||||
|
||||
`FileTileCache` (`lib/src/tiles/tile_cache.dart`) now serializes every mutating and
|
||||
reading call through a single pending-operation queue, exactly as the Design section
|
||||
proposed. `put()` and `clear()` wrap their bodies in `_serialized(...)`. `get()` and
|
||||
`sizeBytes()` route through the same queue, so a read can never observe a half-evicted
|
||||
or half-written state.
|
||||
|
||||
`_fetchAndStore` in `lib/src/tiles/cached_tile_provider.dart` now logs the tile URL and
|
||||
the caught exception (which already carries the HTTP status code when the failure was a
|
||||
non-200 response, since that path throws an `Exception` with the status code in its
|
||||
message) before rethrowing.
|
||||
|
||||
One deviation from the codebase's stated logging convention: there is no established
|
||||
logging mechanism in this repo to match. `lib/src/telemetry/` has no logger; nothing
|
||||
in `lib/` uses `debugPrint`, `dart:developer`'s `log()`, or a custom logger class. The
|
||||
closest precedent is `TelemetryUploader._postBatch` in
|
||||
`lib/src/telemetry/telemetry_uploader.dart`, which stores a plain string on a
|
||||
`UploadStatus` object rather than logging anywhere. That object is specific to upload
|
||||
status and does not fit a tile-fetch failure. Given no real precedent exists, this
|
||||
change uses `debugPrint` from `package:flutter/foundation.dart`, which the file already
|
||||
imports. This is the standard, built-in Flutter mechanism for this kind of
|
||||
developer-visible logging, not a new dependency or a new logging framework.
|
||||
|
||||
The concurrency test lives in `test/tile_cache_test.dart`. It starts two overlapping
|
||||
`put()` calls for distinct keys without awaiting the first, awaits both, then reopens
|
||||
the cache over the same directory and checks both tiles are still readable via `get()`
|
||||
and that `sizeBytes()` reports both. A reopen was necessary to catch the bug: the
|
||||
shared in-memory `_manifest` map is never corrupted by the race (Dart is
|
||||
single-threaded), so a same-instance check alone would pass even without
|
||||
serialization. Only the on-disk `manifest.json`, written by two overlapping
|
||||
`_saveManifest()` calls, is at risk.
|
||||
|
||||
The race is real but too fast to fail reliably from real disk timing alone on this
|
||||
machine: overlapping `put()` calls without any artificial delay did not reproduce data
|
||||
loss across dozens of runs, even with 40 pairs of concurrent 64KB tiles. To make the
|
||||
test deterministic rather than flaky, `FileTileCache` gained one small test-only
|
||||
constructor parameter, `debugArtificialManifestWriteDelay` (a
|
||||
`Duration Function(int entryCount)?`, defaulting to unset). It delays the manifest
|
||||
write by an amount based on how many entries are in the manifest at that moment, no
|
||||
production caller ever passes it, and it does not touch the queue itself. Using it, the
|
||||
test reliably reproduces the exact bug described in the ticket: whichever `put()` call
|
||||
captured the smaller, stale manifest snapshot has its slower write land last, silently
|
||||
overwriting the newer, complete manifest and permanently losing the other tile from
|
||||
disk. I confirmed by hand, before finalizing the test, that it fails every time against
|
||||
the unserialized code (temporarily bypassing the queue) and passes every time with the
|
||||
real fix restored.
|
||||
|
||||
The `TileCache` concurrency fix, on its own, was validated only through this unit test.
|
||||
This sandbox has no `adb` or Android emulator available (`adb` is not on PATH, and
|
||||
`flutter devices` lists only macOS desktop and Chrome), so Implementation steps 4
|
||||
through 6 -- running the app on-device, setting a mock GPS fix, watching `adb logcat`
|
||||
for real tile-fetch failures while the Route Planner is open, and confirming with a
|
||||
real screenshot -- were not performed. I am not claiming on-device verification that
|
||||
did not happen. Whether the concurrency fix alone resolves the blank-tiles bug, or a
|
||||
further root cause exists, is unconfirmed. Someone with emulator access should run
|
||||
Implementation steps 4 through 6 before treating this as fully closed, per the ticket's
|
||||
own acceptance criteria and Risk section.
|
||||
|
||||
`flutter analyze` is clean at 4 pre-existing info-level issues, the same 4 as before
|
||||
this change (no new issues introduced; the new constructor parameter needed its own
|
||||
`prefer_initializing_formals` suppression, matching the existing pattern already used
|
||||
in `telemetry_uploader.dart`, to avoid adding a 5th). `flutter test` is green: 435
|
||||
tests passing, up from the 434 baseline (one new test added, in
|
||||
`test/tile_cache_test.dart`).
|
||||
Reference in New Issue
Block a user