diff --git a/apps/focus_flow_flutter/lib/app/runtime/focus_flow_file_logger.dart b/apps/focus_flow_flutter/lib/app/runtime/focus_flow_file_logger.dart index 74e2b1c..94ac7ba 100644 --- a/apps/focus_flow_flutter/lib/app/runtime/focus_flow_file_logger.dart +++ b/apps/focus_flow_flutter/lib/app/runtime/focus_flow_file_logger.dart @@ -6,10 +6,9 @@ library; import 'dart:io'; -import 'focus_flow_runtime_config.dart'; +import 'package:scheduler_core/scheduler_core.dart' as scheduler_core; -/// Lazily creates a log message only after the target level is enabled. -typedef FocusFlowLogMessage = Object? Function(); +import 'focus_flow_runtime_config.dart'; /// Minimal append-only file logger for FocusFlow runtime diagnostics. final class FocusFlowFileLogger { @@ -17,15 +16,21 @@ final class FocusFlowFileLogger { FocusFlowFileLogger._({ required this.minimumLevel, required this.logFilePath, - required this._now, + required this._logger, }); + /// Additional caller-frame marker for this app wrapper. + static const List _callerFrameIgnores = [ + 'focus_flow_file_logger.dart', + ]; + /// Creates a disabled logger that drops every message. factory FocusFlowFileLogger.disabled({DateTime Function()? now}) { + scheduler_core.logger.disable(now: now); return FocusFlowFileLogger._( minimumLevel: null, logFilePath: null, - now: now ?? _utcNow, + logger: scheduler_core.FocusFlowLogger.disabled(now: now), ); } @@ -44,10 +49,24 @@ final class FocusFlowFileLogger { try { final directory = Directory(location); await directory.create(recursive: true); + final logFilePath = _joinPath(directory.path, fileName); + final resolvedNow = now ?? _utcNow; + final sink = _fileSink(logFilePath); + scheduler_core.logger.configure( + minimumLevel: level, + sink: sink, + now: resolvedNow, + callerFrameIgnores: _callerFrameIgnores, + ); return FocusFlowFileLogger._( minimumLevel: level, - logFilePath: _joinPath(directory.path, fileName), - now: now ?? _utcNow, + logFilePath: logFilePath, + logger: scheduler_core.FocusFlowLogger( + minimumLevel: level, + sink: sink, + now: resolvedNow, + callerFrameIgnores: _callerFrameIgnores, + ), ); } on Object { return FocusFlowFileLogger.disabled(now: now); @@ -60,41 +79,41 @@ final class FocusFlowFileLogger { /// Concrete file path receiving appended log lines. final String? logFilePath; - /// Clock boundary used for log timestamps. - final DateTime Function() _now; + /// Shared logger implementation that owns gating and caller capture. + final scheduler_core.FocusFlowLogger _logger; /// Whether this logger currently writes to a file. - bool get isEnabled => minimumLevel != null && logFilePath != null; + bool get isEnabled => logFilePath != null && _logger.isEnabled; /// Writes a finest-level [message] when enabled for finest logging. Future finest(Object? message) { - return write(FocusFlowLogLevel.finest, message); + return write(scheduler_core.FocusFlowLogLevel.finest, message); } /// Writes a finer-level [message] when enabled for finer logging. Future finer(Object? message) { - return write(FocusFlowLogLevel.finer, message); + return write(scheduler_core.FocusFlowLogLevel.finer, message); } /// Writes a fine-level [message] when enabled for fine logging. Future fine(Object? message) { - return write(FocusFlowLogLevel.fine, message); + return write(scheduler_core.FocusFlowLogLevel.fine, message); } /// Writes a debug-level [message] when enabled for debug or lower. Future debug(Object? message) { - return write(FocusFlowLogLevel.debug, message); + return write(scheduler_core.FocusFlowLogLevel.debug, message); } /// Writes an info-level [message] when enabled for info or lower. Future info(Object? message) { - return write(FocusFlowLogLevel.info, message); + return write(scheduler_core.FocusFlowLogLevel.info, message); } /// Writes a warning-level [message] when enabled for warning or lower. Future warn(Object? message, {Object? error, StackTrace? stackTrace}) { return write( - FocusFlowLogLevel.warn, + scheduler_core.FocusFlowLogLevel.warn, message, error: error, stackTrace: stackTrace, @@ -104,7 +123,7 @@ final class FocusFlowFileLogger { /// Writes an error-level [message] when file logging is enabled. Future error(Object? message, {Object? error, StackTrace? stackTrace}) { return write( - FocusFlowLogLevel.error, + scheduler_core.FocusFlowLogLevel.error, message, error: error, stackTrace: stackTrace, @@ -113,110 +132,28 @@ final class FocusFlowFileLogger { /// Writes [message] at [level] when it passes the configured threshold. Future write( - FocusFlowLogLevel level, + scheduler_core.FocusFlowLogLevel level, Object? message, { Object? error, StackTrace? stackTrace, - }) async { - final path = logFilePath; - final configuredLevel = minimumLevel; - if (path == null || - configuredLevel == null || - !_shouldWrite(level, configuredLevel)) { - return; - } - - final caller = - _shouldCaptureCaller(level: level, minimumLevel: configuredLevel) - ? _callerFrame() - : null; - final resolvedMessage = _resolveMessage(message); - final buffer = StringBuffer() - ..write(_now().toUtc().toIso8601String()) - ..write(' ') - ..write(level.name.toUpperCase()) - ..write(' '); - if (caller != null) { - buffer - ..write('caller=') - ..write(caller) - ..write(' '); - } - buffer.write(resolvedMessage); - if (error != null) { - buffer - ..write(' | error=') - ..write(error); - } - if (stackTrace != null) { - buffer - ..write(' | stackTrace=') - ..write(stackTrace.toString().replaceAll('\n', r'\n')); - } - buffer.writeln(); - - await File( - path, - ).writeAsString(buffer.toString(), mode: FileMode.append, flush: true); + }) { + _logger.write(level, message, error: error, stackTrace: stackTrace); + return Future.value(); } } -/// Returns whether [level] should be written for [minimumLevel]. -bool _shouldWrite(FocusFlowLogLevel level, FocusFlowLogLevel minimumLevel) { - return _severity(level) >= _severity(minimumLevel); -} - -/// Converts [level] to an ordered severity value. -int _severity(FocusFlowLogLevel level) { - return switch (level) { - FocusFlowLogLevel.finest => 0, - FocusFlowLogLevel.finer => 1, - FocusFlowLogLevel.fine => 2, - FocusFlowLogLevel.debug => 3, - FocusFlowLogLevel.info => 4, - FocusFlowLogLevel.warn => 5, - FocusFlowLogLevel.error => 6, - }; -} - -/// Whether automatic callsite capture should run for [level]. -bool _shouldCaptureCaller({ - required FocusFlowLogLevel level, - required FocusFlowLogLevel minimumLevel, -}) { - if (minimumLevel == FocusFlowLogLevel.finest) { - return true; - } - final capturesWarningContext = - level == FocusFlowLogLevel.warn || level == FocusFlowLogLevel.error; - return capturesWarningContext && - _severity(minimumLevel) <= _severity(FocusFlowLogLevel.fine); -} - -/// Resolves a plain or lazy message after level gating has passed. -String _resolveMessage(Object? message) { - final resolved = message is FocusFlowLogMessage ? message() : message; - return resolved?.toString().trim() ?? ''; -} - -/// Captures the first stack frame outside the logger implementation. -String _callerFrame() { - for (final line in StackTrace.current.toString().split('\n')) { - final trimmed = line.trim(); - if (trimmed.isEmpty || trimmed.contains('focus_flow_file_logger.dart')) { - continue; - } - return _sanitizeForSingleLine(trimmed); - } - return 'unknown'; -} - /// Returns the current UTC timestamp. DateTime _utcNow() => DateTime.now().toUtc(); -/// Keeps diagnostic text on one line for append-only file logs. -String _sanitizeForSingleLine(String value) { - return value.replaceAll('\n', r'\n'); +/// Creates a file sink that appends formatted log entries. +scheduler_core.FocusFlowLogSink _fileSink(String path) { + return (entry) { + File(path).writeAsStringSync( + '${entry.toSingleLine()}\n', + mode: FileMode.append, + flush: true, + ); + }; } /// Joins [base] and [child] with the platform path separator. diff --git a/apps/focus_flow_flutter/lib/app/runtime/focus_flow_runtime_config.dart b/apps/focus_flow_flutter/lib/app/runtime/focus_flow_runtime_config.dart index 0013ea8..4c937ab 100644 --- a/apps/focus_flow_flutter/lib/app/runtime/focus_flow_runtime_config.dart +++ b/apps/focus_flow_flutter/lib/app/runtime/focus_flow_runtime_config.dart @@ -7,6 +7,10 @@ library; import 'dart:convert'; import 'dart:io'; +import 'package:scheduler_core/scheduler_core.dart' show FocusFlowLogLevel; + +export 'package:scheduler_core/scheduler_core.dart' show FocusFlowLogLevel; + /// File-backed runtime configuration for optional developer diagnostics. final class FocusFlowRuntimeConfig { /// Creates a runtime configuration with optional logging controls. @@ -67,47 +71,6 @@ final class FocusFlowRuntimeConfig { bool get enablesFileLogging => logLevel != null && logFileLocation != null; } -/// Supported FocusFlow file logging levels, ordered from most to least verbose. -enum FocusFlowLogLevel { - /// Logs every message with automatic callsite detail. - finest, - - /// Logs intra-method minor actions and small state changes. - finer, - - /// Logs secondary details, possible issues, and rich warning/error context. - fine, - - /// Logs debug, info, warning, and error messages. - debug, - - /// Logs normal operational information, warnings, and errors. - info, - - /// Logs warnings and errors. - warn, - - /// Logs only errors. - error; - - /// Parses [value] into a supported logging level. - static FocusFlowLogLevel? tryParse(String? value) { - final normalized = value?.trim().toLowerCase(); - if (normalized == null || normalized.isEmpty) { - return null; - } - if (normalized == 'trace') { - return finest; - } - for (final level in FocusFlowLogLevel.values) { - if (level.name == normalized) { - return level; - } - } - return null; - } -} - /// Reads [value] as a non-empty string when present. String? _optionalString(Object? value) { if (value is! String) { diff --git a/apps/focus_flow_flutter/test/app/runtime_config_test.dart b/apps/focus_flow_flutter/test/app/runtime_config_test.dart index 7cc5251..fbb02d2 100644 --- a/apps/focus_flow_flutter/test/app/runtime_config_test.dart +++ b/apps/focus_flow_flutter/test/app/runtime_config_test.dart @@ -10,9 +10,12 @@ import 'dart:io'; import 'package:flutter_test/flutter_test.dart'; import 'package:focus_flow_flutter/app/runtime/focus_flow_file_logger.dart'; import 'package:focus_flow_flutter/app/runtime/focus_flow_runtime_config.dart'; +import 'package:scheduler_core/scheduler_core.dart' as scheduler_core; /// Runs runtime config tests. void main() { + tearDown(scheduler_core.logger.disable); + group('FocusFlowRuntimeConfig', () { test('missing config file leaves optional settings unset', () async { final directory = await Directory.systemTemp.createTemp( diff --git a/packages/scheduler_core/lib/scheduler_core.dart b/packages/scheduler_core/lib/scheduler_core.dart index 8736dd5..c8eab85 100644 --- a/packages/scheduler_core/lib/scheduler_core.dart +++ b/packages/scheduler_core/lib/scheduler_core.dart @@ -33,6 +33,7 @@ export 'src/persistence/document_mapping.dart'; export 'src/persistence/document_migration.dart'; export 'src/scheduling/free_slots.dart'; export 'src/domain/locked_time.dart'; +export 'src/logging/focus_flow_logger.dart'; export 'src/domain/occupancy_policy.dart'; export 'src/persistence/persistence_contract.dart'; export 'src/domain/project_statistics.dart'; diff --git a/packages/scheduler_core/lib/src/logging/focus_flow_logger.dart b/packages/scheduler_core/lib/src/logging/focus_flow_logger.dart new file mode 100644 index 0000000..efee2f2 --- /dev/null +++ b/packages/scheduler_core/lib/src/logging/focus_flow_logger.dart @@ -0,0 +1,390 @@ +// SPDX-FileCopyrightText: 2026 FocusFlow contributors +// SPDX-License-Identifier: AGPL-3.0-only + +/// Provides shared FocusFlow logging primitives for scheduler code. +library; + +/// Lazily creates a log message after level gating passes. +typedef FocusFlowLogMessage = Object? Function(); + +/// Receives one enabled log entry. +typedef FocusFlowLogSink = void Function(FocusFlowLogEntry entry); + +/// Shared process logger used by scheduler core code. +final FocusFlowLogger logger = FocusFlowLogger.disabled(); + +/// Supported FocusFlow logging levels, ordered from most to least verbose. +enum FocusFlowLogLevel { + /// Extremely granular diagnostics, data dumps, and caller details for every log. + finest, + + /// Intra-method minor actions and small state changes. + finer, + + /// Secondary details, possible issues, and rich warning/error context. + fine, + + /// High-level debug flow and useful state values. + debug, + + /// Very high-level operational checkpoints. + info, + + /// Handled issues where the app recovered and kept going. + warn, + + /// Invalid or unsafe states that need review. + error; + + /// Parses [value] into a supported logging level. + static FocusFlowLogLevel? tryParse(String? value) { + final normalized = value?.trim().toLowerCase(); + if (normalized == null || normalized.isEmpty) { + return null; + } + if (normalized == 'trace') { + return finest; + } + for (final level in FocusFlowLogLevel.values) { + if (level.name == normalized) { + return level; + } + } + return null; + } + + /// Ordered severity used for threshold comparisons. + int get severity { + return switch (this) { + FocusFlowLogLevel.finest => 0, + FocusFlowLogLevel.finer => 1, + FocusFlowLogLevel.fine => 2, + FocusFlowLogLevel.debug => 3, + FocusFlowLogLevel.info => 4, + FocusFlowLogLevel.warn => 5, + FocusFlowLogLevel.error => 6, + }; + } + + /// Whether this level should write when [minimumLevel] is configured. + bool writesAt(FocusFlowLogLevel minimumLevel) { + return severity >= minimumLevel.severity; + } +} + +/// Structured log entry produced after level gating has passed. +final class FocusFlowLogEntry { + /// Creates a structured log entry. + const FocusFlowLogEntry({ + required this.timestamp, + required this.level, + required this.message, + this.caller, + this.error, + this.stackTrace, + }); + + /// UTC timestamp for the log event. + final DateTime timestamp; + + /// Severity level for the log event. + final FocusFlowLogLevel level; + + /// Resolved log message. + final String message; + + /// Optional caller frame captured by [FocusFlowLogger]. + final String? caller; + + /// Optional error object attached to the entry. + final Object? error; + + /// Optional stack trace attached to the entry. + final StackTrace? stackTrace; + + /// Formats this entry as one append-only log line. + String toSingleLine() { + final buffer = StringBuffer() + ..write(timestamp.toUtc().toIso8601String()) + ..write(' ') + ..write(level.name.toUpperCase()) + ..write(' '); + final currentCaller = caller; + if (currentCaller != null) { + buffer + ..write('caller=') + ..write(_sanitizeForSingleLine(currentCaller)) + ..write(' '); + } + buffer.write(_sanitizeForSingleLine(message)); + final currentError = error; + if (currentError != null) { + buffer + ..write(' | error=') + ..write(_sanitizeForSingleLine(currentError.toString())); + } + final currentStackTrace = stackTrace; + if (currentStackTrace != null) { + buffer + ..write(' | stackTrace=') + ..write(_sanitizeForSingleLine(currentStackTrace.toString())); + } + return buffer.toString(); + } +} + +/// Logger that handles level gating, lazy messages, and caller capture. +final class FocusFlowLogger { + /// Creates a logger with optional runtime configuration. + FocusFlowLogger({ + FocusFlowLogLevel? minimumLevel, + FocusFlowLogSink? sink, + DateTime Function()? now, + Iterable callerFrameIgnores = const [], + }) : _minimumLevel = minimumLevel, + _sink = sink, + _now = now ?? _utcNow, + _callerFrameIgnores = _normalizedCallerFrameIgnores( + callerFrameIgnores, + ); + + /// Creates a logger that drops every message. + factory FocusFlowLogger.disabled({DateTime Function()? now}) { + return FocusFlowLogger(now: now); + } + + /// Minimum level currently configured for this logger. + FocusFlowLogLevel? _minimumLevel; + + /// Destination receiving enabled entries. + FocusFlowLogSink? _sink; + + /// Clock used to timestamp log entries. + DateTime Function() _now; + + /// Stack-frame markers ignored when capturing the caller. + List _callerFrameIgnores; + + /// Minimum level that will be written, or null when disabled. + FocusFlowLogLevel? get minimumLevel => _minimumLevel; + + /// Whether this logger has enough configuration to write entries. + bool get isEnabled => _minimumLevel != null && _sink != null; + + /// Replaces this logger's runtime configuration. + void configure({ + required FocusFlowLogLevel minimumLevel, + required FocusFlowLogSink sink, + DateTime Function()? now, + Iterable callerFrameIgnores = const [], + }) { + _minimumLevel = minimumLevel; + _sink = sink; + _now = now ?? _utcNow; + _callerFrameIgnores = _normalizedCallerFrameIgnores(callerFrameIgnores); + } + + /// Disables this logger and drops subsequent messages. + void disable({DateTime Function()? now}) { + _minimumLevel = null; + _sink = null; + _now = now ?? _utcNow; + _callerFrameIgnores = _normalizedCallerFrameIgnores(const []); + } + + /// Whether [level] would currently be written. + bool wouldWrite(FocusFlowLogLevel level) { + final configured = _minimumLevel; + return configured != null && _sink != null && level.writesAt(configured); + } + + /// Writes [message] at `finest` when enabled. + void finest( + Object? message, { + Object? error, + StackTrace? stackTrace, + }) { + write( + FocusFlowLogLevel.finest, + message, + error: error, + stackTrace: stackTrace, + ); + } + + /// Writes [message] at `finer` when enabled. + void finer( + Object? message, { + Object? error, + StackTrace? stackTrace, + }) { + write( + FocusFlowLogLevel.finer, + message, + error: error, + stackTrace: stackTrace, + ); + } + + /// Writes [message] at `fine` when enabled. + void fine( + Object? message, { + Object? error, + StackTrace? stackTrace, + }) { + write( + FocusFlowLogLevel.fine, + message, + error: error, + stackTrace: stackTrace, + ); + } + + /// Writes [message] at `debug` when enabled. + void debug( + Object? message, { + Object? error, + StackTrace? stackTrace, + }) { + write( + FocusFlowLogLevel.debug, + message, + error: error, + stackTrace: stackTrace, + ); + } + + /// Writes [message] at `info` when enabled. + void info( + Object? message, { + Object? error, + StackTrace? stackTrace, + }) { + write( + FocusFlowLogLevel.info, + message, + error: error, + stackTrace: stackTrace, + ); + } + + /// Writes [message] at `warn` when enabled. + void warn( + Object? message, { + Object? error, + StackTrace? stackTrace, + }) { + write( + FocusFlowLogLevel.warn, + message, + error: error, + stackTrace: stackTrace, + ); + } + + /// Writes [message] at `error` when enabled. + void error( + Object? message, { + Object? error, + StackTrace? stackTrace, + }) { + write( + FocusFlowLogLevel.error, + message, + error: error, + stackTrace: stackTrace, + ); + } + + /// Writes [message] at [level] when it passes the configured threshold. + void write( + FocusFlowLogLevel level, + Object? message, { + Object? error, + StackTrace? stackTrace, + }) { + final configured = _minimumLevel; + final currentSink = _sink; + if (configured == null || + currentSink == null || + !level.writesAt(configured)) { + return; + } + + final entry = FocusFlowLogEntry( + timestamp: _now().toUtc(), + level: level, + message: _resolveMessage(message), + caller: _shouldCaptureCaller(level: level, minimumLevel: configured) + ? _callerFrame() + : null, + error: error, + stackTrace: stackTrace, + ); + + try { + currentSink(entry); + } on Object { + return; + } + } + + /// Captures the first stack frame outside known logging internals. + String _callerFrame() { + for (final line in StackTrace.current.toString().split('\n')) { + final trimmed = line.trim(); + final shouldIgnore = _callerFrameIgnores.any(trimmed.contains); + if (trimmed.isEmpty || shouldIgnore) { + continue; + } + return _sanitizeForSingleLine(trimmed); + } + return 'unknown'; + } +} + +/// Returns whether caller capture should run for [level]. +bool _shouldCaptureCaller({ + required FocusFlowLogLevel level, + required FocusFlowLogLevel minimumLevel, +}) { + if (minimumLevel == FocusFlowLogLevel.finest) { + return true; + } + final capturesWarningContext = + level == FocusFlowLogLevel.warn || level == FocusFlowLogLevel.error; + return capturesWarningContext && + minimumLevel.severity <= FocusFlowLogLevel.fine.severity; +} + +/// Resolves a plain or lazy [message] after level gating passes. +String _resolveMessage(Object? message) { + try { + final resolved = message is FocusFlowLogMessage ? message() : message; + return resolved?.toString().trim() ?? ''; + } on Object catch (error) { + return 'Log message evaluation failed: $error'; + } +} + +/// Returns the current UTC timestamp. +DateTime _utcNow() => DateTime.now().toUtc(); + +/// Builds the complete set of caller frame markers to skip. +List _normalizedCallerFrameIgnores( + Iterable callerFrameIgnores, +) { + final ignores = {'focus_flow_logger.dart'}; + for (final ignore in callerFrameIgnores) { + final trimmed = ignore.trim(); + if (trimmed.isNotEmpty) { + ignores.add(trimmed); + } + } + return List.unmodifiable(ignores); +} + +/// Keeps diagnostic text on one physical log line. +String _sanitizeForSingleLine(String value) { + return value.replaceAll('\n', r'\n'); +} diff --git a/packages/scheduler_core/lib/src/scheduling/task_actions.dart b/packages/scheduler_core/lib/src/scheduling/task_actions.dart index d06a096..75340b9 100644 --- a/packages/scheduler_core/lib/src/scheduling/task_actions.dart +++ b/packages/scheduler_core/lib/src/scheduling/task_actions.dart @@ -13,6 +13,7 @@ library; import '../domain/models.dart'; import '../domain/occupancy_policy.dart'; +import '../logging/focus_flow_logger.dart'; import 'scheduling_engine.dart'; import 'task_lifecycle.dart'; import '../domain/time_contracts.dart'; diff --git a/packages/scheduler_core/lib/src/scheduling/task_actions/services/flexible_task_action_service.dart b/packages/scheduler_core/lib/src/scheduling/task_actions/services/flexible_task_action_service.dart index c0715bb..db13f9d 100644 --- a/packages/scheduler_core/lib/src/scheduling/task_actions/services/flexible_task_action_service.dart +++ b/packages/scheduler_core/lib/src/scheduling/task_actions/services/flexible_task_action_service.dart @@ -3,145 +3,6 @@ part of '../../task_actions.dart'; -/// Lazily creates a flexible-task action log message after level gating passes. -typedef FlexibleTaskActionLogMessage = Object? Function(); - -/// Receives a flexible-task action log entry. -typedef FlexibleTaskActionLogSink = void Function( - FlexibleTaskActionLogEntry entry, -); - -/// Log levels used by [FlexibleTaskActionService]. -enum FlexibleTaskActionLogLevel { - /// Extremely granular data dumps with automatic caller information. - finest, - - /// Intra-method minor actions and small state changes. - finer, - - /// Secondary details, possible issues, and rich warning/error context. - fine, - - /// High-level debug flow and state values. - debug, - - /// Very high-level healthy lifecycle checkpoints. - info, - - /// Handled issues where the service recovered and returned a safe result. - warn, - - /// Invalid or unsafe states that should be reviewed. - error, -} - -/// Structured log entry emitted by [FlexibleTaskActionLogger]. -class FlexibleTaskActionLogEntry { - /// Creates a log entry for one flexible-task action event. - const FlexibleTaskActionLogEntry({ - required this.level, - required this.message, - this.caller, - }); - - /// Severity level for this entry. - final FlexibleTaskActionLogLevel level; - - /// Already-resolved message text. - final String message; - - /// Optional source frame captured according to the configured level. - final String? caller; -} - -/// Optional logger used by [FlexibleTaskActionService]. -/// -/// The default constructor is disabled, so existing callers pay only a cheap -/// null/level check. Expensive message construction should be guarded with -/// [isEnabled] and passed as a [FlexibleTaskActionLogMessage]. -class FlexibleTaskActionLogger { - /// Creates a logger that drops every message. - const FlexibleTaskActionLogger.disabled() - : minimumLevel = null, - sink = null; - - /// Creates a logger that sends enabled entries to [sink]. - const FlexibleTaskActionLogger({ - required this.minimumLevel, - required this.sink, - }); - - /// Minimum level to emit, or null when disabled. - final FlexibleTaskActionLogLevel? minimumLevel; - - /// Destination for enabled log entries. - final FlexibleTaskActionLogSink? sink; - - /// Whether [level] would be emitted by this logger. - bool isEnabled(FlexibleTaskActionLogLevel level) { - final configured = minimumLevel; - return configured != null && - sink != null && - _shouldWrite(level, configured); - } - - /// Logs [message] at `finest` when enabled. - void finest(Object? message) { - write(FlexibleTaskActionLogLevel.finest, message); - } - - /// Logs [message] at `finer` when enabled. - void finer(Object? message) { - write(FlexibleTaskActionLogLevel.finer, message); - } - - /// Logs [message] at `fine` when enabled. - void fine(Object? message) { - write(FlexibleTaskActionLogLevel.fine, message); - } - - /// Logs [message] at `debug` when enabled. - void debug(Object? message) { - write(FlexibleTaskActionLogLevel.debug, message); - } - - /// Logs [message] at `info` when enabled. - void info(Object? message) { - write(FlexibleTaskActionLogLevel.info, message); - } - - /// Logs [message] at `warn` when enabled. - void warn(Object? message) { - write(FlexibleTaskActionLogLevel.warn, message); - } - - /// Logs [message] at `error` when enabled. - void error(Object? message) { - write(FlexibleTaskActionLogLevel.error, message); - } - - /// Logs [message] at [level] when enabled. - void write(FlexibleTaskActionLogLevel level, Object? message) { - final configured = minimumLevel; - final currentSink = sink; - if (configured == null || - currentSink == null || - !_shouldWrite(level, configured)) { - return; - } - - currentSink( - FlexibleTaskActionLogEntry( - level: level, - message: _resolveLogMessage(message), - caller: _shouldCaptureCaller(level: level, minimumLevel: configured) - ? _callerFrame() - : null, - ), - ); - } -} - /// Applies low-friction quick actions for flexible task cards. /// /// This service is the adapter between small UI button presses and domain logic. @@ -155,7 +16,6 @@ class FlexibleTaskActionService { this.schedulingEngine = const SchedulingEngine(), this.transitionService = const TaskTransitionService(), this.clock = const SystemClock(), - this.logger = const FlexibleTaskActionLogger.disabled(), }); /// Scheduling dependency used for actions that need timeline changes. @@ -167,9 +27,6 @@ class FlexibleTaskActionService { /// Clock boundary used when an action timestamp is not supplied. final Clock clock; - /// Optional logger for diagnostics around flexible task actions. - final FlexibleTaskActionLogger logger; - /// Apply the first-stage quick action. /// /// Direct actions (`done`, `backlog`) return a changed task. `push` returns the @@ -186,42 +43,35 @@ class FlexibleTaskActionService { Iterable existingActivities = const [], }) { if (!task.isFlexible) { - if (logger.isEnabled(FlexibleTaskActionLogLevel.error)) { - logger.error(() => 'Flexible action rejected for non-flexible task. ' - 'action=${action.name} taskId=${task.id} taskType=${task.type.name} ' - 'taskStatus=${task.status.name}'); - } + logger.error(() => 'Flexible action rejected for non-flexible task. ' + 'action=${action.name} taskId=${task.id} ' + 'taskType=${task.type.name} taskStatus=${task.status.name}'); throw ArgumentError.value( task.type, 'task.type', 'Task must be flexible.'); } - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger.debug(() => 'Applying flexible quick action. ' - 'action=${action.name} taskId=${task.id} ' - 'taskStatus=${task.status.name} hasExplicitUpdatedAt=${updatedAt != null} ' - 'hasOperationId=${operationId != null}'); - } - if (logger.isEnabled(FlexibleTaskActionLogLevel.finest)) { - logger.finest(() => 'Flexible quick action input dump. ' - 'action=${action.name} task=${_taskSummary(task)} ' - 'updatedAt=${updatedAt?.toIso8601String()} operationId=$operationId ' - 'actualStart=${actualStart?.toIso8601String()} ' - 'actualEnd=${actualEnd?.toIso8601String()} ' - 'lockedIntervals=${_intervalSummary(lockedIntervals)} ' - 'existingActivityCount=${existingActivities.length}'); - } + logger.debug(() => 'Applying flexible quick action. ' + 'action=${action.name} taskId=${task.id} ' + 'taskStatus=${task.status.name} hasExplicitUpdatedAt=${updatedAt != null} ' + 'hasOperationId=${operationId != null}'); + logger.finest(() => 'Flexible quick action input dump. ' + 'action=${action.name} task=$task ' + 'updatedAt=${updatedAt?.toIso8601String()} operationId=$operationId ' + 'actualStart=${actualStart?.toIso8601String()} ' + 'actualEnd=${actualEnd?.toIso8601String()} ' + 'lockedIntervals=$lockedIntervals ' + 'existingActivityCount=${existingActivities.length}'); switch (action) { case FlexibleTaskQuickAction.done: final now = updatedAt ?? clock.now(); final opId = operationId ?? _defaultOperationId(action.name, task.id, now); - if (logger.isEnabled(FlexibleTaskActionLogLevel.finer)) { - logger.finer(() => 'Completing flexible task. taskId=${task.id} ' - 'operationId=$opId occurredAt=${now.toIso8601String()} ' - 'hasActualStart=${actualStart != null} hasActualEnd=${actualEnd != null} ' - 'lockedIntervalCount=${lockedIntervals.length}'); - } + logger.finer(() => 'Completing flexible task. taskId=${task.id} ' + 'operationId=$opId occurredAt=${now.toIso8601String()} ' + 'hasActualStart=${actualStart != null} ' + 'hasActualEnd=${actualEnd != null} ' + 'lockedIntervalCount=${lockedIntervals.length}'); final transition = transitionService.apply( task: task, transitionCode: TaskTransitionCode.complete, @@ -237,18 +87,16 @@ class FlexibleTaskActionService { lockedIntervals: lockedIntervals, existingActivities: existingActivities, ); - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger.debug(() => 'Flexible task completion transition finished. ' - 'taskId=${task.id} outcome=${transition.outcomeCode.name} ' - 'nextStatus=${transition.task.status.name} ' - 'activityCount=${transition.activities.length}'); - } - if (transition.outcomeCode != TaskTransitionOutcomeCode.applied && - logger.isEnabled(FlexibleTaskActionLogLevel.fine)) { - logger.fine(() => - 'Possible issue: flexible completion did not apply. ' - 'taskId=${task.id} outcome=${transition.outcomeCode.name} ' - 'previousStatus=${task.status.name} nextStatus=${transition.task.status.name}'); + logger.debug(() => 'Flexible task completion transition finished. ' + 'taskId=${task.id} outcome=${transition.outcomeCode.name} ' + 'nextStatus=${transition.task.status.name} ' + 'activityCount=${transition.activities.length}'); + if (transition.outcomeCode != TaskTransitionOutcomeCode.applied) { + logger + .fine(() => 'Possible issue: flexible completion did not apply. ' + 'taskId=${task.id} outcome=${transition.outcomeCode.name} ' + 'previousStatus=${task.status.name} ' + 'nextStatus=${transition.task.status.name}'); } return FlexibleTaskActionResult( action: action, @@ -257,15 +105,10 @@ class FlexibleTaskActionService { transitionOutcomeCode: transition.outcomeCode, ); case FlexibleTaskQuickAction.push: - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger.debug(() => 'Flexible push destination menu requested. ' - 'taskId=${task.id} taskStatus=${task.status.name}'); - } - if (logger.isEnabled(FlexibleTaskActionLogLevel.finer)) { - logger.finer(() => 'Flexible push destinations prepared. ' - 'taskId=${task.id} destinations=' - '${PushDestination.values.map((destination) => destination.name).join(',')}'); - } + logger.debug(() => 'Flexible push destination menu requested. ' + 'taskId=${task.id} taskStatus=${task.status.name}'); + logger.finer(() => 'Flexible push destinations prepared. ' + 'taskId=${task.id} destinationCount=3'); return FlexibleTaskActionResult( action: action, task: task, @@ -279,13 +122,10 @@ class FlexibleTaskActionService { final now = updatedAt ?? clock.now(); final opId = operationId ?? _defaultOperationId(action.name, task.id, now); - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger - .debug(() => 'Moving flexible task to backlog from quick action. ' - 'taskId=${task.id} operationId=$opId ' - 'occurredAt=${now.toIso8601String()} ' - 'previousStatus=${task.status.name}'); - } + logger.debug(() => 'Moving flexible task to backlog from quick action. ' + 'taskId=${task.id} operationId=$opId ' + 'occurredAt=${now.toIso8601String()} ' + 'previousStatus=${task.status.name}'); final transition = transitionService.apply( task: task, transitionCode: TaskTransitionCode.moveToBacklog, @@ -298,18 +138,16 @@ class FlexibleTaskActionService { occurredAt: now, existingActivities: existingActivities, ); - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger.debug(() => 'Flexible task backlog transition finished. ' - 'taskId=${task.id} outcome=${transition.outcomeCode.name} ' - 'nextStatus=${transition.task.status.name} ' - 'activityCount=${transition.activities.length}'); - } - if (transition.outcomeCode != TaskTransitionOutcomeCode.applied && - logger.isEnabled(FlexibleTaskActionLogLevel.fine)) { + logger.debug(() => 'Flexible task backlog transition finished. ' + 'taskId=${task.id} outcome=${transition.outcomeCode.name} ' + 'nextStatus=${transition.task.status.name} ' + 'activityCount=${transition.activities.length}'); + if (transition.outcomeCode != TaskTransitionOutcomeCode.applied) { logger.fine(() => 'Possible issue: move-to-backlog quick action did not apply. ' 'taskId=${task.id} outcome=${transition.outcomeCode.name} ' - 'previousStatus=${task.status.name} nextStatus=${transition.task.status.name}'); + 'previousStatus=${task.status.name} ' + 'nextStatus=${transition.task.status.name}'); } return FlexibleTaskActionResult( action: action, @@ -318,10 +156,8 @@ class FlexibleTaskActionService { transitionOutcomeCode: transition.outcomeCode, ); case FlexibleTaskQuickAction.breakUp: - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger.debug(() => 'Flexible break-up flow requested. ' - 'taskId=${task.id} taskStatus=${task.status.name}'); - } + logger.debug(() => 'Flexible break-up flow requested. ' + 'taskId=${task.id} taskStatus=${task.status.name}'); return FlexibleTaskActionResult( action: action, task: task, @@ -345,30 +181,21 @@ class FlexibleTaskActionService { final now = updatedAt ?? clock.now(); final opId = operationId ?? _defaultOperationId('push-${destination.name}', taskId, now); - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger.debug(() => 'Applying flexible push destination. ' - 'destination=${destination.name} taskId=$taskId operationId=$opId ' - 'occurredAt=${now.toIso8601String()} taskCount=${input.tasks.length} ' - 'windowStart=${input.window.start.toIso8601String()} ' - 'windowEnd=${input.window.end.toIso8601String()}'); - } - if (logger.isEnabled(FlexibleTaskActionLogLevel.finest)) { - logger.finest(() => 'Flexible push destination input dump. ' - 'destination=${destination.name} taskId=$taskId ' - 'tasks=${_taskListSummary(input.tasks)} ' - 'lockedIntervals=${_intervalSummary(input.lockedIntervals)} ' - 'requiredVisibleIntervals=${_intervalSummary(input.requiredVisibleIntervals)} ' - 'existingActivityCount=${existingActivities.length}'); - } + logger.debug(() => 'Applying flexible push destination. ' + 'destination=${destination.name} taskId=$taskId operationId=$opId ' + 'occurredAt=${now.toIso8601String()} taskCount=${input.tasks.length} ' + 'windowStart=${input.window.start.toIso8601String()} ' + 'windowEnd=${input.window.end.toIso8601String()}'); + logger.finest(() => 'Flexible push destination input dump. ' + 'destination=${destination.name} taskId=$taskId input=$input ' + 'existingActivityCount=${existingActivities.length}'); if (_hasDuplicateActivity( existingActivities: existingActivities, operationId: opId, taskId: taskId, )) { - if (logger.isEnabled(FlexibleTaskActionLogLevel.warn)) { - logger.warn(() => 'Duplicate flexible push operation ignored. ' - 'destination=${destination.name} taskId=$taskId operationId=$opId'); - } + logger.warn(() => 'Duplicate flexible push operation ignored. ' + 'destination=${destination.name} taskId=$taskId operationId=$opId'); return PushDestinationResult( destination: destination, schedulingResult: SchedulingResult( @@ -382,10 +209,8 @@ class FlexibleTaskActionService { ); } - if (logger.isEnabled(FlexibleTaskActionLogLevel.finer)) { - logger.finer(() => 'Dispatching flexible push destination to scheduler. ' - 'destination=${destination.name} taskId=$taskId'); - } + logger.finer(() => 'Dispatching flexible push destination to scheduler. ' + 'destination=${destination.name} taskId=$taskId'); final result = switch (destination) { PushDestination.nextAvailableSlot => schedulingEngine.pushFlexibleTaskToNextAvailableSlot( @@ -405,30 +230,20 @@ class FlexibleTaskActionService { updatedAt: now, ), }; - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger.debug(() => 'Flexible push destination scheduling finished. ' - 'destination=${destination.name} taskId=$taskId ' - 'outcome=${result.outcomeCode.name} changeCount=${result.changes.length} ' - 'noticeCount=${result.notices.length}'); - } - if (_isHandledPushIssue(result.outcomeCode) && - logger.isEnabled(FlexibleTaskActionLogLevel.warn)) { + logger.debug(() => 'Flexible push destination scheduling finished. ' + 'destination=${destination.name} taskId=$taskId ' + 'outcome=${result.outcomeCode.name} changeCount=${result.changes.length} ' + 'noticeCount=${result.notices.length}'); + if (result.outcomeCode != SchedulingOutcomeCode.success) { logger.warn(() => 'Handled flexible push issue. ' 'destination=${destination.name} taskId=$taskId ' - 'outcome=${result.outcomeCode.name} ' - 'notices=${_noticeSummary(result.notices)}'); - } - if (logger.isEnabled(FlexibleTaskActionLogLevel.fine)) { - logger.fine(() => 'Flexible push result details. ' - 'destination=${destination.name} taskId=$taskId ' - 'changes=${_changeSummary(result.changes)} ' - 'notices=${_noticeSummary(result.notices)}'); - } - if (logger.isEnabled(FlexibleTaskActionLogLevel.finest)) { - logger.finest(() => 'Flexible push destination result dump. ' - 'destination=${destination.name} taskId=$taskId ' - 'tasks=${_taskListSummary(result.tasks)}'); + 'outcome=${result.outcomeCode.name} notices=${result.notices}'); } + logger.fine(() => 'Flexible push result details. ' + 'destination=${destination.name} taskId=$taskId ' + 'changes=${result.changes} notices=${result.notices}'); + logger.finest(() => 'Flexible push destination result dump. ' + 'destination=${destination.name} taskId=$taskId result=$result'); final activities = _activitiesForPushDestination( destination: destination, @@ -439,11 +254,9 @@ class FlexibleTaskActionService { occurredAt: now, existingActivities: existingActivities, ); - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger.debug(() => 'Flexible push destination activities prepared. ' - 'destination=${destination.name} taskId=$taskId ' - 'activityCount=${activities.length}'); - } + logger.debug(() => 'Flexible push destination activities prepared. ' + 'destination=${destination.name} taskId=$taskId ' + 'activityCount=${activities.length}'); return PushDestinationResult( destination: destination, @@ -461,22 +274,15 @@ class FlexibleTaskActionService { required String taskId, DateTime? updatedAt, }) { - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger - .debug(() => 'Moving flexible task to backlog from push destination. ' - 'taskId=$taskId taskCount=${input.tasks.length} ' - 'hasExplicitUpdatedAt=${updatedAt != null}'); - } - if (logger.isEnabled(FlexibleTaskActionLogLevel.finest)) { - logger.finest(() => 'Move-to-backlog input dump. ' - 'taskId=$taskId tasks=${_taskListSummary(input.tasks)}'); - } + logger.debug(() => 'Moving flexible task to backlog from push destination. ' + 'taskId=$taskId taskCount=${input.tasks.length} ' + 'hasExplicitUpdatedAt=${updatedAt != null}'); + logger.finest(() => 'Move-to-backlog input dump. ' + 'taskId=$taskId tasks=${input.tasks}'); final task = _taskById(input.tasks, taskId); if (task == null) { - if (logger.isEnabled(FlexibleTaskActionLogLevel.warn)) { - logger.warn(() => 'Handled move-to-backlog issue: task not found. ' - 'taskId=$taskId'); - } + logger.warn(() => 'Handled move-to-backlog issue: task not found. ' + 'taskId=$taskId'); return SchedulingResult( tasks: input.tasks, operationCode: SchedulingOperationCode.moveFlexibleTaskToBacklog, @@ -493,11 +299,9 @@ class FlexibleTaskActionService { } if (!task.isFlexible || task.status != TaskStatus.planned) { - if (logger.isEnabled(FlexibleTaskActionLogLevel.warn)) { - logger.warn(() => 'Handled move-to-backlog issue: invalid task state. ' - 'taskId=${task.id} taskType=${task.type.name} ' - 'taskStatus=${task.status.name}'); - } + logger.warn(() => 'Handled move-to-backlog issue: invalid task state. ' + 'taskId=${task.id} taskType=${task.type.name} ' + 'taskStatus=${task.status.name}'); return SchedulingResult( tasks: input.tasks, operationCode: SchedulingOperationCode.moveFlexibleTaskToBacklog, @@ -517,12 +321,10 @@ class FlexibleTaskActionService { task, updatedAt: updatedAt, ); - if (logger.isEnabled(FlexibleTaskActionLogLevel.debug)) { - logger.debug(() => 'Flexible task moved to backlog. ' - 'taskId=${task.id} previousStart=${task.scheduledStart?.toIso8601String()} ' - 'previousEnd=${task.scheduledEnd?.toIso8601String()} ' - 'updatedAt=${updatedAt?.toIso8601String()}'); - } + logger.debug(() => 'Flexible task moved to backlog. ' + 'taskId=${task.id} previousStart=${task.scheduledStart?.toIso8601String()} ' + 'previousEnd=${task.scheduledEnd?.toIso8601String()} ' + 'updatedAt=${updatedAt?.toIso8601String()}'); return SchedulingResult( tasks: List.unmodifiable( @@ -562,122 +364,3 @@ class FlexibleTaskActionService { ); } } - -/// Returns whether [level] should be emitted for [minimumLevel]. -bool _shouldWrite( - FlexibleTaskActionLogLevel level, - FlexibleTaskActionLogLevel minimumLevel, -) { - return _severity(level) >= _severity(minimumLevel); -} - -/// Converts [level] to a comparable severity value. -int _severity(FlexibleTaskActionLogLevel level) { - return switch (level) { - FlexibleTaskActionLogLevel.finest => 0, - FlexibleTaskActionLogLevel.finer => 1, - FlexibleTaskActionLogLevel.fine => 2, - FlexibleTaskActionLogLevel.debug => 3, - FlexibleTaskActionLogLevel.info => 4, - FlexibleTaskActionLogLevel.warn => 5, - FlexibleTaskActionLogLevel.error => 6, - }; -} - -/// Returns whether caller capture should run for [level]. -bool _shouldCaptureCaller({ - required FlexibleTaskActionLogLevel level, - required FlexibleTaskActionLogLevel minimumLevel, -}) { - if (minimumLevel == FlexibleTaskActionLogLevel.finest) { - return true; - } - final capturesWarningContext = level == FlexibleTaskActionLogLevel.warn || - level == FlexibleTaskActionLogLevel.error; - return capturesWarningContext && - _severity(minimumLevel) <= _severity(FlexibleTaskActionLogLevel.fine); -} - -/// Resolves a plain or lazy log [message]. -String _resolveLogMessage(Object? message) { - final resolved = - message is FlexibleTaskActionLogMessage ? message() : message; - return resolved?.toString().trim() ?? ''; -} - -/// Captures the first stack frame outside logger internals. -String _callerFrame() { - for (final line in StackTrace.current.toString().split('\n')) { - final trimmed = line.trim(); - if (trimmed.isEmpty || - trimmed.contains('_callerFrame') || - trimmed.contains('FlexibleTaskActionLogger.')) { - continue; - } - return trimmed.replaceAll('\n', r'\n'); - } - return 'unknown'; -} - -/// Returns whether [outcomeCode] represents a handled push issue. -bool _isHandledPushIssue(SchedulingOutcomeCode outcomeCode) { - return switch (outcomeCode) { - SchedulingOutcomeCode.success => false, - SchedulingOutcomeCode.noOp || - SchedulingOutcomeCode.notFound || - SchedulingOutcomeCode.invalidState || - SchedulingOutcomeCode.noSlot || - SchedulingOutcomeCode.overflow || - SchedulingOutcomeCode.conflict => - true, - }; -} - -/// Builds a compact summary for [notices]. -String _noticeSummary(List notices) { - if (notices.isEmpty) { - return 'none'; - } - return notices - .map((notice) => - '${notice.type.name}:${notice.issueCode?.name ?? notice.movementCode?.name ?? 'none'}') - .join(','); -} - -/// Builds a compact summary for [changes]. -String _changeSummary(List changes) { - if (changes.isEmpty) { - return 'none'; - } - return changes - .map((change) => - '${change.taskId}:${change.previousStart?.toIso8601String()}->${change.nextStart?.toIso8601String()}') - .join(','); -} - -/// Builds a compact dump for [tasks]. -String _taskListSummary(List tasks) { - if (tasks.isEmpty) { - return 'none'; - } - return tasks.map(_taskSummary).join(','); -} - -/// Builds a compact dump for [task]. -String _taskSummary(Task task) { - return '${task.id}{type=${task.type.name},status=${task.status.name},' - 'project=${task.projectId},duration=${task.durationMinutes},' - 'start=${task.scheduledStart?.toIso8601String()},' - 'end=${task.scheduledEnd?.toIso8601String()}}'; -} - -/// Builds a compact dump for [intervals]. -String _intervalSummary(List intervals) { - if (intervals.isEmpty) { - return 'none'; - } - return intervals - .map((interval) => - '${interval.start.toIso8601String()}-${interval.end.toIso8601String()}') - .join(','); -} diff --git a/packages/scheduler_core/test/focus_flow_logger_test.dart b/packages/scheduler_core/test/focus_flow_logger_test.dart new file mode 100644 index 0000000..72483bf --- /dev/null +++ b/packages/scheduler_core/test/focus_flow_logger_test.dart @@ -0,0 +1,118 @@ +// SPDX-FileCopyrightText: 2026 FocusFlow contributors +// SPDX-License-Identifier: AGPL-3.0-only + +/// Tests shared FocusFlow logging behavior. +library; + +import 'package:scheduler_core/scheduler_core.dart'; +import 'package:test/test.dart'; + +/// Runs shared logger tests. +void main() { + tearDown(logger.disable); + + group('FocusFlowLogLevel', () { + test('parses every supported level and trace alias', () { + expect(FocusFlowLogLevel.tryParse('finest'), FocusFlowLogLevel.finest); + expect(FocusFlowLogLevel.tryParse('finer'), FocusFlowLogLevel.finer); + expect(FocusFlowLogLevel.tryParse('fine'), FocusFlowLogLevel.fine); + expect(FocusFlowLogLevel.tryParse('debug'), FocusFlowLogLevel.debug); + expect(FocusFlowLogLevel.tryParse('info'), FocusFlowLogLevel.info); + expect(FocusFlowLogLevel.tryParse('warn'), FocusFlowLogLevel.warn); + expect(FocusFlowLogLevel.tryParse('error'), FocusFlowLogLevel.error); + expect(FocusFlowLogLevel.tryParse('trace'), FocusFlowLogLevel.finest); + expect(FocusFlowLogLevel.tryParse('verbose'), isNull); + }); + }); + + group('FocusFlowLogger', () { + test('skips lazy messages below the configured level', () { + final entries = []; + final testLogger = FocusFlowLogger( + minimumLevel: FocusFlowLogLevel.info, + sink: entries.add, + now: () => DateTime.utc(2026, 7, 3, 12), + ); + var evaluated = false; + + testLogger.debug(() { + evaluated = true; + return 'expensive debug state'; + }); + + expect(evaluated, isFalse); + expect(entries, isEmpty); + }); + + test('writes enabled lazy messages with timestamps', () { + final entries = []; + final testLogger = FocusFlowLogger( + minimumLevel: FocusFlowLogLevel.debug, + sink: entries.add, + now: () => DateTime.utc(2026, 7, 3, 12), + ); + + testLogger.debug(() => 'computed debug state'); + + expect(entries.single.level, FocusFlowLogLevel.debug); + expect(entries.single.timestamp, DateTime.utc(2026, 7, 3, 12)); + expect(entries.single.message, 'computed debug state'); + }); + + test('finest captures caller information for every written level', () { + final entries = []; + final testLogger = FocusFlowLogger( + minimumLevel: FocusFlowLogLevel.finest, + sink: entries.add, + now: () => DateTime.utc(2026, 7, 3, 12), + ); + + testLogger.info('high level message'); + + expect(entries.single.caller, contains('focus_flow_logger_test.dart')); + }); + + test('fine captures caller information for warnings and errors', () { + final entries = []; + final testLogger = FocusFlowLogger( + minimumLevel: FocusFlowLogLevel.fine, + sink: entries.add, + now: () => DateTime.utc(2026, 7, 3, 12), + ); + + testLogger.warn('handled warning'); + + expect(entries.single.caller, contains('focus_flow_logger_test.dart')); + }); + + test('info does not capture caller information for warnings', () { + final entries = []; + final testLogger = FocusFlowLogger( + minimumLevel: FocusFlowLogLevel.info, + sink: entries.add, + now: () => DateTime.utc(2026, 7, 3, 12), + ); + + testLogger.warn('minimal warning'); + + expect(entries.single.caller, isNull); + }); + + test('formats errors and stack traces on a single line', () { + final entry = FocusFlowLogEntry( + timestamp: DateTime.utc(2026, 7, 3, 12), + level: FocusFlowLogLevel.error, + message: 'bad state', + caller: '#1 method (file.dart:10:2)', + error: 'boom', + stackTrace: StackTrace.fromString('first\nsecond'), + ); + + expect( + entry.toSingleLine(), + '2026-07-03T12:00:00.000Z ERROR caller=#1 method (file.dart:10:2) ' + r'bad state | error=boom | stackTrace=first\nsecond', + ); + }); + }); +}