From 2c80be32443e3502512958679cb4c6300ee3ad5c Mon Sep 17 00:00:00 2001 From: Strycher Date: Mon, 20 Jul 2026 04:09:08 -0400 Subject: [PATCH 1/9] fix(#333): load channels before channel history, or history reads empty Channel history is keyed by the channel's PSK (#194), and the resolver set on the store reads that PSK out of _channels. After SELF_INFO, loadCachedChannels() and loadAllChannelMessages() were both fired without awaiting, so the messages could load while _channels was still empty. The resolver then returned null, _storageKey() silently fell back to the legacy slot-index key, and channels read as empty even though their history was intact under the PSK key. Silent because the fallback is a legitimate code path: there is no error, no parse failure and no log line, just an empty list. It is indistinguishable from data loss to the user. Observed on a live radio: Public held 566 messages under channel_messages_psk_8b3387e9..., and the app displayed nothing. loadAllChannelMessages() now runs only after loadCachedChannels() completes. The startup call in main.dart already awaits in the right order; it runs before any radio is connected, which is the source of the "Public key hex is not set" warnings at launch, and is harmless once this post-connect load is correct. Was previously committed against #291 on the nav-redesign branch; split out here under its own issue. --- lib/connector/meshcore_connector.dart | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/lib/connector/meshcore_connector.dart b/lib/connector/meshcore_connector.dart index 04cbbbf..a27c2f4 100644 --- a/lib/connector/meshcore_connector.dart +++ b/lib/connector/meshcore_connector.dart @@ -4646,10 +4646,14 @@ class MeshCoreConnector extends ChangeNotifier { _loadChannelOrder(); loadContactCache(); loadChannelSettings(); - loadCachedChannels(); - // Load persisted channel messages - loadAllChannelMessages(); + // Channel history is keyed by the channel's PSK (#194), and the resolver + // set above reads that PSK out of _channels. So the channel list MUST be + // loaded before the messages are: loading them concurrently leaves the + // resolver returning null, _storageKey() silently falls back to the legacy + // slot-index key, and every channel reads as empty even though its history + // is intact under the PSK key. + unawaited(loadCachedChannels().then((_) => loadAllChannelMessages())); loadUnreadState(); _loadDiscoveredContactCache(); From 7f9f6ba63b6fdd065e992e7ba3d7e959c1e7870d Mon Sep 17 00:00:00 2001 From: Strycher Date: Mon, 20 Jul 2026 03:48:45 -0400 Subject: [PATCH 2/9] perf(#306): batch per-contact setting loads instead of notifying 600 times Diagnosed from the app's own log. After SELF_INFO the client went completely silent for 43.7s, then flushed a burst of radio frames all sharing the identical timestamp - queued while the event loop was blocked, not a slow radio. Cause: loadContactCache() looped over every cached contact calling _ensureContactSmazSettingLoaded and _ensureContactCyr2LatSettingLoaded, and each of those notified on completion. With 300 contacts that is 600 notifyListeners() calls in a burst, each rebuilding the whole widget tree, and each rebuild itself walks the contact list. O(contacts^2) on the UI isolate. Both loaders are now awaitable and take notify: false for bulk use. loadContactCache awaits them all and notifies once. Measured on the reporting device (radio 4f6585264e, TCP): 300 contacts, 1090 discovered contacts, 12 channels holding 1841 messages, 6.9 MB prefs file. Log evidence: 43.7s stall between "Pulled battery" and the first channel response, followed by same-millisecond frame delivery. This is the Windows-visible freeze in #306. The platform asymmetry is consistent with contact-list size rather than anything desktop-specific, so whether Android is genuinely faster or simply has a smaller address book on its paired radio is still open - #306 stays open pending a like-for-like re-measure. flutter analyze clean, dart format clean, 469 tests pass. --- lib/connector/meshcore_connector.dart | 49 ++++++++++++++++++--------- 1 file changed, 33 insertions(+), 16 deletions(-) diff --git a/lib/connector/meshcore_connector.dart b/lib/connector/meshcore_connector.dart index a27c2f4..d86443b 100644 --- a/lib/connector/meshcore_connector.dart +++ b/lib/connector/meshcore_connector.dart @@ -1191,10 +1191,17 @@ class MeshCoreConnector extends ChangeNotifier { _contacts ..clear() ..addAll(cached); - for (final contact in cached) { - _ensureContactSmazSettingLoaded(contact.publicKeyHex); - _ensureContactCyr2LatSettingLoaded(contact.publicKeyHex); - } + // Load every contact's settings without notifying per contact, then + // notify once. Per-contact notification rebuilt the whole tree 2x per + // contact (600 rebuilds for 300 contacts), and each rebuild walks the + // contact list, which is what stalled the UI for ~44s on connect. + await Future.wait([ + for (final contact in cached) ...[ + _ensureContactSmazSettingLoaded(contact.publicKeyHex, notify: false), + _ensureContactCyr2LatSettingLoaded(contact.publicKeyHex, notify: false), + ], + ]); + notifyListeners(); } Future _loadDiscoveredContactCache() async { @@ -5625,22 +5632,32 @@ class MeshCoreConnector extends ChangeNotifier { return frame.sublist(prefixOffset, prefixOffset + prefixLen); } - void _ensureContactSmazSettingLoaded(String contactKeyHex) { + /// [notify] is false for bulk loads, which notify once at the end instead. + /// Notifying per contact rebuilds the whole tree once per contact, and each + /// rebuild itself walks the contact list, so a large address book turns this + /// into O(contacts^2) work on the UI isolate. + Future _ensureContactSmazSettingLoaded( + String contactKeyHex, { + bool notify = true, + }) async { if (_contactSmazEnabled.containsKey(contactKeyHex)) return; - _contactSettingsStore.loadSmazEnabled(contactKeyHex).then((enabled) { - if (_contactSmazEnabled[contactKeyHex] == enabled) return; - _contactSmazEnabled[contactKeyHex] = enabled; - notifyListeners(); - }); + final enabled = await _contactSettingsStore.loadSmazEnabled(contactKeyHex); + if (_contactSmazEnabled[contactKeyHex] == enabled) return; + _contactSmazEnabled[contactKeyHex] = enabled; + if (notify) notifyListeners(); } - void _ensureContactCyr2LatSettingLoaded(String contactKeyHex) { + Future _ensureContactCyr2LatSettingLoaded( + String contactKeyHex, { + bool notify = true, + }) async { if (_contactCyr2LatEnabled.containsKey(contactKeyHex)) return; - _contactSettingsStore.loadCyr2LatEnabled(contactKeyHex).then((enabled) { - if (_contactCyr2LatEnabled[contactKeyHex] == enabled) return; - _contactCyr2LatEnabled[contactKeyHex] = enabled; - notifyListeners(); - }); + final enabled = await _contactSettingsStore.loadCyr2LatEnabled( + contactKeyHex, + ); + if (_contactCyr2LatEnabled[contactKeyHex] == enabled) return; + _contactCyr2LatEnabled[contactKeyHex] = enabled; + if (notify) notifyListeners(); } void _ensureContactCyr2LatProfileLoaded(String contactKeyHex) { From bd8779697a70c4ffec90cf3a3ca0668f5ba2fb97 Mon Sep 17 00:00:00 2001 From: Strycher Date: Mon, 20 Jul 2026 03:57:41 -0400 Subject: [PATCH 3/9] perf(#306): time startup loads and frame handlers to locate the UI stalls Two reported freezes: one shortly after connect, one during channel sync, with the sync progress bar never repainting and then completing all at once. That is the UI isolate being blocked, and the log already shows the signature - a long silence followed by many frames sharing one timestamp, which is queued input flushing after the loop frees up. The previous fix (batching 600 per-contact notifications) moved the stall from 43.6s to 40.1s, which is noise. It was the wrong culprit, so this replaces guessing with measurement: - The post-SELF_INFO cache load is split into named steps, each timed and logged as `startup-load took Nms`. The step order is unchanged, and cachedChannels still runs before channelMessages so PSK-keyed history resolves. - Every RX frame handler is timed, and any that occupies the isolate for more than 100ms logs `slow frame handler: code=N blocked UI for Nms`. This names the handler wherever it is, rather than requiring a guess about which one. No behaviour change. Diagnostics only, kept as Perf-tagged logging because this class of stall is worth catching again. flutter analyze clean, dart format clean, 469 tests pass. --- lib/connector/meshcore_connector.dart | 57 ++++++++++++++++++++------- 1 file changed, 43 insertions(+), 14 deletions(-) diff --git a/lib/connector/meshcore_connector.dart b/lib/connector/meshcore_connector.dart index d86443b..1d297c8 100644 --- a/lib/connector/meshcore_connector.dart +++ b/lib/connector/meshcore_connector.dart @@ -4349,7 +4349,26 @@ class MeshCoreConnector extends ChangeNotifier { } } + /// Any frame handler that occupies the UI isolate long enough to drop + /// frames is a bug: it stalls rendering, so progress bars freeze and input + /// stops responding while sync appears to do nothing and then finish at + /// once. Logged rather than assumed, so the offending code is named. + static const Duration _slowHandlerThreshold = Duration(milliseconds: 100); + void _handleFrame(List data) { + final handlerWatch = Stopwatch()..start(); + _handleFrameInner(data); + handlerWatch.stop(); + if (handlerWatch.elapsed > _slowHandlerThreshold && data.isNotEmpty) { + appLogger.info( + 'slow frame handler: code=${data[0]} blocked UI for ' + '${handlerWatch.elapsedMilliseconds}ms', + tag: 'Perf', + ); + } + } + + void _handleFrameInner(List data) { if (data.isEmpty) return; _lastRxTime = DateTime.now(); @@ -4649,20 +4668,10 @@ class MeshCoreConnector extends ChangeNotifier { _channelStore.setPublicKeyHex = selfPublicKeyHex; _unreadStore.setPublicKeyHex = selfPublicKeyHex; - // Now that we have self info, we can load all the persisted data for this node - _loadChannelOrder(); - loadContactCache(); - loadChannelSettings(); - - // Channel history is keyed by the channel's PSK (#194), and the resolver - // set above reads that PSK out of _channels. So the channel list MUST be - // loaded before the messages are: loading them concurrently leaves the - // resolver returning null, _storageKey() silently falls back to the legacy - // slot-index key, and every channel reads as empty even though its history - // is intact under the PSK key. - unawaited(loadCachedChannels().then((_) => loadAllChannelMessages())); - loadUnreadState(); - _loadDiscoveredContactCache(); + // Now that we have self info, we can load all the persisted data for this + // node. Each step is timed: this sequence has stalled the UI isolate for + // ~40s on a large store, and the timings say which step is responsible. + unawaited(_timedStartupLoad()); _awaitingSelfInfo = false; _selfInfoRetryTimer?.cancel(); @@ -4673,6 +4682,26 @@ class MeshCoreConnector extends ChangeNotifier { _maybeStartInitialChannelSync(); } + Future _timedStartupLoad() async { + Future step(String name, Future Function() body) async { + final sw = Stopwatch()..start(); + await body(); + sw.stop(); + appLogger.info( + 'startup-load $name took ${sw.elapsedMilliseconds}ms', + tag: 'Perf', + ); + } + + await step('channelOrder', () async => _loadChannelOrder()); + await step('contactCache', loadContactCache); + await step('channelSettings', () => loadChannelSettings()); + await step('cachedChannels', loadCachedChannels); + await step('channelMessages', () => loadAllChannelMessages()); + await step('unreadState', loadUnreadState); + await step('discoveredContacts', _loadDiscoveredContactCache); + } + /// Extract the additive `offband_caps` byte from a device-info reply. /// /// Offset verified against firmware MyMesh.cpp: the reply tail is three From 4ee2f507031eec0bcfc1fb03ae6aeac37c100031 Mon Sep 17 00:00:00 2001 From: Strycher Date: Mon, 20 Jul 2026 04:04:36 -0400 Subject: [PATCH 4/9] fix(#306): stop rewriting the whole prefs file per channel on connect The connect freeze is a legacy-key migration that writes even when there is nothing to migrate. loadSmazEnabled called prefs.remove(oldKey) unconditionally whenever the scoped key was absent, which is the normal case for a channel that has never had the setting changed. On Windows shared_preferences re-serialises and rewrites the ENTIRE prefs file on any mutation, so each of those no-op removes cost a full multi-MB write. Repeated across every channel slot on every connect, that is tens of full-file rewrites back to back. Measured with the instrumentation from the previous commit, on the reporting device (6.9 MB prefs, ~42 channel slots): startup-load channelOrder 0ms startup-load contactCache 12ms startup-load channelSettings 37792ms <-- here startup-load cachedChannels 0ms startup-load channelMessages 21ms startup-load unreadState 0ms startup-load discoveredContacts 11ms No frame handler exceeded 100ms, confirming the stall was local storage work and not radio traffic. The remove now happens only when a legacy key actually exists, alongside the write that migrates it. contact_settings_store had the identical pattern per contact and is fixed the same way. This also explains the platform gap in the original report: Android's backend batches into native storage, so the same code costs almost nothing there, while every no-op remove on Windows is a full file rewrite. flutter analyze clean, dart format clean, 469 tests pass. --- lib/storage/channel_settings_store.dart | 7 ++++++- lib/storage/contact_settings_store.dart | 7 ++++++- 2 files changed, 12 insertions(+), 2 deletions(-) diff --git a/lib/storage/channel_settings_store.dart b/lib/storage/channel_settings_store.dart index e0b390f..e6af56b 100644 --- a/lib/storage/channel_settings_store.dart +++ b/lib/storage/channel_settings_store.dart @@ -25,13 +25,18 @@ class ChannelSettingsStore { bool? enabled = prefs.getBool(key); if (enabled == null) { // Attempt migration from legacy unscoped key on first load + // Only touch storage when a legacy key actually exists. This ran + // unconditionally, and on Windows shared_preferences re-serialises and + // rewrites the WHOLE prefs file on every mutation, so removing a key + // that was never there still cost a full multi-MB write. Repeated per + // channel/contact on connect, that blocked the UI isolate for ~38s. enabled = prefs.getBool(oldKey); - prefs.remove(oldKey); if (enabled != null) { appLogger.info( 'Migrating channel settings from legacy key $oldKey to scoped key $key', ); await prefs.setBool(key, enabled); + await prefs.remove(oldKey); } } return enabled ?? false; diff --git a/lib/storage/contact_settings_store.dart b/lib/storage/contact_settings_store.dart index 682f1af..109f5eb 100644 --- a/lib/storage/contact_settings_store.dart +++ b/lib/storage/contact_settings_store.dart @@ -25,13 +25,18 @@ class ContactSettingsStore { bool? enabled = prefs.getBool(key); if (enabled == null) { // Attempt migration from legacy unscoped key on first load + // Only touch storage when a legacy key actually exists. This ran + // unconditionally, and on Windows shared_preferences re-serialises and + // rewrites the WHOLE prefs file on every mutation, so removing a key + // that was never there still cost a full multi-MB write. Repeated per + // channel/contact on connect, that blocked the UI isolate for ~38s. enabled = prefs.getBool(oldKey); - prefs.remove(oldKey); if (enabled != null) { appLogger.info( 'Migrating contact settings from legacy key $oldKey to scoped key $key', ); await prefs.setBool(key, enabled); + await prefs.remove(oldKey); } } return prefs.getBool(key) ?? false; From 5eded9e33ca59cce2b986a347f3aa0996e82bcb3 Mon Sep 17 00:00:00 2001 From: Strycher Date: Mon, 20 Jul 2026 04:21:45 -0400 Subject: [PATCH 5/9] fix(#306): guard every legacy-key removal, not just the channel-settings one The previous commit fixed loadSmazEnabled and killed the post-connect stall (startup-load channelSettings: 37792ms -> 0ms, measured twice). The contact pull still choked, in multi-second bursts, each landing immediately after an "Added new contact" line. No frame handler exceeded the 100ms threshold, because the work is not in a handler: the contact handler fires _loadMessagesForContact unawaited, so it runs after the handler returns and escapes that timing. message_store.loadMessages had the same unconditional prefs.remove(oldKey), and it runs ONCE PER CONTACT during a pull. On Windows every prefs mutation rewrites the entire file, so a 234-contact pull meant 234 full multi-MB writes for legacy keys that do not exist. A sweep found the identical pattern in six more stores: contact_store, unread_store, channel_store, community_store, contact_group_store and channel_order_store. Those run once per load rather than per item, so they are far cheaper, but it is the same bug and they are fixed the same way. In every case the removal now happens only when a legacy key actually exists, paired with the write that migrates it, so the cleanup still occurs on a real migration. flutter analyze clean, dart format clean, 494 tests pass. --- lib/storage/channel_order_store.dart | 4 +++- lib/storage/channel_store.dart | 4 +++- lib/storage/community_store.dart | 4 +++- lib/storage/contact_group_store.dart | 4 +++- lib/storage/contact_store.dart | 4 +++- lib/storage/message_store.dart | 7 ++++++- lib/storage/unread_store.dart | 4 +++- 7 files changed, 24 insertions(+), 7 deletions(-) diff --git a/lib/storage/channel_order_store.dart b/lib/storage/channel_order_store.dart index 88d3f7a..4e268b2 100644 --- a/lib/storage/channel_order_store.dart +++ b/lib/storage/channel_order_store.dart @@ -29,13 +29,15 @@ class ChannelOrderStore { String? jsonString = prefs.getString(keyFor); if (jsonString == null || jsonString.isEmpty) { // Attempt migration from legacy unscoped key on first load + // Only remove the legacy key when it actually exists: every prefs + // mutation rewrites the whole file on Windows. final legacyJsonString = prefs.getString(_keyPrefix); - prefs.remove(_keyPrefix); if (legacyJsonString != null && legacyJsonString.isNotEmpty) { appLogger.info( 'Migrating channel order from legacy key $_keyPrefix to scoped key $keyFor', ); await prefs.setString(keyFor, legacyJsonString); + await prefs.remove(_keyPrefix); jsonString = legacyJsonString; } } diff --git a/lib/storage/channel_store.dart b/lib/storage/channel_store.dart index 4f40482..b52b5b7 100644 --- a/lib/storage/channel_store.dart +++ b/lib/storage/channel_store.dart @@ -22,13 +22,15 @@ class ChannelStore { String? jsonString = prefs.getString(keyFor); if (jsonString == null || jsonString.isEmpty) { // Attempt migration from legacy unscoped key on first load + // Only remove the legacy key when it actually exists: every prefs + // mutation rewrites the whole file on Windows. final legacyJsonString = prefs.getString(_keyPrefix); - prefs.remove(_keyPrefix); if (legacyJsonString != null && legacyJsonString.isNotEmpty) { appLogger.info( 'Migrating channel messages from legacy key $_keyPrefix to scoped key $keyFor', ); await prefs.setString(keyFor, legacyJsonString); + await prefs.remove(_keyPrefix); jsonString = legacyJsonString; } } diff --git a/lib/storage/community_store.dart b/lib/storage/community_store.dart index c69d0b8..a8010a1 100644 --- a/lib/storage/community_store.dart +++ b/lib/storage/community_store.dart @@ -28,13 +28,15 @@ class CommunityStore { String? jsonString = prefs.getString(keyFor); if (jsonString == null || jsonString.isEmpty) { // Attempt migration from legacy unscoped key on first load + // Only remove the legacy key when it actually exists: every prefs + // mutation rewrites the whole file on Windows. final legacyJsonString = prefs.getString(_keyPrefix); - prefs.remove(_keyPrefix); if (legacyJsonString != null && legacyJsonString.isNotEmpty) { appLogger.info( 'Migrating communities from legacy key $_keyPrefix to scoped key $keyFor', ); await prefs.setString(keyFor, legacyJsonString); + await prefs.remove(_keyPrefix); jsonString = legacyJsonString; } } diff --git a/lib/storage/contact_group_store.dart b/lib/storage/contact_group_store.dart index ce6a0c6..0813274 100644 --- a/lib/storage/contact_group_store.dart +++ b/lib/storage/contact_group_store.dart @@ -21,13 +21,15 @@ class ContactGroupStore { String? jsonString = prefs.getString(keyFor); if (jsonString == null || jsonString.isEmpty) { // Attempt migration from legacy unscoped key on first load + // Only remove the legacy key when it actually exists: every prefs + // mutation rewrites the whole file on Windows. final legacyJsonString = prefs.getString(_keyPrefix); - prefs.remove(_keyPrefix); if (legacyJsonString != null && legacyJsonString.isNotEmpty) { appLogger.info( 'Migrating channel messages from legacy key $_keyPrefix to scoped key $keyFor', ); await prefs.setString(keyFor, legacyJsonString); + await prefs.remove(_keyPrefix); jsonString = legacyJsonString; } } diff --git a/lib/storage/contact_store.dart b/lib/storage/contact_store.dart index 5d1805d..9085d4e 100644 --- a/lib/storage/contact_store.dart +++ b/lib/storage/contact_store.dart @@ -23,13 +23,15 @@ class ContactStore { String? jsonString = prefs.getString(keyFor); if (jsonString == null || jsonString.isEmpty) { // Attempt migration from legacy unscoped key on first load + // Only remove the legacy key when it actually exists: every prefs + // mutation rewrites the whole file on Windows. final legacyJsonString = prefs.getString(_keyPrefix); - prefs.remove(_keyPrefix); if (legacyJsonString != null && legacyJsonString.isNotEmpty) { appLogger.info( 'Migrating contacts from legacy key $_keyPrefix to scoped key $keyFor', ); await prefs.setString(keyFor, legacyJsonString); + await prefs.remove(_keyPrefix); jsonString = legacyJsonString; } } diff --git a/lib/storage/message_store.dart b/lib/storage/message_store.dart index ccaf9ea..6045342 100644 --- a/lib/storage/message_store.dart +++ b/lib/storage/message_store.dart @@ -40,13 +40,18 @@ class MessageStore { String? jsonString = prefs.getString(key); if (jsonString == null || jsonString.isEmpty) { // Attempt migration from legacy unscoped key on first load + // Only touch storage when a legacy key actually exists. This ran + // unconditionally, and loadMessages is called once per contact during a + // contact pull. On Windows shared_preferences rewrites the WHOLE prefs + // file on every mutation, so each no-op remove cost a full multi-MB + // write - hundreds of them back to back on a large address book. final legacyJsonString = prefs.getString(oldKey); - prefs.remove(oldKey); if (legacyJsonString != null && legacyJsonString.isNotEmpty) { appLogger.info( 'Migrating messages from legacy key $oldKey to scoped key $key', ); await prefs.setString(key, legacyJsonString); + await prefs.remove(oldKey); jsonString = legacyJsonString; } } diff --git a/lib/storage/unread_store.dart b/lib/storage/unread_store.dart index 3b615b1..cc1f377 100644 --- a/lib/storage/unread_store.dart +++ b/lib/storage/unread_store.dart @@ -35,13 +35,15 @@ class UnreadStore { String? jsonString = prefs.getString(keyFor); if (jsonString == null || jsonString.isEmpty) { // Attempt migration from legacy unscoped key on first load + // Only remove the legacy key when it actually exists: every prefs + // mutation rewrites the whole file on Windows. final legacyJsonString = prefs.getString(_keyPrefix); - prefs.remove(_keyPrefix); if (legacyJsonString != null && legacyJsonString.isNotEmpty) { appLogger.info( 'Migrating channel messages from legacy key $_keyPrefix to scoped key $keyFor', ); await prefs.setString(keyFor, legacyJsonString); + await prefs.remove(_keyPrefix); jsonString = legacyJsonString; } } From a7ef7b33257bd1c1e0eba87522fd1701dcc3d9af Mon Sep 17 00:00:00 2001 From: Strycher Date: Mon, 20 Jul 2026 04:40:00 -0400 Subject: [PATCH 6/9] perf(#306): measure the per-contact conversation load The startup loads are now clean (all steps ~0ms, down from 37792ms), but the contact pull still stalls in multi-second bursts: 8.0s and 7.7s at +25s..+52s on the last run, matching the reported freeze from ~15s to ~49s. No frame handler exceeds 100ms, because the work is not in one. _loadMessagesForContact is fired unawaited from the contact handler, so it runs after the handler returns and escapes that timing entirely. This times it directly and reports cumulative store time versus merge+notify time every 25 contacts, so the next run says which half is responsible rather than requiring another guess. Two candidates it will discriminate: - store: prefs read + jsonDecode per contact - merge+notify: the per-contact notifyListeners, i.e. one full widget tree rebuild per contact, each of which walks the contact list Diagnostics only, no behaviour change. flutter analyze clean, dart format clean. --- lib/connector/meshcore_connector.dart | 21 +++++++++++++++++++++ 1 file changed, 21 insertions(+) diff --git a/lib/connector/meshcore_connector.dart b/lib/connector/meshcore_connector.dart index 1d297c8..2bfb1ca 100644 --- a/lib/connector/meshcore_connector.dart +++ b/lib/connector/meshcore_connector.dart @@ -703,11 +703,30 @@ class MeshCoreConnector extends ChangeNotifier { notifyListeners(); } + /// Aggregate cost of the per-contact conversation load, which runs once per + /// contact during a pull. It is fired unawaited from the contact handler, so + /// it escapes the frame-handler timing and has to be measured here. + int _convLoadCount = 0; + int _convLoadStoreMs = 0; + int _convLoadMergeMs = 0; + Future _loadMessagesForContact(String contactKeyHex) async { if (_loadedConversationKeys.contains(contactKeyHex)) return; _loadedConversationKeys.add(contactKeyHex); + final storeWatch = Stopwatch()..start(); final allMessages = await _messageStore.loadMessages(contactKeyHex); + storeWatch.stop(); + final mergeWatch = Stopwatch()..start(); + _convLoadCount++; + _convLoadStoreMs += storeWatch.elapsedMilliseconds; + if (_convLoadCount % 25 == 0) { + appLogger.info( + 'conversation loads: $_convLoadCount contacts, ' + 'store=${_convLoadStoreMs}ms merge=${_convLoadMergeMs}ms cumulative', + tag: 'Perf', + ); + } if (allMessages.isNotEmpty) { // Keep only the most recent N messages in memory to bound memory usage final windowedMessages = allMessages.length > _messageWindowSize @@ -748,6 +767,8 @@ class MeshCoreConnector extends ChangeNotifier { _conversations[contactKeyHex] = windowedMergedMessages; notifyListeners(); } + mergeWatch.stop(); + _convLoadMergeMs += mergeWatch.elapsedMilliseconds; } String _messageMergeKey(Message message) { From 30ab360d66f1fbdd3b906ae1431da48723e64ca6 Mon Sep 17 00:00:00 2001 From: Strycher Date: Mon, 20 Jul 2026 04:43:42 -0400 Subject: [PATCH 7/9] fix(#306): surface silent storage failures per SAFELANE 6 The stores violated the no-silent-failures rule, and that is why tonight's diagnosis took as long as it did. Two classes: 1. Ten catch blocks swallowed decode errors and returned an empty collection. `catch (_) { return []; }` means a corrupt or unreadable store presents to the caller as "no data", so the user sees no contacts, no channels or no history with nothing anywhere explaining why. Indistinguishable from data loss. Every one now logs what failed, with the store named, before returning. 2. ChannelMessageStore._storageKey fell back from the PSK-identity key to the legacy slot-index key without a word. That fallback is correct before a channel list exists, but once history has been migrated to the PSK key it reads a DIFFERENT key and returns empty. That is exactly #333: a user's 566 Public messages were intact on disk while the app showed nothing, with no error, no parse failure and no log line to follow. It now warns when it falls back while a resolver is installed, since that combination specifically means the channel list was not loaded first. Had either of these been loud, #333 would have been a one-line log read instead of a multi-hour investigation that looked like data loss. flutter analyze clean, dart format clean, 494 tests pass. --- lib/storage/channel_message_store.dart | 14 ++++++++++++++ lib/storage/channel_store.dart | 6 +++++- lib/storage/community_store.dart | 12 ++++++++++-- lib/storage/contact_discovery_store.dart | 10 +++++++++- lib/storage/contact_store.dart | 6 +++++- lib/storage/message_store.dart | 7 +++++++ lib/storage/unread_store.dart | 6 +++++- 7 files changed, 55 insertions(+), 6 deletions(-) diff --git a/lib/storage/channel_message_store.dart b/lib/storage/channel_message_store.dart index dfef8c3..63dc24a 100644 --- a/lib/storage/channel_message_store.dart +++ b/lib/storage/channel_message_store.dart @@ -32,11 +32,25 @@ class ChannelMessageStore { String _indexKey(int channelIndex) => '$keyFor$channelIndex'; /// Active storage key: PSK identity when known, else the slot index. + /// + /// The index fallback is legitimate before a channel list has loaded, but it + /// reads a DIFFERENT key: if history was already migrated to the PSK key, the + /// caller gets an empty list that is indistinguishable from data loss. + /// SAFELANE 6 - this must never be silent. Falling back where a resolver + /// exists means the channel list was not ready, which is the #333 race. String _storageKey(int channelIndex) { final pskHex = channelPskResolver?.call(channelIndex); if (pskHex != null && pskHex.isNotEmpty) { return '$keyFor$_pskMarker$pskHex'; } + if (channelPskResolver != null) { + appLogger.warn( + 'Channel $channelIndex has no PSK yet; falling back to the slot-index ' + 'key. Any history already migrated to the PSK key will read as EMPTY. ' + 'This means the channel list was not loaded first (#333).', + tag: 'Storage', + ); + } return _indexKey(channelIndex); } diff --git a/lib/storage/channel_store.dart b/lib/storage/channel_store.dart index b52b5b7..596d3bc 100644 --- a/lib/storage/channel_store.dart +++ b/lib/storage/channel_store.dart @@ -47,7 +47,11 @@ class ChannelStore { return jsonList .map((entry) => _fromJson(entry as Map)) .toList(); - } catch (_) { + } catch (e) { + // SAFELANE 6: never swallow. A decode failure here is + // indistinguishable from 'no data' to the caller, which reads + // to the user as data loss. + appLogger.error('Failed to decode channels: $e', tag: 'Storage'); return []; } } diff --git a/lib/storage/community_store.dart b/lib/storage/community_store.dart index a8010a1..732ff47 100644 --- a/lib/storage/community_store.dart +++ b/lib/storage/community_store.dart @@ -107,7 +107,11 @@ class CommunityStore { final communities = await loadCommunities(); try { return communities.firstWhere((c) => c.id == communityId); - } catch (_) { + } catch (e) { + // SAFELANE 6: never swallow. A decode failure here is + // indistinguishable from 'no data' to the caller, which reads + // to the user as data loss. + appLogger.error('Failed to decode communities: $e', tag: 'Storage'); return null; } } @@ -118,7 +122,11 @@ class CommunityStore { final communities = await loadCommunities(); try { return communities.firstWhere((c) => c.communityId == cid); - } catch (_) { + } catch (e) { + // SAFELANE 6: never swallow. A decode failure here is + // indistinguishable from 'no data' to the caller, which reads + // to the user as data loss. + appLogger.error('Failed to decode communities: $e', tag: 'Storage'); return null; } } diff --git a/lib/storage/contact_discovery_store.dart b/lib/storage/contact_discovery_store.dart index 3f6f171..796652e 100644 --- a/lib/storage/contact_discovery_store.dart +++ b/lib/storage/contact_discovery_store.dart @@ -3,6 +3,7 @@ import 'dart:typed_data'; import '../models/contact.dart'; import 'prefs_manager.dart'; +import '../utils/app_logger.dart'; class ContactDiscoveryStore { static const String _keyPrefix = 'discovered_contacts'; @@ -17,7 +18,14 @@ class ContactDiscoveryStore { return jsonList .map((entry) => _fromJson(entry as Map)) .toList(); - } catch (_) { + } catch (e) { + // SAFELANE 6: never swallow. A decode failure here is + // indistinguishable from 'no data' to the caller, which reads + // to the user as data loss. + appLogger.error( + 'Failed to decode discovered contacts: $e', + tag: 'Storage', + ); return []; } } diff --git a/lib/storage/contact_store.dart b/lib/storage/contact_store.dart index 9085d4e..9149046 100644 --- a/lib/storage/contact_store.dart +++ b/lib/storage/contact_store.dart @@ -47,7 +47,11 @@ class ContactStore { return jsonList .map((entry) => _fromJson(entry as Map)) .toList(); - } catch (_) { + } catch (e) { + // SAFELANE 6: never swallow. A decode failure here is + // indistinguishable from 'no data' to the caller, which reads + // to the user as data loss. + appLogger.error('Failed to decode contacts: $e', tag: 'Storage'); return []; } } diff --git a/lib/storage/message_store.dart b/lib/storage/message_store.dart index 6045342..96595e4 100644 --- a/lib/storage/message_store.dart +++ b/lib/storage/message_store.dart @@ -66,6 +66,13 @@ class MessageStore { final jsonList = jsonDecode(jsonString) as List; return jsonList.map((json) => _messageFromJson(json)).toList(); } catch (e) { + // SAFELANE 6: never swallow. A decode failure here is + // indistinguishable from 'no data' to the caller, which reads + // to the user as data loss. + appLogger.error( + 'Failed to decode messages for $contactKeyHex: $e', + tag: 'Storage', + ); return []; } } diff --git a/lib/storage/unread_store.dart b/lib/storage/unread_store.dart index cc1f377..a9cd4df 100644 --- a/lib/storage/unread_store.dart +++ b/lib/storage/unread_store.dart @@ -57,7 +57,11 @@ class UnreadStore { try { final json = jsonDecode(jsonString) as Map; return json.map((key, value) => MapEntry(key, value as int)); - } catch (_) { + } catch (e) { + // SAFELANE 6: never swallow. A decode failure here is + // indistinguishable from 'no data' to the caller, which reads + // to the user as data loss. + appLogger.error('Failed to decode unread state: $e', tag: 'Storage'); return {}; } } From 77625db575a2724aa6e79f03ca4887d578c7fae5 Mon Sep 17 00:00:00 2001 From: Strycher Date: Mon, 20 Jul 2026 13:31:04 -0400 Subject: [PATCH 8/9] perf(#306): measure cumulative sync time per frame code The conversation-load metric was misread, and nearly caused a fix to the wrong thing. It reported store=30138ms across 300 contacts, which looked like loadMessages costing ~100ms each. It is not: - The device-wide fallback key `messages_` does not exist on the reporting machine, and only 11 per-contact message keys exist in total, so loadMessages does three in-memory map lookups and returns empty. - storeWatch spans an `await`, so it measures WALL time including event-loop queueing, not work. merge, which is synchronous and has no await, measures 0ms - consistent with the isolate being busy elsewhere while those awaits wait their turn. So the 30s is ~300 awaits each waiting for a busy isolate, not 30s of storage work. The metric label now says so, rather than inviting the same misreading. The per-call 100ms threshold cannot see the actual shape here: a handler that takes 40ms and runs 234 times owns ~9s of isolate time and never trips it. Frame handlers now accumulate synchronous time per frame code and report the top codes by total, which names the owner regardless of per-call cost. Diagnostics only, no behaviour change. flutter analyze clean, dart format clean, 494 tests pass. --- lib/connector/meshcore_connector.dart | 45 +++++++++++++++++++++++++-- 1 file changed, 42 insertions(+), 3 deletions(-) diff --git a/lib/connector/meshcore_connector.dart b/lib/connector/meshcore_connector.dart index 2bfb1ca..af5b8a3 100644 --- a/lib/connector/meshcore_connector.dart +++ b/lib/connector/meshcore_connector.dart @@ -723,7 +723,8 @@ class MeshCoreConnector extends ChangeNotifier { if (_convLoadCount % 25 == 0) { appLogger.info( 'conversation loads: $_convLoadCount contacts, ' - 'store=${_convLoadStoreMs}ms merge=${_convLoadMergeMs}ms cumulative', + 'store=${_convLoadStoreMs}ms(WALL, spans await - includes event-loop ' + 'queueing, NOT pure work) merge=${_convLoadMergeMs}ms(sync work)', tag: 'Perf', ); } @@ -4376,17 +4377,55 @@ class MeshCoreConnector extends ChangeNotifier { /// once. Logged rather than assumed, so the offending code is named. static const Duration _slowHandlerThreshold = Duration(milliseconds: 100); + /// Cumulative synchronous time per frame code. A single handler under the + /// slow threshold can still dominate if it runs hundreds of times, which a + /// per-call threshold cannot see. + final Map _frameCodeMicros = {}; + final Map _frameCodeCount = {}; + int _frameTotalMicros = 0; + void _handleFrame(List data) { final handlerWatch = Stopwatch()..start(); _handleFrameInner(data); handlerWatch.stop(); - if (handlerWatch.elapsed > _slowHandlerThreshold && data.isNotEmpty) { + if (data.isEmpty) return; + + final code = data[0]; + final micros = handlerWatch.elapsedMicroseconds; + _frameCodeMicros[code] = (_frameCodeMicros[code] ?? 0) + micros; + _frameCodeCount[code] = (_frameCodeCount[code] ?? 0) + 1; + _frameTotalMicros += micros; + + if (handlerWatch.elapsed > _slowHandlerThreshold) { appLogger.info( - 'slow frame handler: code=${data[0]} blocked UI for ' + 'slow frame handler: code=$code blocked UI for ' '${handlerWatch.elapsedMilliseconds}ms', tag: 'Perf', ); } + + // Periodic cumulative report: names the code that owns the most isolate + // time even when no single call is slow. + if (_frameTotalMicros > 2000000) { + final ranked = _frameCodeMicros.entries.toList() + ..sort((a, b) => b.value.compareTo(a.value)); + final top = ranked + .take(4) + .map( + (e) => + 'code=${e.key} ${(e.value / 1000).round()}ms' + '/${_frameCodeCount[e.key]}calls', + ) + .join(' '); + appLogger.info( + 'frame handler cumulative (${(_frameTotalMicros / 1000).round()}ms ' + 'total sync): $top', + tag: 'Perf', + ); + _frameTotalMicros = 0; + _frameCodeMicros.clear(); + _frameCodeCount.clear(); + } } void _handleFrameInner(List data) { From 2004459556ce4bb669446c6162963ff185c9e79d Mon Sep 17 00:00:00 2001 From: Strycher Date: Mon, 20 Jul 2026 13:45:29 -0400 Subject: [PATCH 9/9] perf(#306): throttle the per-contact notify during a bulk pull Measured, not guessed. Cumulative per-code frame timing named the owner: frame handler cumulative (2002ms total sync): code=3 2002ms/105calls code=3 is RESP_CODE_CONTACT, and it accounted for ALL of the synchronous frame time at ~19ms per contact. That is why a per-call 100ms threshold never fired: no single call is slow, the volume is. The 19ms is _handleContact calling notifyListeners() for every contact. Each notification is a synchronous full-tree rebuild, and each rebuild walks the contact list, so the cost grows with the address book. The channel handler directly alongside already guards its notify with _isLoadingChannels; the contact handler had no equivalent. Notifications are now throttled to one per 250ms while _isLoadingContacts is set, and remain immediate outside a pull so single adverts still update live. Throttled rather than suppressed so the sync progress bar keeps advancing. The existing notifyListeners() when the pull completes still fires, so the final state cannot be stale. Scope of what this accounts for, stated honestly: measured synchronous frame work was ~2s per report window and the pull showed ~4s total, against a ~30s observed freeze. This removes the largest measured contributor. If the stall persists, the remainder is outside the frame handlers and the cumulative counters will show frame time has dropped, which narrows it further. flutter analyze clean, dart format clean, 494 tests pass. --- lib/connector/meshcore_connector.dart | 31 ++++++++++++++++++++++++++- 1 file changed, 30 insertions(+), 1 deletion(-) diff --git a/lib/connector/meshcore_connector.dart b/lib/connector/meshcore_connector.dart index af5b8a3..fdcfc98 100644 --- a/lib/connector/meshcore_connector.dart +++ b/lib/connector/meshcore_connector.dart @@ -5101,6 +5101,28 @@ class MeshCoreConnector extends ChangeNotifier { return physicsMax; } + /// Coalesces notifications during a bulk contact pull. + /// + /// Outside a pull this notifies immediately, preserving live-update + /// behaviour for adverts arriving one at a time. + DateTime? _lastContactPullNotify; + static const Duration _contactPullNotifyInterval = Duration( + milliseconds: 250, + ); + + void _notifyContactPullThrottled() { + if (!_isLoadingContacts) { + notifyListeners(); + return; + } + final now = DateTime.now(); + final last = _lastContactPullNotify; + if (last == null || now.difference(last) >= _contactPullNotifyInterval) { + _lastContactPullNotify = now; + notifyListeners(); + } + } + void _handleContact(Uint8List frame, {bool isContact = true}) { final contactTmp = Contact.fromFrame(frame); if (contactTmp != null) { @@ -5188,7 +5210,14 @@ class MeshCoreConnector extends ChangeNotifier { _pathHistoryService!.handlePathUpdated(contact); } - notifyListeners(); + // During a bulk pull this fired once per contact, and each notification + // is a synchronous full-tree rebuild that itself walks the contact list. + // Measured at ~19ms per contact, which never tripped a per-call slow + // threshold but dominated total isolate time. The channel handler + // already guards its notify with _isLoadingChannels; this is the same + // guard, throttled rather than suppressed so the sync progress bar still + // advances while the pull runs. + _notifyContactPullThrottled(); // Show notification for new contact (advertisement) if (isNewContact && _appSettingsService != null) {