MotorSignal-App/lib/services/field_test/field_test_logger.dart

955 lines
34 KiB
Dart

import 'dart:async';
import 'dart:collection';
import 'dart:convert';
import 'package:flutter/foundation.dart';
import 'package:flutter_riverpod/flutter_riverpod.dart';
import 'package:drift/drift.dart' as drift;
import 'package:shared_preferences/shared_preferences.dart';
import '../../core/version/app_identity.dart';
import '../../database/database.dart' hide FieldTestEvent, FieldTestSummary, TelemetrySample;
import '../../models/field_test_event.dart';
import '../../models/field_test_summary.dart';
import '../../models/telemetry_sample.dart';
import '../validation/telemetry_validator.dart';
final fieldTestModeEnabledProvider = StateNotifierProvider<FieldTestModeNotifier, bool>((ref) {
return FieldTestModeNotifier();
});
class FieldTestModeNotifier extends StateNotifier<bool> {
static const _prefKey = 'field_test_mode_enabled';
FieldTestModeNotifier() : super(false) {
_load();
}
Future<void> _load() async {
try {
final prefs = await SharedPreferences.getInstance();
state = prefs.getBool(_prefKey) ?? false;
} catch (_) {}
}
Future<void> setEnabled(bool enabled) async {
state = enabled;
try {
final prefs = await SharedPreferences.getInstance();
await prefs.setBool(_prefKey, enabled);
} catch (_) {}
}
}
final fieldTestLoggerProvider = Provider<FieldTestLogger>((ref) {
final db = ref.watch(databaseProvider);
final logger = FieldTestLogger(db);
ref.onDispose(() => logger.dispose());
return logger;
});
final activeFieldTestSessionProvider = Provider<int?>((ref) {
return ref.watch(fieldTestLoggerProvider).activeRideId;
});
class FieldTestLogger {
final AppDatabase _db;
int? _activeRideId;
int? get activeRideId => _activeRideId;
bool get isSessionActive => _activeRideId != null;
DateTime? _sessionStartTime;
DateTime? get sessionStartTime => _sessionStartTime;
// In-memory circular buffer for UI timeline (latest 500 events)
final ListQueue<FieldTestEvent> _timelineBuffer = ListQueue(500);
List<FieldTestEvent> get timelineEvents => _timelineBuffer.toList();
final _timelineStreamController = StreamController<List<FieldTestEvent>>.broadcast();
Stream<List<FieldTestEvent>> get timelineStream => _timelineStreamController.stream;
// Bounded batch queue for database persistence (Capacity: 1,000 events)
static const int _maxQueueCapacity = 1000;
final List<FieldTestEventsCompanion> _eventBatch = [];
Timer? _flushTimer;
bool _isFlushing = false;
/// Batch A (A1): the currently in-flight flush, published so an explicit
/// [stopSession] can await the real owner instead of observing a no-op flush.
/// A coordination primitive only - not a second queue and not a second logger.
Future<void>? _activeFlush;
// Requirement 6: Memory / Queue / Database Observability Metrics
int _peakQueueDepth = 0;
int _totalEnqueued = 0;
int _totalFlushed = 0;
int _droppedEventsCount = 0;
String? _oldestDroppedItem;
String? _newestDroppedItem;
int _lastFlushDurationMs = 0;
int _failedFlushCount = 0;
int get currentQueueDepth => _eventBatch.length;
int get peakQueueDepth => _peakQueueDepth;
int get queueCapacity => _maxQueueCapacity;
int get totalEnqueued => _totalEnqueued;
int get totalFlushed => _totalFlushed;
int get droppedEventsCount => _droppedEventsCount;
int _telemetrySamplesLost = 0;
int get telemetrySamplesLost => _telemetrySamplesLost;
/// Records the loss of telemetry samples due to buffer overflow or queue bounds.
void recordTelemetryLoss(int count) {
if (count > 0) {
_telemetrySamplesLost += count;
}
}
/// Sets or replaces the explicit telemetry loss counter for the active session.
set telemetrySamplesLost(int value) {
_telemetrySamplesLost = value < 0 ? 0 : value;
}
String? get oldestDroppedItem => _oldestDroppedItem;
String? get newestDroppedItem => _newestDroppedItem;
int get lastFlushDurationMs => _lastFlushDurationMs;
int get failedFlushCount => _failedFlushCount;
// Requirement 4 & 5: Live Sensor & Timing Health Metrics
DateTime? _lastSampleTimestamp;
DateTime? _lastGpsTimestamp;
double _recentSampleRateHz = 0.0;
int _recentSampleCount = 0;
DateTime? _rateCalcWindowStart;
double _lastGpsAccuracy = 0.0;
int _lastGpsAgeMs = 0;
double _timingJitterSumMs = 0.0;
int _timingJitterCount = 0;
double _currentQualityScore = 100.0;
double get currentSampleRateHz => _recentSampleRateHz;
double get lastGpsAccuracy => _lastGpsAccuracy;
int get lastGpsAgeMs => _lastGpsAgeMs;
double get currentQualityEstimate => _currentQualityScore;
double get averageTimingJitterMs => _timingJitterCount > 0 ? _timingJitterSumMs / _timingJitterCount : 0.0;
// State-transition tracking for De-duplication
bool _isGpsStale = false;
DateTime? _gpsStaleStartTime;
int _gpsStaleMaxAgeMs = 0;
double? _gpsStaleMinAccuracy;
double? _gpsStaleMaxAccuracy;
double? _gpsStaleSpeed;
bool _isGpsAccuracyDegraded = false;
bool _isImuSaturated = false;
bool _isTelemetryGap = false;
DateTime? _telemetryGapStartTime;
int _maxTelemetryGapMs = 0;
DateTime? _lastTelemetryTime;
int _telemetryGapCount = 0;
int _gpsStaleCount = 0;
int _gpsJumpRejectCount = 0;
int _imuSaturationCount = 0;
int _accelerationEventCount = 0;
int _brakingEventCount = 0;
FieldTestLogger(this._db) {
_flushTimer = Timer.periodic(const Duration(seconds: 3), (_) {
_runContainedFlush();
});
}
/// Batch A (A2): explicit ownership of the flush Future.
///
/// A Timer.periodic callback is synchronous, and dispose() cannot await, so the
/// Future returned by [flush] would otherwise be discarded and any rejection
/// would surface as an uncaught zone error. Diagnostics are bounded to
/// runtimeType only - never the exception message, a stack trace, or any event
/// payload. No new timer, no new queue and no blocking shutdown is introduced.
void _runContainedFlush() {
unawaited(
flush().catchError((Object error, StackTrace stackTrace) {
debugPrint(
'[FieldTestLogger] event flush failed class=${error.runtimeType}',
);
}),
);
}
/// Batch A (A1): bounded drain used by [stopSession] so an explicit stop cannot
/// return before its own event tail is durable.
///
/// Awaits any in-flight owner first, then flushes what remains. Bounded rather
/// than convergent: unlike RID-3B-1 there is no event-acceptance cutoff here, so
/// anything still outstanding after the bound is simply retained in memory in
/// chronological order and retried by the periodic timer - never discarded.
static const int _maxStopDrainPasses = 3;
Future<void> _drainEventBatchForStop() async {
for (var pass = 0; pass < _maxStopDrainPasses; pass++) {
final active = _activeFlush;
if (active != null) {
try {
await active;
} catch (_) {
// The owner retains and restores its own snapshot on failure; ownership
// is re-checked on the next pass.
}
}
if (_eventBatch.isEmpty) return;
if (_isFlushing) continue;
await flush();
}
}
AppIdentity? _sessionIdentity;
AppIdentity get sessionIdentity => _sessionIdentity ?? AppIdentity.current();
void startSession(int rideId, {String? notes, DateTime? timestamp}) {
_activeRideId = rideId;
_sessionStartTime = timestamp ?? DateTime.now();
_sessionIdentity = AppIdentity.current();
_timelineBuffer.clear();
_eventBatch.clear();
_resetStateTrackers();
log(
eventType: FieldTestEventType.rideStarted,
severity: EventSeverity.info,
message: 'Field test session started for ride #$rideId [v${sessionIdentity.displayString}]',
rideId: rideId,
timestamp: _sessionStartTime,
metadata: {
'software': sessionIdentity.toJson(),
'notes': ?notes,
},
);
}
Future<FieldTestSummary> stopSession() async {
final rideId = _activeRideId;
if (rideId == null) {
throw StateError('No active field test session to stop');
}
log(
eventType: FieldTestEventType.rideStopped,
severity: EventSeverity.info,
message: 'Field test session completed for ride #$rideId',
rideId: rideId,
);
// Final database flush before generating summary. Awaits any in-flight
// periodic owner first, so a stop inside a batch interval still persists its
// tail before returning successfully (Batch A / A1).
await _drainEventBatchForStop();
final summary = await generateAndSaveSummary(rideId);
_activeRideId = null;
_sessionStartTime = null;
return summary;
}
void _resetStateTrackers() {
_isGpsStale = false;
_gpsStaleStartTime = null;
_gpsStaleMaxAgeMs = 0;
_gpsStaleMinAccuracy = null;
_gpsStaleMaxAccuracy = null;
_gpsStaleSpeed = null;
_isGpsAccuracyDegraded = false;
_isImuSaturated = false;
_isTelemetryGap = false;
_telemetryGapStartTime = null;
_maxTelemetryGapMs = 0;
_lastTelemetryTime = null;
_lastSampleTimestamp = null;
_lastGpsTimestamp = null;
_telemetryGapCount = 0;
_gpsStaleCount = 0;
_gpsJumpRejectCount = 0;
_imuSaturationCount = 0;
_accelerationEventCount = 0;
_brakingEventCount = 0;
_peakQueueDepth = 0;
_totalEnqueued = 0;
_totalFlushed = 0;
_droppedEventsCount = 0;
_oldestDroppedItem = null;
_newestDroppedItem = null;
_failedFlushCount = 0;
_telemetrySamplesLost = 0;
_recentSampleRateHz = 0.0;
_recentSampleCount = 0;
_rateCalcWindowStart = null;
_timingJitterSumMs = 0.0;
_timingJitterCount = 0;
_currentQualityScore = 100.0;
}
/// Non-blocking centralized logging entrypoint
void log({
required FieldTestEventType eventType,
required EventSeverity severity,
required String message,
int? rideId,
DateTime? timestamp,
DateTime? telemetryTimestamp,
int? gpsAgeMs,
double? speed,
double? latitude,
double? longitude,
double? gpsAccuracy,
double? leanAngle,
double? longitudinalG,
double? lateralG,
double? overallConfidence,
Map<String, dynamic>? metadata,
}) {
final effectiveRideId = rideId ?? _activeRideId;
final now = timestamp ?? DateTime.now();
final event = FieldTestEvent(
timestamp: now,
eventType: eventType,
rideId: effectiveRideId,
severity: severity,
message: message,
telemetryTimestamp: telemetryTimestamp,
gpsAgeMs: gpsAgeMs,
speed: speed,
latitude: latitude,
longitude: longitude,
gpsAccuracy: gpsAccuracy,
leanAngle: leanAngle,
longitudinalG: longitudinalG,
lateralG: lateralG,
overallConfidence: overallConfidence,
metadata: metadata,
);
// 1. Add to live in-memory timeline buffer
if (_timelineBuffer.length >= 500) {
_timelineBuffer.removeFirst();
}
_timelineBuffer.add(event);
if (!_timelineStreamController.isClosed) {
_timelineStreamController.add(_timelineBuffer.toList());
}
// 2. Queue for asynchronous batch persistence
_enqueueEvent(event);
}
void _enqueueEvent(FieldTestEvent event) {
_totalEnqueued++;
if (_eventBatch.length >= _maxQueueCapacity) {
// Prioritized Drop Policy: Drop lowest priority info events first
final dropIdx = _eventBatch.indexWhere((e) => e.severity.value == EventSeverity.info.displayName);
if (dropIdx != -1) {
final dropped = _eventBatch.removeAt(dropIdx);
_recordDrop(dropped.eventType.value);
} else if (event.severity == EventSeverity.critical) {
final dropped = _eventBatch.removeAt(0);
_recordDrop(dropped.eventType.value);
} else {
_recordDrop(event.eventType.displayName);
return;
}
}
_eventBatch.add(FieldTestEventsCompanion(
rideId: drift.Value(event.rideId),
timestamp: drift.Value(event.timestamp),
eventType: drift.Value(event.eventType.displayName),
severity: drift.Value(event.severity.displayName),
message: drift.Value(event.message),
telemetryTimestamp: drift.Value(event.telemetryTimestamp),
gpsAgeMs: drift.Value(event.gpsAgeMs),
speed: drift.Value(event.speed),
latitude: drift.Value(event.latitude),
longitude: drift.Value(event.longitude),
gpsAccuracy: drift.Value(event.gpsAccuracy),
leanAngle: drift.Value(event.leanAngle),
longitudinalG: drift.Value(event.longitudinalG),
lateralG: drift.Value(event.lateralG),
overallConfidence: drift.Value(event.overallConfidence),
metadata: drift.Value(event.metadata != null ? jsonEncode(event.metadata) : null),
));
if (_eventBatch.length > _peakQueueDepth) {
_peakQueueDepth = _eventBatch.length;
}
}
void _recordDrop(String eventType) {
_droppedEventsCount++;
_oldestDroppedItem ??= eventType;
_newestDroppedItem = eventType;
}
/// Process live telemetry sample and perform de-duplicated event generation
void processTelemetrySample(TelemetrySample sample, TelemetryQuality quality) {
final now = sample.timestamp;
// Requirement 4 & 5: Live sample rate & jitter calculation
_recentSampleCount++;
if (_rateCalcWindowStart == null) {
_rateCalcWindowStart = now;
} else {
final windowSec = now.difference(_rateCalcWindowStart!).inMilliseconds / 1000.0;
if (windowSec >= 1.0) {
_recentSampleRateHz = _recentSampleCount / windowSec;
_recentSampleCount = 0;
_rateCalcWindowStart = now;
}
}
if (sample.gpsAccuracy != null) _lastGpsAccuracy = sample.gpsAccuracy!;
if (sample.gpsAgeMs != null) _lastGpsAgeMs = sample.gpsAgeMs!;
_currentQualityScore = quality.overallConfidence * 100.0;
// 1. Timing Forensics: Check for timestamp regressions
if (_lastSampleTimestamp != null && now.isBefore(_lastSampleTimestamp!)) {
log(
eventType: FieldTestEventType.timestampError,
severity: EventSeverity.error,
message: 'Sample timestamp regression detected ($now < $_lastSampleTimestamp)',
telemetryTimestamp: now,
);
}
if (sample.gpsTimestamp != null && _lastGpsTimestamp != null && sample.gpsTimestamp!.isBefore(_lastGpsTimestamp!)) {
log(
eventType: FieldTestEventType.timestampError,
severity: EventSeverity.warning,
message: 'GPS fix timestamp regression (${sample.gpsTimestamp} < $_lastGpsTimestamp)',
telemetryTimestamp: now,
);
}
if (sample.gpsTimestamp != null) _lastGpsTimestamp = sample.gpsTimestamp;
// 2. Timing Jitter tracking (nominal interval 50ms)
if (_lastSampleTimestamp != null) {
final dtMs = now.difference(_lastSampleTimestamp!).inMilliseconds;
if (dtMs > 0 && dtMs < 500) {
final jitter = (dtMs - 50).abs().toDouble();
_timingJitterSumMs += jitter;
_timingJitterCount++;
}
}
_lastSampleTimestamp = now;
// 3. Telemetry Gap Detection & Recovery
if (_lastTelemetryTime != null) {
final deltaMs = now.difference(_lastTelemetryTime!).inMilliseconds;
if (deltaMs > 2000) {
_telemetryGapCount++;
if (deltaMs > _maxTelemetryGapMs) _maxTelemetryGapMs = deltaMs;
if (!_isTelemetryGap) {
_isTelemetryGap = true;
_telemetryGapStartTime = _lastTelemetryTime;
log(
eventType: FieldTestEventType.telemetryGap,
severity: EventSeverity.warning,
message: 'Telemetry stream gap detected (${deltaMs}ms)',
telemetryTimestamp: sample.timestamp,
speed: sample.speed,
metadata: {'gapMs': deltaMs},
);
}
} else if (_isTelemetryGap && deltaMs < 200) {
_isTelemetryGap = false;
final gapDuration = _telemetryGapStartTime != null
? now.difference(_telemetryGapStartTime!).inMilliseconds / 1000.0
: 0.0;
log(
eventType: FieldTestEventType.telemetryRecovered,
severity: EventSeverity.info,
message: 'Telemetry stream recovered after ${gapDuration.toStringAsFixed(1)}s',
telemetryTimestamp: sample.timestamp,
speed: sample.speed,
metadata: {'gapDurationSeconds': gapDuration},
);
}
}
_lastTelemetryTime = now;
// 4. GPS Freshness / Stale De-duplication
final gpsAge = sample.gpsAgeMs ?? 0;
final speedMph = sample.speed ?? 0.0;
if (gpsAge > 2000 && speedMph > 3.0) {
if (!_isGpsStale) {
_isGpsStale = true;
_gpsStaleStartTime = now;
_gpsStaleMaxAgeMs = gpsAge;
_gpsStaleMinAccuracy = sample.gpsAccuracy;
_gpsStaleMaxAccuracy = sample.gpsAccuracy;
_gpsStaleSpeed = speedMph;
_gpsStaleCount++;
log(
eventType: FieldTestEventType.gpsStale,
severity: EventSeverity.warning,
message: 'GPS fix became stale (${gpsAge}ms age at ${speedMph.toStringAsFixed(1)} MPH)',
telemetryTimestamp: sample.timestamp,
gpsAgeMs: gpsAge,
speed: speedMph,
gpsAccuracy: sample.gpsAccuracy,
latitude: sample.latitude,
longitude: sample.longitude,
);
} else {
if (gpsAge > _gpsStaleMaxAgeMs) _gpsStaleMaxAgeMs = gpsAge;
if (sample.gpsAccuracy != null) {
if (_gpsStaleMinAccuracy == null || sample.gpsAccuracy! < _gpsStaleMinAccuracy!) {
_gpsStaleMinAccuracy = sample.gpsAccuracy;
}
if (_gpsStaleMaxAccuracy == null || sample.gpsAccuracy! > _gpsStaleMaxAccuracy!) {
_gpsStaleMaxAccuracy = sample.gpsAccuracy;
}
}
}
} else if (_isGpsStale && gpsAge <= 500) {
_isGpsStale = false;
final staleDuration = _gpsStaleStartTime != null
? now.difference(_gpsStaleStartTime!).inMilliseconds / 1000.0
: 0.0;
log(
eventType: FieldTestEventType.gpsRecovered,
severity: EventSeverity.info,
message: 'GPS fix recovered after ${staleDuration.toStringAsFixed(1)}s (max age ${_gpsStaleMaxAgeMs}ms)',
telemetryTimestamp: sample.timestamp,
gpsAgeMs: gpsAge,
speed: speedMph,
gpsAccuracy: sample.gpsAccuracy,
latitude: sample.latitude,
longitude: sample.longitude,
metadata: {
'staleStartTime': _gpsStaleStartTime?.toIso8601String(),
'staleDurationSeconds': staleDuration,
'maxGpsAgeMs': _gpsStaleMaxAgeMs,
'minAccuracy': _gpsStaleMinAccuracy,
'maxAccuracy': _gpsStaleMaxAccuracy,
'speedDuringOutage': _gpsStaleSpeed,
},
);
}
// 5. GPS Accuracy Degradation De-duplication
final accuracy = sample.gpsAccuracy ?? 0.0;
if (accuracy > 35.0) {
if (!_isGpsAccuracyDegraded) {
_isGpsAccuracyDegraded = true;
log(
eventType: FieldTestEventType.gpsAccuracyDegraded,
severity: EventSeverity.warning,
message: 'GPS accuracy degraded to ${accuracy.toStringAsFixed(1)}m',
telemetryTimestamp: sample.timestamp,
gpsAccuracy: accuracy,
speed: speedMph,
);
}
} else if (_isGpsAccuracyDegraded && accuracy <= 15.0) {
_isGpsAccuracyDegraded = false;
log(
eventType: FieldTestEventType.gpsRecovered,
severity: EventSeverity.info,
message: 'GPS accuracy restored to precision ${accuracy.toStringAsFixed(1)}m',
telemetryTimestamp: sample.timestamp,
gpsAccuracy: accuracy,
speed: speedMph,
);
}
// 6. IMU Saturation De-duplication
if (quality.isSensorSaturated) {
_imuSaturationCount++;
if (!_isImuSaturated) {
_isImuSaturated = true;
log(
eventType: FieldTestEventType.imuSaturation,
severity: EventSeverity.error,
message: 'IMU accelerometer saturation limit exceeded (>120 m/s²)',
telemetryTimestamp: sample.timestamp,
longitudinalG: sample.longitudinalG,
lateralG: sample.lateralG,
);
}
} else if (_isImuSaturated) {
_isImuSaturated = false;
log(
eventType: FieldTestEventType.imuRecovered,
severity: EventSeverity.info,
message: 'IMU accelerometer returned to normal operating range',
telemetryTimestamp: sample.timestamp,
);
}
// 7. GPS Jump Rejection
if (quality.reasons.any((r) => r.contains('jump') || r.contains('Teleportation'))) {
_gpsJumpRejectCount++;
log(
eventType: FieldTestEventType.gpsJumpRejected,
severity: EventSeverity.error,
message: 'Impossible GPS velocity/position jump rejected',
telemetryTimestamp: sample.timestamp,
speed: speedMph,
latitude: sample.latitude,
longitude: sample.longitude,
);
}
// 8. Significant Acceleration / Braking Events
final longG = sample.longitudinalG ?? 0.0;
if (longG > 0.60 && speedMph > 5.0) {
_accelerationEventCount++;
log(
eventType: FieldTestEventType.accelerationEvent,
severity: EventSeverity.info,
message: 'Hard Acceleration Event: ${longG.toStringAsFixed(2)}g at ${speedMph.toStringAsFixed(1)} MPH',
telemetryTimestamp: sample.timestamp,
speed: speedMph,
longitudinalG: longG,
lateralG: sample.lateralG,
);
} else if (longG < -0.80 && speedMph > 5.0) {
_brakingEventCount++;
log(
eventType: FieldTestEventType.brakingEvent,
severity: EventSeverity.info,
message: 'Hard Braking Event: ${longG.toStringAsFixed(2)}g at ${speedMph.toStringAsFixed(1)} MPH',
telemetryTimestamp: sample.timestamp,
speed: speedMph,
longitudinalG: longG,
lateralG: sample.lateralG,
);
}
// 9. Sample Validation Status
if (quality.status == ValidationStatus.rejected) {
log(
eventType: FieldTestEventType.sampleRejected,
severity: EventSeverity.error,
message: 'Sample rejected: ${quality.reasons.join(", ")}',
telemetryTimestamp: sample.timestamp,
speed: speedMph,
overallConfidence: quality.overallConfidence,
);
}
}
/// Flushes buffered events to SQLite in a single transaction.
///
/// Batch A (A1) ownership contract - the RID-3A/RID-3B-2 principles applied
/// with the smallest logger-specific implementation (no duplicated ride-state
/// machinery, no new queue, no new timer, no second logger, no persistence
/// redesign):
/// - the owned snapshot is taken and removed from the live buffer BEFORE the
/// await, so exactly one owner exists per event
/// - ownership is guaranteed by the synchronous [_isFlushing] guard, raised
/// before the first await; concurrent callers return without taking a
/// second snapshot
/// - the successful return of `_db.batch(...)` is the durability COMMIT POINT
/// - a PRE-commit failure restores the owned events to the FRONT of the live
/// buffer, preserving their chronological precedence over events that
/// arrived during the await, so they remain retryable
/// - a POST-commit bookkeeping failure can never restore or duplicate events
/// that are already durable
///
/// Invariant: every accepted event is either durably persisted exactly once, or
/// retained in memory in original chronological order for retry. A pre-commit
/// persistence failure never silently discards an event.
Future<void> flush() async {
if (_isFlushing || _eventBatch.isEmpty) return;
_isFlushing = true;
final stopwatch = Stopwatch()..start();
final toWrite = List<FieldTestEventsCompanion>.from(_eventBatch);
_eventBatch.clear();
// Publish this exact in-flight operation so an explicit stopSession() can
// await the real owner instead of observing a no-op flush and returning
// before its own tail is durable.
final completion = Completer<void>();
_activeFlush = completion.future;
try {
// ---- PRE-COMMIT PHASE: the only block that may fail persistence. ----
try {
await _db.batch((batch) {
batch.insertAll(_db.fieldTestEvents, toWrite);
});
} catch (e) {
// Not durable, so restore the owned events to the FRONT of the live
// buffer. Owned A B C plus arrivals D E during the await must become
// A B C D E - never D E A B C - so chronological order survives retry.
_eventBatch.insertAll(0, toWrite);
_failedFlushCount++;
// Bounded diagnostic: operation, runtimeType and event count only. The
// exception object is never logged because its message may carry
// implementation or payload detail.
if (kDebugMode) {
debugPrint(
'[FieldTestLogger] event batch write failed '
'class=${e.runtimeType} events=${toWrite.length}',
);
}
return;
}
// ---- COMMIT POINT REACHED: the owned events are durable. ----
// Post-commit bookkeeping only. Nothing below may restore the snapshot or
// cause a second write of events that are already durable.
_totalFlushed += toWrite.length;
stopwatch.stop();
_lastFlushDurationMs = stopwatch.elapsedMilliseconds;
} finally {
_isFlushing = false;
if (!completion.isCompleted) completion.complete();
_activeFlush = null;
}
}
/// Generates forensic summary from recorded ride telemetry and events
Future<FieldTestSummary> generateAndSaveSummary(
int rideId, {
int? telemetrySamplesLost,
bool wasRecovered = false,
}) async {
final effectiveTelemetryLost = telemetrySamplesLost ?? _telemetrySamplesLost;
final ride = await (_db.select(_db.rides)..where((r) => r.id.equals(rideId))).getSingleOrNull();
final startTime = ride?.startTime ?? DateTime.now();
final endTime = ride?.endTime ?? DateTime.now();
final duration = endTime.difference(startTime);
// Query all samples for this ride
final samples = await (_db.select(_db.telemetrySamples)
..where((t) => t.rideId.equals(rideId))
..orderBy([(t) => drift.OrderingTerm(expression: t.timestamp)])
).get();
final totalSamples = samples.length;
int validSamples = 0;
int suspectSamples = 0;
int rejectedSamples = 0;
int gpsFixCount = 0;
double accuracySum = 0.0;
double? worstAccuracy;
int? maxGpsAge;
double maxSpeed = 0.0;
double maxLean = 0.0;
double maxLongG = 0.0;
double maxLatG = 0.0;
final validator = TelemetryValidator();
for (final s in samples) {
final sample = TelemetrySample(
timestamp: s.timestamp,
latitude: s.latitude,
longitude: s.longitude,
speed: s.speed,
heading: s.heading,
gpsAccuracy: s.gpsAccuracy,
leanAngle: s.leanAngle,
longitudinalG: s.longitudinalG,
lateralG: s.lateralG,
);
final q = validator.validate(sample);
if (q.isValid) {
validSamples++;
} else if (q.isSuspect) {
suspectSamples++;
} else {
rejectedSamples++;
}
if (s.latitude != null && s.longitude != null) {
gpsFixCount++;
}
if (s.gpsAccuracy != null) {
accuracySum += s.gpsAccuracy!;
if (worstAccuracy == null || s.gpsAccuracy! > worstAccuracy) {
worstAccuracy = s.gpsAccuracy;
}
}
final speedVal = s.speed ?? 0.0;
final isMoving = speedVal >= 3.0;
if (s.speed != null && s.speed! > maxSpeed && s.speed! < 223.7) {
maxSpeed = s.speed!;
}
if (s.leanAngle != null && s.leanAngle!.abs() <= 65.0) {
if (isMoving && s.leanAngle!.abs() > maxLean) {
maxLean = s.leanAngle!.abs();
}
}
if (s.longitudinalG != null && s.longitudinalG!.abs() <= 2.5) {
if (isMoving && s.longitudinalG!.abs() > maxLongG) {
maxLongG = s.longitudinalG!.abs();
}
}
if (s.lateralG != null && s.lateralG!.abs() <= 2.5) {
if (isMoving && s.lateralG!.abs() > maxLatG) {
maxLatG = s.lateralG!.abs();
}
}
}
final validPct = totalSamples > 0 ? (validSamples / totalSamples) * 100.0 : 100.0;
final suspectPct = totalSamples > 0 ? (suspectSamples / totalSamples) * 100.0 : 0.0;
final rejectedPct = totalSamples > 0 ? (rejectedSamples / totalSamples) * 100.0 : 0.0;
final avgAccuracy = gpsFixCount > 0 ? accuracySum / gpsFixCount : null;
// Performance Runs for this ride
final perfRuns = await (_db.select(_db.performanceRuns)
..where((p) => p.rideId.equals(rideId))
).get();
final zeroTo60Runs = perfRuns.where((p) => p.type == '0-60').toList();
final zeroTo100Runs = perfRuns.where((p) => p.type == '0-100').toList();
double? best0to60;
double? best0to100;
for (final r in zeroTo60Runs) {
if (best0to60 == null || r.timeMs < best0to60) best0to60 = r.timeMs;
}
for (final r in zeroTo100Runs) {
if (best0to100 == null || r.timeMs < best0to100) best0to100 = r.timeMs;
}
// Query events count
final events = await (_db.select(_db.fieldTestEvents)..where((e) => e.rideId.equals(rideId))).get();
final qualityReport = RideQualityReport.evaluate(
totalSamples: totalSamples,
validSamples: validSamples,
suspectSamples: suspectSamples,
rejectedSamples: rejectedSamples,
timestampGaps: _telemetryGapCount,
gpsFixCount: gpsFixCount,
totalGpsAccuracy: accuracySum,
databaseSamplesLost: effectiveTelemetryLost,
imuSaturationCount: _imuSaturationCount,
isMountCalibrated: true,
);
final summary = FieldTestSummary(
rideId: rideId,
startTime: startTime,
endTime: endTime,
duration: duration,
totalSamples: totalSamples,
validSamples: validSamples,
suspectSamples: suspectSamples,
rejectedSamples: rejectedSamples,
validPercentage: validPct,
suspectPercentage: suspectPct,
rejectedPercentage: rejectedPct,
gpsFixCount: gpsFixCount,
gpsStaleEventCount: _gpsStaleCount,
gpsJumpRejectCount: _gpsJumpRejectCount,
maxGpsAgeMs: maxGpsAge,
averageGpsAccuracy: avgAccuracy,
worstGpsAccuracy: worstAccuracy,
telemetryGapCount: _telemetryGapCount,
maxTelemetryGapMs: _maxTelemetryGapMs > 0 ? _maxTelemetryGapMs : null,
imuSaturationCount: _imuSaturationCount,
maxSpeedMph: maxSpeed > 0 ? maxSpeed : null,
maxLeanAngle: maxLean > 0 ? maxLean : null,
maxLongitudinalG: maxLongG > 0 ? maxLongG : null,
maxLateralG: maxLatG > 0 ? maxLatG : null,
accelerationEventCount: _accelerationEventCount,
brakingEventCount: _brakingEventCount,
zeroTo60Count: zeroTo60Runs.length,
zeroTo100Count: zeroTo100Runs.length,
bestZeroTo60: best0to60,
bestZeroTo100: best0to100,
databaseSamplesWritten: totalSamples,
databaseSamplesLost: effectiveTelemetryLost,
eventCount: events.length,
overallConfidence: qualityReport.overallScore / 100.0,
rideQualityScore: qualityReport.overallScore,
rideQualityRating: qualityReport.rating,
wasRecoveredAfterCrash: wasRecovered,
wasInterrupted: ride?.endTime == null || wasRecovered,
exportIntegrity: 'VERIFIED_OK',
);
// Save summary to database
await _db.into(_db.fieldTestSummaries).insertOnConflictUpdate(
FieldTestSummariesCompanion.insert(
rideId: rideId,
startTime: startTime,
endTime: drift.Value(endTime),
durationSeconds: drift.Value(duration.inSeconds),
totalSamples: drift.Value(totalSamples),
validSamples: drift.Value(validSamples),
suspectSamples: drift.Value(suspectSamples),
rejectedSamples: drift.Value(rejectedSamples),
validPercentage: drift.Value(validPct),
suspectPercentage: drift.Value(suspectPct),
rejectedPercentage: drift.Value(rejectedPct),
gpsFixCount: drift.Value(gpsFixCount),
gpsStaleEventCount: drift.Value(_gpsStaleCount),
gpsJumpRejectCount: drift.Value(_gpsJumpRejectCount),
maxGpsAgeMs: drift.Value(maxGpsAge),
averageGpsAccuracy: drift.Value(avgAccuracy),
worstGpsAccuracy: drift.Value(worstAccuracy),
telemetryGapCount: drift.Value(_telemetryGapCount),
maxTelemetryGapMs: drift.Value(_maxTelemetryGapMs > 0 ? _maxTelemetryGapMs : null),
imuSaturationCount: drift.Value(_imuSaturationCount),
maxSpeedMph: drift.Value(maxSpeed > 0 ? maxSpeed : null),
maxLeanAngle: drift.Value(maxLean > 0 ? maxLean : null),
maxLongitudinalG: drift.Value(maxLongG > 0 ? maxLongG : null),
maxLateralG: drift.Value(maxLatG > 0 ? maxLatG : null),
accelerationEventCount: drift.Value(_accelerationEventCount),
brakingEventCount: drift.Value(_brakingEventCount),
zeroTo60Count: drift.Value(zeroTo60Runs.length),
zeroTo100Count: drift.Value(zeroTo100Runs.length),
bestZeroTo60: drift.Value(best0to60),
bestZeroTo100: drift.Value(best0to100),
databaseSamplesWritten: drift.Value(totalSamples),
databaseSamplesLost: drift.Value(effectiveTelemetryLost),
eventCount: drift.Value(events.length),
overallConfidence: drift.Value(qualityReport.overallScore / 100.0),
rideQualityScore: drift.Value(qualityReport.overallScore),
rideQualityRating: drift.Value(qualityReport.rating),
wasRecoveredAfterCrash: drift.Value(wasRecovered),
wasInterrupted: drift.Value(ride?.endTime == null || wasRecovered),
exportIntegrity: const drift.Value('VERIFIED_OK'),
),
);
return summary;
}
Future<void> clearAllSessions() async {
await _db.delete(_db.fieldTestEvents).go();
await _db.delete(_db.fieldTestSummaries).go();
_timelineBuffer.clear();
if (!_timelineStreamController.isClosed) {
_timelineStreamController.add([]);
}
}
void dispose() {
_flushTimer?.cancel();
// Batch A (A2): dispose() is NOT an awaitable OS durability boundary and this
// makes NO persistence guarantee. The flush is best-effort only, but it is
// explicitly owned so no rejection escapes as an unhandled async error, and
// flush()'s own guards keep a pre-commit failure safe: owned events are
// restored to the in-memory buffer rather than discarded, and nothing mutates
// state after the await. stopSession() remains the real awaitable
// logger-finalization path.
_runContainedFlush();
_timelineStreamController.close();
}
}