diff --git a/packages/logger-plugin/src/action-logger.ts b/packages/logger-plugin/src/action-logger.ts index e15e4c680..599d90f39 100644 --- a/packages/logger-plugin/src/action-logger.ts +++ b/packages/logger-plugin/src/action-logger.ts @@ -5,6 +5,10 @@ import { formatTime } from './internals'; import { LogWriter } from './log-writer'; export class ActionLogger { + private _synchronousWorkEnded = false; + private _actionCompleted = false; + private _startedTime = new Date(); + constructor( private action: any, private store: Store, @@ -12,10 +16,7 @@ export class ActionLogger { ) {} dispatched(state: any) { - const actionName = getActionTypeFromInstance(this.action); - const formattedTime = formatTime(new Date()); - - const message = `action ${actionName} @ ${formattedTime}`; + const message = this._getActionLogHeader(); this.logWriter.startGroup(message); // print payload only if at least one property is supplied @@ -27,19 +28,41 @@ export class ActionLogger { } completed(nextState: any) { + if (this._synchronousWorkEnded) { + this.logWriter.startGroup(`(async work completed) ${this._getActionLogHeader()}`); + } this.logWriter.logGreen('next state', nextState); this.logWriter.endGroup(); + this._actionCompleted = true; } errored(error: any) { + if (this._synchronousWorkEnded) { + this.logWriter.startGroup(`(async work error) ${this._getActionLogHeader()}`); + } this.logWriter.logRedish('next state after error', this.store.snapshot()); this.logWriter.logRedish('error', error); this.logWriter.endGroup(); + this._actionCompleted = true; + } + + syncWorkComplete() { + if (!this._actionCompleted) { + this.logWriter.logGreen('next state (synchronous)', this.store.snapshot()); + this.logWriter.logGreen('( action doing async work... )', undefined); + this.logWriter.endGroup(); + } + this._synchronousWorkEnded = true; + } + + private _getActionLogHeader() { + const actionName = getActionTypeFromInstance(this.action); + const formattedTime = formatTime(this._startedTime); + return `action ${actionName} (started @ ${formattedTime})`; } private _hasPayload(event: any) { - const nonEmptyProperties = this._getNonEmptyProperties(event); - return nonEmptyProperties.length > 0; + return this._getNonEmptyProperties(event).length > 0; } private _getNonEmptyProperties(event: any) { diff --git a/packages/logger-plugin/src/logger.plugin.ts b/packages/logger-plugin/src/logger.plugin.ts index 9c958d331..3f7244b89 100644 --- a/packages/logger-plugin/src/logger.plugin.ts +++ b/packages/logger-plugin/src/logger.plugin.ts @@ -1,7 +1,7 @@ import { inject, Injectable, Injector, runInInjectionContext } from '@angular/core'; import { Store } from '@ngxs/store'; import { NgxsNextPluginFn, NgxsPlugin } from '@ngxs/store/plugins'; -import { catchError, tap } from 'rxjs'; +import { catchError, defer, EMPTY, merge, Observable, tap } from 'rxjs'; import { LogWriter } from './log-writer'; import { ActionLogger } from './action-logger'; @@ -28,7 +28,7 @@ export class NgxsLoggerPlugin implements NgxsPlugin { actionLogger.dispatched(state); - return next(state, event).pipe( + const result = next(state, event).pipe( tap(nextState => { actionLogger.completed(nextState); }), @@ -37,6 +37,8 @@ export class NgxsLoggerPlugin implements NgxsPlugin { throw error; }) ); + + return afterSubscribe(result, () => actionLogger.syncWorkComplete()); } private _skipLogging(state: any, event: any) { @@ -50,3 +52,13 @@ export class NgxsLoggerPlugin implements NgxsPlugin { return !allowLogging; } } + +function afterSubscribe(source: Observable, callback: VoidFunction): Observable { + return merge( + source, + defer(() => { + callback(); + return EMPTY; + }) + ); +} diff --git a/packages/logger-plugin/tests/helpers/symbols.ts b/packages/logger-plugin/tests/helpers/symbols.ts index d730e8f17..bf77b7a4e 100644 --- a/packages/logger-plugin/tests/helpers/symbols.ts +++ b/packages/logger-plugin/tests/helpers/symbols.ts @@ -1 +1 @@ -export type CallStack = (string | {})[][]; +export type CallStack = (string | {} | undefined)[][]; diff --git a/packages/logger-plugin/tests/helpers/utils.ts b/packages/logger-plugin/tests/helpers/utils.ts index ca2152d74..86ef30fb4 100644 --- a/packages/logger-plugin/tests/helpers/utils.ts +++ b/packages/logger-plugin/tests/helpers/utils.ts @@ -18,7 +18,7 @@ export function formatActionCallStack(options: FormatActionCallStackOptions): Ca : []; const formattedCallstack = [ - [collapsed ? 'groupCollapsed' : 'group', `action ${action} @ `], + [collapsed ? 'groupCollapsed' : 'group', `action ${action} (started @ )`], ...formattedPayload, ['log', '%c prev state', 'color: #9E9E9E; font-weight: bold', { test: prevState }] ]; diff --git a/packages/logger-plugin/tests/logger.plugin.spec.ts b/packages/logger-plugin/tests/logger.plugin.spec.ts index 74c0962e6..4e17daab5 100644 --- a/packages/logger-plugin/tests/logger.plugin.spec.ts +++ b/packages/logger-plugin/tests/logger.plugin.spec.ts @@ -6,7 +6,8 @@ import { State, StateContext } from '@ngxs/store'; -import { throwError } from 'rxjs'; +import { of, throwError } from 'rxjs'; +import { delay, tap } from 'rxjs/operators'; import { setupWithLogger, formatActionCallStack, LoggerSpy } from './helpers'; @@ -24,6 +25,16 @@ describe('NgxsLoggerPlugin', () => { static type = 'ERROR'; } + class AsyncAction { + static type = 'ASYNC_ACTION'; + constructor(public bar?: string) {} + } + + class AsyncError { + static type = 'ASYNC_ERROR'; + constructor(public message: string) {} + } + interface StateModel { bar: string; } @@ -47,6 +58,27 @@ describe('NgxsLoggerPlugin', () => { error() { return throwError(new Error(thrownErrorMessage)); } + + @Action(AsyncAction) + asyncAction({ patchState }: StateContext, { bar }: AsyncAction) { + patchState({ bar: '...' }); + return of(null).pipe( + delay(1), + tap(() => patchState({ bar: bar || defaultBarValue })) + ); + } + + @Action(AsyncError) + asyncErrorAction({ patchState }: StateContext, { message }: AsyncError) { + patchState({ bar: '...' }); + return of(null).pipe( + delay(1), + tap(() => { + patchState({ bar: 'erroring' }); + throw new Error(message); + }) + ); + } } it('should log success action', () => { @@ -153,6 +185,99 @@ describe('NgxsLoggerPlugin', () => { expect(logger.callStack).toEqual(expectedCallStack); }); + it('should log async success action', async () => { + const { store, logger } = setupWithLogger([TestState]); + const payload = 'qux'; + + const promise = store.dispatch(new AsyncAction(payload)).toPromise(); + logger.log('Some other work'); + await promise; + + const expectedCallStack = LoggerSpy.createCallStack([ + ...formatActionCallStack({ action: InitState.type, prevState: stateModelDefaults }), + ['group', 'action ASYNC_ACTION (started @ )'], + ['log', '%c payload', 'color: #9E9E9E; font-weight: bold', { bar: payload }], + [ + 'log', + '%c prev state', + 'color: #9E9E9E; font-weight: bold', + { test: stateModelDefaults } + ], + [ + 'log', + '%c next state (synchronous)', + 'color: #4CAF50; font-weight: bold', + { test: { bar: '...' } } + ], + [ + 'log', + '%c ( action doing async work... )', + 'color: #4CAF50; font-weight: bold', + undefined + ], + ['groupEnd'], + ['log', 'Some other work'], + ['group', '(async work completed) action ASYNC_ACTION (started @ )'], + [ + 'log', + '%c next state', + 'color: #4CAF50; font-weight: bold', + { test: { bar: payload } } + ], + ['groupEnd'] + ]); + + expect(logger.callStack).toEqual(expectedCallStack); + }); + + it('should log async error action', async () => { + const { store, logger } = setupWithLogger([TestState]); + const errorMessage = 'qux error'; + + const promise = store.dispatch(new AsyncError(errorMessage)).toPromise(); + logger.log('Some other work'); + try { + await promise; + } catch {} + + const expectedCallStack = LoggerSpy.createCallStack([ + ...formatActionCallStack({ action: InitState.type, prevState: stateModelDefaults }), + ['group', 'action ASYNC_ERROR (started @ )'], + ['log', '%c payload', 'color: #9E9E9E; font-weight: bold', { message: errorMessage }], + [ + 'log', + '%c prev state', + 'color: #9E9E9E; font-weight: bold', + { test: stateModelDefaults } + ], + [ + 'log', + '%c next state (synchronous)', + 'color: #4CAF50; font-weight: bold', + { test: { bar: '...' } } + ], + [ + 'log', + '%c ( action doing async work... )', + 'color: #4CAF50; font-weight: bold', + undefined + ], + ['groupEnd'], + ['log', 'Some other work'], + ['group', '(async work error) action ASYNC_ERROR (started @ )'], + [ + 'log', + '%c next state after error', + 'color: #FD8182; font-weight: bold', + { test: { bar: 'erroring' } } + ], + ['log', '%c error', 'color: #FD8182; font-weight: bold', new Error(errorMessage)], + ['groupEnd'] + ]); + + expect(logger.callStack).toEqual(expectedCallStack); + }); + it('should pass state snapshot to filter predicate', () => { const { store, logger } = setupWithLogger([TestState], { filter: (_, state) => state.test.bar