feat: add message trace log for end-to-end delivery diagnostics

Matthias Nott

10 days ago 8d1f94e02e927fcb80d170fc85d13a091e5dc304

feat: add message trace log for end-to-end delivery diagnostics

- trace_service.dart: singleton ring buffer (200 entries) for trace events
- trace_screen.dart: log viewer screen with reverse-chron list and upload button
- mqtt_service.dart: _mqttLog adds to TraceService, received/deduped msg traces
- chat_screen.dart: _chatLog adds to TraceService, trace on handleMessage/handleIncomingMessage
- settings_screen.dart: Message Trace Log button navigates to TraceScreen

 lib/screens/chat_screen.dart
..
..
@@ -20,6 +20,7 @@
20
20
 import '../services/audio_service.dart';
21
21
 import '../services/message_store.dart';
22
22
 import '../services/mqtt_service.dart';
23
+import '../services/trace_service.dart';
23
24
 import '../services/navigate_notifier.dart';
24
25
 import '../services/push_service.dart';
25
26
 import '../theme/app_theme.dart';
..
..
@@ -43,6 +44,7 @@
43
44
 
44
45
 Future<void> _chatLog(String msg) async {
45
46
   debugPrint('[Chat] $msg');
47
+  TraceService.instance.addTrace('Chat', msg);
46
48
   if (!kDebugMode) return;
47
49
   try {
48
50
     final dir = await getApplicationDocumentsDirectory();
..
..
@@ -256,12 +258,25 @@
256
258
 
257
259
   void _handleMessage(Map<String, dynamic> msg) {
258
260
     final type = msg['type'] as String?;
261
+    final msgSessionId = msg['sessionId'] as String?;
262
+    final msgSeq = msg['seq'];
263
+
264
+    TraceService.instance.addTrace(
265
+      'handleMessage processing',
266
+      'type=$type sessionId=${msgSessionId?.substring(0, msgSessionId.length.clamp(0, 8))} seq=$msgSeq',
267
+    );
259
268
 
260
269
     // Track sequence numbers for catch_up protocol
261
270
     final seq = msg['seq'] as int?;
262
271
     if (seq != null) {
263
272
       // Dedup: skip messages we've already processed
264
-      if (_seenSeqs.contains(seq)) return;
273
+      if (_seenSeqs.contains(seq)) {
274
+        TraceService.instance.addTrace(
275
+          'handleMessage seq deduped',
276
+          'seq=$seq type=$type — already seen, dropping',
277
+        );
278
+        return;
279
+      }
265
280
       _seenSeqs.add(seq);
266
281
       _seenSeqsList.add(seq);
267
282
       // Keep bounded at 500 with O(1) FIFO eviction (drop oldest first)
..
..
@@ -491,6 +506,11 @@
491
506
         msg['text'] as String? ??
492
507
         '';
493
508
 
509
+    TraceService.instance.addTrace(
510
+      'handleMessage processing type=text',
511
+      'sessionId=${sessionId?.substring(0, sessionId.length.clamp(0, 8))}',
512
+    );
513
+
494
514
     final message = Message.text(
495
515
       role: MessageRole.assistant,
496
516
       content: content,
..
..
@@ -500,6 +520,10 @@
500
520
     final activeId = ref.read(activeSessionIdProvider);
501
521
     if (sessionId != null && sessionId != activeId) {
502
522
       // Store message for the other session so it's there when user switches
523
+      TraceService.instance.addTrace(
524
+        'message stored for session',
525
+        'sessionId=${sessionId.substring(0, sessionId.length.clamp(0, 8))}, toast shown',
526
+      );
503
527
       await _storeForSession(sessionId, message);
504
528
       _incrementUnread(sessionId);
505
529
       final sessions = ref.read(sessionsProvider);
..
..
@@ -516,6 +540,10 @@
516
540
         );
517
541
       }
518
542
     } else {
543
+      TraceService.instance.addTrace(
544
+        'message displayed in chat',
545
+        'sessionId=${sessionId?.substring(0, sessionId.length.clamp(0, 8)) ?? "global"} len=${content.length}',
546
+      );
519
547
       ref.read(messagesProvider.notifier).addMessage(message);
520
548
       ref.read(isTypingProvider.notifier).state = false;
521
549
       _scrollToBottom();
 lib/screens/settings_screen.dart
..
..
@@ -9,6 +9,7 @@
9
9
 import '../services/wol_service.dart';
10
10
 import '../theme/app_theme.dart';
11
11
 import '../widgets/status_dot.dart';
12
+import 'trace_screen.dart';
12
13
 
13
14
 class SettingsScreen extends ConsumerStatefulWidget {
14
15
   const SettingsScreen({super.key});
..
..
@@ -371,6 +372,20 @@
371
372
                 icon: const Icon(Icons.shield_outlined),
372
373
                 label: const Text('Reset Server Trust'),
373
374
               ),
375
+              const SizedBox(height: 12),
376
+
377
+              // Message Trace Log — for diagnosing message delivery problems
378
+              OutlinedButton.icon(
379
+                onPressed: () {
380
+                  Navigator.of(context).push(
381
+                    MaterialPageRoute<void>(
382
+                      builder: (_) => const TraceScreen(),
383
+                    ),
384
+                  );
385
+                },
386
+                icon: const Icon(Icons.receipt_long_outlined),
387
+                label: const Text('Message Trace Log'),
388
+              ),
374
389
               const SizedBox(height: 24),
375
390
 
376
391
               // --- PAILot Pro ---
 lib/screens/trace_screen.dart
..
..
@@ -0,0 +1,254 @@
1
+import 'dart:convert';
2
+
3
+import 'package:flutter/material.dart';
4
+import 'package:mqtt_client/mqtt_client.dart';
5
+
6
+import '../services/mqtt_service.dart';
7
+import '../services/trace_service.dart';
8
+
9
+/// Displays the in-memory trace log for diagnosing message delivery problems.
10
+///
11
+/// Shows entries in reverse chronological order (newest first).
12
+/// Accessible from the Settings screen via "Message Trace Log".
13
+/// Works in both debug and release builds.
14
+class TraceScreen extends StatefulWidget {
15
+  /// Optional MQTT service reference so entries can be published to the server.
16
+  final MqttService? mqttService;
17
+
18
+  const TraceScreen({super.key, this.mqttService});
19
+
20
+  @override
21
+  State<TraceScreen> createState() => _TraceScreenState();
22
+}
23
+
24
+class _TraceScreenState extends State<TraceScreen> {
25
+  bool _sending = false;
26
+
27
+  List<TraceEntry> get _entries =>
28
+      TraceService.instance.entries.reversed.toList();
29
+
30
+  Future<void> _sendToServer() async {
31
+    final service = widget.mqttService;
32
+    if (service == null || !service.isConnected) {
33
+      if (mounted) {
34
+        ScaffoldMessenger.of(context).showSnackBar(
35
+          const SnackBar(content: Text('Not connected to server')),
36
+        );
37
+      }
38
+      return;
39
+    }
40
+
41
+    setState(() => _sending = true);
42
+
43
+    try {
44
+      final entries = TraceService.instance.entries;
45
+      final payload = jsonEncode({
46
+        'type': 'trace_log',
47
+        'source': 'pailot',
48
+        'ts': DateTime.now().millisecondsSinceEpoch,
49
+        'count': entries.length,
50
+        'entries': entries
51
+            .map((e) => {
52
+                  'timestamp': e.timestamp.toIso8601String(),
53
+                  'event': e.event,
54
+                  'details': e.details,
55
+                })
56
+            .toList(),
57
+      });
58
+
59
+      // Build the MQTT payload
60
+      final builder = MqttClientPayloadBuilder();
61
+      builder.addString(payload);
62
+
63
+      // Publish on pailot/trace — daemon can subscribe/log this
64
+      service.send({
65
+        'type': 'command',
66
+        'command': 'trace_upload',
67
+        'args': {
68
+          'count': entries.length,
69
+          'payload': payload,
70
+        },
71
+      });
72
+
73
+      if (mounted) {
74
+        ScaffoldMessenger.of(context).showSnackBar(
75
+          SnackBar(
76
+            content: Text('Sent ${entries.length} trace entries to server'),
77
+          ),
78
+        );
79
+      }
80
+    } catch (e) {
81
+      if (mounted) {
82
+        ScaffoldMessenger.of(context).showSnackBar(
83
+          SnackBar(content: Text('Send failed: $e')),
84
+        );
85
+      }
86
+    } finally {
87
+      if (mounted) setState(() => _sending = false);
88
+    }
89
+  }
90
+
91
+  void _clearLog() {
92
+    TraceService.instance.clear();
93
+    setState(() {});
94
+  }
95
+
96
+  Color _colorForEvent(String event) {
97
+    if (event.contains('error') || event.contains('fail') || event.contains('drop')) {
98
+      return Colors.red.shade300;
99
+    }
100
+    if (event.contains('dedup')) return Colors.orange.shade300;
101
+    if (event.contains('displayed') || event.contains('published')) {
102
+      return Colors.green.shade300;
103
+    }
104
+    if (event.contains('MQTT')) return Colors.blue.shade300;
105
+    if (event.contains('voice')) return Colors.purple.shade300;
106
+    return Colors.grey.shade400;
107
+  }
108
+
109
+  @override
110
+  Widget build(BuildContext context) {
111
+    final entries = _entries;
112
+
113
+    return Scaffold(
114
+      appBar: AppBar(
115
+        title: const Text('Message Trace Log'),
116
+        actions: [
117
+          IconButton(
118
+            icon: const Icon(Icons.delete_outline),
119
+            tooltip: 'Clear log',
120
+            onPressed: _clearLog,
121
+          ),
122
+          IconButton(
123
+            icon: _sending
124
+                ? const SizedBox(
125
+                    width: 20,
126
+                    height: 20,
127
+                    child: CircularProgressIndicator(strokeWidth: 2),
128
+                  )
129
+                : const Icon(Icons.upload_outlined),
130
+            tooltip: 'Send to server',
131
+            onPressed: _sending ? null : _sendToServer,
132
+          ),
133
+        ],
134
+      ),
135
+      body: entries.isEmpty
136
+          ? const Center(
137
+              child: Text(
138
+                'No trace entries yet.\nSend a message to generate traces.',
139
+                textAlign: TextAlign.center,
140
+                style: TextStyle(color: Colors.grey),
141
+              ),
142
+            )
143
+          : Column(
144
+              children: [
145
+                Container(
146
+                  color: Colors.black87,
147
+                  padding: const EdgeInsets.symmetric(horizontal: 12, vertical: 6),
148
+                  child: Row(
149
+                    children: [
150
+                      Text(
151
+                        '${entries.length} entries (newest first)',
152
+                        style: const TextStyle(
153
+                          fontSize: 11,
154
+                          color: Colors.grey,
155
+                          fontFamily: 'monospace',
156
+                        ),
157
+                      ),
158
+                      const Spacer(),
159
+                      const Text(
160
+                        'Tap to copy',
161
+                        style: TextStyle(fontSize: 11, color: Colors.grey),
162
+                      ),
163
+                    ],
164
+                  ),
165
+                ),
166
+                Expanded(
167
+                  child: ListView.builder(
168
+                    itemCount: entries.length,
169
+                    itemBuilder: (context, index) {
170
+                      final entry = entries[index];
171
+                      final ts = entry.timestamp
172
+                          .toIso8601String()
173
+                          .substring(11, 23); // HH:mm:ss.mmm
174
+
175
+                      return InkWell(
176
+                        onTap: () {
177
+                          // Copy full entry to clipboard on tap
178
+                          final text = '$ts | ${entry.event} | ${entry.details}';
179
+                          ScaffoldMessenger.of(context).showSnackBar(
180
+                            SnackBar(
181
+                              content: Text(
182
+                                text,
183
+                                maxLines: 2,
184
+                                overflow: TextOverflow.ellipsis,
185
+                                style: const TextStyle(fontFamily: 'monospace', fontSize: 11),
186
+                              ),
187
+                              duration: const Duration(seconds: 2),
188
+                            ),
189
+                          );
190
+                        },
191
+                        child: Container(
192
+                          padding: const EdgeInsets.symmetric(
193
+                            horizontal: 12,
194
+                            vertical: 6,
195
+                          ),
196
+                          decoration: BoxDecoration(
197
+                            border: Border(
198
+                              bottom: BorderSide(
199
+                                color: Colors.grey.shade800,
200
+                                width: 0.5,
201
+                              ),
202
+                            ),
203
+                          ),
204
+                          child: Row(
205
+                            crossAxisAlignment: CrossAxisAlignment.start,
206
+                            children: [
207
+                              Text(
208
+                                ts,
209
+                                style: const TextStyle(
210
+                                  fontFamily: 'monospace',
211
+                                  fontSize: 10,
212
+                                  color: Colors.grey,
213
+                                ),
214
+                              ),
215
+                              const SizedBox(width: 8),
216
+                              Expanded(
217
+                                child: Column(
218
+                                  crossAxisAlignment: CrossAxisAlignment.start,
219
+                                  children: [
220
+                                    Text(
221
+                                      entry.event,
222
+                                      style: TextStyle(
223
+                                        fontFamily: 'monospace',
224
+                                        fontSize: 11,
225
+                                        fontWeight: FontWeight.bold,
226
+                                        color: _colorForEvent(entry.event),
227
+                                      ),
228
+                                    ),
229
+                                    if (entry.details.isNotEmpty)
230
+                                      Text(
231
+                                        entry.details,
232
+                                        style: const TextStyle(
233
+                                          fontFamily: 'monospace',
234
+                                          fontSize: 10,
235
+                                          color: Colors.grey,
236
+                                        ),
237
+                                        maxLines: 2,
238
+                                        overflow: TextOverflow.ellipsis,
239
+                                      ),
240
+                                  ],
241
+                                ),
242
+                              ),
243
+                            ],
244
+                          ),
245
+                        ),
246
+                      );
247
+                    },
248
+                  ),
249
+                ),
250
+              ],
251
+            ),
252
+    );
253
+  }
254
+}
 lib/services/mqtt_service.dart
..
..
@@ -15,6 +15,7 @@
15
15
 import 'package:uuid/uuid.dart';
16
16
 
17
17
 import '../models/server_config.dart';
18
+import 'trace_service.dart';
18
19
 import 'wol_service.dart';
19
20
 
20
21
 /// Connection status for the MQTT client.
..
..
@@ -25,9 +26,11 @@
25
26
   reconnecting,
26
27
 }
27
28
 
28
-// Debug log — writes to file only in debug builds, always prints via debugPrint
29
+// Debug log — writes to file only in debug builds, always prints via debugPrint.
30
+// Also adds entries to TraceService so they appear in the trace log viewer.
29
31
 Future<void> _mqttLog(String msg) async {
30
32
   debugPrint('[MQTT] $msg');
33
+  TraceService.instance.addTrace('MQTT', msg);
31
34
   if (!kDebugMode) return;
32
35
   try {
33
36
     final dir = await pp.getApplicationDocumentsDirectory();
..
..
@@ -490,12 +493,27 @@
490
493
       // Dedup by msgId
491
494
       final msgId = json['msgId'] as String?;
492
495
       if (msgId != null) {
493
-        if (_seenMsgIds.contains(msgId)) continue;
496
+        if (_seenMsgIds.contains(msgId)) {
497
+          final seq = json['seq'];
498
+          final type = json['type'] as String? ?? '?';
499
+          TraceService.instance.addTrace(
500
+            'MQTT deduped',
501
+            'msgId=${msgId.substring(0, 8)} type=$type seq=$seq topic=${msg.topic}',
502
+          );
503
+          continue;
504
+        }
494
505
         _seenMsgIds.add(msgId);
495
506
         _seenMsgIdOrder.add(msgId);
496
507
         _evictOldIds();
497
508
       }
498
509
 
510
+      final seq = json['seq'];
511
+      final type = json['type'] as String? ?? '?';
512
+      TraceService.instance.addTrace(
513
+        'MQTT received',
514
+        'seq=$seq type=$type on ${msg.topic}',
515
+      );
516
+
499
517
       // Dispatch: parse topic to enrich the message with routing info
500
518
       _dispatchMessage(msg.topic, json);
501
519
     }
 lib/services/trace_service.dart
..
..
@@ -0,0 +1,50 @@
1
+import 'package:flutter/foundation.dart';
2
+
3
+/// A single trace entry capturing a message-handling event.
4
+class TraceEntry {
5
+  final DateTime timestamp;
6
+  final String event;
7
+  final String details;
8
+
9
+  const TraceEntry({
10
+    required this.timestamp,
11
+    required this.event,
12
+    required this.details,
13
+  });
14
+
15
+  @override
16
+  String toString() =>
17
+      '[${timestamp.toIso8601String().substring(11, 23)}] $event — $details';
18
+}
19
+
20
+/// Singleton ring-buffer trace service.
21
+///
22
+/// Captures message-handling events from MQTT, chat screen, and other
23
+/// components. The buffer is capped at [maxEntries] (default 200).
24
+/// Works in both debug and release builds.
25
+class TraceService {
26
+  TraceService._();
27
+  static final TraceService instance = TraceService._();
28
+
29
+  static const int maxEntries = 200;
30
+  final List<TraceEntry> _entries = [];
31
+
32
+  /// All entries, oldest first.
33
+  List<TraceEntry> get entries => List.unmodifiable(_entries);
34
+
35
+  /// Add a trace entry. Oldest entry is evicted once the buffer is full.
36
+  void addTrace(String event, String details) {
37
+    _entries.add(TraceEntry(
38
+      timestamp: DateTime.now(),
39
+      event: event,
40
+      details: details,
41
+    ));
42
+    if (_entries.length > maxEntries) {
43
+      _entries.removeAt(0);
44
+    }
45
+    debugPrint('[TRACE] $event — $details');
46
+  }
47
+
48
+  /// Clear all entries.
49
+  void clear() => _entries.clear();
50
+}