feat: expand runtime logger levels

This commit is contained in:
Ashley Venn 2026-07-02 18:38:41 -07:00
parent d8f3368c3d
commit 9a7f8933c7
4 changed files with 243 additions and 22 deletions

View file

@ -51,16 +51,30 @@ Supported optional keys:
```json ```json
{ {
"LogLevel": "debug", "LogLevel": "fine",
"LogfileLocation": "~/ADHD_Scheduler/debug/" "LogfileLocation": "~/ADHD_Scheduler/debug/"
} }
``` ```
`LogLevel` accepts `trace`, `debug`, `info`, `warn`, or `error`. `LogLevel` accepts `finest`, `finer`, `fine`, `debug`, `info`, `warn`, or
`error`.
`LogfileLocation` is treated as a directory, and the app writes `LogfileLocation` is treated as a directory, and the app writes
`focus_flow.log` inside it. If either key is absent or invalid, file logging is `focus_flow.log` inside it. If either key is absent or invalid, file logging is
not enabled and the app ignores that setting. not enabled and the app ignores that setting.
Verbose log levels can include automatic caller information without requiring
each call site to pass it manually. `finest` includes caller frames for every
written message. `fine`, `finer`, and `finest` include caller frames for
warnings and errors. This caller lookup is skipped when the configured level
does not require it.
For expensive debug/detail messages, pass a lazy closure so work is skipped when
the configured level would not write the log:
```dart
logger.debug(() => 'state=${expensiveStateDump()}');
```
## Package Boundary ## Package Boundary
Allowed app imports include public scheduler APIs such as: Allowed app imports include public scheduler APIs such as:

View file

