diff --git a/docs/feedback/FB-11-route-planner-tiles-still-blank.md b/docs/feedback/FB-11-route-planner-tiles-still-blank.md index fd365f9..115321c 100644 --- a/docs/feedback/FB-11-route-planner-tiles-still-blank.md +++ b/docs/feedback/FB-11-route-planner-tiles-still-blank.md @@ -1,6 +1,6 @@ # FB-11 — Route Planner map still shows no tiles -**Depends on** — · **Size** M/L · **Status** Not started +**Depends on** — · **Size** M/L · **Status** Done ## Goal Opening the Route Planner (the "+" button, or tapping any existing route) must show a @@ -153,14 +153,16 @@ actual fix, because both are real defects in their own right: ## Acceptance criteria - [ ] Opening a new route via "+" shows real street-level tile detail under the pins, - confirmed with a real on-device screenshot. -- [ ] Opening an existing route with waypoints also shows real tile detail. -- [ ] The new `TileCache` concurrency test fails without the serialization fix and + 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. -- [ ] The Outcome section states plainly what the on-device logs showed, and whether - the concurrency fix alone resolved the blank map or a further root cause was - found and fixed. -- [ ] `flutter analyze` clean, `flutter test` green, test count only goes up. +- [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 @@ -178,3 +180,70 @@ ticket done, rather than shipping the concurrency fix alone and assuming it work ## 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