From 354404060450ec8ffb6c8e7ce7cf10fe60fb1cd4 Mon Sep 17 00:00:00 2001 From: dimeloper Date: Thu, 6 Nov 2025 17:34:10 +0200 Subject: [PATCH] Improve logging and showcase state rollback. --- README.md | 67 ++++++++--- .../pages/task-board/task-board.component.ts | 18 ++- src/app/services/task.service.ts | 25 ++-- src/app/stores/shared/with-event-logging.ts | 5 +- src/app/stores/task-store/task.effects.ts | 26 ++-- src/app/stores/task-store/task.events.ts | 6 +- src/app/stores/task-store/task.reducer.ts | 67 ++++++++--- src/app/stores/task-store/task.store.spec.ts | 112 ++++++++++++++++-- 8 files changed, 256 insertions(+), 70 deletions(-) diff --git a/README.md b/README.md index b861e3c..5ff3b79 100644 --- a/README.md +++ b/README.md @@ -207,47 +207,76 @@ src/ ### Logging System -The application includes comprehensive logging to visualize the complete event flow through the Flux architecture. Event logging is implemented as a reusable store feature (`withEventLogging`) that can be composed into any store. +The application includes comprehensive logging to visualize the complete event flow through the Flux architecture. Logs are strategically placed at each layer to show the unidirectional data flow. #### Log Prefixes ```text -[Service - Request] - Outgoing API calls -[Service - Response] - API responses - -[Store Event] [event group] [event name] - All events flowing through the store -[Task Store] Response from getTasks - Raw service response (in effects) -[Task Store] Dispatching [event name] - Event being dispatched (in effects) +[Component] Dispatching: [event name] - Event dispatched from UI component +[Event → Reducer] [description] - Event being processed by reducer (synchronous) +[Event → Effect] [event group] [event] - Event reaching effects (asynchronous) +[Effect] [description] - Effect internal operations +[Service - Response] [description] - API/Service responses ``` +#### Execution Order + +The logs reveal NgRx Signals' internal execution model: + +1. **Component dispatches** - User action initiates the flow +2. **Reducers process first** - Synchronous state updates happen immediately +3. **Effects run after** - Asynchronous side effects (logging, API calls) execute +4. **Service responds** - External operations complete +5. **Success events flow** - Results trigger new reducer and effect cycles + The `withEventLogging` feature automatically: - Logs all events from specified event groups using `Object.values()` - Detects error events (containing "Failure") and logs with `console.error` +- Runs as an effect, so logs appear after reducers process events - Requires no maintenance when new events are added #### Example Event Flow -**Loading tasks:** +**Changing task status (optimistic update):** ```text -1. [Store Event] [Task Page] opened (User action) -2. [Service - Request] Fetching tasks (Effect triggers API) -3. [Service - Response] Tasks fetched (API responds) -4. [Task Store] Dispatching tasksLoadedSuccess (Effect dispatches result) -5. [Store Event] [Task API] tasksLoadedSuccess (Event logged) +1. [Component] Dispatching: taskStatusChanged (User clicks to move task) + {id: '1', status: 'in-progress'} + +2. [Event → Reducer] Task status changed (optimistic) (State updated immediately) + {taskId: '1', newStatus: 'in-progress'} + +3. [Event → Effect] [Task Page] taskStatusChanged (Event logger effect runs) + {id: '1', status: 'in-progress'} + +4. [Service - Response] Task status updated successfully (API confirms change) + +5. [Event → Effect] [Task API] taskStatusChangedSuccess (Success event logged) + {id: '1', status: 'in-progress'} ``` -**Creating a task:** +**Loading tasks:** ```text -1. [Store Event] [Task Page] taskCreated (User action) -2. [Service - Request] Creating task (Effect triggers API) -3. [Service - Response] Task created (API responds) -4. [Store Event] [Task API] taskCreatedSuccess (Result event) +1. [Component] Dispatching: opened (Page initializes) + +2. [Event → Reducer] Page opened - setting isLoading: true (Loading state set) + +3. [Event → Effect] [Task Page] opened (Event logger) + +4. [Effect] Response from getTasks (Service responds) + {tasks: [...], totalPages: 1} + +5. [Effect] Dispatching tasksLoadedSuccess (Effect dispatches result) + +6. [Event → Reducer] Tasks loaded successfully (State updated with tasks) + {count: 10, taskIds: ['1', '2', ...]} + +7. [Event → Effect] [Task API] tasksLoadedSuccess (Success event logged) ``` -This logging pattern makes it easy to trace the complete lifecycle of any user action through the system. +This logging pattern makes it easy to trace the complete lifecycle of any user action through the system and understand the order of execution in the Flux architecture. ## Testing diff --git a/src/app/pages/task-board/task-board.component.ts b/src/app/pages/task-board/task-board.component.ts index 0ac46f1..1205bcf 100644 --- a/src/app/pages/task-board/task-board.component.ts +++ b/src/app/pages/task-board/task-board.component.ts @@ -38,6 +38,7 @@ export class TaskBoardComponent { constructor() { // Dispatch the 'opened' event when component initializes // This triggers the effect to load tasks + console.log('[Component] Dispatching: opened'); this.dispatch.opened(); } @@ -52,6 +53,7 @@ export class TaskBoardComponent { // Dispatch event: task.effects.ts handles the API call // task.reducer.ts updates the store state on success + console.log('[Component] Dispatching: taskCreated', newTask); this.dispatch.taskCreated(newTask); this.taskForm.reset(); } @@ -59,13 +61,27 @@ export class TaskBoardComponent { deleteTask(taskId: string) { if (confirm('Are you sure you want to delete this task?')) { // Dispatch event: handled by effects and reducer + console.log('[Component] Dispatching: taskDeleted', { taskId }); this.dispatch.taskDeleted(taskId); } } moveTo(taskId: string, targetStatus: TaskStatus) { + // Capture current status before dispatching for potential rollback + const task = this.store.taskEntities().find(t => t.id === taskId); + const previousStatus = task?.status; + // Dispatch event: optimistic update by reducer // Effects handle API call and revert on failure - this.dispatch.taskStatusChanged({ id: taskId, status: targetStatus }); + console.log('[Component] Dispatching: taskStatusChanged', { + id: taskId, + status: targetStatus, + previousStatus, + }); + this.dispatch.taskStatusChanged({ + id: taskId, + status: targetStatus, + previousStatus: previousStatus!, + }); } } diff --git a/src/app/services/task.service.ts b/src/app/services/task.service.ts index c1e3ddf..3392efc 100644 --- a/src/app/services/task.service.ts +++ b/src/app/services/task.service.ts @@ -32,7 +32,6 @@ export class TaskService { // .set('pageSize', pageSize.toString()); // return this.http.get<{ tasks: Task[]; totalPages: number }>(this.API_URL, { params }); - console.log('[Service - Request] Fetching tasks', { page, pageSize }); const start = (page - 1) * pageSize; const end = start + pageSize; const tasks = this.MOCK_DATA.slice(start, end); @@ -56,7 +55,6 @@ export class TaskService { // Returns: Task (with id and createdAt) // return this.http.post(this.API_URL, task); - console.log('[Service - Request] Creating task', task); const newTask: Task = { ...task, id: `${this.MOCK_DATA.length + 1}`, @@ -77,7 +75,6 @@ export class TaskService { // Returns: boolean (success/failure) // return this.http.delete(`${this.API_URL}/${taskId}`); - console.log('[Service - Request] Deleting task', taskId); const index = this.MOCK_DATA.findIndex(task => task.id === taskId); if (index > -1) { this.MOCK_DATA.splice(index, 1); @@ -106,10 +103,24 @@ export class TaskService { // Returns: boolean (success/failure) // return this.http.patch(`${this.API_URL}/${taskId}/status`, { status: newStatus }); - console.log('[Service - Request] Updating task status', { - taskId, - newStatus, - }); + // Simulate failure for task ID '3' to demonstrate optimistic update rollback + if (taskId === '3') { + return of(false).pipe( + delay(200), + tap(() => { + console.error( + '[Service - Response] Failed to update task status (simulated failure for task 3)' + ); + }), + // Convert false to error to trigger catchError in effect + tap(() => { + throw new Error( + 'Failed to update task status: Server error (simulated for task 3)' + ); + }) + ); + } + const taskIndex = this.MOCK_DATA.findIndex(task => task.id === taskId); if (taskIndex > -1) { this.MOCK_DATA[taskIndex] = { diff --git a/src/app/stores/shared/with-event-logging.ts b/src/app/stores/shared/with-event-logging.ts index b479bb0..5b165d0 100644 --- a/src/app/stores/shared/with-event-logging.ts +++ b/src/app/stores/shared/with-event-logging.ts @@ -39,10 +39,11 @@ export function withEventLogging(eventGroups: EventGroup[]) { logAllEvents$: events.on(...(allEvents as [any, ...any[]])).pipe( tap((event: EventWithPayload) => { const isError = event.type.includes('Failure'); + if (isError) { - console.error(`[Store Event] ${event.type}:`, event.payload); + console.error(`[Event → Effect] ${event.type}:`, event.payload); } else { - console.log(`[Store Event] ${event.type}`, event.payload); + console.log(`[Event → Effect] ${event.type}`, event.payload); } }) ), diff --git a/src/app/stores/task-store/task.effects.ts b/src/app/stores/task-store/task.effects.ts index ae67d25..045b78c 100644 --- a/src/app/stores/task-store/task.effects.ts +++ b/src/app/stores/task-store/task.effects.ts @@ -21,7 +21,7 @@ export function withTaskEffects() { exhaustMap(() => taskService.getTasks(1, 10).pipe( tap(response => { - console.log('[Task Store] Response from getTasks:', response); + console.log('[Effect] Response from getTasks:', response); }), catchError((error: { message: string }) => of(taskApiEvents.tasksLoadedFailure(error.message)) @@ -33,7 +33,7 @@ export function withTaskEffects() { } // Dispatch success with tasks array console.log( - '[Task Store] Dispatching tasksLoadedSuccess with:', + '[Effect] Dispatching tasksLoadedSuccess with:', response.tasks ); return of(taskApiEvents.tasksLoadedSuccess(response.tasks)); @@ -75,29 +75,25 @@ export function withTaskEffects() { // Change task status changeTaskStatus$: events.on(taskPageEvents.taskStatusChanged).pipe( exhaustMap(event => { - const taskEntitiesFn = store['taskEntities'] as - | (() => Task[]) - | undefined; - const taskEntities = taskEntitiesFn?.() || []; - const task = taskEntities.find( - (t: Task) => t.id === event.payload.id - ); - const previousStatus = task?.status; - return taskService .updateTaskStatus(event.payload.id, event.payload.status) .pipe( + concatMap(() => + of( + taskApiEvents.taskStatusChangedSuccess({ + id: event.payload.id, + status: event.payload.status, + }) + ) + ), catchError((error: { message: string }) => of( taskApiEvents.taskStatusChangedFailure({ id: event.payload.id, - previousStatus: previousStatus!, + previousStatus: event.payload.previousStatus, error: error.message, }) ) - ), - concatMap(() => - of(taskApiEvents.taskStatusChangedSuccess(event.payload)) ) ); }) diff --git a/src/app/stores/task-store/task.events.ts b/src/app/stores/task-store/task.events.ts index 785d5b5..1b67198 100644 --- a/src/app/stores/task-store/task.events.ts +++ b/src/app/stores/task-store/task.events.ts @@ -8,7 +8,11 @@ export const taskPageEvents = eventGroup({ opened: type(), taskCreated: type>(), taskDeleted: type(), - taskStatusChanged: type<{ id: string; status: TaskStatus }>(), + taskStatusChanged: type<{ + id: string; + status: TaskStatus; + previousStatus: TaskStatus; + }>(), pageChanged: type(), }, }); diff --git a/src/app/stores/task-store/task.reducer.ts b/src/app/stores/task-store/task.reducer.ts index 0b21111..78a06da 100644 --- a/src/app/stores/task-store/task.reducer.ts +++ b/src/app/stores/task-store/task.reducer.ts @@ -13,12 +13,19 @@ export function withTaskReducer() { return signalStoreFeature( withReducer( // Handle loading states - on(taskPageEvents.opened, () => ({ isLoading: true })), + on(taskPageEvents.opened, () => { + console.log('[Event → Reducer] Page opened - setting isLoading: true'); + return { isLoading: true }; + }), // Handle successful task loading // In NGRX Signals Events, the on() handler receives only the event (not state) // The event object has a .payload property containing the data on(taskApiEvents.tasksLoadedSuccess, (event: { payload: Task[] }) => { + console.log('[Event → Reducer] Tasks loaded successfully', { + count: event.payload.length, + taskIds: event.payload.map(t => t.id), + }); return [ setAllEntities(event.payload, { collection: 'task' }), { isLoading: false }, @@ -26,29 +33,46 @@ export function withTaskReducer() { }), // Handle failed task loading - on(taskApiEvents.tasksLoadedFailure, (event: { payload: string }) => ({ - isLoading: false, - error: event.payload, - })), + on(taskApiEvents.tasksLoadedFailure, (event: { payload: string }) => { + console.log('[Event → Reducer] Tasks load failed', { + error: event.payload, + }); + return { + isLoading: false, + error: event.payload, + }; + }), // Handle successful task creation - on(taskApiEvents.taskCreatedSuccess, (event: { payload: Task }) => - addEntity(event.payload, { collection: 'task' }) - ), + on(taskApiEvents.taskCreatedSuccess, (event: { payload: Task }) => { + console.log('[Event → Reducer] Task created', { + taskId: event.payload.id, + title: event.payload.title, + }); + return addEntity(event.payload, { collection: 'task' }); + }), // Handle successful task deletion - on(taskApiEvents.taskDeletedSuccess, (event: { payload: string }) => - removeEntity(event.payload, { collection: 'task' }) - ), + on(taskApiEvents.taskDeletedSuccess, (event: { payload: string }) => { + console.log('[Event → Reducer] Task deleted', { + taskId: event.payload, + }); + return removeEntity(event.payload, { collection: 'task' }); + }), // Handle optimistic status update on( taskPageEvents.taskStatusChanged, - (event: { payload: { id: string; status: TaskStatus } }) => - updateEntity( + (event: { payload: { id: string; status: TaskStatus } }) => { + console.log('[Event → Reducer] Task status changed (optimistic)', { + taskId: event.payload.id, + newStatus: event.payload.status, + }); + return updateEntity( { id: event.payload.id, changes: { status: event.payload.status } }, { collection: 'task' } - ) + ); + } ), // Handle status update failure (revert) @@ -56,14 +80,23 @@ export function withTaskReducer() { taskApiEvents.taskStatusChangedFailure, (event: { payload: { id: string; previousStatus: TaskStatus; error: string }; - }) => - updateEntity( + }) => { + console.log( + '[Event → Reducer] Task status change failed - reverting', + { + taskId: event.payload.id, + revertingTo: event.payload.previousStatus, + error: event.payload.error, + } + ); + return updateEntity( { id: event.payload.id, changes: { status: event.payload.previousStatus }, }, { collection: 'task' } - ) + ); + } ) ) ); diff --git a/src/app/stores/task-store/task.store.spec.ts b/src/app/stores/task-store/task.store.spec.ts index 5bd7225..00cfcae 100644 --- a/src/app/stores/task-store/task.store.spec.ts +++ b/src/app/stores/task-store/task.store.spec.ts @@ -202,11 +202,16 @@ describe('TaskStore', () => { describe('Update Task Status Flow', () => { it('should dispatch taskStatusChanged event for optimistic update', async () => { const taskId = '1'; + const previousStatus = TaskStatus.TODO; const newStatus = TaskStatus.IN_PROGRESS; - mockTaskService.updateTaskStatus.mockReturnValue(of(void 0)); + mockTaskService.updateTaskStatus.mockReturnValue(of(true)); - // Act: Dispatch taskStatusChanged event - dispatch.taskStatusChanged({ id: taskId, status: newStatus }); + // Act: Dispatch taskStatusChanged event with previousStatus + dispatch.taskStatusChanged({ + id: taskId, + status: newStatus, + previousStatus: previousStatus, + }); // Wait for async effects await new Promise(resolve => setTimeout(resolve, 100)); @@ -218,19 +223,63 @@ describe('TaskStore', () => { ); }); - it('should handle status update failures', async () => { + it('should handle status update failures and revert to previous status', async () => { + // Arrange: Set up initial task state + const initialTask: Task = { + id: '1', + title: 'Test Task', + status: TaskStatus.TODO, + createdAt: new Date().toISOString(), + }; + const mockTasks: Task[] = [initialTask]; + + // Load initial tasks + mockTaskService.getTasks.mockReturnValue( + of({ tasks: mockTasks, totalPages: 1 }) + ); + dispatch.opened(); + await new Promise(resolve => setTimeout(resolve, 100)); + + // Setup: Mock service to fail mockTaskService.updateTaskStatus.mockReturnValue( throwError(() => ({ message: 'Update failed' })) ); - // Act: Dispatch taskStatusChanged event - dispatch.taskStatusChanged({ id: '1', status: TaskStatus.DONE }); + // Act: Try to change status (optimistic update) + const newStatus = TaskStatus.DONE; + dispatch.taskStatusChanged({ + id: '1', + status: newStatus, + previousStatus: initialTask.status, // Capture before change + }); // Wait for async effects await new Promise(resolve => setTimeout(resolve, 100)); - // Assert: Service was called even though it failed - expect(mockTaskService.updateTaskStatus).toHaveBeenCalled(); + // Assert: Service was called + expect(mockTaskService.updateTaskStatus).toHaveBeenCalledWith( + '1', + newStatus + ); + + // TODO: In a real scenario with proper event processing, + // we would verify that the task status reverted to TaskStatus.TODO + // Currently this requires TestBed.flushEffects() or similar mechanism + }); + + it('should include previousStatus in event payload for rollback capability', () => { + // This test ensures the event structure includes previousStatus + const previousStatus = TaskStatus.TODO; + const newStatus = TaskStatus.IN_PROGRESS; + + // This will fail at compile time if previousStatus is not in the event type + const eventPayload: Parameters[0] = { + id: '1', + status: newStatus, + previousStatus: previousStatus, + }; + + expect(eventPayload.previousStatus).toBe(previousStatus); }); }); }); @@ -249,4 +298,51 @@ describe('TaskStore', () => { expect(store.tasksDone().length).toBe(0); }); }); + + describe('Integration: Optimistic Update with Rollback', () => { + it('should demonstrate the bug: effect reads status after reducer optimistically updates it', async () => { + // This test demonstrates why the bug occurred: + // 1. Reducer updates state optimistically (synchronous) + // 2. Effect runs after and reads the ALREADY UPDATED status + // 3. When API fails, it tries to revert to the NEW status instead of OLD status + + const initialTask: Task = { + id: '3', + title: 'Rollback Test Task', + status: TaskStatus.TODO, // Original status + createdAt: new Date().toISOString(), + }; + + // Setup: Load initial task + mockTaskService.getTasks.mockReturnValue( + of({ tasks: [initialTask], totalPages: 1 }) + ); + dispatch.opened(); + await new Promise(resolve => setTimeout(resolve, 100)); + + // Act: Try to change status, but API fails + mockTaskService.updateTaskStatus.mockReturnValue( + throwError(() => ({ message: 'Server error' })) + ); + + // Critical: We must capture previousStatus BEFORE dispatch + // because after dispatch, the reducer will have already updated it + const capturedPreviousStatus = initialTask.status; // TODO + + dispatch.taskStatusChanged({ + id: '3', + status: TaskStatus.DONE, + previousStatus: capturedPreviousStatus, // Must be captured before! + }); + + await new Promise(resolve => setTimeout(resolve, 100)); + + // Expected behavior: + // - Task should revert to TaskStatus.TODO (original status) + // If previousStatus wasn't captured before dispatch, it would revert to DONE (wrong!) + + // Note: This test documents the requirement that previousStatus + // must be captured BEFORE dispatching the event + }); + }); });