Enhance USB serial services with debug logging and reset functionality

- Introduced debug logging in USB serial services for better traceability.
- Added reset method to UsbSerialFrameDecoder to clear buffered data.
- Updated tests to verify the reset functionality of the decoder.
This commit is contained in:
just_stuff_tm
2026-03-02 18:54:12 -05:00
committed by just-stuff-tm
parent c2f544eeba
commit 4c7ee3b3b0
5 changed files with 153 additions and 30 deletions
+92 -21
View File
@@ -350,11 +350,38 @@ class MeshCoreConnector extends ChangeNotifier {
? allMessages.sublist(allMessages.length - _messageWindowSize) ? allMessages.sublist(allMessages.length - _messageWindowSize)
: allMessages; : allMessages;
_conversations[contactKeyHex] = windowedMessages; final currentMessages =
_conversations[contactKeyHex] ?? const <Message>[];
final mergedMessages = <Message>[...windowedMessages];
final existingKeys = <String>{
for (final message in windowedMessages) _messageMergeKey(message),
};
for (final message in currentMessages) {
final key = _messageMergeKey(message);
if (existingKeys.add(key)) {
mergedMessages.add(message);
}
}
mergedMessages.sort((a, b) => a.timestamp.compareTo(b.timestamp));
final windowedMergedMessages = mergedMessages.length > _messageWindowSize
? mergedMessages.sublist(mergedMessages.length - _messageWindowSize)
: mergedMessages;
_conversations[contactKeyHex] = windowedMergedMessages;
notifyListeners(); notifyListeners();
} }
} }
String _messageMergeKey(Message message) {
final messageId = message.messageId;
if (messageId != null && messageId.isNotEmpty) {
return 'id:$messageId';
}
return 'fallback:${message.isOutgoing}:${message.timestamp.millisecondsSinceEpoch}:${message.text}';
}
/// Load older messages for a contact (pagination) /// Load older messages for a contact (pagination)
Future<List<Message>> loadOlderMessages( Future<List<Message>> loadOlderMessages(
String contactKeyHex, { String contactKeyHex, {
@@ -590,6 +617,7 @@ class MeshCoreConnector extends ChangeNotifier {
_bleDebugLogService = bleDebugLogService; _bleDebugLogService = bleDebugLogService;
_appDebugLogService = appDebugLogService; _appDebugLogService = appDebugLogService;
_backgroundService = backgroundService; _backgroundService = backgroundService;
_usbSerialService.setDebugLogService(_appDebugLogService);
// Initialize notification service // Initialize notification service
_notificationService.initialize(); _notificationService.initialize();
@@ -749,7 +777,7 @@ class MeshCoreConnector extends ChangeNotifier {
androidScanMode: AndroidScanMode.lowLatency, androidScanMode: AndroidScanMode.lowLatency,
); );
} catch (error) { } catch (error) {
debugPrint('[BLE Scan] Scan/picker failure: $error'); _appDebugLogService?.warn('Scan/picker failure: $error', tag: 'BLE Scan');
_setState(MeshCoreConnectionState.disconnected); _setState(MeshCoreConnectionState.disconnected);
rethrow; rethrow;
} }
@@ -806,7 +834,10 @@ class MeshCoreConnector extends ChangeNotifier {
try { try {
final connectLabel = _deviceDisplayName ?? _deviceId; final connectLabel = _deviceDisplayName ?? _deviceId;
debugPrint('[BLE Connect] Starting connect to $connectLabel'); _appDebugLogService?.info(
'Starting connect to $connectLabel',
tag: 'BLE Connect',
);
_connectionSubscription = device.connectionState.listen((state) { _connectionSubscription = device.connectionState.listen((state) {
if (state == BluetoothConnectionState.disconnected && isConnected) { if (state == BluetoothConnectionState.disconnected && isConnected) {
_handleDisconnection(); _handleDisconnection();
@@ -820,7 +851,10 @@ class MeshCoreConnector extends ChangeNotifier {
license: License.free, license: License.free,
); );
} catch (error) { } catch (error) {
debugPrint('[BLE Connect] device.connect() failure: $error'); _appDebugLogService?.error(
'device.connect() failure: $error',
tag: 'BLE Connect',
);
rethrow; rethrow;
} }
@@ -828,9 +862,12 @@ class MeshCoreConnector extends ChangeNotifier {
if (!PlatformInfo.isWeb) { if (!PlatformInfo.isWeb) {
try { try {
final mtu = await device.requestMtu(185); final mtu = await device.requestMtu(185);
debugPrint('MTU set to: $mtu'); _appDebugLogService?.info('MTU set to: $mtu', tag: 'BLE Connect');
} catch (e) { } catch (e) {
debugPrint('MTU request failed: $e, using default'); _appDebugLogService?.warn(
'MTU request failed: $e, using default',
tag: 'BLE Connect',
);
} }
} }
@@ -838,11 +875,15 @@ class MeshCoreConnector extends ChangeNotifier {
try { try {
services = await device.discoverServices(); services = await device.discoverServices();
} catch (error) { } catch (error) {
debugPrint('[BLE Connect] service discovery failure: $error'); _appDebugLogService?.error(
'service discovery failure: $error',
tag: 'BLE Connect',
);
if (PlatformInfo.isWeb && if (PlatformInfo.isWeb &&
error.toString().contains('GATT Server is disconnected')) { error.toString().contains('GATT Server is disconnected')) {
debugPrint( _appDebugLogService?.warn(
'[BLE Connect] retrying service discovery after transient web disconnect', 'retrying service discovery after transient web disconnect',
tag: 'BLE Connect',
); );
await Future<void>.delayed(const Duration(milliseconds: 300)); await Future<void>.delayed(const Duration(milliseconds: 300));
await device.connect( await device.connect(
@@ -882,17 +923,32 @@ class MeshCoreConnector extends ChangeNotifier {
} }
if (PlatformInfo.isWeb) { if (PlatformInfo.isWeb) {
debugPrint('Starting setNotifyValue(true)'); _appDebugLogService?.info(
debugPrint('Web: Calling setNotifyValue(true) without awaiting'); 'Starting setNotifyValue(true)',
tag: 'BLE Connect',
);
_appDebugLogService?.info(
'Web: Calling setNotifyValue(true) without awaiting',
tag: 'BLE Connect',
);
unawaited(() async { unawaited(() async {
try { try {
await _txCharacteristic!.setNotifyValue(true); await _txCharacteristic!.setNotifyValue(true);
} catch (error) { } catch (error) {
debugPrint('[BLE Connect] notify failure (web, ignored): $error'); _appDebugLogService?.warn(
debugPrint('Web setNotifyValue error (ignoring): $error'); 'notify failure (web, ignored): $error',
tag: 'BLE Connect',
);
_appDebugLogService?.warn(
'Web setNotifyValue error (ignoring): $error',
tag: 'BLE Connect',
);
} }
}()); }());
debugPrint('setNotifyValue(true) configuration completed'); _appDebugLogService?.info(
'setNotifyValue(true) configuration completed',
tag: 'BLE Connect',
);
} else { } else {
bool notifySet = false; bool notifySet = false;
for (int attempt = 0; attempt < 3 && !notifySet; attempt++) { for (int attempt = 0; attempt < 3 && !notifySet; attempt++) {
@@ -903,8 +959,11 @@ class MeshCoreConnector extends ChangeNotifier {
await _txCharacteristic!.setNotifyValue(true); await _txCharacteristic!.setNotifyValue(true);
notifySet = true; notifySet = true;
} catch (e) { } catch (e) {
debugPrint('[BLE Connect] notify failure: $e'); _appDebugLogService?.warn('notify failure: $e', tag: 'BLE Connect');
debugPrint('setNotifyValue attempt ${attempt + 1}/3 failed: $e'); _appDebugLogService?.warn(
'setNotifyValue attempt ${attempt + 1}/3 failed: $e',
tag: 'BLE Connect',
);
if (attempt == 2) rethrow; if (attempt == 2) rethrow;
} }
} }
@@ -925,7 +984,19 @@ class MeshCoreConnector extends ChangeNotifier {
_activeTransport == MeshCoreTransportType.bluetooth) { _activeTransport == MeshCoreTransportType.bluetooth) {
// Chrome's Web Bluetooth stack commonly delays incoming notifications // Chrome's Web Bluetooth stack commonly delays incoming notifications
// until the non-blocking notify setup settles. Avoid stacking extra // until the non-blocking notify setup settles. Avoid stacking extra
// startup writes while that is happening. // startup writes while that is happening. Defer the clock sync until
// the connection has had time to settle.
unawaited(
Future<void>(() async {
await Future<void>.delayed(const Duration(seconds: 5));
if (!isConnected ||
!PlatformInfo.isWeb ||
_activeTransport != MeshCoreTransportType.bluetooth) {
return;
}
await syncTime();
}),
);
} else { } else {
final gotSelfInfo = await _waitForSelfInfo( final gotSelfInfo = await _waitForSelfInfo(
timeout: const Duration(seconds: 3), timeout: const Duration(seconds: 3),
@@ -943,7 +1014,7 @@ class MeshCoreConnector extends ChangeNotifier {
unawaited(getChannels()); unawaited(getChannels());
} }
} catch (e) { } catch (e) {
debugPrint("Connection error: $e"); _appDebugLogService?.error('Connection error: $e', tag: 'BLE Connect');
await disconnect(manual: false); await disconnect(manual: false);
rethrow; rethrow;
} }
@@ -986,7 +1057,7 @@ class MeshCoreConnector extends ChangeNotifier {
_usbFrameSubscription = _usbSerialService.frameStream.listen( _usbFrameSubscription = _usbSerialService.frameStream.listen(
_handleFrame, _handleFrame,
onError: (error, stackTrace) { onError: (error, stackTrace) {
debugPrint('USB transport error: $error'); _appDebugLogService?.error('USB transport error: $error', tag: 'USB');
unawaited(disconnect(manual: false)); unawaited(disconnect(manual: false));
}, },
onDone: () { onDone: () {
@@ -1013,7 +1084,7 @@ class MeshCoreConnector extends ChangeNotifier {
await syncTime(); await syncTime();
} catch (error) { } catch (error) {
debugPrint('USB connection error: $error'); _appDebugLogService?.error('USB connection error: $error', tag: 'USB');
await disconnect(manual: false); await disconnect(manual: false);
rethrow; rethrow;
} }
@@ -1149,7 +1220,7 @@ class MeshCoreConnector extends ChangeNotifier {
// Skip queued BLE operations so disconnect doesn't get stuck behind them. // Skip queued BLE operations so disconnect doesn't get stuck behind them.
await _device?.disconnect(queue: false); await _device?.disconnect(queue: false);
} catch (e) { } catch (e) {
debugPrint("Disconnect error: $e"); _appDebugLogService?.warn('Disconnect error: $e', tag: 'BLE Connect');
} }
_device = null; _device = null;
+5
View File
@@ -37,6 +37,11 @@ class UsbSerialFrameDecoder {
final List<int> _rxBuffer = <int>[]; final List<int> _rxBuffer = <int>[];
int _startIndex = 0; int _startIndex = 0;
void reset() {
_rxBuffer.clear();
_startIndex = 0;
}
List<UsbSerialDecodedPacket> ingest(Uint8List bytes) { List<UsbSerialDecodedPacket> ingest(Uint8List bytes) {
if (bytes.isEmpty) { if (bytes.isEmpty) {
return const <UsbSerialDecodedPacket>[]; return const <UsbSerialDecodedPacket>[];
+19 -5
View File
@@ -5,6 +5,7 @@ import 'package:flserial/flserial_exception.dart';
import 'package:flutter/foundation.dart'; import 'package:flutter/foundation.dart';
import 'package:flutter/services.dart'; import 'package:flutter/services.dart';
import 'app_debug_log_service.dart';
import '../utils/platform_info.dart'; import '../utils/platform_info.dart';
import '../utils/usb_port_labels.dart'; import '../utils/usb_port_labels.dart';
import 'usb_serial_frame_codec.dart'; import 'usb_serial_frame_codec.dart';
@@ -29,6 +30,7 @@ class UsbSerialService {
String? _connectedPortKey; String? _connectedPortKey;
String? _connectedPortLabel; String? _connectedPortLabel;
FlSerial? _serial; FlSerial? _serial;
AppDebugLogService? _debugLogService;
UsbSerialStatus get status => _status; UsbSerialStatus get status => _status;
String? get activePortKey => _connectedPortKey; String? get activePortKey => _connectedPortKey;
@@ -66,6 +68,10 @@ class UsbSerialService {
return Future.value(FlSerial.listPorts()); return Future.value(FlSerial.listPorts());
} }
void setDebugLogService(AppDebugLogService? service) {
_debugLogService = service;
}
Future<void> connect({ Future<void> connect({
required String portName, required String portName,
int baudRate = 115200, int baudRate = 115200,
@@ -80,6 +86,7 @@ class UsbSerialService {
_status = UsbSerialStatus.connecting; _status = UsbSerialStatus.connecting;
final normalizedPortName = normalizeUsbPortName(portName); final normalizedPortName = normalizeUsbPortName(portName);
_frameDecoder.reset();
if (_useAndroidUsbHost) { if (_useAndroidUsbHost) {
try { try {
@@ -87,8 +94,9 @@ class UsbSerialService {
'portName': normalizedPortName, 'portName': normalizedPortName,
'baudRate': baudRate, 'baudRate': baudRate,
}); });
debugPrint( _debugLogService?.info(
'USB serial opened port=$normalizedPortName on Android via USB host bridge', 'USB serial opened port=$normalizedPortName on Android via USB host bridge',
tag: 'USB Serial',
); );
} on PlatformException catch (error) { } on PlatformException catch (error) {
_status = UsbSerialStatus.disconnected; _status = UsbSerialStatus.disconnected;
@@ -111,8 +119,9 @@ class UsbSerialService {
serial.setFlowControlNone(); serial.setFlowControlNone();
serial.setRTS(false); serial.setRTS(false);
serial.setDTR(true); serial.setDTR(true);
debugPrint( _debugLogService?.info(
'USB serial opened port=$normalizedPortName cts=${serial.getCTS()} dsr=${serial.getDSR()} dtr=true rts=false', 'USB serial opened port=$normalizedPortName cts=${serial.getCTS()} dsr=${serial.getDSR()} dtr=true rts=false',
tag: 'USB Serial',
); );
} on FlSerialException catch (error) { } on FlSerialException catch (error) {
_serial?.free(); _serial?.free();
@@ -174,6 +183,7 @@ class UsbSerialService {
_status = UsbSerialStatus.disconnecting; _status = UsbSerialStatus.disconnecting;
_connectedPortKey = null; _connectedPortKey = null;
_connectedPortLabel = null; _connectedPortLabel = null;
_frameDecoder.reset();
await _androidDataSubscription?.cancel(); await _androidDataSubscription?.cancel();
_androidDataSubscription = null; _androidDataSubscription = null;
await _dataSubscription?.cancel(); await _dataSubscription?.cancel();
@@ -255,8 +265,9 @@ class UsbSerialService {
void _ingestRawBytes(Uint8List bytes) { void _ingestRawBytes(Uint8List bytes) {
for (final packet in _frameDecoder.ingest(bytes)) { for (final packet in _frameDecoder.ingest(bytes)) {
if (!packet.isRxFrame) { if (!packet.isRxFrame) {
debugPrint( _debugLogService?.info(
'USB ignored packet start=0x${packet.frameStart.toRadixString(16).padLeft(2, '0')} len=${packet.payload.length}', 'USB ignored packet start=0x${packet.frameStart.toRadixString(16).padLeft(2, '0')} len=${packet.payload.length}',
tag: 'USB Serial',
); );
continue; continue;
} }
@@ -287,10 +298,13 @@ class UsbSerialService {
void _logFrameSummary(String prefix, Uint8List bytes) { void _logFrameSummary(String prefix, Uint8List bytes) {
if (bytes.isEmpty) { if (bytes.isEmpty) {
debugPrint('$prefix len=0'); _debugLogService?.info('$prefix len=0', tag: 'USB Serial');
return; return;
} }
debugPrint('$prefix code=${bytes[0]} len=${bytes.length}'); _debugLogService?.info(
'$prefix code=${bytes[0]} len=${bytes.length}',
tag: 'USB Serial',
);
} }
} }
+19 -4
View File
@@ -5,6 +5,7 @@ import 'dart:js_interop_unsafe';
import 'package:flutter/foundation.dart'; import 'package:flutter/foundation.dart';
import 'package:web/web.dart' as web; import 'package:web/web.dart' as web;
import 'app_debug_log_service.dart';
import '../utils/usb_port_labels.dart'; import '../utils/usb_port_labels.dart';
import 'usb_serial_frame_codec.dart'; import 'usb_serial_frame_codec.dart';
@@ -27,6 +28,7 @@ class UsbSerialService {
String? _connectedPortName; String? _connectedPortName;
String? _connectedPortKey; String? _connectedPortKey;
String _requestPortLabel = 'Choose USB Device'; String _requestPortLabel = 'Choose USB Device';
AppDebugLogService? _debugLogService;
UsbSerialStatus get status => _status; UsbSerialStatus get status => _status;
String? get activePortKey => _connectedPortKey; String? get activePortKey => _connectedPortKey;
@@ -69,6 +71,7 @@ class UsbSerialService {
} }
_status = UsbSerialStatus.connecting; _status = UsbSerialStatus.connecting;
_frameDecoder.reset();
try { try {
final requestedPortName = normalizeUsbPortName(portName); final requestedPortName = normalizeUsbPortName(portName);
@@ -88,7 +91,10 @@ class UsbSerialService {
_status = UsbSerialStatus.connected; _status = UsbSerialStatus.connected;
unawaited(_pumpReads()); unawaited(_pumpReads());
debugPrint('USB serial opened port=$_connectedPortName via Web Serial'); _debugLogService?.info(
'USB serial opened port=$_connectedPortName via Web Serial',
tag: 'USB Serial',
);
} catch (error) { } catch (error) {
await _cleanupFailedConnect(); await _cleanupFailedConnect();
_status = UsbSerialStatus.disconnected; _status = UsbSerialStatus.disconnected;
@@ -126,6 +132,7 @@ class UsbSerialService {
_port = null; _port = null;
_connectedPortName = null; _connectedPortName = null;
_connectedPortKey = null; _connectedPortKey = null;
_frameDecoder.reset();
if (reader != null) { if (reader != null) {
try { try {
@@ -169,6 +176,10 @@ class UsbSerialService {
_requestPortLabel = trimmed; _requestPortLabel = trimmed;
} }
void setDebugLogService(AppDebugLogService? service) {
_debugLogService = service;
}
void dispose() { void dispose() {
unawaited(disconnect().whenComplete(_closeFrameController)); unawaited(disconnect().whenComplete(_closeFrameController));
} }
@@ -407,8 +418,9 @@ class UsbSerialService {
void _ingestRawBytes(Uint8List bytes) { void _ingestRawBytes(Uint8List bytes) {
for (final packet in _frameDecoder.ingest(bytes)) { for (final packet in _frameDecoder.ingest(bytes)) {
if (!packet.isRxFrame) { if (!packet.isRxFrame) {
debugPrint( _debugLogService?.info(
'USB ignored packet start=0x${packet.frameStart.toRadixString(16).padLeft(2, '0')} len=${packet.payload.length}', 'USB ignored packet start=0x${packet.frameStart.toRadixString(16).padLeft(2, '0')} len=${packet.payload.length}',
tag: 'USB Serial',
); );
continue; continue;
} }
@@ -439,10 +451,13 @@ class UsbSerialService {
void _logFrameSummary(String prefix, Uint8List bytes) { void _logFrameSummary(String prefix, Uint8List bytes) {
if (bytes.isEmpty) { if (bytes.isEmpty) {
debugPrint('$prefix len=0'); _debugLogService?.info('$prefix len=0', tag: 'USB Serial');
return; return;
} }
debugPrint('$prefix code=${bytes[0]} len=${bytes.length}'); _debugLogService?.info(
'$prefix code=${bytes[0]} len=${bytes.length}',
tag: 'USB Serial',
);
} }
} }
@@ -120,4 +120,22 @@ void main() {
expect(packets.single.payload, orderedEquals(<int>[0x44])); expect(packets.single.payload, orderedEquals(<int>[0x44]));
}, },
); );
test('UsbSerialFrameDecoder reset clears buffered partial data', () {
final decoder = UsbSerialFrameDecoder();
expect(
decoder.ingest(Uint8List.fromList(<int>[usbSerialRxFrameStart, 0x02])),
isEmpty,
);
decoder.reset();
final packets = decoder.ingest(
Uint8List.fromList(<int>[usbSerialRxFrameStart, 0x01, 0x00, 0x55]),
);
expect(packets, hasLength(1));
expect(packets.single.payload, orderedEquals(<int>[0x55]));
});
} }