Reducer is deleting state keys

[Chnapy]

Hi,
I have a very strange issue.
Sometimes, after dispatching some actions, I have some keys of my state deleted.

I encounter this issue in a quite big project after passing it to redux/toolkit, so to be understable I show you a simple example:

Middleware

I have a middleware that can dispatch MyAction action, async:

const myMiddleware = api => next => action => {
  next(action);

  if(SomeAction.match(action)) {

    setTimeout(() => api.dispatch(MyAction()));
  }
};

Reducer

I have my reducer, created with createReducer():

type MyState = {
  a: number;
  b: number;
  c: number;
};

const initialState = {a: 1, b: 1, c: 1};

const myReducer = createReducer(initialState, {
  [MyAction.type]: (state, action) => {
  
    return {
      ...state,
      c: 5
    };
  }
});

The issue happens on the MyAction dispatch.
redux-logger shows me:

• previous state: {a: 1, b: 1, c: 1}
• next state: {c: 5}

In the reducer, the ...state seems to be ignored. When I want to console.log the received state I obtain a Proxy object, it does not give me useful information.
Also, if instead of returning the new state I mutate the proxy, like that: state.c = 5, it works.

This issue seems to happen only when I dispatch an action from a middleware. When I do that it's always asynchronous, sometimes deffered of several seconds.
It happens only in reducers returning a new state using spread ...state.

I'm using redux/toolkit 1.3.6, with default middlewares.

I do not succeed to reproduce the issue with a basic example, I'm quite lost on why it happens on my project so any advice on how to debug that is welcome !

[Chnapy]

I can give you a concrete example of one of my middlewares:

type Dependencies<S> = {
    extractState: (getState: () => S) => CycleState;
    extractCurrentCharacters: (getState: () => S) => Character<'current'>[];
};

export const cycleMiddleware: <S>(deps: Dependencies<S>) => Middleware = ({
    extractState,
    extractCurrentCharacters
}) => api => next => {

    const getCharacter = (characterId: string): Character<'current'> => extractCurrentCharacters(api.getState)
        .find(c => c.id === characterId)!;

    const getNextCharacterInfos = (currentCharacterId: string, index: number = 0): {
        id: string;
        duration: number;
    } | null => {
        const { globalTurnOrder } = extractState(api.getState);

        if (index === globalTurnOrder.length) {
            return null;
        }

        const orderIndex = globalTurnOrder.indexOf(currentCharacterId) + 1;

        const id = globalTurnOrder[ orderIndex % globalTurnOrder.length ];

        if (isCharacterDead(id)) {
            return getNextCharacterInfos(id, index + 1);
        }

        return {
            id,
            duration: getCharacter(id).features.actionTime
        };
    };

    const differTurnStart = (turnSnapshot: TurnSnapshot) => {

        const delta = turnSnapshot.startTime - Date.now();

        cancelTimeout();

        timeout = setTimeout(() => {

            const currentCharacter = extractCurrentCharacters(api.getState)
                .find(c => c.id === turnSnapshot.characterId)!;

            api.dispatch(BattleStateTurnStartAction({
                turnSnapshot,
                currentCharacter
            }));

            differTurnEnd(turnSnapshot.characterId, turnSnapshot.startTime);

        }, delta);
    };

    const differTurnEnd = (characterId: string, startTime?: number) => {

        cancelTimeout();

        const character = getCharacter(characterId);

        const endTime = startTime
            ? startTime + character.features.actionTime
            : Date.now();
        const duration = endTime - Date.now();

        timeout = setTimeout(() => {

            api.dispatch(BattleStateTurnEndAction());

            const { turnId, currentCharacterId } = extractState(api.getState);

            const nextChar = getNextCharacterInfos(currentCharacterId);

            if (nextChar) {
                differTurnStart({
                    id: turnId + 1,
                    startTime: endTime + TURN_DELAY,
                    characterId: nextChar.id,
                    duration: nextChar.duration
                });
            }

        }, duration);
    };

    const turnQueue: TurnSnapshot[] = [];

    let timeout: NodeJS.Timeout | null = null;

    const cancelTimeout = () => {
        if (timeout) {
            clearTimeout(timeout);
            timeout = null;
        }
    };

    return (action: AnyAction) => {

        next(action);

        if (BattleStartAction.match(action)) {

            const { globalTurnSnapshot } = action.payload;

            differTurnStart(globalTurnSnapshot.currentTurn);

        } else if (ReceiveMessageAction.match(action)) {

            const { payload } = action;

            if (payload.type === 'battle-run/turn-start') {

                const state = extractState(api.getState);

                const { id, characterId, startTime } = payload.turnState;

                if (state.turnId === id) {

                    if (state.turnStartTime !== startTime) {

                        differTurnEnd(characterId, startTime);
                    }

                } else if (id === state.turnId + 1) {

                    if (getTurnState(state) === 'ended') {

                        differTurnStart(payload.turnState);

                    } else {

                        turnQueue.push(payload.turnState);
                    }
                }

            }

        }
    };
};

I'm sure I'm doing something wrong on my middlewares, but I don't know what..

[phryneas]

That should not happen :/

On logging: You can log the state by doing console.log({...state}) or import {original } from "immer"; and console.log(original(state)).

Couls you please check which version(s) of immer your app is using by running yarn why immer or npx npm-why immer (depending if you use yarn or npm)?

[markerikson]

I've seen one or two other reports like this in the past. Not sure where they are in the issues here, but something like this has been reported.

