chore(#51): log queue-sync flow to the App Debug Log

Mirror every queue-drain decision -- requested, deferred (which guard),
asking radio, message received, no-more, timeout/give-up, post-channel
proactive fire -- into the App Debug Log via _logQueueSync, so a missed or
stuck drain on reconnect is diagnosable from the device.

Diagnostic only; the targeted fix follows once the log shows the failure.

Refs #51
pull/209/head
Strycher 1 month ago
parent c2346e88d7
commit 2005e5f8c7

@ -3547,21 +3547,37 @@ class MeshCoreConnector extends ChangeNotifier {
await sendFrame(buildSetDeviceTimeFrame(now)); await sendFrame(buildSetDeviceTimeFrame(now));
} }
// Mirror queue-sync events to the in-app App Debug Log (plus the console) so
// a missed/stuck drain is diagnosable from the device. See #51.
void _logQueueSync(String msg) {
debugPrint('[QueueSync] $msg');
_appDebugLogService?.info(msg, tag: 'QueueSync');
}
Future<void> syncQueuedMessages({bool force = false}) async { Future<void> syncQueuedMessages({bool force = false}) async {
if (!isConnected) return; if (!isConnected) return;
if (!force && _isSyncingQueuedMessages) return; if (!force && _isSyncingQueuedMessages) return;
_logQueueSync('drain requested (force: $force)');
if (_isProcessingDeferredQueuedContactMessages) { if (_isProcessingDeferredQueuedContactMessages) {
_logQueueSync('deferred: still processing deferred contact messages');
_pendingQueueSync = true; _pendingQueueSync = true;
return; return;
} }
if (_awaitingSelfInfo || _isLoadingContacts) { if (_awaitingSelfInfo || _isLoadingContacts) {
_logQueueSync(
'deferred: awaitingSelfInfo=$_awaitingSelfInfo loadingContacts=$_isLoadingContacts',
);
_pendingQueueSync = true; _pendingQueueSync = true;
return; return;
} }
if (_isSyncingChannels || _channelSyncInFlight) { if (_isSyncingChannels || _channelSyncInFlight) {
_logQueueSync(
'deferred: syncingChannels=$_isSyncingChannels inFlight=$_channelSyncInFlight',
);
_pendingQueueSync = true; _pendingQueueSync = true;
return; return;
} }
_logQueueSync('starting drain');
_isSyncingQueuedMessages = true; _isSyncingQueuedMessages = true;
notifyListeners(); notifyListeners();
await _requestNextQueuedMessage(); await _requestNextQueuedMessage();
@ -3585,14 +3601,14 @@ class MeshCoreConnector extends ChangeNotifier {
_handleQueueSyncTimeout(); _handleQueueSyncTimeout();
}); });
debugPrint( _logQueueSync(
'[QueueSync] Requesting next message (retry: $_queueSyncRetries/$_maxQueueSyncRetries)', 'asking radio for next message (retry $_queueSyncRetries/$_maxQueueSyncRetries)',
); );
try { try {
await sendFrame(buildSyncNextMessageFrame()); await sendFrame(buildSyncNextMessageFrame());
} catch (e) { } catch (e) {
debugPrint('[QueueSync] Error sending sync request: $e'); _logQueueSync('error sending sync request: $e');
_queuedMessageSyncInFlight = false; _queuedMessageSyncInFlight = false;
_isSyncingQueuedMessages = false; _isSyncingQueuedMessages = false;
_queueSyncTimeout?.cancel(); _queueSyncTimeout?.cancel();
@ -3603,8 +3619,8 @@ class MeshCoreConnector extends ChangeNotifier {
} }
void _handleQueueSyncTimeout() { void _handleQueueSyncTimeout() {
debugPrint( _logQueueSync(
'[QueueSync] Timeout waiting for message (retry: $_queueSyncRetries/$_maxQueueSyncRetries)', 'timeout waiting for message (retry $_queueSyncRetries/$_maxQueueSyncRetries)',
); );
if (_queueSyncRetries < _maxQueueSyncRetries) { if (_queueSyncRetries < _maxQueueSyncRetries) {
@ -3614,7 +3630,7 @@ class MeshCoreConnector extends ChangeNotifier {
_requestNextQueuedMessage(); _requestNextQueuedMessage();
} else { } else {
// Max retries reached, give up // Max retries reached, give up
debugPrint('[QueueSync] Max retries reached, stopping sync'); _logQueueSync('gave up after max retries -- queue NOT fully drained');
_queuedMessageSyncInFlight = false; _queuedMessageSyncInFlight = false;
_isSyncingQueuedMessages = false; _isSyncingQueuedMessages = false;
_queueSyncRetries = 0; _queueSyncRetries = 0;
@ -3870,6 +3886,7 @@ class MeshCoreConnector extends ChangeNotifier {
void _startPostChannelInitialQueuedMessageSync() { void _startPostChannelInitialQueuedMessageSync() {
if (_pendingInitialQueuedMessageSync || _pendingQueueSync) { if (_pendingInitialQueuedMessageSync || _pendingQueueSync) {
_logQueueSync('post-channel-sync: firing initial queue drain');
_deferQueuedContactMessagesUntilContacts = _pendingInitialContactsSync; _deferQueuedContactMessagesUntilContacts = _pendingInitialContactsSync;
_pendingInitialQueuedMessageSync = false; _pendingInitialQueuedMessageSync = false;
_pendingQueueSync = false; _pendingQueueSync = false;
@ -4369,7 +4386,7 @@ class MeshCoreConnector extends ChangeNotifier {
} }
void _handleNoMoreMessages() { void _handleNoMoreMessages() {
debugPrint('[QueueSync] No more messages, sync complete'); _logQueueSync('radio: no more messages, drain complete');
_queueSyncTimeout?.cancel(); _queueSyncTimeout?.cancel();
_isSyncingQueuedMessages = false; _isSyncingQueuedMessages = false;
_queuedMessageSyncInFlight = false; _queuedMessageSyncInFlight = false;
@ -4436,7 +4453,7 @@ class MeshCoreConnector extends ChangeNotifier {
void _handleQueuedMessageReceived() { void _handleQueuedMessageReceived() {
if (!_isSyncingQueuedMessages) return; if (!_isSyncingQueuedMessages) return;
debugPrint('[QueueSync] Message received, requesting next'); _logQueueSync('message received, asking for next');
_queueSyncTimeout?.cancel(); // Cancel timeout - message arrived _queueSyncTimeout?.cancel(); // Cancel timeout - message arrived
_queuedMessageSyncInFlight = false; _queuedMessageSyncInFlight = false;
_queueSyncRetries = 0; // Reset retry counter on successful message _queueSyncRetries = 0; // Reset retry counter on successful message

Loading…
Cancel
Save

Powered by TurnKey Linux.