diff --git a/docs/feedback/FB-11-route-planner-tiles-still-blank.md b/docs/feedback/FB-11-route-planner-tiles-still-blank.md new file mode 100644 index 0000000..115321c --- /dev/null +++ b/docs/feedback/FB-11-route-planner-tiles-still-blank.md @@ -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 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 _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 _queue = Future.value(); + + Future _serialized(Future 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`). diff --git a/lib/src/tiles/cached_tile_provider.dart b/lib/src/tiles/cached_tile_provider.dart index 8bdd3ec..ac2132d 100644 --- a/lib/src/tiles/cached_tile_provider.dart +++ b/lib/src/tiles/cached_tile_provider.dart @@ -91,7 +91,11 @@ class _CacheBackedImage extends ImageProvider<_CacheBackedImage> { await cache.put(key, bytes); connectivity?.reportSuccess(); return bytes; - } catch (_) { + } catch (e) { + // FB-11: record the URL and the underlying HTTP status/exception so a real + // fetch failure is visible on-device -- before this, `catch (_)` discarded the + // cause and there was no way to tell a real failure from a rendering bug. + debugPrint('CachedTileProvider: tile fetch failed for $url: $e'); // UI-02: a cache miss whose network fetch also failed is exactly the "no // connection" signal skeleton mode is watching for -- report it and rethrow so // flutter_map's own error handling for this tile is unchanged. diff --git a/lib/src/tiles/tile_cache.dart b/lib/src/tiles/tile_cache.dart index 3576759..5eabb85 100644 --- a/lib/src/tiles/tile_cache.dart +++ b/lib/src/tiles/tile_cache.dart @@ -30,16 +30,44 @@ abstract class TileCache { /// last-access time for LRU eviction. No database engine for what is, at the end of the /// day, a directory of small binary blobs with one number (last access) attached to each. class FileTileCache implements TileCache { - FileTileCache({required Directory directory, required this.maxBytes}) - : _dir = directory; + /// [debugArtificialManifestWriteDelay] is a test-only knob (defaults to a no-op, + /// and every production caller leaves it unset): given the size of the manifest + /// about to be written, it returns how long to artificially pad that write by. It + /// exists so a concurrency test can force two overlapping mutations to actually + /// interleave at the `_saveManifest` await point -- on a real disk this can happen + /// on its own (variable I/O latency, eviction work delaying one caller but not the + /// other), but a test needs it to happen every time, not just when it gets lucky. + FileTileCache({ + required Directory directory, + required this.maxBytes, + Duration Function(int entryCount)? debugArtificialManifestWriteDelay, + }) : _dir = directory, + _debugArtificialManifestWriteDelay = debugArtificialManifestWriteDelay; + // ignore_for_file: prefer_initializing_formals + // Dart does not permit a named parameter whose name begins with an underscore, so the + // lint's suggested `this._debugArtificialManifestWriteDelay` will not compile here. final Directory _dir; final int maxBytes; + final Duration Function(int entryCount)? _debugArtificialManifestWriteDelay; final _manifest = {}; bool _loaded = false; int _clock = 0; + /// Serializes every mutating (and manifest-reading) operation so two overlapping + /// calls -- e.g. the persistent background map and a freshly-opened Route Planner + /// map both fetching tiles at once -- can never interleave at one of the many + /// `await` points below. Every call is chained onto this future; each one only + /// starts once the previous one (success or failure) has finished. + Future _queue = Future.value(); + + Future _serialized(Future Function() op) { + final result = _queue.then((_) => op()); + _queue = result.then((_) {}, onError: (_) {}); + return result; + } + File get _manifestFile => File('${_dir.path}/manifest.json'); File _tileFile(TileKey key) => File('${_dir.path}/${_fileName(key)}'); String _fileName(TileKey key) => '${key.z}_${key.x}_${key.y}.tile'; @@ -60,15 +88,20 @@ class FileTileCache implements TileCache { } } - Future _saveManifest() => _manifestFile.writeAsString( - jsonEncode({ + Future _saveManifest() async { + final encoded = jsonEncode({ for (final e in _manifest.entries) e.key: {'bytes': e.value.bytes, 'lastAccess': e.value.lastAccess}, - }), - ); + }); + final delay = _debugArtificialManifestWriteDelay?.call(_manifest.length); + if (delay != null && delay > Duration.zero) { + await Future.delayed(delay); + } + await _manifestFile.writeAsString(encoded); + } @override - Future put(TileKey key, Uint8List bytes) async { + Future put(TileKey key, Uint8List bytes) => _serialized(() async { await _ensureLoaded(); final name = _fileName(key); @@ -83,7 +116,7 @@ class FileTileCache implements TileCache { await _tileFile(key).writeAsBytes(bytes); _manifest[name] = _Entry(bytes: bytes.length, lastAccess: _clock++); await _saveManifest(); - } + }); Future _evictUntilFits(int incomingBytes) async { // Oldest-accessed first. @@ -100,7 +133,7 @@ class FileTileCache implements TileCache { int _totalBytes() => _manifest.values.fold(0, (sum, e) => sum + e.bytes); @override - Future get(TileKey key) async { + Future get(TileKey key) => _serialized(() async { await _ensureLoaded(); final name = _fileName(key); final entry = _manifest[name]; @@ -115,16 +148,16 @@ class FileTileCache implements TileCache { } entry.lastAccess = _clock++; return file.readAsBytes(); - } + }); @override - Future sizeBytes() async { + Future sizeBytes() => _serialized(() async { await _ensureLoaded(); return _totalBytes(); - } + }); @override - Future clear() async { + Future clear() => _serialized(() async { await _ensureLoaded(); for (final key in _manifest.keys.toList()) { final f = File('${_dir.path}/$key'); @@ -132,7 +165,7 @@ class FileTileCache implements TileCache { } _manifest.clear(); await _saveManifest(); - } + }); @override Future dispose() async {} diff --git a/test/tile_cache_test.dart b/test/tile_cache_test.dart index a524409..b52583b 100644 --- a/test/tile_cache_test.dart +++ b/test/tile_cache_test.dart @@ -90,6 +90,45 @@ void main() { expect(await reopened.sizeBytes(), 64); }); + test('overlapping put() calls for distinct keys are both readable afterward ' + '(FB-11: concurrent background-map + Route Planner tile fetches must not race)', + () async { + // `_saveManifest()` computes its JSON snapshot synchronously, then writes it to + // disk. Two overlapping `put()` calls can interleave so that the call that + // captured the *older*, smaller snapshot (fewer entries) is also the one whose + // disk write finishes last -- silently overwriting the newer, complete manifest + // with a stale one that is missing the other call's tile. On a real device this + // depends on incidental I/O timing (which is exactly why it was so hard to catch + // and produced a rider-visible blank map only sometimes); this artificial delay + // makes that interleaving happen every single time instead of by chance, so the + // test is deterministic rather than flaky. It has no effect on production + // callers, which never pass it. + cache = FileTileCache( + directory: tempDir, + maxBytes: 1024 * 1024, + debugArtificialManifestWriteDelay: (entryCount) => + entryCount < 2 ? const Duration(milliseconds: 50) : Duration.zero, + ); + const a = TileKey(9, 1, 0); + const b = TileKey(9, 2, 0); + + // Started without awaiting the first before starting the second, so both calls + // are in flight and racing across the same `await` points (`_ensureLoaded`, + // `writeAsBytes`, `_saveManifest`) at once. + final futureA = cache.put(a, bytesOfSize(1024)); + final futureB = cache.put(b, bytesOfSize(1024)); + await Future.wait([futureA, futureB]); + + // Reopen over the same directory: this reads the manifest back from disk, which + // is exactly the file the two overlapping writes above raced to overwrite. An + // in-memory-only check wouldn't catch this -- the shared `_manifest` map itself + // is never corrupted (Dart is single-threaded), only what ends up on disk. + final reopened = FileTileCache(directory: tempDir, maxBytes: 1024 * 1024); + expect(await reopened.get(a), isNotNull, reason: 'tile a must survive the race'); + expect(await reopened.get(b), isNotNull, reason: 'tile b must survive the race'); + expect(await reopened.sizeBytes(), 2048); + }); + test('a tile cached under one provider directory is not served from another ' '(UI-09)', () async { // `TileKey` carries no provider identity -- (z, x, y) alone can't tell an OSM tan