display a warning if immutableStateInvariantMiddleware or `ser… (#427)

* display a warning if `immutableStateInvariantMiddleware` or `serializableStateInvariantMiddleware` take too long * Update src/utils.ts Co-authored-by: Mark Erikson <[email protected]>
reduxjs · Mar 12, 2020 · 5929c30 · 5929c30
1 parent 36b25fc
commit 5929c30
Show file tree

Hide file tree

Showing 6 changed files with 196 additions and 56 deletions.
diff --git a/etc/redux-toolkit.api.md b/etc/redux-toolkit.api.md
@@ -251,6 +251,7 @@ export interface SerializableStateInvariantMiddlewareOptions {
     ignoredActions?: string[];
     ignoredPaths?: string[];
     isSerializable?: (value: any) => boolean;
+    warnAfter?: number;
 }
 
 // @alpha (undocumented)

diff --git a/src/immutableStateInvariantMiddleware.test.ts b/src/immutableStateInvariantMiddleware.test.ts
@@ -5,6 +5,7 @@ import {
   trackForMutations,
   ImmutableStateInvariantMiddlewareOptions
 } from './immutableStateInvariantMiddleware'
+import { mockConsole, createConsole, getLog } from 'console-testing-library'
 
 describe('createImmutableStateInvariantMiddleware', () => {
   let state: { foo: { bar: number[]; baz: string } }
@@ -121,6 +122,42 @@ describe('createImmutableStateInvariantMiddleware', () => {
       dispatch({ type: 'SOME_ACTION' })
     }).not.toThrow()
   })
+
+  it('Should print a warning if execution takes too long', () => {
+    state.foo.bar = new Array(10000).fill({ value: 'more' })
+
+    const next: Dispatch = action => action
+
+    const dispatch = middleware({ warnAfter: 4 })(next)
+
+    const restore = mockConsole(createConsole())
+    try {
+      dispatch({ type: 'SOME_ACTION' })
+      expect(getLog().log).toMatch(
+        /^ImmutableStateInvariantMiddleware took \d*ms, which is more than the warning threshold of 4ms./
+      )
+    } finally {
+      restore()
+    }
+  })
+
+  it('Should not print a warning if "next" takes too long', () => {
+    const next: Dispatch = action => {
+      const started = Date.now()
+      while (Date.now() - started < 8) {}
+      return action
+    }
+
+    const dispatch = middleware({ warnAfter: 4 })(next)
+
+    const restore = mockConsole(createConsole())
+    try {
+      dispatch({ type: 'SOME_ACTION' })
+      expect(getLog().log).toEqual('')
+    } finally {
+      restore()
+    }
+  })
 })
 
 describe('trackForMutations', () => {

diff --git a/src/immutableStateInvariantMiddleware.ts b/src/immutableStateInvariantMiddleware.ts
@@ -1,4 +1,5 @@
 import { Middleware } from 'redux'
+import { getTimeMeasureUtils } from './utils'
 
 type EntryProcessor = (key: string, value: any) => any
 
@@ -174,6 +175,7 @@ type IsImmutableFunc = (value: any) => boolean
 export interface ImmutableStateInvariantMiddlewareOptions {
   isImmutable?: IsImmutableFunc
   ignoredPaths?: string[]
+  warnAfter?: number
 }
 
 export function createImmutableStateInvariantMiddleware(
@@ -183,7 +185,11 @@ export function createImmutableStateInvariantMiddleware(
     return () => next => action => next(action)
   }
 
-  const { isImmutable = isImmutableDefault, ignoredPaths } = options
+  const {
+    isImmutable = isImmutableDefault,
+    ignoredPaths,
+    warnAfter = 32
+  } = options
   const track = trackForMutations.bind(null, isImmutable, ignoredPaths)
 
   return ({ getState }) => {
@@ -192,39 +198,51 @@ export function createImmutableStateInvariantMiddleware(
 
     let result
     return next => action => {
-      state = getState()
-
-      result = tracker.detectMutations()
-      // Track before potentially not meeting the invariant
-      tracker = track(state)
-
-      invariant(
-        !result.wasMutated,
-        `A state mutation was detected between dispatches, in the path '${(
-          result.path || []
-        ).join(
-          '.'
-        )}'.  This may cause incorrect behavior. (http://redux.js.org/docs/Troubleshooting.html#never-mutate-reducer-arguments)`
+      const measureUtils = getTimeMeasureUtils(
+        warnAfter,
+        'ImmutableStateInvariantMiddleware'
       )
 