Any chance this is an Electron app of some kind? I feel like that was involved the one time.

[Chnapy]

On logging: You can log the state by doing console.log({...state}) or import {original } from "immer"; and console.log(original(state)).

I added console.log({...state}, original(state)). Then I obtain this:

(note that original(state) always give undefined, even in reducers that work fine)

Couls you please check which version(s) of immer your app is using by running yarn why immer or npx npm-why immer (depending if you use yarn or npm)?

Doing yarn why immer gives me that:

yarn why v1.21.1
[1/4] Why do we have the module "immer"...?
[2/4] Initialising dependency graph...
[3/4] Finding dependency...
[4/4] Calculating file sizes...

=> Found "immer@1.10.0"
info Has been hoisted to "immer"
info Reasons this module exists
   - "workspace-aggregator-13dbd72c-ee67-489f-a24e-099be60a4eec" depends on it
   - Hoisted from "_project_#react-dev-utils#immer"
   - Hoisted from "_project_#@timeflies#front#timeflies-react-scripts#react-dev-utils#immer"
info Disk size without dependencies: "268KB"
info Disk size with unique dependencies: "268KB"
info Disk size with transitive dependencies: "268KB"
info Number of shared dependencies: 0

=> Found "@reduxjs/toolkit#immer@6.0.8"
info This module exists because "_project_#@timeflies#front#@reduxjs#toolkit" depends on it.
info Disk size without dependencies: "1008KB"
info Disk size with unique dependencies: "1008KB"
info Disk size with transitive dependencies: "1008KB"
info Number of shared dependencies: 0
Done in 2.44s.

It seems that immer@1.10.0 come from my fork of create-react-app/react-scripts, which is named timeflies-react-scripts. It's a very recent fork (v3.4.1), with only some minor changes.
But anyway, RTK should use only its own version of Immer right ?

Any chance this is an Electron app of some kind? I feel like that was involved the one time.

Nop, it's a regular web app, initialized using create-react-app.

I found a very strange behavior. Since the issue is always present using the classic yarn start, I don't have it when I test my app using Storybook. But testing my app using storybook does not change anything of my store, middlewares, or reducers. Only initial states and actions payload values change, nothing that can cause this issue (?). Also storybook loads the app in a iframe.

Thanks for your time 👍

[markerikson]

Hmm. Yeah, I remember seeing that Immer mismatch in a prior issue. See #459 and facebook/create-react-app#8750 .

And yeah, the hoisting of Immer v1 here is likely causing the issue somehow.

[Chnapy]

I edited my package.json to resolve immer version:

"resolutions": {
  "immer": "6.0.8"
}

After a yarn install, when I do yarn why immer I got this time only one immer, with the correct version: 6.0.8.

On the app, the console.log that showed
{} undefined
shows now
{} {a: 1, b: 1, c: 1} <= the previous state

But the issue is still there, redux-logger shows me that I loose state keys.

Do you think that there is a version mismatch on another dependency ?

--
Also to be sure that the state sent to the reducer concerned is good, I add some logs on the parent reducer. The state is fine at this level.

[markerikson]

At this point I'd need to get hands-on with a project that reproduces the issue, and step through the entire process one line at a time to see where things are breaking. I understand it may be hard to provide a repro for this. If you can't, all I can suggest is stepping through things yourself.

[Chnapy]

I did not succeed to make a repro of this issue.
I continued my investigations by adding logs in createReducer function in my node_modules.

function createReducer(initialState, mapOrBuilderCallback) {
  var actionsMap = typeof mapOrBuilderCallback === 'function' ? executeReducerBuilderCallback(mapOrBuilderCallback) : mapOrBuilderCallback;
  return function (state, action) {
    if (state === void 0) {
      state = initialState;
    }

    var caseReducer = actionsMap[action.type];
    
    const shouldLog = action.type === '...';
    if(shouldLog) {
        console.log('state infos', state, isDraft(state));
    }

    if (caseReducer) {
      if (isDraft(state)) {
        // we must already be inside a `createNextState` call, likely because
        // this is being wrapped in `createReducer`, `createSlice`, or nested
        // inside an existing draft. It's safe to just pass the draft to the mutator.
        var draft = state; // We can aassume this is already a draft

        return caseReducer(draft, action) || state;
      } else {
        // @ts-ignore createNextState() produces an Immutable<Draft<S>> rather
        // than an Immutable<S>, and TypeScript cannot find out how to reconcile
        // these two types.
        return createNextState(state, function (draft) {
            if(shouldLog) {
                console.log(
                    'state', state, isDraftable(state),
                    'draft', {
                        draft, draftSpread: {...draft}, draftOriginal: original(draft)
                    } 
                );
            }
          return caseReducer(draft, action);
        });
      }
    }

    return state;
  };
}

When my issue occurs:

• received state is well formed, and is not draft
• on the createNextState call, given state is well formed, draftable, but the generated draft is not (it's empty) !

I still don't understand why this issue occurs on middleware dispatch, but since that on the createNextState call given state is fine, but generated draft is not, it seems that it's the fault of immer, not RTK.

[Chnapy]

Ok finally it's a V8 bug, I found this thanks to this issue immerjs/immer#346 !

I was testing my app on Chromium v73, the bug is fixed since v74 😄
Fiuuu I'm relieved !

Thank you to have take the time to help me 👍

[markerikson]

Well, there's one you don't see every day!

Appreciate you taking the time to dig through this :)