@ -8,6 +8,9 @@ import 'dart:io';
import 'focus_flow_runtime_config.dart'; import 'focus_flow_runtime_config.dart';
/// Lazily creates a log message only after the target level is enabled.
typedef FocusFlowLogMessage = Object? Function();
/// Minimal append-only file logger for FocusFlow runtime diagnostics. /// Minimal append-only file logger for FocusFlow runtime diagnostics.
final class FocusFlowFileLogger { final class FocusFlowFileLogger {
/// Creates a logger with explicit runtime state. /// Creates a logger with explicit runtime state.
@ -63,23 +66,33 @@ final class FocusFlowFileLogger {
/// Whether this logger currently writes to a file. /// Whether this logger currently writes to a file.
bool get isEnabled => minimumLevel != null && logFilePath != null; bool get isEnabled => minimumLevel != null && logFilePath != null;
/// Writes a trace-level [message] when enabled for trace. /// Writes a finest-level [message] when enabled for finest logging.
Future<void> trace(String message) { Future<void> finest(Object? message) {
return write(FocusFlowLogLevel.trace, message); return write(FocusFlowLogLevel.finest, message);
}
/// Writes a finer-level [message] when enabled for finer logging.
Future<void> finer(Object? message) {
return write(FocusFlowLogLevel.finer, message);
}
/// Writes a fine-level [message] when enabled for fine logging.
Future<void> fine(Object? message) {
return write(FocusFlowLogLevel.fine, message);
} }
/// Writes a debug-level [message] when enabled for debug or lower. /// Writes a debug-level [message] when enabled for debug or lower.
Future<void> debug(String message) { Future<void> debug(Object? message) {
return write(FocusFlowLogLevel.debug, message); return write(FocusFlowLogLevel.debug, message);
} }
/// Writes an info-level [message] when enabled for info or lower. /// Writes an info-level [message] when enabled for info or lower.
Future<void> info(String message) { Future<void> info(Object? message) {
return write(FocusFlowLogLevel.info, message); return write(FocusFlowLogLevel.info, message);
} }
/// Writes a warning-level [message] when enabled for warning or lower. /// Writes a warning-level [message] when enabled for warning or lower.
Future<void> warn(String message, {Object? error, StackTrace? stackTrace}) { Future<void> warn(Object? message, {Object? error, StackTrace? stackTrace}) {
return write( return write(
FocusFlowLogLevel.warn, FocusFlowLogLevel.warn,
message, message,
@ -89,7 +102,7 @@ final class FocusFlowFileLogger {
} }
/// Writes an error-level [message] when file logging is enabled. /// Writes an error-level [message] when file logging is enabled.
Future<void> error(String message, {Object? error, StackTrace? stackTrace}) { Future<void> error(Object? message, {Object? error, StackTrace? stackTrace}) {
return write( return write(
FocusFlowLogLevel.error, FocusFlowLogLevel.error,
message, message,
@ -101,7 +114,7 @@ final class FocusFlowFileLogger {
/// Writes [message] at [level] when it passes the configured threshold. /// Writes [message] at [level] when it passes the configured threshold.
Future<void> write( Future<void> write(
FocusFlowLogLevel level, FocusFlowLogLevel level,
String message, { Object? message, {
Object? error, Object? error,
StackTrace? stackTrace, StackTrace? stackTrace,
}) async { }) async {
@ -113,12 +126,23 @@ final class FocusFlowFileLogger {
return; return;
} }
final caller =
_shouldCaptureCaller(level: level, minimumLevel: configuredLevel)
? _callerFrame()
: null;
final resolvedMessage = _resolveMessage(message);
final buffer = StringBuffer() final buffer = StringBuffer()
..write(_now().toUtc().toIso8601String()) ..write(_now().toUtc().toIso8601String())
..write(' ') ..write(' ')
..write(level.name.toUpperCase()) ..write(level.name.toUpperCase())
..write(' ') ..write(' ');
..write(message.trim()); if (caller != null) {
buffer
..write('caller=')
..write(caller)
..write(' ');
}
buffer.write(resolvedMessage);
if (error != null) { if (error != null) {
buffer buffer
..write(' | error=') ..write(' | error=')
@ -145,17 +169,56 @@ bool _shouldWrite(FocusFlowLogLevel level, FocusFlowLogLevel minimumLevel) {
/// Converts [level] to an ordered severity value. /// Converts [level] to an ordered severity value.
int _severity(FocusFlowLogLevel level) { int _severity(FocusFlowLogLevel level) {
return switch (level) { return switch (level) {
FocusFlowLogLevel.trace => 0, FocusFlowLogLevel.finest => 0,
FocusFlowLogLevel.debug => 1, FocusFlowLogLevel.finer => 1,
FocusFlowLogLevel.info => 2, FocusFlowLogLevel.fine => 2,
FocusFlowLogLevel.warn => 3, FocusFlowLogLevel.debug => 3,
FocusFlowLogLevel.error => 4, 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. /// Returns the current UTC timestamp.
DateTime _utcNow() => DateTime.now().toUtc(); 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');
}
/// Joins [base] and [child] with the platform path separator. /// Joins [base] and [child] with the platform path separator.
String _joinPath(String base, String child) { String _joinPath(String base, String child) {
if (base.endsWith('/') || base.endsWith(r'\')) { if (base.endsWith('/') || base.endsWith(r'\')) {

View file

@ -67,10 +67,16 @@ final class FocusFlowRuntimeConfig {
bool get enablesFileLogging => logLevel != null && logFileLocation != null; bool get enablesFileLogging => logLevel != null && logFileLocation != null;
} }
/// Supported FocusFlow file logging levels. /// Supported FocusFlow file logging levels, ordered from most to least verbose.
enum FocusFlowLogLevel { enum FocusFlowLogLevel {
/// Logs every message, including trace-level detail. /// Logs every message with automatic callsite detail.
trace, 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. /// Logs debug, info, warning, and error messages.
debug, debug,
@ -90,6 +96,9 @@ enum FocusFlowLogLevel {
if (normalized == null || normalized.isEmpty) { if (normalized == null || normalized.isEmpty) {
return null; return null;
} }
if (normalized == 'trace') {
return finest;
}
for (final level in FocusFlowLogLevel.values) { for (final level in FocusFlowLogLevel.values) {
if (level.name == normalized) { if (level.name == normalized) {
return level; return level;

View file

@ -38,16 +38,26 @@ void main() {
'${directory.path}${Platform.pathSeparator}config.json', '${directory.path}${Platform.pathSeparator}config.json',
); );
await configFile.writeAsString( await configFile.writeAsString(
jsonEncode({'LogLevel': 'trace', 'LogfileLocation': directory.path}), jsonEncode({'LogLevel': 'finest', 'LogfileLocation': directory.path}),
); );
final config = await FocusFlowRuntimeConfig.load(path: configFile.path); final config = await FocusFlowRuntimeConfig.load(path: configFile.path);
expect(config.logLevel, FocusFlowLogLevel.trace); expect(config.logLevel, FocusFlowLogLevel.finest);
expect(config.logFileLocation, directory.path); expect(config.logFileLocation, directory.path);
expect(config.enablesFileLogging, isTrue); expect(config.enablesFileLogging, isTrue);
}); });
test('parses every supported log level', () {
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);
});
test('loads supported logging settings from JSON', () { test('loads supported logging settings from JSON', () {
final config = FocusFlowRuntimeConfig.fromJson({ final config = FocusFlowRuntimeConfig.fromJson({
'LogLevel': 'debug', 'LogLevel': 'debug',
@ -107,5 +117,130 @@ void main() {
expect(contents, contains('written warning')); expect(contents, contains('written warning'));
expect(contents, contains('ERROR written error | error=boom')); expect(contents, contains('ERROR written error | error=boom'));
}); });
test('skips lazy message work below the configured level', () async {
final directory = await Directory.systemTemp.createTemp(
'focus-flow-lazy-skip-test-',
);
addTearDown(() => directory.delete(recursive: true));
final logger = await FocusFlowFileLogger.open(
FocusFlowRuntimeConfig(
logLevel: FocusFlowLogLevel.info,
logFileLocation: directory.path,
),
);
var evaluated = false;
await logger.debug(() {
evaluated = true;
return 'expensive debug state';
});
expect(evaluated, isFalse);
expect(
File(
'${directory.path}${Platform.pathSeparator}focus_flow.log',
).existsSync(),
isFalse,
);
});
test('evaluates lazy messages once the level is enabled', () async {
final directory = await Directory.systemTemp.createTemp(
'focus-flow-lazy-write-test-',
);
addTearDown(() => directory.delete(recursive: true));
final logger = await FocusFlowFileLogger.open(
FocusFlowRuntimeConfig(
logLevel: FocusFlowLogLevel.debug,
logFileLocation: directory.path,
),
now: () => DateTime.utc(2026, 7, 3, 12),
);
var evaluations = 0;
await logger.debug(() {
evaluations += 1;
return 'computed debug state';
});
expect(evaluations, 1);
final contents = await File(
'${directory.path}${Platform.pathSeparator}focus_flow.log',
).readAsString();
expect(contents, contains('DEBUG computed debug state'));
});
test(
'finest captures caller information for every written level',
() async {
final directory = await Directory.systemTemp.createTemp(
'focus-flow-finest-caller-test-',
);
addTearDown(() => directory.delete(recursive: true));
final logger = await FocusFlowFileLogger.open(
FocusFlowRuntimeConfig(
logLevel: FocusFlowLogLevel.finest,
logFileLocation: directory.path,
),
now: () => DateTime.utc(2026, 7, 3, 12),
);
await logger.info('high level message');
final contents = await File(
'${directory.path}${Platform.pathSeparator}focus_flow.log',
).readAsString();
expect(contents, contains('INFO caller='));
expect(contents, contains('runtime_config_test.dart'));
expect(contents, contains('high level message'));
},
);
test('fine captures caller information for warnings and errors', () async {
final directory = await Directory.systemTemp.createTemp(
'focus-flow-fine-caller-test-',
);
addTearDown(() => directory.delete(recursive: true));
final logger = await FocusFlowFileLogger.open(
FocusFlowRuntimeConfig(
logLevel: FocusFlowLogLevel.fine,
logFileLocation: directory.path,
),
now: () => DateTime.utc(2026, 7, 3, 12),
);
await logger.warn('handled warning');
final contents = await File(
'${directory.path}${Platform.pathSeparator}focus_flow.log',
).readAsString();
expect(contents, contains('WARN caller='));
expect(contents, contains('runtime_config_test.dart'));
expect(contents, contains('handled warning'));
});
test('info does not capture caller information for warnings', () async {
final directory = await Directory.systemTemp.createTemp(
'focus-flow-info-caller-test-',
);
addTearDown(() => directory.delete(recursive: true));
final logger = await FocusFlowFileLogger.open(
FocusFlowRuntimeConfig(
logLevel: FocusFlowLogLevel.info,
logFileLocation: directory.path,
),
now: () => DateTime.utc(2026, 7, 3, 12),
);
await logger.warn('minimal warning');
final contents = await File(
'${directory.path}${Platform.pathSeparator}focus_flow.log',
).readAsString();
expect(contents, contains('WARN minimal warning'));
expect(contents, isNot(contains('caller=')));
expect(contents, isNot(contains('runtime_config_test.dart')));
});
}); });
} }