-      const dispatchedAction = next(action)
-      state = getState()
+      measureUtils.measureTime(() => {
+        state = getState()
 
-      result = tracker.detectMutations()
-      // Track before potentially not meeting the invariant
-      tracker = track(state)
+        result = tracker.detectMutations()
+        // Track before potentially not meeting the invariant
+        tracker = track(state)
 
-      result.wasMutated &&
         invariant(
           !result.wasMutated,
-          `A state mutation was detected inside a dispatch, in the path: ${(
+          `A state mutation was detected between dispatches, in the path '${(
             result.path || []
           ).join(
             '.'
-          )}. Take a look at the reducer(s) handling the action ${stringify(
-            action
-          )}. (http://redux.js.org/docs/Troubleshooting.html#never-mutate-reducer-arguments)`
+          )}'.  This may cause incorrect behavior. (http://redux.js.org/docs/Troubleshooting.html#never-mutate-reducer-arguments)`
         )
+      })
+
+      const dispatchedAction = next(action)
+
+      measureUtils.measureTime(() => {
+        state = getState()
+
+        result = tracker.detectMutations()
+        // Track before potentially not meeting the invariant
+        tracker = track(state)
+
+        result.wasMutated &&
+          invariant(
+            !result.wasMutated,
+            `A state mutation was detected inside a dispatch, in the path: ${(
+              result.path || []
+            ).join(
+              '.'
+            )}. Take a look at the reducer(s) handling the action ${stringify(
+              action
+            )}. (http://redux.js.org/docs/Troubleshooting.html#never-mutate-reducer-arguments)`
+          )
+      })
+
+      measureUtils.warnIfExceeded()
 
       return dispatchedAction
     }

diff --git a/src/serializableStateInvariantMiddleware.test.ts b/src/serializableStateInvariantMiddleware.test.ts
@@ -408,4 +408,51 @@ describe('serializableStateInvariantMiddleware', () => {
     expect(log).toBe('')
     const q = 42
   })
+
+  it('Should print a warning if execution takes too long', () => {
+    const reducer: Reducer = (state = 42, action) => {
+      return state
+    }
+
+    const serializableStateInvariantMiddleware = createSerializableStateInvariantMiddleware(
+      { warnAfter: 4 }
+    )
+
+    const store = configureStore({
+      reducer: {
+        testSlice: reducer
+      },
+      middleware: [serializableStateInvariantMiddleware]
+    })
+
+    store.dispatch({
+      type: 'SOME_ACTION',
+      payload: new Array(10000).fill({ value: 'more' })
+    })
+    expect(getLog().log).toMatch(
+      /^SerializableStateInvariantMiddleware took \d*ms, which is more than the warning threshold of 4ms./
+    )
+  })
+
+  it('Should not print a warning if "reducer" takes too long', () => {
+    const reducer: Reducer = (state = 42, action) => {
+      const started = Date.now()
+      while (Date.now() - started < 8) {}
+      return state
+    }
+
+    const serializableStateInvariantMiddleware = createSerializableStateInvariantMiddleware(
+      { warnAfter: 4 }
+    )
+
+    const store = configureStore({
+      reducer: {
+        testSlice: reducer
+      },
+      middleware: [serializableStateInvariantMiddleware]
+    })
+
+    store.dispatch({ type: 'SOME_ACTION' })
+    expect(getLog().log).toMatch('')
+  })
 })
diff --git a/src/serializableStateInvariantMiddleware.ts b/src/serializableStateInvariantMiddleware.ts
@@ -1,5 +1,6 @@
 import isPlainObject from './isPlainObject'
 import { Middleware } from 'redux'
+import { getTimeMeasureUtils } from './utils'
 
 /**
  * Returns true if the passed value is "plain", i.e. a value that is either
@@ -114,6 +115,10 @@ export interface SerializableStateInvariantMiddlewareOptions {
    * An array of dot-separated path strings to ignore when checking for serializability, Defaults to []
    */
   ignoredPaths?: string[]
