Circuit-Forge/focus-flow
6
0
Fork 0
forked from eva/focus-flow
Code Pull requests Activity

feat: add logging to entire project

Browse source
This commit is contained in:
Ashley Venn 2026-07-03 10:21:02 -07:00
parent 1d0e2b01d7
commit a24b64179a
65 changed files with 1196 additions and 75 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

7
analysis_options.yaml
View file

@ -4,6 +4,13 @@
include: package:lints/recommended.yaml
analyzer:
exclude:
- .dart_tool/**
- archive/**
- builds/**
- coverage/**
- doc/api/**
- logging_handoff_with_logging/**
language:
strict-casts: true
strict-inference: true

26
apps/focus_flow_flutter/lib/app/home/focus_flow_home_state.dart
View file

@ -23,6 +23,7 @@ class _FocusFlowHomeState extends State<FocusFlowHome> {
@override
void initState() {
super.initState();
logger.debug(() => 'FocusFlow home initializing controllers.');
selectedDateController = widget.composition.createSelectedDateController();
controller = widget.composition.createTodayScreenController(
selectedDates: selectedDateController,
@ -31,6 +32,7 @@ class _FocusFlowHomeState extends State<FocusFlowHome> {
refreshReads: controller.load,
selectedDate: () => selectedDateController.date,
);
logger.finer(() => 'FocusFlow home triggering initial Today load.');
controller.load();
}
@ -38,6 +40,7 @@ class _FocusFlowHomeState extends State<FocusFlowHome> {
/// Controllers, listeners, and other disposable collaborators should be cleaned up here to avoid stale callbacks.
@override
void dispose() {
logger.debug(() => 'FocusFlow home disposing controllers.');
commandController.dispose();
controller.dispose();
selectedDateController.dispose();
@ -49,8 +52,16 @@ class _FocusFlowHomeState extends State<FocusFlowHome> {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
Future<void> _toggleCardCompletion(TimelineCardModel card) async {
if (!card.canToggleCompletion) {
logger.finer(
() => 'Timeline completion toggle ignored. cardId=${card.id}',
);
return;
}
logger.debug(
() =>
'Timeline completion toggle requested. '
'cardId=${card.id} taskType=${card.taskType.name} isCompleted=${card.isCompleted}',
);
if (card.isCompleted) {
await commandController.uncompleteTask(taskId: card.id);
} else {
@ -63,11 +74,13 @@ class _FocusFlowHomeState extends State<FocusFlowHome> {
/// Adds a generic filler task from the timeline context menu.
Future<void> _addGenericFlexibleTask() async {
logger.debug(() => 'Timeline add generic flexible task requested.');
await commandController.addGenericFlexibleTask();
}
/// Pushes [card] to the next available slot after the current clock time.
Future<void> _pushCardToNext(TimelineCardModel card) async {
logger.debug(() => 'Timeline push-to-next requested. cardId=${card.id}');
await commandController.pushTaskToNextAvailableSlot(
taskId: card.id,
expectedUpdatedAt: card.expectedUpdatedAt,
@ -76,6 +89,9 @@ class _FocusFlowHomeState extends State<FocusFlowHome> {
/// Pushes [card] to tomorrow's first available slot.
Future<void> _pushCardToTomorrow(TimelineCardModel card) async {
logger.debug(
() => 'Timeline push-to-tomorrow requested. cardId=${card.id}',
);
await commandController.pushTaskToTomorrow(
taskId: card.id,
expectedUpdatedAt: card.expectedUpdatedAt,
@ -84,6 +100,7 @@ class _FocusFlowHomeState extends State<FocusFlowHome> {
/// Pushes [card] back to Backlog.
Future<void> _pushCardToBacklog(TimelineCardModel card) async {
logger.debug(() => 'Timeline push-to-backlog requested. cardId=${card.id}');
await commandController.pushTaskToBacklog(
taskId: card.id,
expectedUpdatedAt: card.expectedUpdatedAt,
@ -92,11 +109,13 @@ class _FocusFlowHomeState extends State<FocusFlowHome> {
/// Moves the visible planning date backward by one day.
void _selectPreviousDate() {
logger.finer(() => 'Previous date action requested.');
selectedDateController.selectPreviousDay();
}
/// Moves the visible planning date forward by one day.
void _selectNextDate() {
logger.finer(() => 'Next date action requested.');
selectedDateController.selectNextDay();
}
@ -110,9 +129,14 @@ class _FocusFlowHomeState extends State<FocusFlowHome> {
builder: _buildDatePickerTheme,
);
if (picked == null) {
logger.finer(() => 'Date picker dismissed without selection.');
return;
}
selectedDateController.selectDate(_civilDateForDateTime(picked));
final selected = _civilDateForDateTime(picked);
logger.debug(
() => 'Date picker selected date. date=${selected.toIsoString()}',
);
selectedDateController.selectDate(selected);
}
/// Builds the widget subtree for this component.

36
apps/focus_flow_flutter/lib/app/persistent_scheduler_composition.dart
View file

@ -6,7 +6,10 @@ library;
import 'dart:io';
import 'package:scheduler_core/scheduler_core.dart';
import 'package:scheduler_core/scheduler_core.dart' hide logger;
import 'package:scheduler_core/scheduler_core.dart'
as scheduler_core
show logger;
import 'package:scheduler_persistence_sqlite/sqlite.dart';
import '../controllers/scheduler_command_controller.dart';
@ -38,27 +41,31 @@ final class PersistentSchedulerComposition implements SchedulerAppComposition {
}) async {
final resolvedLogger = logger ?? FocusFlowFileLogger.disabled();
final resolvedSqlitePath = sqlitePath ?? sqlitePathFromEnvironment();
await resolvedLogger.info('Opening SQLite runtime at $resolvedSqlitePath.');
scheduler_core.logger.info(
() => 'Opening SQLite runtime. sqlitePath=$resolvedSqlitePath',
);
final runtime = await SqliteApplicationRuntime.open(
path: resolvedSqlitePath,
);
final bootstrap = await runtime.bootstrap();
if (bootstrap.isFailure) {
await runtime.close();
await resolvedLogger.error(
'SQLite bootstrap failed.',
scheduler_core.logger.error(
() =>
'SQLite bootstrap failed. failureCode=${bootstrap.failure!.code.name}',
error: bootstrap.failure!.code.name,
);
throw StateError(
'SQLite bootstrap failed: ${bootstrap.failure!.code.name}',
);
}
await resolvedLogger.debug('SQLite bootstrap completed.');
scheduler_core.logger.debug(() => 'SQLite bootstrap completed.');
final resolvedClock = clock ?? const SystemClock();
final date = selectedDate ?? CivilDate.fromDateTime(resolvedClock.now());
final readAt = resolvedClock.now().toUtc();
await resolvedLogger.info(
'Persistent scheduler composition opened for ${date.toIsoString()}.',
scheduler_core.logger.info(
() =>
'Persistent scheduler composition opened. date=${date.toIsoString()} readAt=${readAt.toIso8601String()}',
);
return PersistentSchedulerComposition._(
@ -140,6 +147,10 @@ final class PersistentSchedulerComposition implements SchedulerAppComposition {
/// Creates the controller that owns the visible planning date.
@override
SelectedDateController createSelectedDateController() {
scheduler_core.logger.finer(
() =>
'Creating selected date controller. date=${initialDate.toIsoString()}',
);
return SelectedDateController(initialDate: initialDate);
}
@ -148,6 +159,9 @@ final class PersistentSchedulerComposition implements SchedulerAppComposition {
TodayScreenController createTodayScreenController({
required SelectedDateController selectedDates,
}) {
scheduler_core.logger.finer(
() => 'Creating today screen controller. date=${date.toIsoString()}',
);
return TodayScreenController(
selectedDates: selectedDates,
dateLabelFor: dateLabelFor,
@ -169,6 +183,10 @@ final class PersistentSchedulerComposition implements SchedulerAppComposition {
required ReadRefresh refreshReads,
required SelectedDateReader selectedDate,
}) {
scheduler_core.logger.finer(
() =>
'Creating scheduler command controller. operationIdPrefix=ui-command-${readAt.microsecondsSinceEpoch}',
);
return SchedulerCommandController(
commands: commandUseCases,
contextFor: context,
@ -200,8 +218,8 @@ final class PersistentSchedulerComposition implements SchedulerAppComposition {
/// Closes runtime resources and records shutdown diagnostics when enabled.
Future<void> _dispose() async {
await logger.debug('Closing SQLite runtime.');
scheduler_core.logger.debug(() => 'Closing SQLite runtime.');
await runtime.close();
await logger.info('SQLite runtime closed.');
scheduler_core.logger.info(() => 'SQLite runtime closed.');
}
}

11
apps/focus_flow_flutter/lib/app/runtime/focus_flow_file_logger.dart
View file

@ -58,6 +58,10 @@ final class FocusFlowFileLogger {
now: resolvedNow,
callerFrameIgnores: _callerFrameIgnores,
);
scheduler_core.logger.info(
() =>
'FocusFlow file logging configured. level=${level.name} path=$logFilePath',
);
return FocusFlowFileLogger._(
minimumLevel: level,
logFilePath: logFilePath,
@ -68,7 +72,12 @@ final class FocusFlowFileLogger {
callerFrameIgnores: _callerFrameIgnores,
),
);
} on Object {
} on Object catch (error, stackTrace) {
scheduler_core.logger.error(
() => 'FocusFlow file logging setup failed; disabling file logging.',
error: error,
stackTrace: stackTrace,
);
return FocusFlowFileLogger.disabled(now: now);
}
}

30
apps/focus_flow_flutter/lib/app/runtime/focus_flow_runtime_config.dart
View file

@ -8,6 +8,7 @@ import 'dart:convert';
import 'dart:io';
import 'package:scheduler_core/scheduler_core.dart' show FocusFlowLogLevel;
import 'package:scheduler_core/scheduler_core.dart' show logger;
export 'package:scheduler_core/scheduler_core.dart' show FocusFlowLogLevel;
@ -21,15 +22,33 @@ final class FocusFlowRuntimeConfig {
final configPath = path ?? configPathFromEnvironment();
final file = File(_expandHome(configPath));
if (!await file.exists()) {
logger.finer(() => 'Runtime config file not found. path=${file.path}');
return const FocusFlowRuntimeConfig();
}
try {
logger.debug(() => 'Loading runtime config. path=${file.path}');
final decoded = jsonDecode(await file.readAsString());
if (decoded is Map<String, Object?>) {
return fromJson(decoded);
final config = fromJson(decoded);
logger.debug(
() =>
'Runtime config loaded. hasLogLevel=${config.logLevel != null} '
'hasLogFileLocation=${config.logFileLocation != null}',
);
return config;
}
} on Object {
logger.warn(
() =>
'Runtime config ignored because decoded JSON was not an object. '
'path=${file.path} decodedType=${decoded.runtimeType}',
);
} on Object catch (error, stackTrace) {
logger.warn(
() => 'Runtime config unreadable; using defaults. path=${file.path}',
error: error,
stackTrace: stackTrace,
);
return const FocusFlowRuntimeConfig();
}
@ -41,9 +60,14 @@ final class FocusFlowRuntimeConfig {
const configured = String.fromEnvironment('FOCUS_FLOW_CONFIG_PATH');
final trimmed = configured.trim();
if (trimmed.isNotEmpty) {
logger.finer(
() => 'Runtime config path resolved from environment. path=$trimmed',
);
return trimmed;
}
return defaultConfigPath();
final path = defaultConfigPath();
logger.finer(() => 'Runtime config path resolved from default. path=$path');
return path;
}
/// Returns the default config file path.

86
apps/focus_flow_flutter/lib/controllers/command/scheduler_command_controller_impl.dart
View file

@ -12,10 +12,9 @@ class SchedulerCommandController extends ChangeNotifier {
required this.selectedDate,
required this.refreshReads,
required this.quickCaptureProjectId,
String operationIdPrefix = 'ui-command',
this.operationIdPrefix = 'ui-command',
DateTime Function()? now,
}) : _operationIdPrefix = operationIdPrefix,
now = now ?? _utcNow;
}) : now = now ?? _utcNow;
/// Scheduler write use cases invoked by this controller.
final V1ApplicationCommandUseCases commands;
@ -32,9 +31,8 @@ class SchedulerCommandController extends ChangeNotifier {
/// Project id used by quick-capture commands.
final String quickCaptureProjectId;
/// Private state stored as `_operationIdPrefix` for this implementation.
/// The field is intentionally scoped to this library so only the owning type can change the related scheduler or UI behavior.
final String _operationIdPrefix;
/// Prefix used to generate unique operation ids for scheduler commands.
final String operationIdPrefix;
/// Clock used by direct UI commands such as marking a task complete.
final DateTime Function() now;
@ -58,6 +56,11 @@ class SchedulerCommandController extends ChangeNotifier {
/// Captures [title] as a backlog task.
Future<void> quickCaptureToBacklog(String title) async {
logger.debug(
() =>
'UI command requested: quick capture to backlog. '
'projectId=$quickCaptureProjectId hasTitle=${title.trim().isNotEmpty}',
);
await _run(
label: 'Capturing task',
successMessage: 'Task captured',
@ -75,6 +78,11 @@ class SchedulerCommandController extends ChangeNotifier {
/// Adds a generic flexible task to the next available Today slot.
Future<void> addGenericFlexibleTask() async {
logger.debug(
() =>
'UI command requested: add generic flexible task. '
'durationMinutes=$_genericFlexibleTaskDurationMinutes projectId=$quickCaptureProjectId',
);
await _run(
label: 'Adding task',
successMessage: 'Task added',
@ -98,6 +106,12 @@ class SchedulerCommandController extends ChangeNotifier {
required int durationMinutes,
required DateTime expectedUpdatedAt,
}) async {
logger.debug(
() =>
'UI command requested: schedule backlog item. '
'taskId=$taskId durationMinutes=$durationMinutes '
'expectedUpdatedAt=${expectedUpdatedAt.toIso8601String()}',
);
await _run(
label: 'Scheduling task',
successMessage: 'Task scheduled',
@ -134,6 +148,13 @@ class SchedulerCommandController extends ChangeNotifier {
DateTime? expectedUpdatedAt,
}) async {
final completedAt = now();
logger.debug(
() =>
'UI command requested: complete task. '
'taskId=$taskId taskType=${taskType.name} '
'hasExpectedUpdatedAt=${expectedUpdatedAt != null} '
'occurredAt=${completedAt.toIso8601String()}',
);
await _run(
label: 'Completing task',
successMessage: 'Task completed',
@ -177,6 +198,12 @@ class SchedulerCommandController extends ChangeNotifier {
DateTime? expectedUpdatedAt,
}) async {
final occurredAt = now();
logger.debug(
() =>
'UI command requested: uncomplete task. '
'taskId=$taskId hasExpectedUpdatedAt=${expectedUpdatedAt != null} '
'occurredAt=${occurredAt.toIso8601String()}',
);
await _run(
label: 'Reopening task',
successMessage: 'Task marked as not done',
@ -198,6 +225,12 @@ class SchedulerCommandController extends ChangeNotifier {
DateTime? expectedUpdatedAt,
}) async {
final commandAt = now();
logger.debug(
() =>
'UI command requested: push task to next available slot. '
'taskId=$taskId hasExpectedUpdatedAt=${expectedUpdatedAt != null} '
'occurredAt=${commandAt.toIso8601String()}',
);
await _run(
label: 'Pushing task',
successMessage: 'Task pushed',
@ -219,6 +252,12 @@ class SchedulerCommandController extends ChangeNotifier {
DateTime? expectedUpdatedAt,
}) async {
final commandAt = now();
logger.debug(
() =>
'UI command requested: push task to tomorrow. '
'taskId=$taskId hasExpectedUpdatedAt=${expectedUpdatedAt != null} '
'occurredAt=${commandAt.toIso8601String()}',
);
await _run(
label: 'Pushing task',
successMessage: 'Task moved to tomorrow',
@ -240,6 +279,12 @@ class SchedulerCommandController extends ChangeNotifier {
DateTime? expectedUpdatedAt,
}) async {
final commandAt = now();
logger.debug(
() =>
'UI command requested: push task to backlog. '
'taskId=$taskId hasExpectedUpdatedAt=${expectedUpdatedAt != null} '
'occurredAt=${commandAt.toIso8601String()}',
);
await _run(
label: 'Moving task to backlog',
successMessage: 'Task moved to backlog',
@ -266,19 +311,44 @@ class SchedulerCommandController extends ChangeNotifier {
action,
}) async {
final operationId = _nextOperationId();
logger.debug(
() => 'Scheduler command started. operationId=$operationId label=$label',
);
_setState(SchedulerCommandRunning(label));
try {
final result = await action(operationId);
final failure = result.failure;
if (failure != null) {
logger.warn(
() =>
'Scheduler command returned failure. '
'operationId=$operationId code=${failure.code.name} '
'detailCode=${failure.detailCode} entityId=${failure.entityId}',
);
_setState(SchedulerCommandFailure(failure: failure));
return;
}
logger.debug(
() =>
'Scheduler command succeeded. operationId=$operationId '
'refreshAfterSuccess=$refreshAfterSuccess',
);
if (refreshAfterSuccess) {
logger.finer(
() =>
'Refreshing reads after scheduler command. '
'operationId=$operationId',
);
await refreshReads();
}
_setState(SchedulerCommandSuccess(successMessage));
} on Object catch (error) {
} on Object catch (error, stackTrace) {
logger.error(
() =>
'Scheduler command threw unexpectedly. operationId=$operationId label=$label',
error: error,
stackTrace: stackTrace,
);
_setState(SchedulerCommandFailure(error: error));
}
}
@ -287,7 +357,7 @@ class SchedulerCommandController extends ChangeNotifier {
/// The helper centralizes a small piece of transformation or validation so higher-level scheduler flow remains easier to read.
String _nextOperationId() {
_sequence += 1;
return '$_operationIdPrefix-$_sequence';
return '$operationIdPrefix-$_sequence';
}
/// Runs the `_setState` helper used inside this library.

24
apps/focus_flow_flutter/lib/controllers/scheduler_read_controller.dart
View file

@ -98,21 +98,35 @@ class ApplicationReadController<T> extends UiReadController<T> {
/// Loads the current value and updates [state].
@override
Future<void> load() async {
logger.debug(() => 'Scheduler read started. valueType=$T');
_setState(SchedulerReadLoading<T>());
try {
final result = await read();
final failure = result.failure;
if (failure != null) {
logger.warn(
() =>
'Scheduler read returned failure. valueType=$T '
'code=${failure.code.name} detailCode=${failure.detailCode} '
'entityId=${failure.entityId}',
);
_setState(SchedulerReadFailure<T>(failure: failure));
return;
}
final value = result.requireValue;
_setState(
isEmpty(value)
? SchedulerReadEmpty<T>(value)
: SchedulerReadData<T>(value),
final empty = isEmpty(value);
logger.debug(
() => 'Scheduler read finished. valueType=$T isEmpty=$empty',
);
_setState(
empty ? SchedulerReadEmpty<T>(value) : SchedulerReadData<T>(value),
);
} on Object catch (error, stackTrace) {
logger.error(
() => 'Scheduler read threw unexpectedly. valueType=$T',
error: error,
stackTrace: stackTrace,
);
} on Object catch (error) {
_setState(SchedulerReadFailure<T>(error: error));
}
}

5
apps/focus_flow_flutter/lib/controllers/selected_date_controller.dart
View file

@ -25,8 +25,13 @@ class SelectedDateController extends ChangeNotifier {
/// Selects [date] as the visible planning day.
bool selectDate(CivilDate date) {
if (date == _date) {
logger.finer(() => 'Selected date unchanged. date=${date.toIsoString()}');
return false;
}
logger.debug(
() =>
'Selected date changed. previous=${_date.toIsoString()} next=${date.toIsoString()}',
);
_date = date;
notifyListeners();
return true;

48
apps/focus_flow_flutter/lib/controllers/today_screen_controller.dart
View file

@ -118,15 +118,30 @@ class TodayScreenController extends ChangeNotifier {
Future<void> load() async {
final date = selectedDates.date;
final sequence = _nextLoadSequence();
logger.debug(
() =>
'Today screen load started. date=${date.toIsoString()} sequence=$sequence',
);
_state = TodayScreenLoading(dateLabelFor(date));
notifyListeners();
try {
final result = await read(date);
if (_isStale(sequence)) {
logger.finer(
() =>
'Ignoring stale Today screen load result. '
'date=${date.toIsoString()} sequence=$sequence currentSequence=$_loadSequence',
);
return;
}
final failure = result.failure;
if (failure != null) {
logger.warn(
() =>
'Today screen load returned failure. '
'date=${date.toIsoString()} code=${failure.code.name} '
'detailCode=${failure.detailCode} entityId=${failure.entityId}',
);
_state = TodayScreenFailure(
message: failure.detailCode ?? failure.code.name,
data: _emptyDataFor(date),
@ -143,11 +158,27 @@ class TodayScreenController extends ChangeNotifier {
_state = data.cards.isEmpty
? TodayScreenEmpty(data)
: TodayScreenReady(data);
logger.debug(
() =>
'Today screen load finished. date=${date.toIsoString()} '
'sequence=$sequence cardCount=${data.cards.length}',
);
notifyListeners();
} on Object catch (error) {
} on Object catch (error, stackTrace) {
if (_isStale(sequence)) {
logger.finer(
() =>
'Ignoring stale Today screen load exception. '
'date=${date.toIsoString()} sequence=$sequence currentSequence=$_loadSequence',
);
return;
}
logger.error(
() =>
'Today screen load threw unexpectedly. date=${date.toIsoString()} sequence=$sequence',
error: error,
stackTrace: stackTrace,
);
_state = TodayScreenFailure(
message: error.toString(),
data: _emptyDataFor(date),
@ -159,8 +190,12 @@ class TodayScreenController extends ChangeNotifier {
/// Selects [card] when the card allows selection.
void selectCard(TimelineCardModel card) {
if (!card.isSelectable) {
logger.finer(
() => 'Today screen card selection ignored. cardId=${card.id}',
);
return;
}
logger.finer(() => 'Today screen card selected. cardId=${card.id}');
_selectedCard = card;
notifyListeners();
}
@ -170,6 +205,9 @@ class TodayScreenController extends ChangeNotifier {
if (_selectedCard == null) {
return;
}
logger.finer(
() => 'Today screen card selection cleared. cardId=${_selectedCard!.id}',
);
_selectedCard = null;
notifyListeners();
}
@ -185,6 +223,10 @@ class TodayScreenController extends ChangeNotifier {
/// Runs the `_handleSelectedDateChanged` helper used inside this library.
/// The helper centralizes a small piece of transformation or validation so higher-level scheduler flow remains easier to read.
void _handleSelectedDateChanged() {
logger.debug(
() =>
'Today screen selected date changed. date=${selectedDates.date.toIsoString()}',
);
_selectedCard = null;
unawaited(load());
}
@ -221,6 +263,10 @@ class TodayScreenController extends ChangeNotifier {
return;
}
}
logger.finer(
() =>
'Today screen selected card no longer present. cardId=${selected.id}',
);
_selectedCard = null;
}

15
apps/focus_flow_flutter/lib/main.dart
View file

@ -5,6 +5,9 @@
library;
import 'package:flutter/material.dart';
import 'package:scheduler_core/scheduler_core.dart'
as scheduler_core
show logger;
import 'app/focus_flow_app.dart';
import 'app/persistent_scheduler_composition.dart';
@ -22,18 +25,18 @@ Future<void> main() async {
try {
final config = await FocusFlowRuntimeConfig.load();
logger = await FocusFlowFileLogger.open(config);
await logger.info('FocusFlow startup started.');
await logger.debug(
'Runtime config loaded. fileLogging=${logger.isEnabled}',
scheduler_core.logger.info(() => 'FocusFlow startup started.');
scheduler_core.logger.debug(
() => 'Runtime config loaded. fileLogging=${logger.isEnabled}',
);
final composition = await PersistentSchedulerComposition.open(
logger: logger,
);
await logger.info('FocusFlow startup completed.');
scheduler_core.logger.info(() => 'FocusFlow startup completed.');
runApp(FocusFlowApp(composition: composition));
} on Object catch (error, stackTrace) {
await logger.error(
'FocusFlow startup failed.',
scheduler_core.logger.error(
() => 'FocusFlow startup failed.',
error: error,
stackTrace: stackTrace,
);

12
apps/focus_flow_flutter/lib/widgets/timeline/task_card/task_timeline_card_state.dart
View file

@ -117,13 +117,25 @@ class _TaskTimelineCardState extends State<TaskTimelineCard> {
Future<void> Function(TimelineCardModel card) callback,
) async {
if (_isPushRunning) {
logger.warn(
() => 'Duplicate card push action ignored. cardId=${widget.card.id}',
);
return;
}
logger.debug(() => 'Card push action started. cardId=${widget.card.id}');
setState(() {
_isPushRunning = true;
});
try {
await callback(widget.card);
logger.debug(() => 'Card push action finished. cardId=${widget.card.id}');
} on Object catch (error, stackTrace) {
logger.error(
() => 'Card push action failed. cardId=${widget.card.id}',
error: error,
stackTrace: stackTrace,
);
rethrow;
} finally {
if (mounted) {
setState(() {

1
apps/focus_flow_flutter/lib/widgets/timeline/task_timeline_card.dart
View file

@ -8,6 +8,7 @@ import 'dart:async';
import 'dart:math' as math;
import 'package:flutter/material.dart';
import 'package:scheduler_core/scheduler_core.dart' show logger;
import '../../models/today_screen_models.dart';
import '../../theme/focus_flow_tokens.dart';

4
apps/focus_flow_flutter/test/persistent_composition_test.dart
View file

@ -128,7 +128,7 @@ void main() {
selectedDate: selectedDate,
clock: FixedClock(_instant(8, 10)),
);
var scheduled = await _readTodayItem(
final scheduled = await _readTodayItem(
tester,
composition,
tomorrow,
@ -225,7 +225,7 @@ void main() {
selectedDate: _date,
clock: FixedClock(commandNow),
);
var commandController = _commandController(
final commandController = _commandController(
composition,
selectedDate: _date,
operationIdPrefix: 'past-push',

1
packages/scheduler_backup/lib/src/encrypted_backup.dart
View file

@ -10,6 +10,7 @@ import 'dart:math';
import 'dart:typed_data';
import 'package:cryptography/cryptography.dart';
import 'package:scheduler_core/scheduler_core.dart' show logger;
part 'encrypted_backup/errors/backup_decryption_exception.dart';
part 'encrypted_backup/codec/backup_encryption_codec.dart';
part 'encrypted_backup/errors/backup_exception.dart';

14
packages/scheduler_backup/lib/src/encrypted_backup/codec/backup_encryption_codec.dart
View file

@ -56,9 +56,19 @@ Future<List<int>> _decryptBytes({
SecretBox(cipherText, nonce: nonce, mac: mac),
secretKey: key,
);
} on BackupDecryptionException {
} on BackupDecryptionException catch (error, stackTrace) {
logger.error(
() => 'Encrypted backup decryption failed with known backup error.',
error: error,
stackTrace: stackTrace,
);
rethrow;
} on Object {
} on Object catch (error, stackTrace) {
logger.error(
() => 'Encrypted backup decryption failed.',
error: error,
stackTrace: stackTrace,
);
throw const BackupDecryptionException();
}
}

16
packages/scheduler_backup/lib/src/encrypted_backup/operations/encrypted_backup_operations.dart
View file

@ -16,7 +16,10 @@ Future<File> createEncryptedBackup({
DateTime? now,
}) async {
final source = sqliteFile ?? defaultSchedulerSqliteFile();
logger.info(() => 'Encrypted backup started. sourcePath=${source.path}');
if (!await source.exists()) {
logger.warn(() =>
'Encrypted backup source file missing. sourcePath=${source.path}');
throw BackupException('SQLite file does not exist: ${source.path}');
}
@ -35,7 +38,11 @@ Future<File> createEncryptedBackup({
passphrase: passphrase,
plaintext: plaintext,
);
return destination.writeAsBytes(encoded, flush: true);
final output = await destination.writeAsBytes(encoded, flush: true);
logger.info(() => 'Encrypted backup completed. sourcePath=${source.path} '
'destinationPath=${output.path} sourceBytes=${plaintext.length} '
'encodedBytes=${encoded.length}');
return output;
}
/// Restore an encrypted backup over the scheduler SQLite file.
@ -47,7 +54,11 @@ Future<void> restoreEncryptedBackup(
String passphrase, {
File? targetFile,
}) async {
logger.info(
() => 'Encrypted backup restore started. backupPath=${backup.path}');
if (!await backup.exists()) {
logger.warn(() =>
'Encrypted backup restore source missing. backupPath=${backup.path}');
throw BackupException('Backup file does not exist: ${backup.path}');
}
@ -64,4 +75,7 @@ Future<void> restoreEncryptedBackup(
await target.delete();
}
await temporary.rename(target.path);
logger.info(
() => 'Encrypted backup restore completed. backupPath=${backup.path} '
'targetPath=${target.path} restoredBytes=${plaintext.length}');
}

2
packages/scheduler_backup/lib/src/encrypted_backup/paths/backup_paths.dart
View file

@ -28,6 +28,8 @@ Directory _homeDirectory() {
Platform.environment['USERPROFILE'] ??
Platform.environment['HOMEDRIVE'];
if (home == null || home.trim().isEmpty) {
logger.warn(
() => 'Backup home directory could not be resolved from environment.');
throw const BackupException('Home directory could not be resolved.');
}
return Directory(home);

1
packages/scheduler_backup/pubspec.yaml
View file

@ -13,6 +13,7 @@ environment:
dependencies:
cryptography: ^2.7.0
encrypt: ^5.0.3
scheduler_core: any
dev_dependencies:
lints: ^5.0.0

1
packages/scheduler_core/lib/src/application/application_commands.dart
View file

@ -21,6 +21,7 @@ import '../scheduling/scheduling_engine.dart';
import '../scheduling/task_actions.dart';
import '../scheduling/task_lifecycle.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'application_commands/codes/application_command_code.dart';
part 'application_commands/messages/application_child_task_draft.dart';
part 'application_commands/messages/application_command_read_hint.dart';

91
packages/scheduler_core/lib/src/application/application_commands/use_cases/v1_application_command_use_cases.dart
View file

@ -80,6 +80,10 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} hasTitle=${title.trim().isNotEmpty} '
'projectId=$projectId taskType=${type.name} durationMinutes=$durationMinutes');
final result = quickCaptureService.capture(
QuickCaptureRequest(
id: context.idGenerator.nextId(),
@ -136,6 +140,11 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} '
'hasTitle=${title.trim().isNotEmpty} projectId=$projectId '
'durationMinutes=$durationMinutes');
final state =
await _loadPlanningState(repositories, context, localDate);
final taskId = context.idGenerator.nextId();
@ -199,9 +208,16 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} '
'taskId=$taskId durationMinutes=$durationMinutes');
var state = await _loadPlanningState(repositories, context, localDate);
var task = _taskById(state.tasks, taskId);
if (task == null) {
logger.finer(() =>
'Planning-state task lookup missed; reading by id. '
'command=${commandCode.name} taskId=$taskId operationId=${context.operationId}');
task = await repositories.tasks.findById(taskId);
if (task != null) {
state = state.withTask(task);
@ -316,6 +332,9 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(
() => 'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} taskId=$taskId');
final task = await repositories.tasks.findById(taskId);
if (task == null) {
return _failure(ApplicationFailureCode.notFound, entityId: taskId);
@ -370,9 +389,15 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} taskId=$taskId');
var state = await _loadPlanningState(repositories, context, localDate);
var task = _taskById(state.tasks, taskId);
if (task == null) {
logger.finer(() =>
'Planning-state task lookup missed; reading by id. '
'command=${commandCode.name} taskId=$taskId operationId=${context.operationId}');
task = await repositories.tasks.findById(taskId);
if (task != null) {
state = state.withTask(task);
@ -432,9 +457,15 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} taskId=$taskId');
var state = await _loadPlanningState(repositories, context, localDate);
var task = _taskById(state.tasks, taskId);
if (task == null) {
logger.finer(() =>
'Planning-state task lookup missed; reading by id. '
'command=${commandCode.name} taskId=$taskId operationId=${context.operationId}');
task = await repositories.tasks.findById(taskId);
if (task != null) {
state = state.withTask(task);
@ -492,9 +523,16 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} taskId=$taskId '
'action=${action.name}');
var state = await _loadPlanningState(repositories, context, localDate);
var task = _taskById(state.tasks, taskId);
if (task == null) {
logger.finer(() =>
'Planning-state task lookup missed; reading by id. '
'command=${commandCode.name} taskId=$taskId operationId=${context.operationId}');
task = await repositories.tasks.findById(taskId);
if (task != null) {
state = state.withTask(task);
@ -560,6 +598,11 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} '
'hasTitle=${title.trim().isNotEmpty} hasStartedAt=${startedAt != null} '
'timeUsedMinutes=$timeUsedMinutes projectId=$projectId');
final state =
await _loadPlanningState(repositories, context, localDate);
final logResult = surpriseTaskLogService.log(
@ -613,6 +656,11 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} '
'start=${start.toIso8601String()} end=${end.toIso8601String()} '
'projectId=$projectId hasTitle=${title.trim().isNotEmpty}');
final freeSlot = freeSlotService.create(
id: context.idGenerator.nextId(),
title: title,
@ -654,6 +702,11 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} taskId=$taskId '
'start=${start.toIso8601String()} end=${end.toIso8601String()} '
'hasTitle=${title != null} projectId=$projectId');
final task = await repositories.tasks.findById(taskId);
if (task == null) {
return _failure(ApplicationFailureCode.notFound, entityId: taskId);
@ -698,6 +751,9 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} taskId=$taskId');
final task = await repositories.tasks.findById(taskId);
if (task == null) {
return _failure(ApplicationFailureCode.notFound, entityId: taskId);
@ -746,6 +802,10 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(
() => 'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} parentTaskId=$parentTaskId '
'childDraftCount=${children.length}');
final tasks = await repositories.tasks.findAll();
final parent = _taskById(tasks, parentTaskId);
if (parent == null) {
@ -882,9 +942,16 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(() =>
'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} localDate=${localDate.toIsoString()} taskId=$taskId '
'destination=${destination.name}');
var state = await _loadPlanningState(repositories, context, localDate);
var task = _taskById(state.tasks, taskId);
if (task == null) {
logger.finer(() =>
'Planning-state task lookup missed; reading by id. '
'command=${commandCode.name} taskId=$taskId operationId=${context.operationId}');
task = await repositories.tasks.findById(taskId);
if (task != null) {
state = state.withTask(task);
@ -950,6 +1017,9 @@ class V1ApplicationCommandUseCases {
context: context,
operationName: commandCode.name,
action: (repositories) async {
logger.debug(
() => 'Application command executing. command=${commandCode.name} '
'operationId=${context.operationId} taskId=$taskId');
final tasks = await repositories.tasks.findAll();
final task = _taskById(tasks, taskId);
if (task == null) {
@ -989,6 +1059,8 @@ class V1ApplicationCommandUseCases {
CivilDate localDate,
) async {
final ownerId = context.ownerTimeZone.ownerId;
logger.debug(() => 'Loading planning state. ownerId=$ownerId '
'localDate=${localDate.toIsoString()} operationId=${context.operationId}');
final settings = await repositories.ownerSettings.findByOwnerId(ownerId) ??
OwnerSettings(
ownerId: ownerId,
@ -1027,6 +1099,11 @@ class V1ApplicationCommandUseCases {
resolutionOptions: resolutionOptions,
);
logger.debug(() =>
'Planning state loaded. ownerId=$ownerId localDate=${localDate.toIsoString()} '
'taskCount=${tasks.length} lockedIntervalCount=${lockedExpansion.schedulingIntervals.length} '
'windowStart=${window.start.toIso8601String()} windowEnd=${window.end.toIso8601String()}');
return _PlanningState(
tasks: tasks,
window: window,
@ -1067,6 +1144,11 @@ class V1ApplicationCommandUseCases {
List<String> childTaskIds = const <String>[],
}) async {
final changedTasks = _changedTasks(beforeTasks, afterTasks);
logger.debug(() =>
'Persisting application command result. command=${commandCode.name} '
'operationId=${context.operationId} changedTaskCount=${changedTasks.length} '
'activityCount=${activities.length} noticeCount=${schedulingResult?.notices.length ?? 0} '
'changeCount=${schedulingResult?.changes.length ?? 0}');
await repositories.tasks.saveAll(changedTasks);
await repositories.taskActivities.saveAll(activities);
final projectStats = await _saveProjectStatistics(
@ -1075,6 +1157,11 @@ class V1ApplicationCommandUseCases {
tasks: afterTasks,
);
logger.debug(() =>
'Application command persisted. command=${commandCode.name} '
'operationId=${context.operationId} changedTaskCount=${changedTasks.length} '
'projectStatisticsCount=${projectStats.length}');
return ApplicationResult.success(
ApplicationCommandResult(
commandCode: commandCode,
@ -1104,6 +1191,8 @@ class V1ApplicationCommandUseCases {
.where((activity) => activity.code == TaskActivityCode.completed)
.map((activity) => activity.projectId)
.toSet();
logger.finer(() => 'Saving project statistics after command. '
'projectCount=${projectIds.length} activityCount=${activities.length}');
final updated = <ProjectStatistics>[];
for (final projectId in projectIds) {
@ -1119,6 +1208,8 @@ class V1ApplicationCommandUseCases {
if (result.appliedActivityIds.isEmpty) {
continue;
}
logger.finer(() => 'Project statistics updated. projectId=$projectId '
'appliedActivityCount=${result.appliedActivityIds.length}');
await repositories.projectStatistics.save(result.statistics);
updated.add(result.statistics);
}

1
packages/scheduler_core/lib/src/application/application_layer.dart
View file

@ -18,6 +18,7 @@ import '../persistence/repositories.dart';
import '../scheduling/scheduling_engine.dart';
import '../scheduling/task_lifecycle.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'application_layer/context/owner_time_zone_context.dart';
part 'application_layer/context/application_operation_context.dart';
part 'application_layer/results/application_failure_code.dart';

83
packages/scheduler_core/lib/src/application/application_layer/repositories/in_memory/in_memory_application_unit_of_work.dart
View file

@ -195,7 +195,13 @@ class InMemoryApplicationUnitOfWork implements ApplicationUnitOfWork {
ApplicationUnitOfWorkRepositories repositories,
) action,
}) async {
logger.debug(() => 'In-memory unit of work run started. '
'operationId=${context.operationId} operationName=$operationName '
'ownerId=${context.ownerTimeZone.ownerId}');
if (_state.operationsById.containsKey(context.operationId)) {
logger.warn(() =>
'Duplicate operation ignored by in-memory unit of work. '
'operationId=${context.operationId} operationName=$operationName');
return ApplicationResult.failure(
ApplicationFailure(
code: ApplicationFailureCode.duplicateOperation,
@ -210,6 +216,9 @@ class InMemoryApplicationUnitOfWork implements ApplicationUnitOfWork {
try {
final result = await action(repositories);
if (result.isFailure) {
logger.warn(() => 'In-memory unit of work action returned failure. '
'operationId=${context.operationId} operationName=$operationName '
'code=${result.failure!.code.name} detailCode=${result.failure!.detailCode}');
return result;
}
@ -222,14 +231,29 @@ class InMemoryApplicationUnitOfWork implements ApplicationUnitOfWork {
if (_failNextCommit) {
_failNextCommit = false;
logger.error(() => 'In-memory unit of work commit failed by test hook. '
'operationId=${context.operationId} operationName=$operationName');
throw const ApplicationPersistenceException();
}
_state = staged;
logger.debug(() => 'In-memory unit of work run committed. '
'operationId=${context.operationId} operationName=$operationName '
'taskCount=${_state.tasksById.length} projectCount=${_state.projectsById.length} '
'lockedBlockCount=${_state.lockedBlocksById.length} '
'snapshotCount=${_state.schedulingSnapshotsById.length} '
'operationCount=${_state.operationsById.length}');
return result;
} on ApplicationFailureException catch (error) {
logger.warn(() => 'In-memory unit of work caught application failure. '
'operationId=${context.operationId} operationName=$operationName '
'code=${error.failure.code.name} detailCode=${error.failure.detailCode}');
return ApplicationResult.failure(error.failure);
} on DomainValidationException catch (error) {
logger.warn(
() => 'In-memory unit of work caught domain validation failure. '
'operationId=${context.operationId} operationName=$operationName '
'code=${error.code.name}');
return ApplicationResult.failure(
ApplicationFailure(
code: ApplicationFailureCode.validation,
@ -237,19 +261,35 @@ class InMemoryApplicationUnitOfWork implements ApplicationUnitOfWork {
),
);
} on ArgumentError catch (error) {
logger.warn(
() => 'In-memory unit of work caught argument validation failure. '
'operationId=${context.operationId} operationName=$operationName '
'argumentName=${error.name}');
return ApplicationResult.failure(
ApplicationFailure(
code: ApplicationFailureCode.validation,
detailCode: error.name,
),
);
} on ApplicationPersistenceException {
} on ApplicationPersistenceException catch (error, stackTrace) {
logger.error(
() => 'In-memory unit of work persistence failure. '
'operationId=${context.operationId} operationName=$operationName',
error: error,
stackTrace: stackTrace,
);
return ApplicationResult.failure(
const ApplicationFailure(
code: ApplicationFailureCode.persistenceFailure,
),
);
} catch (_) {
} catch (error, stackTrace) {
logger.error(
() => 'In-memory unit of work unexpected failure. '
'operationId=${context.operationId} operationName=$operationName',
error: error,
stackTrace: stackTrace,
);
return ApplicationResult.failure(
const ApplicationFailure(code: ApplicationFailureCode.unexpected),
);
@ -264,14 +304,34 @@ class InMemoryApplicationUnitOfWork implements ApplicationUnitOfWork {
ApplicationUnitOfWorkRepositories repositories,
) action,
}) async {
logger.debug(() => 'In-memory unit of work read started. '
'taskCount=${_state.tasksById.length} projectCount=${_state.projectsById.length} '
'lockedBlockCount=${_state.lockedBlocksById.length} '
'snapshotCount=${_state.schedulingSnapshotsById.length}');
final staged = _state.copy();
final repositories = _InMemoryApplicationRepositories(staged);
try {
return await action(repositories);
final result = await action(repositories);
if (result.isFailure) {
logger.warn(() => 'In-memory unit of work read returned failure. '
'code=${result.failure!.code.name} detailCode=${result.failure!.detailCode}');
} else {
logger.debug(() => 'In-memory unit of work read finished. '
'taskCount=${staged.tasksById.length} projectCount=${staged.projectsById.length} '
'lockedBlockCount=${staged.lockedBlocksById.length} '
'snapshotCount=${staged.schedulingSnapshotsById.length}');
}
return result;
} on ApplicationFailureException catch (error) {
logger.warn(() =>
'In-memory unit of work read caught application failure. '
'code=${error.failure.code.name} detailCode=${error.failure.detailCode}');
return ApplicationResult.failure(error.failure);
} on DomainValidationException catch (error) {
logger.warn(
() => 'In-memory unit of work read caught domain validation failure. '
'code=${error.code.name}');
return ApplicationResult.failure(
ApplicationFailure(
code: ApplicationFailureCode.validation,
@ -279,19 +339,32 @@ class InMemoryApplicationUnitOfWork implements ApplicationUnitOfWork {
),
);
} on ArgumentError catch (error) {
logger.warn(() =>
'In-memory unit of work read caught argument validation failure. '
'argumentName=${error.name}');
return ApplicationResult.failure(
ApplicationFailure(
code: ApplicationFailureCode.validation,
detailCode: error.name,
),
);
} on ApplicationPersistenceException {
} on ApplicationPersistenceException catch (error, stackTrace) {
logger.error(
() => 'In-memory unit of work read persistence failure.',
error: error,
stackTrace: stackTrace,
);
return ApplicationResult.failure(
const ApplicationFailure(
code: ApplicationFailureCode.persistenceFailure,
),
);
} catch (_) {
} catch (error, stackTrace) {
logger.error(
() => 'In-memory unit of work read unexpected failure.',
error: error,
stackTrace: stackTrace,
);
return ApplicationResult.failure(
const ApplicationFailure(code: ApplicationFailureCode.unexpected),
);

1
packages/scheduler_core/lib/src/application/application_management.dart
View file

@ -17,6 +17,7 @@ import '../domain/locked_time.dart';
import '../domain/models.dart';
import '../domain/project_statistics.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'application_management/codes/application_management_command_code.dart';
part 'application_management/codes/owner_settings_warning_code.dart';
part 'application_management/requests/get_backlog_request.dart';

115
packages/scheduler_core/lib/src/application/application_management/use_cases/v1_application_management_use_cases.dart
View file

@ -26,6 +26,8 @@ class V1ApplicationManagementUseCases {
return applicationStore.read(
action: (repositories) async {
final ownerId = request.context.ownerTimeZone.ownerId;
logger.debug(() => 'Loading backlog query. ownerId=$ownerId '
'sortKey=${request.sortKey.name} hasFilter=${request.filter != null}');
final settings = await _ownerSettingsOrDefault(
repositories,
request.context.ownerTimeZone,
@ -46,6 +48,9 @@ class V1ApplicationManagementUseCases {
stalenessSettings: settings.backlogStalenessSettings,
);
final sorted = view.sorted(request.sortKey);
logger.debug(() => 'Backlog query loaded. ownerId=$ownerId '
'candidateCount=${candidates.length} filteredCount=${filtered.length} '
'itemCount=${sorted.length}');
return ApplicationResult.success(
BacklogQueryResult(
@ -70,6 +75,9 @@ class V1ApplicationManagementUseCases {
) {
return applicationStore.read(
action: (repositories) async {
logger.debug(() =>
'Loading project defaults. ownerId=${request.context.ownerTimeZone.ownerId} '
'includeArchived=${request.includeArchived}');
final projects = (await repositories.projects.findByOwner(
ownerId: request.context.ownerTimeZone.ownerId,
includeArchived: request.includeArchived,
@ -94,6 +102,10 @@ class V1ApplicationManagementUseCases {
);
}
logger.debug(() =>
'Project defaults loaded. ownerId=${request.context.ownerTimeZone.ownerId} '
'projectCount=${projects.length} resolutionCount=${resolutions.length}');
return ApplicationResult.success(
ProjectDefaultsQueryResult(
ownerId: request.context.ownerTimeZone.ownerId,
@ -115,8 +127,14 @@ class V1ApplicationManagementUseCases {
operationName: ApplicationManagementCommandCode.createProject.name,
action: (repositories) async {
final id = draft.id ?? context.idGenerator.nextId();
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.createProject.name} '
'operationId=${context.operationId} projectId=$id hasName=${draft.name.trim().isNotEmpty} '
'defaultDurationMinutes=${draft.defaultDurationMinutes}');
final existing = await repositories.projects.findById(id);
if (existing != null) {
logger.warn(() => 'Create project failed: project already exists. '
'operationId=${context.operationId} projectId=$id');
return _failure(
ApplicationFailureCode.conflict,
entityId: id,
@ -134,6 +152,8 @@ class V1ApplicationManagementUseCases {
defaultDurationMinutes: draft.defaultDurationMinutes,
);
await repositories.projects.save(project);
logger.debug(() =>
'Project created. operationId=${context.operationId} projectId=$id');
return ApplicationResult.success(project);
},
);
@ -150,6 +170,10 @@ class V1ApplicationManagementUseCases {
context: context,
operationName: ApplicationManagementCommandCode.updateProject.name,
action: (repositories) async {
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.updateProject.name} '
'operationId=${context.operationId} projectId=$projectId '
'hasName=${update.name != null} hasColorKey=${update.colorKey != null}');
final project = await _requireProject(repositories, projectId);
final updated = project.copyWith(
name: update.name,
@ -162,6 +186,8 @@ class V1ApplicationManagementUseCases {
clearDefaultDuration: update.clearDefaultDuration,
);
await repositories.projects.save(updated);
logger.debug(() =>
'Project updated. operationId=${context.operationId} projectId=$projectId');
return ApplicationResult.success(updated);
},
);
@ -177,9 +203,14 @@ class V1ApplicationManagementUseCases {
context: context,
operationName: ApplicationManagementCommandCode.archiveProject.name,
action: (repositories) async {
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.archiveProject.name} '
'operationId=${context.operationId} projectId=$projectId');
final project = await _requireProject(repositories, projectId);
final archived = project.copyWith(archivedAt: context.now);
await repositories.projects.save(archived);
logger.debug(() =>
'Project archived. operationId=${context.operationId} projectId=$projectId');
return ApplicationResult.success(archived);
},
);
@ -196,8 +227,14 @@ class V1ApplicationManagementUseCases {
operationName: ApplicationManagementCommandCode.createLockedBlock.name,
action: (repositories) async {
final id = draft.id ?? context.idGenerator.nextId();
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.createLockedBlock.name} '
'operationId=${context.operationId} lockedBlockId=$id date=${draft.date?.toIsoString()} '
'hasRecurrence=${draft.recurrence != null} hiddenByDefault=${draft.hiddenByDefault}');
final existing = await repositories.lockedBlocks.findBlockById(id);
if (existing != null) {
logger.warn(() => 'Create locked block failed: block already exists. '
'operationId=${context.operationId} lockedBlockId=$id');
return _failure(
ApplicationFailureCode.conflict,
entityId: id,
@ -217,6 +254,8 @@ class V1ApplicationManagementUseCases {
updatedAt: context.now,
);
await repositories.lockedBlocks.saveBlock(block);
logger.debug(() =>
'Locked block created. operationId=${context.operationId} lockedBlockId=$id');
return ApplicationResult.success(block);
},
);
@ -233,6 +272,11 @@ class V1ApplicationManagementUseCases {
context: context,
operationName: ApplicationManagementCommandCode.updateLockedBlock.name,
action: (repositories) async {
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.updateLockedBlock.name} '
'operationId=${context.operationId} lockedBlockId=$lockedBlockId '
'hasName=${update.name != null} hasDate=${update.date != null} '
'hasRecurrence=${update.recurrence != null}');
final block = await _requireLockedBlock(repositories, lockedBlockId);
final updated = block.copyWith(
name: update.name,
@ -245,6 +289,8 @@ class V1ApplicationManagementUseCases {
updatedAt: context.now,
);
await repositories.lockedBlocks.saveBlock(updated);
logger.debug(() =>
'Locked block updated. operationId=${context.operationId} lockedBlockId=$lockedBlockId');
return ApplicationResult.success(updated);
},
);
@ -260,12 +306,17 @@ class V1ApplicationManagementUseCases {
context: context,
operationName: ApplicationManagementCommandCode.archiveLockedBlock.name,
action: (repositories) async {
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.archiveLockedBlock.name} '
'operationId=${context.operationId} lockedBlockId=$lockedBlockId');
final block = await _requireLockedBlock(repositories, lockedBlockId);
final archived = block.copyWith(
updatedAt: context.now,
archivedAt: context.now,
);
await repositories.lockedBlocks.saveBlock(archived);
logger.debug(() =>
'Locked block archived. operationId=${context.operationId} lockedBlockId=$lockedBlockId');
return ApplicationResult.success(archived);
},
);
@ -287,6 +338,10 @@ class V1ApplicationManagementUseCases {
operationName:
ApplicationManagementCommandCode.addLockedBlockOverride.name,
action: (repositories) async {
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.addLockedBlockOverride.name} '
'operationId=${context.operationId} date=${date.toIsoString()} hiddenByDefault=$hiddenByDefault '
'hasProjectId=${projectId != null}');
final override = LockedBlockOverride.add(
id: context.idGenerator.nextId(),
date: date,
@ -298,6 +353,8 @@ class V1ApplicationManagementUseCases {
createdAt: context.now,
);
await repositories.lockedBlocks.saveOverride(override);
logger.debug(() =>
'Locked block override added. operationId=${context.operationId} overrideId=${override.id}');
return ApplicationResult.success(override);
},
);
@ -315,6 +372,9 @@ class V1ApplicationManagementUseCases {
operationName:
ApplicationManagementCommandCode.removeLockedBlockOccurrence.name,
action: (repositories) async {
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.removeLockedBlockOccurrence.name} '
'operationId=${context.operationId} lockedBlockId=$lockedBlockId date=${date.toIsoString()}');
await _requireLockedBlock(repositories, lockedBlockId);
final override = LockedBlockOverride.remove(
id: context.idGenerator.nextId(),
@ -323,6 +383,9 @@ class V1ApplicationManagementUseCases {
createdAt: context.now,
);
await repositories.lockedBlocks.saveOverride(override);
logger.debug(() =>
'Locked block occurrence removed. operationId=${context.operationId} '
'lockedBlockId=$lockedBlockId overrideId=${override.id}');
return ApplicationResult.success(override);
},
);
@ -345,6 +408,10 @@ class V1ApplicationManagementUseCases {
operationName:
ApplicationManagementCommandCode.replaceLockedBlockOccurrence.name,
action: (repositories) async {
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.replaceLockedBlockOccurrence.name} '
'operationId=${context.operationId} lockedBlockId=$lockedBlockId date=${date.toIsoString()} '
'hasName=${name != null} hiddenByDefault=$hiddenByDefault');
await _requireLockedBlock(repositories, lockedBlockId);
final override = LockedBlockOverride.replace(
id: context.idGenerator.nextId(),
@ -358,6 +425,9 @@ class V1ApplicationManagementUseCases {
createdAt: context.now,
);
await repositories.lockedBlocks.saveOverride(override);
logger.debug(() =>
'Locked block occurrence replaced. operationId=${context.operationId} '
'lockedBlockId=$lockedBlockId overrideId=${override.id}');
return ApplicationResult.success(override);
},
);
@ -373,6 +443,11 @@ class V1ApplicationManagementUseCases {
context: context,
operationName: ApplicationManagementCommandCode.updateOwnerSettings.name,
action: (repositories) async {
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.updateOwnerSettings.name} '
'operationId=${context.operationId} ownerId=${context.ownerTimeZone.ownerId} '
'hasTimeZone=${update.timeZoneId != null} hasDayStart=${update.dayStart != null} '
'hasDayEnd=${update.dayEnd != null} hasStaleness=${update.backlogStalenessSettings != null}');
final current = await _ownerSettingsOrDefault(
repositories,
context.ownerTimeZone,
@ -382,6 +457,9 @@ class V1ApplicationManagementUseCases {
(stalenessSettings.greenMaxAge.isNegative ||
stalenessSettings.blueMaxAge.isNegative ||
stalenessSettings.blueMaxAge < stalenessSettings.greenMaxAge)) {
logger.warn(() =>
'Owner settings update failed: invalid staleness thresholds. '
'operationId=${context.operationId} ownerId=${context.ownerTimeZone.ownerId}');
return _failure(
ApplicationFailureCode.validation,
detailCode: 'invalidBacklogStalenessThresholds',
@ -404,6 +482,9 @@ class V1ApplicationManagementUseCases {
OwnerSettingsWarningCode.planningWindowChanged,
];
await repositories.ownerSettings.save(updated);
logger.debug(() =>
'Owner settings updated. operationId=${context.operationId} '
'ownerId=${context.ownerTimeZone.ownerId} warningCount=${warnings.length}');
return ApplicationResult.success(
OwnerSettingsUpdateResult(settings: updated, warnings: warnings),
);
@ -422,8 +503,13 @@ class V1ApplicationManagementUseCases {
operationName: ApplicationManagementCommandCode.acknowledgeNotice.name,
action: (repositories) async {
final ownerId = context.ownerTimeZone.ownerId;
logger.debug(() =>
'Management command executing. command=${ApplicationManagementCommandCode.acknowledgeNotice.name} '
'operationId=${context.operationId} ownerId=$ownerId noticeId=$noticeId');
final parsed = _parseNoticeId(noticeId);
if (parsed == null) {
logger.warn(() => 'Notice acknowledgement failed: invalid notice id. '
'operationId=${context.operationId} noticeId=$noticeId');
return _failure(
ApplicationFailureCode.validation,
entityId: noticeId,
@ -433,6 +519,9 @@ class V1ApplicationManagementUseCases {
final snapshot =
await repositories.schedulingSnapshots.findById(parsed.snapshotId);
if (snapshot == null || parsed.noticeIndex >= snapshot.notices.length) {
logger.warn(() => 'Notice acknowledgement failed: notice not found. '
'operationId=${context.operationId} noticeId=$noticeId '
'snapshotId=${parsed.snapshotId} noticeIndex=${parsed.noticeIndex}');
return _failure(
ApplicationFailureCode.notFound,
entityId: noticeId,
@ -444,6 +533,9 @@ class V1ApplicationManagementUseCases {
noticeId: noticeId,
);
if (existing != null) {
logger.finer(() =>
'Notice already acknowledged. operationId=${context.operationId} '
'noticeId=$noticeId ownerId=$ownerId');
return ApplicationResult.success(
NoticeAcknowledgementResult(
record: existing,
@ -458,6 +550,9 @@ class V1ApplicationManagementUseCases {
acknowledgedAt: context.now,
);
await repositories.noticeAcknowledgements.save(record);
logger.debug(
() => 'Notice acknowledged. operationId=${context.operationId} '
'noticeId=$noticeId ownerId=$ownerId');
return ApplicationResult.success(
NoticeAcknowledgementResult(
record: record,
@ -476,6 +571,7 @@ class V1ApplicationManagementUseCases {
) async {
final project = await repositories.projects.findById(projectId);
if (project == null) {
logger.warn(() => 'Required project not found. projectId=$projectId');
throw ApplicationFailureException(
ApplicationFailure(
code: ApplicationFailureCode.notFound,
@ -495,6 +591,8 @@ class V1ApplicationManagementUseCases {
) async {
final block = await repositories.lockedBlocks.findBlockById(lockedBlockId);
if (block == null) {
logger.warn(() =>
'Required locked block not found. lockedBlockId=$lockedBlockId');
throw ApplicationFailureException(
ApplicationFailure(
code: ApplicationFailureCode.notFound,
@ -513,12 +611,17 @@ Future<OwnerSettings> _ownerSettingsOrDefault(
ApplicationUnitOfWorkRepositories repositories,
OwnerTimeZoneContext ownerTimeZone,
) async {
return await repositories.ownerSettings
.findByOwnerId(ownerTimeZone.ownerId) ??
OwnerSettings(
ownerId: ownerTimeZone.ownerId,
timeZoneId: ownerTimeZone.timeZoneId,
);
final settings =
await repositories.ownerSettings.findByOwnerId(ownerTimeZone.ownerId);
if (settings != null) {
return settings;
}
logger.finer(() => 'Owner settings missing; using defaults. '
'ownerId=${ownerTimeZone.ownerId} timeZoneId=${ownerTimeZone.timeZoneId}');
return OwnerSettings(
ownerId: ownerTimeZone.ownerId,
timeZoneId: ownerTimeZone.timeZoneId,
);
}
/// Top-level helper that performs the `_failure<T>` operation for this file.

1
packages/scheduler_core/lib/src/application/application_recovery.dart
View file

@ -17,6 +17,7 @@ import '../persistence/repositories.dart';
import '../scheduling/scheduling_engine.dart';
import '../scheduling/task_lifecycle.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'application_recovery/app_open_recovery_outcome.dart';
part 'application_recovery/run_app_open_recovery_request.dart';
part 'application_recovery/app_open_recovery_result.dart';

50
packages/scheduler_core/lib/src/application/application_recovery/v1_app_open_recovery_use_cases.dart
View file

@ -42,9 +42,16 @@ class V1AppOpenRecoveryUseCases {
ownerId: ownerId,
sourceDate: sourceDate,
);
logger.info(() => 'App-open recovery started. ownerId=$ownerId '
'operationId=${context.operationId} sourceDate=${sourceDate.toIsoString()} '
'targetDate=${targetDate.toIsoString()} snapshotId=$snapshotId');
final existingSnapshot =
await repositories.schedulingSnapshots.findById(snapshotId);
if (existingSnapshot != null) {
logger.info(() =>
'App-open recovery already processed. ownerId=$ownerId '
'operationId=${context.operationId} snapshotId=$snapshotId '
'noticeCount=${existingSnapshot.notices.length} changeCount=${existingSnapshot.changes.length}');
return ApplicationResult.success(
AppOpenRecoveryResult(
outcome: AppOpenRecoveryOutcome.alreadyProcessed,
@ -87,6 +94,10 @@ class V1AppOpenRecoveryUseCases {
timeZoneResolver: timeZoneResolver,
resolutionOptions: resolutionOptions,
);
logger.debug(() => 'App-open recovery loaded source and target state. '
'ownerId=$ownerId taskCount=${tasks.length} blockCount=${blocks.length} '
'overrideCount=${overrides.length} '
'lockedIntervalCount=${lockedExpansion.schedulingIntervals.length}');
final input = SchedulingInput(
tasks: tasks,
window: targetWindow,
@ -101,6 +112,10 @@ class V1AppOpenRecoveryUseCases {
if (schedulingResult.outcomeCode == SchedulingOutcomeCode.overflow ||
schedulingResult.outcomeCode == SchedulingOutcomeCode.noSlot) {
logger.warn(() => 'App-open recovery could not place rollover tasks. '
'ownerId=$ownerId operationId=${context.operationId} '
'snapshotId=$snapshotId outcome=${schedulingResult.outcomeCode.name} '
'noticeCount=${schedulingResult.notices.length}');
return ApplicationResult.failure(
ApplicationFailure(
code: ApplicationFailureCode.noSlot,
@ -135,9 +150,16 @@ class V1AppOpenRecoveryUseCases {
operationName: 'appOpenRecovery',
);
logger.debug(() => 'Persisting app-open recovery. ownerId=$ownerId '
'operationId=${context.operationId} snapshotId=$snapshotId '
'changedTaskCount=${changedTasks.length} activityCount=${activities.length} '
'noticeCount=${snapshot.notices.length} changeCount=${schedulingResult.changes.length}');
await repositories.tasks.saveAll(changedTasks);
await repositories.taskActivities.saveAll(activities);
await repositories.schedulingSnapshots.save(snapshot);
logger.info(() => 'App-open recovery completed. ownerId=$ownerId '
'operationId=${context.operationId} outcome=${rolloverNotice == null ? AppOpenRecoveryOutcome.noUnfinishedFlexibleTasks.name : AppOpenRecoveryOutcome.rolledOver.name} '
'changedTaskCount=${changedTasks.length} activityCount=${activities.length}');
return ApplicationResult.success(
AppOpenRecoveryResult(
@ -198,12 +220,17 @@ Future<OwnerSettings> _ownerSettingsOrDefault(
ApplicationUnitOfWorkRepositories repositories,
OwnerTimeZoneContext ownerTimeZone,
) async {
return await repositories.ownerSettings
.findByOwnerId(ownerTimeZone.ownerId) ??
OwnerSettings(
ownerId: ownerTimeZone.ownerId,
timeZoneId: ownerTimeZone.timeZoneId,
);
final settings =
await repositories.ownerSettings.findByOwnerId(ownerTimeZone.ownerId);
if (settings != null) {
return settings;
}
logger.finer(() => 'Owner settings missing during recovery; using defaults. '
'ownerId=${ownerTimeZone.ownerId} timeZoneId=${ownerTimeZone.timeZoneId}');
return OwnerSettings(
ownerId: ownerTimeZone.ownerId,
timeZoneId: ownerTimeZone.timeZoneId,
);
}
/// Top-level helper that performs the `_loadSourceAndTargetTasks` operation for this file.
@ -213,6 +240,11 @@ Future<List<Task>> _loadSourceAndTargetTasks(
required SchedulingWindow sourceWindow,
required SchedulingWindow targetWindow,
}) async {
logger.debug(() => 'Loading recovery source and target tasks. '
'sourceStart=${sourceWindow.start.toIso8601String()} '
'sourceEnd=${sourceWindow.end.toIso8601String()} '
'targetStart=${targetWindow.start.toIso8601String()} '
'targetEnd=${targetWindow.end.toIso8601String()}');
final byId = <String, Task>{};
for (final task in await repositories.tasks.findScheduledInWindow(
sourceWindow,
@ -224,6 +256,8 @@ Future<List<Task>> _loadSourceAndTargetTasks(
)) {
byId[task.id] = task;
}
logger.debug(() =>
'Recovery source and target tasks loaded. taskCount=${byId.length}');
return List<Task>.unmodifiable(byId.values);
}
@ -249,8 +283,12 @@ SchedulingNotice? _rolloverNotice({
.map((change) => change.taskId)
.toSet();
if (rolledTaskIds.isEmpty) {
logger.finer(
() => 'No rollover notice needed; no tasks moved from source day.');
return null;
}
logger.debug(
() => 'Rollover notice created. rolledTaskCount=${rolledTaskIds.length}');
return SchedulingNotice(
'${rolledTaskIds.length} unfinished flexible tasks were moved to today.',

1
packages/scheduler_core/lib/src/persistence/document_migration.dart
View file

@ -13,6 +13,7 @@ library;
import 'document_mapping.dart';
import 'persistence_contract.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'document_migration/codes/document_migration_entity.dart';
part 'document_migration/codes/document_migration_status.dart';
part 'document_migration/codes/document_migration_failure_code.dart';

34
packages/scheduler_core/lib/src/persistence/document_migration/service/v1_document_migration_service.dart
View file

@ -80,8 +80,14 @@ class V1DocumentMigrationService {
required void Function(Map<String, Object?> document) validateCurrent,
}) {
final documentId = _documentId(document);
logger.debug(() => 'Document migration started. '
'entity=${entity.name} documentId=$documentId '
'ownerId=$ownerId migratedAt=${migratedAt.toIso8601String()}');
final schemaRead = _readSchemaVersion(document);
if (schemaRead.failure != null) {
logger.warn(() => 'Document migration failed schema version read. '
'entity=${entity.name} documentId=$documentId '
'detailCode=${schemaRead.failure}');
return _failed(
entity: entity,
documentId: documentId,
@ -93,10 +99,15 @@ class V1DocumentMigrationService {
}
final fromVersion = schemaRead.version;
logger.finer(() => 'Document migration schema version resolved. '
'entity=${entity.name} documentId=$documentId fromSchemaVersion=$fromVersion');
if (fromVersion == v1SchemaVersion) {
try {
final copy = _deepCopyDocument(document);
validateCurrent(copy);
logger.debug(() =>
'Document migration skipped; document already current. '
'entity=${entity.name} documentId=$documentId fromSchemaVersion=$fromVersion');
return DocumentMigrationResult(
document: copy,
report: DocumentMigrationReport(
@ -107,6 +118,11 @@ class V1DocumentMigrationService {
),
);
} on DocumentMappingException catch (error) {
logger.warn(
() => 'Document migration failed current document validation. '
'entity=${entity.name} documentId=$documentId '
'fromSchemaVersion=$fromVersion mappingCode=${error.code.name} '
'fieldName=${error.fieldName} detailCode=${error.detailCode}');
return _failedFromMapping(
entity: entity,
documentId: documentId,
@ -118,6 +134,9 @@ class V1DocumentMigrationService {
}
if (fromVersion > v1SchemaVersion || fromVersion < 0) {
logger.warn(() =>
'Document migration rejected unsupported schema version. '
'entity=${entity.name} documentId=$documentId fromSchemaVersion=$fromVersion');
return _failed(
entity: entity,
documentId: documentId,
@ -129,6 +148,9 @@ class V1DocumentMigrationService {
}
if (fromVersion != 0) {
logger.warn(() =>
'Document migration rejected unsupported schema version. '
'entity=${entity.name} documentId=$documentId fromSchemaVersion=$fromVersion');
return _failed(
entity: entity,
documentId: documentId,
@ -144,6 +166,10 @@ class V1DocumentMigrationService {
try {
migrated = migrateV0(document, notes);
} on _LegacyDocumentException catch (error) {
logger.warn(() => 'Document migration failed legacy document validation. '
'entity=${entity.name} documentId=$documentId '
'fromSchemaVersion=$fromVersion fieldName=${error.fieldName} '
'detailCode=${error.detailCode}');
return _failed(
entity: entity,
documentId: documentId,
@ -157,6 +183,11 @@ class V1DocumentMigrationService {
try {
validateCurrent(migrated);
} on DocumentMappingException catch (error) {
logger
.warn(() => 'Document migration failed migrated document validation. '
'entity=${entity.name} documentId=$documentId '
'fromSchemaVersion=$fromVersion mappingCode=${error.code.name} '
'fieldName=${error.fieldName} detailCode=${error.detailCode}');
return _failedFromMapping(
entity: entity,
documentId: documentId,
@ -166,6 +197,9 @@ class V1DocumentMigrationService {
);
}
logger.debug(() => 'Document migration finished. '
'entity=${entity.name} documentId=$documentId fromSchemaVersion=$fromVersion '
'toSchemaVersion=$v1SchemaVersion noteCount=${notes.length}');
return DocumentMigrationResult(
document: migrated,
report: DocumentMigrationReport(

1
packages/scheduler_core/lib/src/scheduling/child_tasks.dart
View file

@ -13,6 +13,7 @@ library;
import '../domain/models.dart';
import 'task_lifecycle.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'child_tasks/models/child_task_entry.dart';
part 'child_tasks/requests/child_task_break_up_request.dart';
part 'child_tasks/results/child_task_break_up_result.dart';

23
packages/scheduler_core/lib/src/scheduling/child_tasks/services/child_task_break_up_service.dart
View file

@ -17,8 +17,14 @@ class ChildTaskBreakUpService {
required List<Task> tasks,
required ChildTaskBreakUpRequest request,
}) {
logger.debug(
() => 'Breaking up parent task. parentTaskId=${request.parentTaskId} '
'entryCount=${request.entries.length} taskCount=${tasks.length} '
'operationId=${request.operationId}');
final parent = _taskById(tasks, request.parentTaskId);
if (parent == null) {
logger.warn(() => 'Child task break-up failed: parent not found. '
'parentTaskId=${request.parentTaskId} operationId=${request.operationId}');
throw ArgumentError.value(
request.parentTaskId,
'parentTaskId',
@ -26,6 +32,8 @@ class ChildTaskBreakUpService {
);
}
if (request.entries.isEmpty) {
logger.warn(() => 'Child task break-up failed: no child entries. '
'parentTaskId=${request.parentTaskId} operationId=${request.operationId}');
throw ArgumentError.value(
request.entries,
'entries',
@ -38,9 +46,14 @@ class ChildTaskBreakUpService {
for (final entry in request.entries) {
final childId = entry.id.trim();
if (childId.isEmpty) {
logger.warn(() => 'Child task break-up failed: blank child id. '
'parentTaskId=${parent.id} operationId=${request.operationId}');
throw ArgumentError.value(entry.id, 'id', 'Child id is required.');
}
if (childId == parent.id) {
logger
.warn(() => 'Child task break-up failed: child id matched parent. '
'parentTaskId=${parent.id} operationId=${request.operationId}');
throw ArgumentError.value(
entry.id,
'id',
@ -48,6 +61,9 @@ class ChildTaskBreakUpService {
);
}
if (!requestedIds.add(childId)) {
logger.warn(() => 'Child task break-up failed: duplicate child id. '
'parentTaskId=${parent.id} childTaskId=$childId '
'operationId=${request.operationId}');
throw ArgumentError.value(
entry.id,
'id',
@ -55,6 +71,10 @@ class ChildTaskBreakUpService {
);
}
if (existingIds.contains(childId)) {
logger
.warn(() => 'Child task break-up failed: child id already exists. '
'parentTaskId=${parent.id} childTaskId=$childId '
'operationId=${request.operationId}');
throw ArgumentError.value(
entry.id,
'id',
@ -66,6 +86,9 @@ class ChildTaskBreakUpService {
final childTasks = request.entries
.map((entry) => entry.toTask(parent: parent))
.toList(growable: false);
logger.debug(() => 'Parent task break-up produced children. '
'parentTaskId=${parent.id} childCount=${childTasks.length} '
'operationId=${request.operationId}');
return ChildTaskBreakUpResult(
tasks: List<Task>.unmodifiable([...tasks, ...childTasks]),

38
packages/scheduler_core/lib/src/scheduling/child_tasks/services/child_task_completion_service.dart
View file

@ -32,19 +32,28 @@ class ChildTaskCompletionService {
Iterable<String> appliedActivityIds = const <String>[],
}) {
final now = updatedAt ?? clock.now();
logger.debug(() => 'Completing child task. childTaskId=$childTaskId '
'taskCount=${tasks.length} operationId=$operationId '
'updatedAt=${now.toIso8601String()}');
final child = _taskById(tasks, childTaskId);
if (child == null) {
logger.warn(() => 'Child completion failed: task not found. '
'childTaskId=$childTaskId operationId=$operationId');
throw ArgumentError.value(childTaskId, 'childTaskId', 'Task not found.');
}
final parentId = child.parentTaskId;
if (parentId == null) {
logger.warn(() => 'Child completion failed: task has no parent. '
'childTaskId=$childTaskId operationId=$operationId');
throw ArgumentError.value(
childTaskId, 'childTaskId', 'Task is not a child.');
}
final parent = _taskById(tasks, parentId);
if (parent == null) {
logger.warn(() => 'Child completion failed: parent not found. '
'childTaskId=$childTaskId parentTaskId=$parentId operationId=$operationId');
throw ArgumentError.value(parentId, 'parentTaskId', 'Parent not found.');
}
@ -69,6 +78,9 @@ class ChildTaskCompletionService {
final outcomes = <TaskTransitionOutcomeCode>[childTransition.outcomeCode];
if (!shouldCompleteParent) {
logger.debug(() => 'Child task completed without parent auto-complete. '
'childTaskId=${child.id} parentTaskId=${parent.id} '
'childApplied=${childTransition.applied} operationId=$opId');
return ChildTaskCompletionResult(
tasks: List<Task>.unmodifiable(withChildCompleted),
changedTaskIds: childTransition.applied ? [child.id] : const <String>[],
@ -100,6 +112,10 @@ class ChildTaskCompletionService {
if (parentTransition.applied) parent.id,
];
logger.debug(() => 'Child task completion auto-completed parent. '
'childTaskId=${child.id} parentTaskId=${parent.id} '
'changedCount=${changedTaskIds.length} operationId=$opId');
return ChildTaskCompletionResult(
tasks: List<Task>.unmodifiable(completedTasks),
changedTaskIds: List<String>.unmodifiable(changedTaskIds),
@ -120,12 +136,19 @@ class ChildTaskCompletionService {
Iterable<TaskActivity> existingActivities = const <TaskActivity>[],
Iterable<String> appliedActivityIds = const <String>[],
}) {
logger.debug(() => 'Completing parent from child. childTaskId=$childTaskId '
'taskCount=${tasks.length} operationId=$operationId');
final child = _taskById(tasks, childTaskId);
if (child == null) {
logger.warn(() => 'Parent-from-child completion failed: task not found. '
'childTaskId=$childTaskId operationId=$operationId');
throw ArgumentError.value(childTaskId, 'childTaskId', 'Task not found.');
}
final parentId = child.parentTaskId;
if (parentId == null) {
logger.warn(
() => 'Parent-from-child completion failed: task has no parent. '
'childTaskId=$childTaskId operationId=$operationId');
throw ArgumentError.value(
childTaskId,
'childTaskId',
@ -155,8 +178,13 @@ class ChildTaskCompletionService {
Iterable<String> appliedActivityIds = const <String>[],
}) {
final now = updatedAt ?? clock.now();
logger.debug(() => 'Completing parent task. parentTaskId=$parentTaskId '
'taskCount=${tasks.length} initiatingChildTaskId=$initiatingChildTaskId '
'operationId=$operationId updatedAt=${now.toIso8601String()}');
final parent = _taskById(tasks, parentTaskId);
if (parent == null) {
logger.warn(() => 'Parent completion failed: parent not found. '
'parentTaskId=$parentTaskId operationId=$operationId');
throw ArgumentError.value(
parentTaskId, 'parentTaskId', 'Parent not found.');
}
@ -164,6 +192,10 @@ class ChildTaskCompletionService {
final directChildren = ChildTaskView(tasks: tasks).childrenOf(parent);
if (initiatingChildTaskId != null &&
!directChildren.any((child) => child.id == initiatingChildTaskId)) {
logger.warn(
() => 'Parent completion failed: initiating child is not direct. '
'parentTaskId=${parent.id} childTaskId=$initiatingChildTaskId '
'operationId=$operationId');
throw ArgumentError.value(
initiatingChildTaskId,
'initiatingChildTaskId',
@ -234,6 +266,12 @@ class ChildTaskCompletionService {
updatedTasks.add(task);
}
logger.debug(
() => 'Parent task completion finished. parentTaskId=${parent.id} '
'directChildCount=${directChildren.length} '
'forceCompletedCount=${forceCompletedChildIds.length} '
'changedCount=${changedTaskIds.length} operationId=$opId');
return ChildTaskCompletionResult(
tasks: List<Task>.unmodifiable(updatedTasks),
changedTaskIds: List<String>.unmodifiable(changedTaskIds),

1
packages/scheduler_core/lib/src/scheduling/free_slots.dart
View file

@ -13,6 +13,7 @@ library;
import '../domain/models.dart';
import '../domain/occupancy_policy.dart';
import 'scheduling_engine.dart';
import '../logging/focus_flow_logger.dart';
part 'free_slots/required_commitment_schedule_status.dart';
part 'free_slots/protected_free_slot_conflict.dart';
part 'free_slots/required_commitment_schedule_result.dart';

22
packages/scheduler_core/lib/src/scheduling/free_slots/free_slot_service.dart
View file

@ -19,6 +19,9 @@ class FreeSlotService {
String projectId = 'inbox',
DateTime? updatedAt,
}) {
logger.debug(() => 'Creating protected free slot. taskId=$id '
'start=${start.toIso8601String()} end=${end.toIso8601String()} '
'projectId=$projectId');
final interval = TimeInterval(start: start, end: end, label: id);
return Task(
@ -45,7 +48,12 @@ class FreeSlotService {
String? title,
String? projectId,
}) {
logger.debug(() => 'Updating protected free slot. taskId=${freeSlot.id} '
'start=${start.toIso8601String()} end=${end.toIso8601String()} '
'projectId=$projectId hasTitle=${title != null}');
if (freeSlot.type != TaskType.freeSlot) {
logger.error(() => 'Free slot update failed: invalid task type. '
'taskId=${freeSlot.id} taskType=${freeSlot.type.name}');
throw ArgumentError.value(
freeSlot.type,
'freeSlot.type',
@ -78,8 +86,14 @@ class FreeSlotService {
required DateTime end,
DateTime? updatedAt,
}) {
logger.debug(() => 'Scheduling required commitment. taskId=$taskId '
'start=${start.toIso8601String()} end=${end.toIso8601String()} '
'taskCount=${input.tasks.length}');
final task = _taskById(input.tasks, taskId);
if (task == null) {
logger
.warn(() => 'Required commitment scheduling failed: task not found. '
'taskId=$taskId');
return _unchangedRequiredResult(
input: input,
status: RequiredCommitmentScheduleStatus.taskNotFound,
@ -94,6 +108,9 @@ class FreeSlotService {
}
if (!task.isRequiredVisible) {
logger.warn(
() => 'Required commitment scheduling failed: invalid task type. '
'taskId=${task.id} taskType=${task.type.name}');
return _unchangedRequiredResult(
input: input,
status: RequiredCommitmentScheduleStatus.invalidTaskType,
@ -171,6 +188,11 @@ class FreeSlotService {
),
];
logger.debug(() =>
'Required commitment scheduling finished. taskId=${task.id} '
'status=${conflicts.isEmpty ? RequiredCommitmentScheduleStatus.scheduled.name : RequiredCommitmentScheduleStatus.scheduledWithProtectedFreeSlotConflict.name} '
'conflictCount=${conflicts.length} changeCount=${changes.length}');
return RequiredCommitmentScheduleResult(
status: conflicts.isEmpty
? RequiredCommitmentScheduleStatus.scheduled

1
packages/scheduler_core/lib/src/scheduling/quick_capture.dart
View file

@ -13,6 +13,7 @@ library;
import '../domain/models.dart';
import 'scheduling_engine.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'quick_capture/quick_capture_status.dart';
part 'quick_capture/quick_capture_request.dart';
part 'quick_capture/quick_capture_result.dart';

31
packages/scheduler_core/lib/src/scheduling/quick_capture/quick_capture_service.dart
View file

@ -41,6 +41,10 @@ class QuickCaptureService {
SchedulingInput? schedulingInput,
DateTime? updatedAt,
}) {
logger.debug(() => 'Quick capture requested. taskId=${request.id} '
'projectId=${request.projectId} taskType=${request.type.name} '
'hasDuration=${request.durationMinutes != null} '
'addToNextAvailableSlot=${request.addToNextAvailableSlot}');
final capturedTaskWithoutDuration = Task.quickCapture(
id: request.id,
title: request.title,
@ -55,6 +59,9 @@ class QuickCaptureService {
);
if (request.durationMinutes != null && request.durationMinutes! <= 0) {
logger.warn(() =>
'Quick capture validation failed: non-positive duration. '
'taskId=${request.id} durationMinutes=${request.durationMinutes}');
return QuickCaptureResult(
task: capturedTaskWithoutDuration,
status: QuickCaptureStatus.validationError,
@ -67,6 +74,8 @@ class QuickCaptureService {
);
if (!request.addToNextAvailableSlot) {
logger.debug(
() => 'Quick capture added to backlog. taskId=${capturedTask.id}');
return QuickCaptureResult(
task: capturedTask,
status: QuickCaptureStatus.addedToBacklog,
@ -74,6 +83,9 @@ class QuickCaptureService {
}
if (request.durationMinutes == null || request.durationMinutes! <= 0) {
logger.warn(
() => 'Quick capture scheduling validation failed: missing duration. '
'taskId=${capturedTask.id}');
return QuickCaptureResult(
task: capturedTask,
status: QuickCaptureStatus.validationError,
@ -82,6 +94,9 @@ class QuickCaptureService {
}
if (request.type != TaskType.flexible) {
logger.warn(() =>
'Quick capture scheduling validation failed: non-flexible task. '
'taskId=${capturedTask.id} taskType=${request.type.name}');
return QuickCaptureResult(
task: capturedTask,
status: QuickCaptureStatus.validationError,
@ -90,6 +105,9 @@ class QuickCaptureService {
}
if (schedulingInput == null) {
logger.warn(() =>
'Quick capture scheduling validation failed: missing scheduling input. '
'taskId=${capturedTask.id}');
return QuickCaptureResult(
task: capturedTask,
status: QuickCaptureStatus.validationError,
@ -110,6 +128,9 @@ class QuickCaptureService {
final scheduledTask = _taskById(result.tasks, capturedTask.id);
if (scheduledTask == null || scheduledTask.isBacklog) {
logger.warn(() => 'Quick capture scheduling did not place task. '
'taskId=${capturedTask.id} outcome=${result.outcomeCode.name} '
'noticeCount=${result.notices.length}');
return QuickCaptureResult(
task: capturedTask,
status: QuickCaptureStatus.validationError,
@ -118,6 +139,10 @@ class QuickCaptureService {
);
}
logger.debug(() => 'Quick capture scheduled. taskId=${scheduledTask.id} '
'start=${scheduledTask.scheduledStart?.toIso8601String()} '
'end=${scheduledTask.scheduledEnd?.toIso8601String()} '
'changeCount=${result.changes.length} noticeCount=${result.notices.length}');
return QuickCaptureResult(
task: scheduledTask,
status: QuickCaptureStatus.scheduled,
@ -142,10 +167,16 @@ class QuickCaptureService {
}) {
final generator = idGenerator;
if (generator == null) {
logger.error(
() => 'Quick capture rejected because id generator is missing.');
throw StateError('Quick capture needs an id generator.');
}
final now = createdAt ?? updatedAt ?? clock.now();
logger.debug(() => 'Quick capture new task requested. '
'hasTitle=${title.trim().isNotEmpty} projectId=$projectId '
'type=${type.name} addToNextAvailableSlot=$addToNextAvailableSlot '
'occurredAt=${now.toIso8601String()}');
return capture(
QuickCaptureRequest(

1
packages/scheduler_core/lib/src/scheduling/reminder_policy.dart
View file

@ -12,6 +12,7 @@ library;
import '../domain/models.dart';
import '../domain/occupancy_policy.dart';
import '../logging/focus_flow_logger.dart';
part 'reminder_policy/directives/reminder_directive_action.dart';
part 'reminder_policy/directives/reminder_directive_reason.dart';
part 'reminder_policy/profiles/effective_reminder_profile.dart';

30
packages/scheduler_core/lib/src/scheduling/reminder_policy/services/reminder_policy_service.dart
View file

@ -25,6 +25,8 @@ class ReminderPolicyService {
}) {
final override = task.reminderOverride;
if (override != null) {
logger.finer(() => 'Reminder profile resolved from task override. '
'taskId=${task.id} profile=${override.name}');
return EffectiveReminderProfile(
profile: override,
source: EffectiveReminderProfileSource.taskOverride,
@ -32,12 +34,17 @@ class ReminderPolicyService {
}
if (project != null) {
logger.finer(() => 'Reminder profile resolved from project default. '
'taskId=${task.id} projectId=${project.id} '
'profile=${project.defaultReminderProfile.name}');
return EffectiveReminderProfile(
profile: project.defaultReminderProfile,
source: EffectiveReminderProfileSource.projectDefault,
);
}
logger.finer(() => 'Reminder profile resolved from fallback. '
'taskId=${task.id} profile=${fallbackProfile.name}');
return EffectiveReminderProfile(
profile: fallbackProfile,
source: EffectiveReminderProfileSource.fallback,
@ -51,11 +58,19 @@ class ReminderPolicyService {
ProjectProfile? project,
Iterable<Task> contextTasks = const <Task>[],
}) {
logger.debug(() => 'Reminder directive evaluation started. '
'taskId=${task.id} type=${task.type.name} status=${task.status.name} '
'now=${now.toIso8601String()}');
final effective = resolveEffectiveProfile(task: task, project: project);
final activeFreeSlot = _activeProtectedFreeSlot(
now: now,
contextTasks: contextTasks,
);
if (activeFreeSlot != null) {
logger.finer(() => 'Reminder directive found active protected free slot. '
'taskId=${task.id} freeSlotTaskId=${activeFreeSlot.taskId} '
'freeSlotEnd=${activeFreeSlot.interval?.end.toIso8601String()}');
}
return _directiveForTask(
task: task,
@ -81,6 +96,12 @@ class ReminderPolicyService {
required ReminderDirectiveReason reason,
DateTime? nextEligibleAt,
}) {
logger.debug(() => 'Reminder directive evaluation finished. '
'taskId=${task.id} action=${action.name} reason=${reason.name} '
'profile=${effective.profile.name} source=${effective.source.name} '
'hasSchedule=${start != null && end != null} '
'nextEligibleAt=${nextEligibleAt?.toIso8601String()} '
'protectedFreeSlotTaskId=${activeFreeSlot?.taskId}');
return ReminderDirective(
taskId: task.id,
action: action,
@ -165,6 +186,8 @@ class ReminderPolicyService {
if (task.type == TaskType.critical &&
effective.profile == ReminderProfile.strict) {
logger.finer(() => 'Reminder directive requires acknowledgement. '
'taskId=${task.id} profile=${effective.profile.name}');
return build(
action: ReminderDirectiveAction.requireAcknowledgement,
reason: ReminderDirectiveReason.requireRequiredAcknowledgement,
@ -191,6 +214,9 @@ class ReminderPolicyService {
}) {
if (task.type == TaskType.critical &&
effective.profile == ReminderProfile.strict) {
logger.finer(() =>
'Reminder directive requires acknowledgement during protected rest. '
'taskId=${task.id} profile=${effective.profile.name}');
return build(
action: ReminderDirectiveAction.requireAcknowledgement,
reason: ReminderDirectiveReason.requireRequiredAcknowledgement,
@ -199,6 +225,10 @@ class ReminderPolicyService {
if (task.type == TaskType.inflexible &&
effective.profile == ReminderProfile.gentle) {
logger.finer(() =>
'Reminder directive deferred required task during protected rest. '
'taskId=${task.id} profile=${effective.profile.name} '
'nextEligibleAt=${freeSlotEnd?.toIso8601String()}');
return build(
action: ReminderDirectiveAction.defer,
reason: ReminderDirectiveReason.deferRequiredDuringProtectedRest,

1
packages/scheduler_core/lib/src/scheduling/scheduling_engine.dart
View file

@ -22,6 +22,7 @@ import '../domain/models.dart';
import '../domain/occupancy_policy.dart';
import 'task_lifecycle.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'scheduling_engine/codes/notices/scheduling_notice_type.dart';
part 'scheduling_engine/codes/operations/scheduling_operation_code.dart';
part 'scheduling_engine/codes/operations/scheduling_outcome_code.dart';

81
packages/scheduler_core/lib/src/scheduling/scheduling_engine/engine/scheduling_engine.dart
View file

@ -45,10 +45,16 @@ class SchedulingEngine {
required String taskId,
DateTime? updatedAt,
}) {
logger.debug(() => 'Scheduling backlog task into next available slot. '
'taskId=$taskId taskCount=${input.tasks.length} '
'windowStart=${input.window.start.toIso8601String()} '
'windowEnd=${input.window.end.toIso8601String()}');
// Step 1: resolve and validate the task. The engine does not create tasks;
// quick capture or persistence code is responsible for adding it to the list.
final task = _taskById(input.tasks, taskId);
if (task == null) {
logger.warn(
() => 'Backlog scheduling failed: task not found. taskId=$taskId');
return _unchangedResult(
input,
SchedulingNotice(
@ -64,6 +70,8 @@ class SchedulingEngine {
}
if (!task.isFlexible || !task.isBacklog) {
logger.warn(() => 'Backlog scheduling failed: invalid task state. '
'taskId=${task.id} taskType=${task.type.name} taskStatus=${task.status.name}');
return _unchangedResult(
input,
SchedulingNotice(
@ -80,6 +88,8 @@ class SchedulingEngine {
final taskDuration = _durationFromMinutes(task.durationMinutes);
if (taskDuration == null) {
logger.warn(() => 'Backlog scheduling failed: missing positive duration. '
'taskId=${task.id} durationMinutes=${task.durationMinutes}');
return _unchangedResult(
input,
SchedulingNotice(
@ -103,6 +113,8 @@ class SchedulingEngine {
);
if (placement == null) {
logger.warn(() => 'Backlog scheduling failed: no available slot. '
'taskId=${task.id} blockedIntervalCount=${input.blockedIntervals.length}');
return _unchangedResult(
input,
SchedulingNotice(
@ -140,10 +152,15 @@ class SchedulingEngine {
DateTime? earliestStart,
bool countAsManualPush = true,
}) {
logger.debug(() => 'Pushing flexible task to next available slot. '
'taskId=$taskId taskCount=${input.tasks.length} '
'earliestStart=${earliestStart?.toIso8601String()} '
'countAsManualPush=$countAsManualPush');
// Resolve the selected task by id so UI code only needs to pass a stable
// identifier, not object references.
final task = _taskById(input.tasks, taskId);
if (task == null) {
logger.warn(() => 'Flexible push failed: task not found. taskId=$taskId');
return _unchangedResult(
input,
SchedulingNotice(
@ -159,6 +176,8 @@ class SchedulingEngine {
}
if (!task.isFlexible || task.status != TaskStatus.planned) {
logger.warn(() => 'Flexible push failed: invalid task state. '
'taskId=${task.id} taskType=${task.type.name} taskStatus=${task.status.name}');
return _unchangedResult(
input,
SchedulingNotice(
@ -176,6 +195,9 @@ class SchedulingEngine {
final currentInterval = _scheduledIntervalFor(task);
if (currentInterval == null ||
(earliestStart == null && !input.window.contains(currentInterval))) {
logger.warn(() =>
'Flexible push failed: missing or out-of-window scheduled slot. '
'taskId=${task.id} hasCurrentInterval=${currentInterval != null}');
return _unchangedResult(
input,
SchedulingNotice(
@ -191,6 +213,9 @@ class SchedulingEngine {
}
if (currentInterval.duration.inMicroseconds <= 0) {
logger.warn(() =>
'Flexible push failed: non-positive scheduled duration. '
'taskId=${task.id} durationMicroseconds=${currentInterval.duration.inMicroseconds}');
return _unchangedResult(
input,
SchedulingNotice(
@ -213,6 +238,8 @@ class SchedulingEngine {
);
if (placement == null) {
logger.warn(() =>
'Flexible push failed: no available slot today. taskId=${task.id}');
return _unchangedResult(
input,
SchedulingNotice(
@ -253,8 +280,13 @@ class SchedulingEngine {
required String taskId,
DateTime? updatedAt,
}) {
logger.debug(() => 'Pushing flexible task to tomorrow top of queue. '
'taskId=$taskId taskCount=${input.tasks.length} '
'windowStart=${input.window.start.toIso8601String()} '
'windowEnd=${input.window.end.toIso8601String()}');
final task = _taskById(input.tasks, taskId);
if (task == null) {
logger.warn(() => 'Tomorrow push failed: task not found. taskId=$taskId');
return _unchangedResult(
input,
SchedulingNotice(
@ -270,6 +302,8 @@ class SchedulingEngine {
}
if (!task.isFlexible || task.status != TaskStatus.planned) {
logger.warn(() => 'Tomorrow push failed: invalid task state. '
'taskId=${task.id} taskType=${task.type.name} taskStatus=${task.status.name}');
return _unchangedResult(
input,
SchedulingNotice(
@ -287,6 +321,8 @@ class SchedulingEngine {
final taskDuration = _scheduledIntervalFor(task)?.duration ??
_durationFromMinutes(task.durationMinutes);
if (taskDuration == null || taskDuration.inMicroseconds <= 0) {
logger.warn(() => 'Tomorrow push failed: missing positive duration. '
'taskId=${task.id} durationMinutes=${task.durationMinutes}');
return _unchangedResult(
input,
SchedulingNotice(
@ -308,6 +344,8 @@ class SchedulingEngine {
);
if (placement == null) {
logger.warn(
() => 'Tomorrow push failed: no available slot. taskId=${task.id}');
return _unchangedResult(
input,
SchedulingNotice(
@ -352,6 +390,10 @@ class SchedulingEngine {
SchedulingWindow? sourceWindow,
DateTime? updatedAt,
}) {
logger.debug(() => 'Rolling over unfinished flexible tasks. '
'taskCount=${input.tasks.length} targetWindowStart=${input.window.start.toIso8601String()} '
'targetWindowEnd=${input.window.end.toIso8601String()} '
'hasSourceWindow=${sourceWindow != null}');
// Build the explicit queue of tasks to roll before asking the planner to
// place anything. This keeps selection separate from placement.
final rolledItems = <_PlacementItem>[];
@ -388,6 +430,8 @@ class SchedulingEngine {
}
if (rolledItems.isEmpty) {
logger
.debug(() => 'Rollover finished with no unfinished flexible tasks.');
return SchedulingResult(
tasks: input.tasks,
operationCode: SchedulingOperationCode.rollOverUnfinishedFlexibleTasks,
@ -408,6 +452,9 @@ class SchedulingEngine {
);
if (placement == null) {
logger.warn(
() => 'Rollover failed: unfinished flexible tasks could not fit. '
'rolledCount=${rolledItems.length}');
return _unchangedResult(
input,
SchedulingNotice(
@ -434,6 +481,8 @@ class SchedulingEngine {
/// reports any overlap with blocked intervals. It deliberately returns the
/// original task list unchanged.
SchedulingResult analyzeSchedule(SchedulingInput input) {
logger.debug(() => 'Analyzing schedule. taskCount=${input.tasks.length} '
'conflictOccupancyCount=${input.conflictReportingOccupancies.length}');
final overlaps = <SchedulingOverlap>[];
final notices = <SchedulingNotice>[];
final conflictOccupancies = input.conflictReportingOccupancies;
@ -477,6 +526,9 @@ class SchedulingEngine {
}
}
logger.debug(
() => 'Schedule analysis finished. overlapCount=${overlaps.length} '
'noticeCount=${notices.length}');
return SchedulingResult(
tasks: input.tasks,
operationCode: SchedulingOperationCode.analyzeSchedule,
@ -495,6 +547,8 @@ class SchedulingEngine {
/// reports can distinguish this from a task that was never scheduled.
Task moveToBacklog(Task task, {DateTime? updatedAt}) {
final now = updatedAt ?? clock.now();
logger.debug(() => 'Legacy move-to-backlog requested. taskId=${task.id} '
'taskStatus=${task.status.name} occurredAt=${now.toIso8601String()}');
final result = _transitionService.apply(
task: task,
transitionCode: TaskTransitionCode.moveToBacklog,
@ -503,6 +557,8 @@ class SchedulingEngine {
'legacy-move-to-backlog:${task.id}:${now.toIso8601String()}:activity',
occurredAt: now,
);
logger.debug(() => 'Legacy move-to-backlog finished. taskId=${task.id} '
'outcome=${result.outcomeCode.name} nextStatus=${result.task.status.name}');
return result.applied ? result.task : task;
}
@ -512,6 +568,9 @@ class SchedulingEngine {
/// actual scheduled slot should change.
Task markManuallyPushed(Task task, {DateTime? updatedAt}) {
final now = updatedAt ?? clock.now();
logger.debug(
() => 'Legacy manual push statistic requested. taskId=${task.id} '
'occurredAt=${now.toIso8601String()}');
final result = _transitionService.apply(
task: task,
transitionCode: TaskTransitionCode.manualPush,
@ -520,6 +579,9 @@ class SchedulingEngine {
'legacy-manual-push:${task.id}:${now.toIso8601String()}:activity',
occurredAt: now,
);
logger
.debug(() => 'Legacy manual push statistic finished. taskId=${task.id} '
'outcome=${result.outcomeCode.name}');
return result.applied ? result.task : task;
}
@ -530,6 +592,9 @@ class SchedulingEngine {
/// or time block that cannot simply be rescheduled automatically.
Task markMissed(Task task, {DateTime? updatedAt}) {
final now = updatedAt ?? clock.now();
logger.debug(() => 'Legacy mark-missed requested. taskId=${task.id} '
'taskType=${task.type.name} taskStatus=${task.status.name} '
'occurredAt=${now.toIso8601String()}');
final result = _transitionService.apply(
task: task,
transitionCode: TaskTransitionCode.miss,
@ -537,6 +602,8 @@ class SchedulingEngine {
activityId: 'legacy-miss:${task.id}:${now.toIso8601String()}:activity',
occurredAt: now,
);
logger.debug(() => 'Legacy mark-missed finished. taskId=${task.id} '
'outcome=${result.outcomeCode.name} nextStatus=${result.task.status.name}');
return result.applied ? result.task : task;
}
@ -553,6 +620,10 @@ class SchedulingEngine {
required Duration duration,
required List<TimeInterval> blocked,
}) {
logger.debug(() => 'Finding first open interval. '
'windowStart=${windowStart.toIso8601String()} '
'windowEnd=${windowEnd.toIso8601String()} '
'durationMinutes=${duration.inMinutes} blockedCount=${blocked.length}');
final sortedBlocked = [...blocked]
..sort((a, b) => a.start.compareTo(b.start));
var cursor = windowStart;
@ -745,7 +816,7 @@ _BacklogInsertionPlan? _planFlexiblePush({
}) {
final pushPoint = _laterOf(
currentInterval.end,
earliestStart == null ? input.window.start : earliestStart,
earliestStart ?? input.window.start,
);
final fixedBlocks = <TimeInterval>[
...input.blockedIntervals,
@ -999,6 +1070,9 @@ SchedulingResult _applyPlacement({
);
}
logger.debug(() => 'Backlog insertion placement applied. '
'insertedTaskId=${insertedTask.id} changeCount=${changes.length} '
'noticeCount=${notices.length}');
return SchedulingResult(
tasks: List<Task>.unmodifiable(updatedTasks),
operationCode:
@ -1092,6 +1166,9 @@ SchedulingResult _applyPushPlacement({
);
}
logger.debug(() => 'Flexible push placement applied. '
'operationCode=${operationCode.name} pushedTaskId=${pushedTask.id} '
'changeCount=${changes.length} noticeCount=${notices.length}');
return SchedulingResult(
tasks: List<Task>.unmodifiable(updatedTasks),
operationCode: operationCode,
@ -1193,6 +1270,8 @@ SchedulingResult _applyRolloverPlacement({
),
);
logger.debug(() => 'Rollover placement applied. rolledCount=$rolledCount '
'changeCount=${changes.length} noticeCount=${notices.length}');
return SchedulingResult(
tasks: List<Task>.unmodifiable(updatedTasks),
operationCode: SchedulingOperationCode.rollOverUnfinishedFlexibleTasks,

14
packages/scheduler_core/lib/src/scheduling/task_actions/services/required_task_action_service.dart
View file

@ -37,7 +37,12 @@ class RequiredTaskActionService {
List<TimeInterval> lockedIntervals = const <TimeInterval>[],
Iterable<TaskActivity> existingActivities = const <TaskActivity>[],
}) {
logger.debug(() => 'Applying required task action. taskId=${task.id} '
'action=${action.name} taskType=${task.type.name} status=${task.status.name} '
'operationId=$operationId');
if (!task.isRequiredVisible) {
logger.error(() => 'Required task action failed: invalid task type. '
'taskId=${task.id} taskType=${task.type.name} action=${action.name}');
throw ArgumentError.value(
task.type,
'task.type',
@ -61,6 +66,10 @@ class RequiredTaskActionService {
RequiredTaskAction.noLongerRelevant => TaskActivityCode.noLongerRelevant,
};
final opId = operationId ?? _defaultOperationId(action.name, task.id, now);
logger.finer(
() => 'Required task action resolved transition. taskId=${task.id} '
'action=${action.name} transition=${transitionCode.name} '
'operationId=$opId');
final transition = transitionService.apply(
task: task,
transitionCode: transitionCode,
@ -73,6 +82,11 @@ class RequiredTaskActionService {
existingActivities: existingActivities,
);
logger.debug(() => 'Required task action finished. taskId=${task.id} '
'action=${action.name} outcome=${transition.outcomeCode.name} '
'activityCount=${transition.activities.length} '
'removedFromActivePlan=${transition.task.status == TaskStatus.backlog || transition.task.status == TaskStatus.cancelled || transition.task.status == TaskStatus.noLongerRelevant}');
return RequiredTaskActionResult(
action: action,
task: transition.task,

34
packages/scheduler_core/lib/src/scheduling/task_actions/services/surprise_task_log_service.dart
View file

@ -39,9 +39,16 @@ class SurpriseTaskLogService {
bool revealHiddenLockedDetails = false,
}) {
final now = updatedAt ?? clock.now();
logger.debug(() => 'Logging surprise task. taskId=${request.id} '
'taskCount=${input.tasks.length} hasStartedAt=${request.startedAt != null} '
'hasDuration=${request.timeUsedMinutes != null} '
'revealHiddenLockedDetails=$revealHiddenLockedDetails');
final existingTask = _taskById(input.tasks, request.id);
if (existingTask != null) {
if (existingTask.type != TaskType.surprise) {
logger.error(() =>
'Surprise task log failed: id already used by another task type. '
'taskId=${request.id} taskType=${existingTask.type.name}');
throw ArgumentError.value(
request.id,
'request.id',
@ -49,6 +56,8 @@ class SurpriseTaskLogService {
);
}
logger.warn(
() => 'Duplicate surprise task log ignored. taskId=${request.id}');
return SurpriseTaskLogResult(
surpriseTask: existingTask,
schedulingResult: SchedulingResult(
@ -82,6 +91,8 @@ class SurpriseTaskLogService {
var currentTasks = <Task>[surpriseTask, ...input.tasks];
if (surpriseInterval == null) {
logger.debug(() => 'Surprise task logged without occupying interval. '
'taskId=${surpriseTask.id} activityCount=1');
return SurpriseTaskLogResult(
surpriseTask: surpriseTask,
schedulingResult: SchedulingResult(
@ -113,6 +124,12 @@ class SurpriseTaskLogService {
final movementNotices = <SchedulingNotice>[];
var usedNormalPushRules = false;
logger.debug(() =>
'Surprise task repair scanning overlaps. taskId=${surpriseTask.id} '
'requiredOverlapCount=${requiredOverlaps.length} '
'lockedOverlapCount=${lockedOverlaps.length} '
'flexibleOverlapCount=${flexibleTaskIds.length}');
for (final taskId in flexibleTaskIds) {
final currentTask = _taskById(currentTasks, taskId);
final currentInterval =
@ -120,9 +137,14 @@ class SurpriseTaskLogService {
if (currentTask == null ||
currentInterval == null ||
!currentInterval.overlaps(surpriseInterval)) {
logger.finer(() => 'Surprise task repair skipped flexible candidate. '
'surpriseTaskId=${surpriseTask.id} taskId=$taskId '
'hasCurrentTask=${currentTask != null} hasInterval=${currentInterval != null}');
continue;
}
logger.finer(() => 'Surprise task repair pushing flexible overlap. '
'surpriseTaskId=${surpriseTask.id} taskId=$taskId');
final pushResult = schedulingEngine.pushFlexibleTaskToNextAvailableSlot(
input: SchedulingInput(
tasks: currentTasks,
@ -157,6 +179,11 @@ class SurpriseTaskLogService {
)
.toList(growable: false);
logger.debug(() => 'Surprise task log finished. taskId=${surpriseTask.id} '
'outcome=${requiredOverlaps.isEmpty ? SchedulingOutcomeCode.success.name : SchedulingOutcomeCode.conflict.name} '
'changeCount=${changes.length} noticeCount=${movementNotices.length + overlapNotices.length + 1} '
'requiredOverlapCount=${requiredOverlaps.length} lockedOverlapCount=${lockedOverlaps.length}');
return SurpriseTaskLogResult(
surpriseTask: _taskById(currentTasks, surpriseTask.id) ?? surpriseTask,
schedulingResult: SchedulingResult(
@ -196,10 +223,15 @@ class SurpriseTaskLogService {
}) {
final generator = idGenerator;
if (generator == null) {
logger.error(() => 'Surprise task logNew failed: missing id generator.');
throw StateError('Surprise task logging needs an id generator.');
}
final now = createdAt ?? updatedAt ?? clock.now();
logger.debug(() =>
'Logging new surprise task. hasTitle=${title.trim().isNotEmpty} '
'hasStartedAt=${startedAt != null} hasDuration=${timeUsedMinutes != null} '
'projectId=$projectId');
return log(
request: SurpriseTaskLogRequest(
@ -227,6 +259,8 @@ class SurpriseTaskLogService {
}) {
final trimmedTitle = request.title.trim();
if (trimmedTitle.isEmpty) {
logger.warn(() => 'Surprise task creation failed: blank title. '
'taskId=${request.id}');
throw ArgumentError.value(request.title, 'title', 'Title is required.');
}

1
packages/scheduler_core/lib/src/scheduling/task_lifecycle.dart
View file

@ -13,6 +13,7 @@ library;
import '../domain/models.dart';
import '../domain/task_statistics.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'task_lifecycle/codes/task_transition_code.dart';
part 'task_lifecycle/codes/task_activity_code.dart';
part 'task_lifecycle/codes/task_transition_outcome_code.dart';

32
packages/scheduler_core/lib/src/scheduling/task_lifecycle/services/task_transition_service.dart
View file

@ -37,12 +37,19 @@ class TaskTransitionService {
Map<String, Object?> metadata = const <String, Object?>{},
}) {
final now = occurredAt ?? clock.now();
logger.debug(() => 'Applying task transition. '
'taskId=${task.id} transition=${transitionCode.name} '
'operationId=$operationId taskStatus=${task.status.name} '
'occurredAt=${now.toIso8601String()}');
final duplicate = _duplicateActivity(
existingActivities: existingActivities,
taskId: task.id,
operationId: operationId,
);
if (duplicate != null) {
logger.warn(() => 'Duplicate task transition ignored. '
'taskId=${task.id} transition=${transitionCode.name} '
'operationId=$operationId duplicateActivityId=${duplicate.id}');
return TaskTransitionResult(
transitionCode: transitionCode,
outcomeCode: TaskTransitionOutcomeCode.duplicateOperation,
@ -52,6 +59,10 @@ class TaskTransitionService {
}
if (!_actualIntervalShapeIsValid(actualStart, actualEnd)) {
logger.warn(() => 'Task transition rejected: invalid actual interval. '
'taskId=${task.id} transition=${transitionCode.name} '
'actualStart=${actualStart?.toIso8601String()} '
'actualEnd=${actualEnd?.toIso8601String()}');
return TaskTransitionResult(
transitionCode: transitionCode,
outcomeCode: TaskTransitionOutcomeCode.invalidState,
@ -60,6 +71,9 @@ class TaskTransitionService {
}
if (_isNoOpTerminalRepeat(task, transitionCode)) {
logger.fine(() => 'Possible issue: terminal task transition repeated. '
'taskId=${task.id} transition=${transitionCode.name} '
'taskStatus=${task.status.name}');
return TaskTransitionResult(
transitionCode: transitionCode,
outcomeCode: TaskTransitionOutcomeCode.noOp,
@ -68,6 +82,10 @@ class TaskTransitionService {
}
if (_isBlockedByTerminalState(task, transitionCode)) {
logger.warn(
() => 'Task transition rejected: terminal state blocks transition. '
'taskId=${task.id} transition=${transitionCode.name} '
'taskStatus=${task.status.name}');
return TaskTransitionResult(
transitionCode: transitionCode,
outcomeCode: TaskTransitionOutcomeCode.invalidState,
@ -75,7 +93,7 @@ class TaskTransitionService {
);
}
return switch (transitionCode) {
final result = switch (transitionCode) {
TaskTransitionCode.complete => _complete(
task: task,
operationId: operationId,
@ -156,6 +174,16 @@ class TaskTransitionService {
metadata: metadata,
),
};
logger.debug(() => 'Task transition finished. taskId=${task.id} '
'transition=${transitionCode.name} outcome=${result.outcomeCode.name} '
'nextStatus=${result.task.status.name} activityCount=${result.activities.length}');
if (result.outcomeCode == TaskTransitionOutcomeCode.invalidState) {
logger.warn(() => 'Task transition returned invalid state. '
'taskId=${task.id} transition=${transitionCode.name} '
'taskType=${task.type.name} previousStatus=${task.status.name} '
'nextStatus=${result.task.status.name}');
}
return result;
}
/// Runs the `_complete` helper used inside this library.
@ -751,6 +779,8 @@ TaskTransitionResult _invalid(Task task, TaskTransitionCode transitionCode) {
/// Top-level helper that performs the `_noOp` operation for this file.
/// Keeping the helper private makes the surrounding flow easier to read while preventing unrelated libraries from depending on implementation detail.
TaskTransitionResult _noOp(Task task, TaskTransitionCode transitionCode) {
logger.fine(() => 'Possible issue: task transition no-op. taskId=${task.id} '
'transition=${transitionCode.name} taskStatus=${task.status.name}');
return TaskTransitionResult(
transitionCode: transitionCode,
outcomeCode: TaskTransitionOutcomeCode.noOp,

1
packages/scheduler_core/lib/src/scheduling/today_state.dart
View file

@ -17,6 +17,7 @@ import '../persistence/repositories.dart';
import 'scheduling_engine.dart';
import 'timeline_state.dart';
import '../domain/time_contracts.dart';
import '../logging/focus_flow_logger.dart';
part 'today_state/models/today_timeline_item_source.dart';
part 'today_state/requests/get_today_state_request.dart';
part 'today_state/models/today_timeline_item.dart';

22
packages/scheduler_core/lib/src/scheduling/today_state/queries/get_today_state_query.dart
View file

@ -30,6 +30,10 @@ class GetTodayStateQuery {
action: (repositories) async {
final context = request.context;
final ownerId = context.ownerTimeZone.ownerId;
logger.debug(() => 'Today state query started. '
'ownerId=$ownerId date=${request.date.toIsoString()} '
'revealHiddenLockedBlocks=${request.revealHiddenLockedBlocks} '
'includeNextFlexibleItem=${request.includeNextFlexibleItem}');
final storedSettings =
await repositories.ownerSettings.findByOwnerId(ownerId);
final settings = storedSettings ??
@ -37,6 +41,11 @@ class GetTodayStateQuery {
ownerId: ownerId,
timeZoneId: context.ownerTimeZone.timeZoneId,
);
if (storedSettings == null) {
logger.finer(() =>
'Today state query owner settings missing; using defaults. '
'ownerId=$ownerId timeZoneId=${context.ownerTimeZone.timeZoneId}');
}
final timeZoneId = settings.timeZoneId;
final dayStart = _resolve(
date: request.date,
@ -76,6 +85,12 @@ class GetTodayStateQuery {
(await repositories.noticeAcknowledgements.findByOwnerId(ownerId))
.map((record) => record.noticeId)
.toSet();
logger.debug(() => 'Today state query loaded persisted inputs. '
'ownerId=$ownerId date=${request.date.toIsoString()} '
'projectCount=${projects.length} taskCount=${tasks.length} '
'lockedBlockCount=${blocks.length} overrideCount=${overrides.length} '
'snapshotCount=${snapshots.length} '
'acknowledgedNoticeCount=${acknowledgedNoticeIds.length}');
final lockedExpansion = expandLockedBlocksForDay(
blocks: blocks,
@ -138,6 +153,13 @@ class GetTodayStateQuery {
snapshots,
acknowledgedNoticeIds: acknowledgedNoticeIds,
);
logger.debug(() => 'Today state query finished. '
'ownerId=$ownerId date=${request.date.toIsoString()} '
'timelineItemCount=${selectedItems.length} '
'pendingNoticeCount=${pendingNotices.length} '
'hasCurrent=${selectedCurrent != null} '
'hasNextRequired=${selectedNextRequired != null} '
'hasNextFlexible=${selectedNextFlexible != null}');
return ApplicationResult.success(
TodayState(

19
packages/scheduler_export/lib/src/export_controller/controller/export_controller.dart
View file

@ -27,6 +27,8 @@ final class ExportController {
required StringSink sink,
int pageSize = 100,
}) {
core.logger.info(() => 'Task export to sink requested. '
'ownerId=${context.ownerId.value} format=$format pageSize=$pageSize');
final writer = _writerRegistry.create(format, sink);
return exportTasks(
context: context,
@ -41,11 +43,18 @@ final class ExportController {
required ExportWriter writer,
int pageSize = 100,
}) async {
core.logger.info(() => 'Task export started. '
'ownerId=${context.ownerId.value} timezone=${context.timezone} '
'version=${context.version} pageSize=$pageSize');
if (pageSize <= 0) {
core.logger.warn(() => 'Task export rejected invalid page size. '
'ownerId=${context.ownerId.value} pageSize=$pageSize');
throw ArgumentError.value(pageSize, 'pageSize', 'Must be positive.');
}
await writer.begin(context);
var pageCount = 0;
var taskCount = 0;
String? cursor;
do {
final result = await _taskRepository.findByOwner(
@ -53,14 +62,24 @@ final class ExportController {
page: core.PageRequest(cursor: cursor, limit: pageSize),
);
if (result.isLeft) {
core.logger.warn(() => 'Task export repository read failed. '
'ownerId=${context.ownerId.value} pageCount=$pageCount '
'taskCount=$taskCount failureType=${result.left.runtimeType}');
throw ExportRepositoryException(result.left);
}
final page = result.right;
pageCount += 1;
core.logger.finer(() => 'Task export page loaded. '
'ownerId=${context.ownerId.value} pageNumber=$pageCount '
'itemCount=${page.items.length} hasNext=${page.nextCursor != null}');
for (final task in page.items) {
await writer.writeTask(task);
taskCount += 1;
}
cursor = page.nextCursor;
} while (cursor != null);
await writer.end();
core.logger.info(() => 'Task export completed. '
'ownerId=${context.ownerId.value} pageCount=$pageCount taskCount=$taskCount');
}
}

7
packages/scheduler_export/lib/src/export_controller/writers/registry/export_writer_registry.dart
View file

@ -34,7 +34,9 @@ final class ExportWriterRegistry {
/// Register [factory] for [format].
void register(String format, ExportWriterFactory factory) {
_factories[_normalizeFormat(format)] = factory;
final normalized = _normalizeFormat(format);
core.logger.finer(() => 'Export writer registered. format=$normalized');
_factories[normalized] = factory;
}
/// Create a writer for [format] using [sink].
@ -42,8 +44,11 @@ final class ExportWriterRegistry {
final normalized = _normalizeFormat(format);
final factory = _factories[normalized];
if (factory == null) {
core.logger.warn(() => 'Export writer lookup failed: unknown format. '
'format=$normalized availableFormatCount=${_factories.length}');
throw ExportException('Unknown export format: $format');
}
core.logger.finer(() => 'Export writer created. format=$normalized');
return factory(sink);
}
}

2
packages/scheduler_export_json/lib/src/json_csv_writers.dart
View file

@ -15,6 +15,8 @@ part 'json_csv_writers/csv_export_writer.dart';
/// Create the readable export writer registry used by export commands.
ExportWriterRegistry readableExportWriterRegistry() {
core.logger
.finer(() => 'Readable export writer registry created. formatCount=2');
return ExportWriterRegistry(
factories: <String, ExportWriterFactory>{
'json': JsonExportWriter.new,

1
packages/scheduler_notifications/lib/src/notification_adapter.dart
View file

@ -5,6 +5,7 @@
library;
import 'dart:async';
import 'package:scheduler_core/scheduler_core.dart' show logger;
part 'notification_adapter/requests/notification_request.dart';
part 'notification_adapter/requests/notification_request_impl.dart';
part 'notification_adapter/feedback/notification_feedback_type.dart';

12
packages/scheduler_notifications/lib/src/notification_adapter/adapter/fake_notification_adapter.dart
View file

@ -35,6 +35,9 @@ final class FakeNotificationAdapter implements NotificationAdapter {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> schedule(NotificationRequest request) async {
logger.debug(() => 'Fake notification scheduled. '
'notificationId=${request.id} '
'scheduledDateTimeUtc=${request.scheduledDateTimeUtc.toIso8601String()}');
_scheduled[request.id] = request;
}
@ -43,17 +46,24 @@ final class FakeNotificationAdapter implements NotificationAdapter {
@override
Future<void> cancel(String id) async {
final trimmed = _requiredTrimmed(id, 'id');
_scheduled.remove(trimmed);
final removed = _scheduled.remove(trimmed) != null;
_cancelledIds.add(trimmed);
logger.debug(() => 'Fake notification cancelled. '
'notificationId=$trimmed removed=$removed');
}
/// Emit [event] to feedback listeners.
void emitFeedback(NotificationFeedback event) {
logger.debug(() => 'Fake notification feedback emitted. '
'notificationId=${event.id} type=${event.type.name} '
'hasAction=${event.actionId != null}');
_feedbackController.add(event);
}
/// Release stream resources held by this fake.
Future<void> close() {
logger.debug(() => 'Fake notification adapter closing. '
'scheduledCount=${_scheduled.length} cancelledCount=${_cancelledIds.length}');
return _feedbackController.close();
}
}

3
packages/scheduler_notifications/pubspec.yaml
View file

@ -10,6 +10,9 @@ resolution: workspace
environment:
sdk: '>=3.6.0 <4.0.0'
dependencies:
scheduler_core: any
dev_dependencies:
lints: ^5.0.0
test: ^1.25.0

1
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_io.dart
View file

@ -9,6 +9,7 @@ import 'dart:convert';
import 'dart:io';
import 'package:scheduler_notifications/notifications.dart';
import 'package:scheduler_core/scheduler_core.dart' show logger;
part 'desktop_notification_adapter_io/platform/desktop_notification_platform.dart';
part 'desktop_notification_adapter_io/callbacks/desktop_notification_log_sink.dart';
part 'desktop_notification_adapter_io/callbacks/desktop_process_runner.dart';

12
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_io/adapter/desktop_notification_adapter.dart
View file

@ -19,6 +19,9 @@ final class DesktopNotificationAdapter implements NotificationAdapter {
DesktopProcessRunner? processRunner,
DesktopNotificationLogSink? logSink,
}) {
logger.info(() => 'Creating desktop notification adapter. '
'requestedPlatform=${platform?.name} hasCustomRunner=${processRunner != null} '
'hasCustomLogSink=${logSink != null}');
return DesktopNotificationAdapter(
backend: createDefaultDesktopNotificationBackend(
platform: platform,
@ -37,6 +40,10 @@ final class DesktopNotificationAdapter implements NotificationAdapter {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> schedule(NotificationRequest request) {
logger.debug(() => 'Desktop notification schedule requested. '
'notificationId=${request.id} '
'scheduledDateTimeUtc=${request.scheduledDateTimeUtc.toIso8601String()} '
'backendSupported=${_backend.isSupported}');
return _backend.deliver(request);
}
@ -44,6 +51,9 @@ final class DesktopNotificationAdapter implements NotificationAdapter {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> cancel(String id) {
return _backend.cancel(id.trim());
final trimmed = id.trim();
logger.debug(() => 'Desktop notification cancel requested. '
'notificationId=$trimmed backendSupported=${_backend.isSupported}');
return _backend.cancel(trimmed);
}
}

3
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_io/backends/core/desktop_notification_backend_factory.dart
View file

@ -15,6 +15,9 @@ DesktopNotificationBackend createDefaultDesktopNotificationBackend({
logSink: logSink ?? stdout.writeln,
platform: resolvedPlatform,
);
logger.info(() => 'Resolved desktop notification backend. '
'platform=${resolvedPlatform.name} hasCustomRunner=${processRunner != null} '
'hasCustomLogSink=${logSink != null}');
return switch (resolvedPlatform) {
DesktopNotificationPlatform.linux => LinuxNotifySendBackend(

7
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_io/backends/fallback/stdout_notification_backend.dart
View file

@ -27,6 +27,8 @@ final class StdoutNotificationBackend implements DesktopNotificationBackend {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> deliver(NotificationRequest request) async {
logger.warn(() => 'Desktop notification fallback delivery used. '
'platform=${platform.name} notificationId=${request.id}');
_logSink(
'notification[$platform] ${request.id}: ${request.title} - '
'${request.body}',
@ -37,6 +39,9 @@ final class StdoutNotificationBackend implements DesktopNotificationBackend {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> cancel(String id) async {
_logSink('notification[$platform] cancel: ${id.trim()}');
final trimmed = id.trim();
logger.finer(() => 'Desktop notification fallback cancel used. '
'platform=${platform.name} notificationId=$trimmed');
_logSink('notification[$platform] cancel: $trimmed');
}
}

17
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_io/backends/platform/linux_notify_send_backend.dart
View file

@ -29,6 +29,8 @@ final class LinuxNotifySendBackend implements DesktopNotificationBackend {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> deliver(NotificationRequest request) async {
logger.debug(() => 'Linux notification delivery requested. '
'notificationId=${request.id} backend=notify-send');
await _runOrFallback(
request,
() => _processRunner('notify-send', <String>[
@ -43,6 +45,8 @@ final class LinuxNotifySendBackend implements DesktopNotificationBackend {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> cancel(String id) async {
logger.finer(() => 'Linux notification cancel delegated to fallback. '
'notificationId=${id.trim()}');
await _fallback.cancel(id);
}
@ -55,9 +59,20 @@ final class LinuxNotifySendBackend implements DesktopNotificationBackend {
try {
final result = await run();
if (result.exitCode != 0) {
logger.warn(() => 'Linux notification command failed; using fallback. '
'notificationId=${request.id} exitCode=${result.exitCode}');
await _fallback.deliver(request);
} else {
logger.debug(() => 'Linux notification command completed. '
'notificationId=${request.id} exitCode=${result.exitCode}');
}
} on ProcessException {
} on ProcessException catch (error, stackTrace) {
logger.warn(
() => 'Linux notification command unavailable; using fallback. '
'notificationId=${request.id}',
error: error,
stackTrace: stackTrace,
);
await _fallback.deliver(request);
}
}

17
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_io/backends/platform/mac_os_notification_backend.dart
View file

@ -29,14 +29,27 @@ final class MacOsNotificationBackend implements DesktopNotificationBackend {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> deliver(NotificationRequest request) async {
logger.debug(() => 'macOS notification delivery requested. '
'notificationId=${request.id} backend=osascript');
final script = 'display notification ${_appleScriptString(request.body)} '
'with title ${_appleScriptString(request.title)}';
try {
final result = await _processRunner('osascript', <String>['-e', script]);
if (result.exitCode != 0) {
logger.warn(() => 'macOS notification command failed; using fallback. '
'notificationId=${request.id} exitCode=${result.exitCode}');
await _fallback.deliver(request);
} else {
logger.debug(() => 'macOS notification command completed. '
'notificationId=${request.id} exitCode=${result.exitCode}');
}
} on ProcessException {
} on ProcessException catch (error, stackTrace) {
logger.warn(
() => 'macOS notification command unavailable; using fallback. '
'notificationId=${request.id}',
error: error,
stackTrace: stackTrace,
);
await _fallback.deliver(request);
}
}
@ -45,6 +58,8 @@ final class MacOsNotificationBackend implements DesktopNotificationBackend {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> cancel(String id) async {
logger.finer(() => 'macOS notification cancel delegated to fallback. '
'notificationId=${id.trim()}');
await _fallback.cancel(id);
}
}

1
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_stub.dart
View file

@ -7,6 +7,7 @@ library;
import 'dart:async';
import 'package:scheduler_notifications/notifications.dart';
import 'package:scheduler_core/scheduler_core.dart' show logger;
part 'desktop_notification_adapter_stub/platform/desktop_notification_platform.dart';
part 'desktop_notification_adapter_stub/callbacks/desktop_notification_log_sink.dart';
part 'desktop_notification_adapter_stub/backends/desktop_notification_backend.dart';

12
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_stub/adapter/desktop_notification_adapter.dart
View file

@ -19,6 +19,9 @@ final class DesktopNotificationAdapter implements NotificationAdapter {
Object? processRunner,
DesktopNotificationLogSink? logSink,
}) {
logger.info(() => 'Creating stub desktop notification adapter. '
'requestedPlatform=${platform?.name} hasCustomRunner=${processRunner != null} '
'hasCustomLogSink=${logSink != null}');
return DesktopNotificationAdapter(
backend: createDefaultDesktopNotificationBackend(
platform: platform,
@ -37,6 +40,10 @@ final class DesktopNotificationAdapter implements NotificationAdapter {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> schedule(NotificationRequest request) {
logger.debug(() => 'Stub desktop notification schedule requested. '
'notificationId=${request.id} '
'scheduledDateTimeUtc=${request.scheduledDateTimeUtc.toIso8601String()} '
'backendSupported=${_backend.isSupported}');
return _backend.deliver(request);
}
@ -44,6 +51,9 @@ final class DesktopNotificationAdapter implements NotificationAdapter {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> cancel(String id) {
return _backend.cancel(id.trim());
final trimmed = id.trim();
logger.debug(() => 'Stub desktop notification cancel requested. '
'notificationId=$trimmed backendSupported=${_backend.isSupported}');
return _backend.cancel(trimmed);
}
}

6
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_stub/backends/desktop_notification_backend_factory.dart
View file

@ -9,8 +9,12 @@ DesktopNotificationBackend createDefaultDesktopNotificationBackend({
Object? processRunner,
DesktopNotificationLogSink? logSink,
}) {
final resolvedPlatform = platform ?? DesktopNotificationPlatform.unsupported;
logger.info(() => 'Resolved stub desktop notification backend. '
'platform=${resolvedPlatform.name} hasCustomRunner=${processRunner != null} '
'hasCustomLogSink=${logSink != null}');
return StdoutNotificationBackend(
logSink: logSink ?? _defaultLogSink,
platform: platform ?? DesktopNotificationPlatform.unsupported,
platform: resolvedPlatform,
);
}

7
packages/scheduler_notifications_desktop/lib/src/desktop_notification_adapter_stub/backends/stdout_notification_backend.dart
View file

@ -27,6 +27,8 @@ final class StdoutNotificationBackend implements DesktopNotificationBackend {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> deliver(NotificationRequest request) async {
logger.warn(() => 'Stub desktop notification fallback delivery used. '
'platform=${platform.name} notificationId=${request.id}');
_logSink(
'notification[$platform] ${request.id}: ${request.title} - '
'${request.body}',
@ -37,6 +39,9 @@ final class StdoutNotificationBackend implements DesktopNotificationBackend {
/// Callers should await the returned future so repository writes, UI refreshes, and failure handling happen in a predictable order.
@override
Future<void> cancel(String id) async {
_logSink('notification[$platform] cancel: ${id.trim()}');
final trimmed = id.trim();
logger.finer(() => 'Stub desktop notification fallback cancel used. '
'platform=${platform.name} notificationId=$trimmed');
_logSink('notification[$platform] cancel: $trimmed');
}
}

1
packages/scheduler_notifications_desktop/pubspec.yaml
View file

@ -11,6 +11,7 @@ environment:
sdk: '>=3.6.0 <4.0.0'
dependencies:
scheduler_core: any
scheduler_notifications: any
dev_dependencies:

12
packages/scheduler_persistence_memory/lib/persistence_memory/repositories/in_memory_schedule_snapshot_repository.dart
View file

@ -94,6 +94,9 @@ Either<RepositoryFailure, _Record<T>> _checkWrite<T>({
required core.Revision expectedRevision,
}) {
if (expectedRevision.value <= 0) {
core.logger.warn(() =>
'In-memory repository write rejected invalid revision. '
'entityId=$id ownerId=${ownerId.value} expectedRevision=${expectedRevision.value}');
return Left(
RepositoryInvalidRevision(
entityId: id,
@ -103,12 +106,21 @@ Either<RepositoryFailure, _Record<T>> _checkWrite<T>({
}
final record = records[id];
if (record == null) {
core.logger.warn(() => 'In-memory repository write target missing. '
'entityId=$id ownerId=${ownerId.value} expectedRevision=${expectedRevision.value}');
return Left(RepositoryNotFound(entityId: id));
}
if (record.ownerId != ownerId) {
core.logger.warn(() =>
'In-memory repository write rejected owner mismatch. '
'entityId=$id ownerId=${ownerId.value} recordOwnerId=${record.ownerId.value}');
return Left(RepositoryOwnerMismatch(entityId: id));
}
if (record.revision != expectedRevision) {
core.logger.warn(() =>
'In-memory repository write rejected stale revision. '
'entityId=$id ownerId=${ownerId.value} expectedRevision=${expectedRevision.value} '
'actualRevision=${record.revision.value}');
return Left(
RepositoryStaleRevision(
entityId: id,

22
packages/scheduler_persistence_sqlite/lib/src/sqlite_application/sqlite_application_runtime.dart
View file

@ -28,12 +28,17 @@ final class SqliteApplicationRuntime {
required String path,
String defaultOwnerId = defaultV1OwnerId,
}) async {
core.logger.info(() => 'Opening SQLite application runtime. '
'path=$path defaultOwnerId=$defaultOwnerId');
final file = File(path);
await file.parent.create(recursive: true);
return SqliteApplicationRuntime(
final runtime = SqliteApplicationRuntime(
db: SchedulerDb(NativeDatabase(file)),
defaultOwnerId: defaultOwnerId,
);
core.logger.info(() => 'SQLite application runtime opened. '
'path=$path defaultOwnerId=$defaultOwnerId');
return runtime;
}
/// Shared SQLite database handle.
@ -48,6 +53,8 @@ final class SqliteApplicationRuntime {
String timeZoneId = defaultV1TimeZoneId,
String defaultProjectId = defaultV1ProjectId,
}) {
core.logger.info(() => 'SQLite application bootstrap started. '
'ownerId=$ownerId timeZoneId=$timeZoneId defaultProjectId=$defaultProjectId');
return _guardApplicationErrors(() {
return db.transaction(() async {
final repositories = _SqliteApplicationRepositories(
@ -58,6 +65,8 @@ final class SqliteApplicationRuntime {
ownerId,
);
if (settings == null) {
core.logger.finer(() => 'SQLite bootstrap creating owner settings. '
'ownerId=$ownerId timeZoneId=$timeZoneId');
await repositories.ownerSettings.save(
core.OwnerSettings(
ownerId: ownerId,
@ -69,6 +78,8 @@ final class SqliteApplicationRuntime {
final project = await repositories.projects.findById(defaultProjectId);
if (project == null) {
core.logger.finer(() => 'SQLite bootstrap creating default project. '
'ownerId=$ownerId projectId=$defaultProjectId');
await repositories.projects.save(
core.ProjectProfile(
id: defaultProjectId,
@ -78,13 +89,18 @@ final class SqliteApplicationRuntime {
);
}
core.logger.info(() => 'SQLite application bootstrap completed. '
'ownerId=$ownerId createdSettings=${settings == null} '
'createdProject=${project == null}');
return core.ApplicationResult.success(null);
});
});
}
/// Closes the underlying SQLite database.
Future<void> close() {
return db.close();
Future<void> close() async {
core.logger.info(() => 'Closing SQLite application runtime.');
await db.close();
core.logger.info(() => 'SQLite application runtime closed.');
}
}

58
packages/scheduler_persistence_sqlite/lib/src/sqlite_application/sqlite_application_unit_of_work.dart
View file

@ -26,6 +26,9 @@ final class SqliteApplicationUnitOfWork implements core.ApplicationUnitOfWork {
core.ApplicationUnitOfWorkRepositories repositories,
) action,
}) {
core.logger.debug(() => 'SQLite unit of work run started. '
'operationId=${context.operationId} operationName=$operationName '
'ownerId=${context.ownerTimeZone.ownerId}');
return _guardApplicationErrors(() {
return db.transaction(() async {
final repositories = _SqliteApplicationRepositories(
@ -36,6 +39,9 @@ final class SqliteApplicationUnitOfWork implements core.ApplicationUnitOfWork {
context.operationId,
);
if (existing != null) {
core.logger.warn(() =>
'Duplicate operation ignored by SQLite unit of work. '
'operationId=${context.operationId} operationName=$operationName');
return core.ApplicationResult.failure(
core.ApplicationFailure(
code: core.ApplicationFailureCode.duplicateOperation,
@ -46,6 +52,10 @@ final class SqliteApplicationUnitOfWork implements core.ApplicationUnitOfWork {
final result = await action(repositories);
if (result.isFailure) {
core.logger.warn(() => 'SQLite unit of work action returned failure. '
'operationId=${context.operationId} operationName=$operationName '
'code=${result.failure!.code.name} '
'detailCode=${result.failure!.detailCode}');
return result;
}
@ -58,6 +68,9 @@ final class SqliteApplicationUnitOfWork implements core.ApplicationUnitOfWork {
),
);
if (!operationResult.isSuccess) {
core.logger.warn(() =>
'SQLite unit of work operation record insert conflicted. '
'operationId=${context.operationId} operationName=$operationName');
return core.ApplicationResult.failure(
core.ApplicationFailure(
code: core.ApplicationFailureCode.duplicateOperation,
@ -66,6 +79,8 @@ final class SqliteApplicationUnitOfWork implements core.ApplicationUnitOfWork {
);
}
core.logger.debug(() => 'SQLite unit of work run committed. '
'operationId=${context.operationId} operationName=$operationName');
return result;
});
});
@ -78,13 +93,23 @@ final class SqliteApplicationUnitOfWork implements core.ApplicationUnitOfWork {
core.ApplicationUnitOfWorkRepositories repositories,
) action,
}) {
return _guardApplicationErrors(() {
return action(
core.logger.debug(() => 'SQLite unit of work read started. '
'defaultOwnerId=$defaultOwnerId');
return _guardApplicationErrors(() async {
final result = await action(
_SqliteApplicationRepositories(
db,
defaultOwnerId: defaultOwnerId,
),
);
if (result.isFailure) {
core.logger.warn(() => 'SQLite unit of work read returned failure. '
'code=${result.failure!.code.name} detailCode=${result.failure!.detailCode}');
} else {
core.logger.debug(() => 'SQLite unit of work read finished. '
'defaultOwnerId=$defaultOwnerId');
}
return result;
});
}
}
@ -96,8 +121,13 @@ Future<core.ApplicationResult<T>> _guardApplicationErrors<T>(
try {
return await action();
} on core.ApplicationFailureException catch (error) {
core.logger.warn(() => 'SQLite application caught application failure. '
'code=${error.failure.code.name} detailCode=${error.failure.detailCode}');
return core.ApplicationResult.failure(error.failure);
} on core.DomainValidationException catch (error) {
core.logger
.warn(() => 'SQLite application caught domain validation failure. '
'code=${error.code.name}');
return core.ApplicationResult.failure(
core.ApplicationFailure(
code: core.ApplicationFailureCode.validation,
@ -105,25 +135,43 @@ Future<core.ApplicationResult<T>> _guardApplicationErrors<T>(
),
);
} on ArgumentError catch (error) {
core.logger
.warn(() => 'SQLite application caught argument validation failure. '
'argumentName=${error.name}');
return core.ApplicationResult.failure(
core.ApplicationFailure(
code: core.ApplicationFailureCode.validation,
detailCode: error.name,
),
);
} on core.ApplicationPersistenceException {
} on core.ApplicationPersistenceException catch (error, stackTrace) {
core.logger.error(
() => 'SQLite application persistence failure.',
error: error,
stackTrace: stackTrace,
);
return core.ApplicationResult.failure(
const core.ApplicationFailure(
code: core.ApplicationFailureCode.persistenceFailure,
),
);
} on sqlite.SqliteException catch (_) {
} on sqlite.SqliteException catch (error, stackTrace) {
core.logger.error(
() => 'SQLite database operation failed. errorType=${error.runtimeType}',
error: error,
stackTrace: stackTrace,
);
return core.ApplicationResult.failure(
const core.ApplicationFailure(
code: core.ApplicationFailureCode.persistenceFailure,
),
);
} catch (_) {
} catch (error, stackTrace) {
core.logger.error(
() => 'SQLite application unexpected failure.',
error: error,
stackTrace: stackTrace,
);
return core.ApplicationResult.failure(
const core.ApplicationFailure(
code: core.ApplicationFailureCode.unexpected),