+  /**
+   * Execution time warning threshold. If the middleware takes longer than `warnAfter` ms, a warning will be displayed in the console. Defaults to 32
+   */
+  warnAfter?: number
 }
 
 /**
@@ -135,56 +140,67 @@ export function createSerializableStateInvariantMiddleware(
     isSerializable = isPlain,
     getEntries,
     ignoredActions = [],
-    ignoredPaths = []
+    ignoredPaths = [],
+    warnAfter = 32
   } = options
 
   return storeAPI => next => action => {
     if (ignoredActions.length && ignoredActions.indexOf(action.type) !== -1) {
       return next(action)
     }
 
-    const foundActionNonSerializableValue = findNonSerializableValue(
-      action,
-      [],
-      isSerializable,
-      getEntries
+    const measureUtils = getTimeMeasureUtils(
+      warnAfter,
+      'SerializableStateInvariantMiddleware'
     )
-
-    if (foundActionNonSerializableValue) {
-      const { keyPath, value } = foundActionNonSerializableValue
-
-      console.error(
-        `A non-serializable value was detected in an action, in the path: \`${keyPath}\`. Value:`,
-        value,
-        '\nTake a look at the logic that dispatched this action: ',
+    measureUtils.measureTime(() => {
+      const foundActionNonSerializableValue = findNonSerializableValue(
         action,
-        '\n(See https://redux.js.org/faq/actions#why-should-type-be-a-string-or-at-least-serializable-why-should-my-action-types-be-constants)'
+        [],
+        isSerializable,
+        getEntries
       )
-    }
+
+      if (foundActionNonSerializableValue) {
+        const { keyPath, value } = foundActionNonSerializableValue
+
+        console.error(
+          `A non-serializable value was detected in an action, in the path: \`${keyPath}\`. Value:`,
+          value,
+          '\nTake a look at the logic that dispatched this action: ',
+          action,
+          '\n(See https://redux.js.org/faq/actions#why-should-type-be-a-string-or-at-least-serializable-why-should-my-action-types-be-constants)'
+        )
+      }
+    })
 
     const result = next(action)
 
-    const state = storeAPI.getState()
+    measureUtils.measureTime(() => {
+      const state = storeAPI.getState()
 
-    const foundStateNonSerializableValue = findNonSerializableValue(
-      state,
-      [],
-      isSerializable,
-      getEntries,
-      ignoredPaths
-    )
+      const foundStateNonSerializableValue = findNonSerializableValue(
+        state,
+        [],
+        isSerializable,
+        getEntries,
+        ignoredPaths
+      )
 
-    if (foundStateNonSerializableValue) {
-      const { keyPath, value } = foundStateNonSerializableValue
+      if (foundStateNonSerializableValue) {
+        const { keyPath, value } = foundStateNonSerializableValue
 
-      console.error(
-        `A non-serializable value was detected in the state, in the path: \`${keyPath}\`. Value:`,
-        value,
-        `
+        console.error(
+          `A non-serializable value was detected in the state, in the path: \`${keyPath}\`. Value:`,
+          value,
+          `
 Take a look at the reducer(s) handling this action type: ${action.type}.
 (See https://redux.js.org/faq/organizing-state#can-i-put-functions-promises-or-other-non-serializable-items-in-my-store-state)`
-      )
-    }
+        )
+      }
+    })
+
+    measureUtils.warnIfExceeded()
 
     return result
   }

diff --git a/src/utils.ts b/src/utils.ts
@@ -0,0 +1,21 @@
+export function getTimeMeasureUtils(maxDelay: number, fnName: string) {
+  let elapsed = 0
+  return {
+    measureTime<T>(fn: () => T): T {
+      const started = Date.now()
+      try {
+        return fn()
+      } finally {
+        const finished = Date.now()
+        elapsed += finished - started
+      }
+    },
+    warnIfExceeded() {
+      if (elapsed > maxDelay) {
+        console.warn(`${fnName} took ${elapsed}ms, which is more than the warning threshold of ${maxDelay}ms. 
+If your state or actions are very large, you may want to disable the middleware as it might cause too much of a slowdown in development mode. See https://redux-toolkit.js.org/api/getDefaultMiddleware for instructions.
+It is disabled in production builds, so you don't need to worry about that.`)
+      }
+    }
+  }
+}