After upgrading to React Native 0.73 & Jest 29, bundle splitter seems to cause rendering issues in inner components (in tests)

matt-dalton commented 3 months ago

Sorry, this is quite a tricky bug to narrow down as there are lots of variables involved, but hopefully there's enough here for a hint of the problem

Describe the bug We have upgraded from React Native 0.68 and jest 26-29. Quite a big jump, but we managed to get most of our 700 tests working after tweaking some of the fake timer logic.

We're having problems in two suites, both of which involve the bundle splitter layer.

If I import a component using bundle splitter, the useEffect in my component never seems to run. I have tried all manner of jest.runOnlyPendingTimers etc, and have also tried real timers, increasing jest timeouts etc and nothing seems to get this to work. If I call React Native test library rerender it then calls useEffect once, but this is obviously a hack.

The test then works fine when I import the component normally.

Code snippet Component file

const SignUpScreen = () => {
    //This render logic successfully runs in my test
    React.useEffect(() => {
         //but this useEffect never does
         triggerTracking()
    }, [])

    const triggerTracking = ()=>{
         myTrackingFn()
    }

Navigation layer file

const SignUpScreen = register({
    loader: () => require('Screens/SignUpScreen'),
    group: ONBOARDING,
})
// import SignUpScreen from 'Screens/SignUpScreen' // If I comment the above and use this, everything works as expected

Test file

        const component = <Navigator {...props} />

        const renderedComponent = await waitFor(() => render(component))

        // Check screen has rendered
        const image = await renderedComponent.findByTestId(SIGNUP_IMG_TEST_ID)
        expect(image).toBeTruthy()

        // Initial Paywall
        act(() => {
            // Nothing in here causes the useEffect to fire...have tried many many combinations!
            jest.runOnlyPendingTimers()
            //jest.runAllTimers Also doesn't work
            // renderedComponent.rerender(component) //This gets the useEffect to fire once
        })

        // This never triggers, even with real timers, because the useEffect never runs
        await waitFor(() => expect(myTrackingFn).toHaveBeenCalled(), {
            timeout: 40000,
        })

I can fix it using this mock:

const RNBundleSplitter = jest.requireActual('react-native-bundle-splitter')

module.exports = {
    ...RNBundleSplitter,
    register: (props: any) => {
        const Component = props.loader().default

        return Component
    },
}

but would be nice if I could test the real behaviour in my tests.

Expected behavior The useEffect in the inner component should render in tests

Smartphone (please complete the following information):

Desktop OS MacOS 14.4
Device: n/a
JS engine: Jest (node)
Library version 2.2.3

Any idea what this could be?

kirillzyusko commented 3 months ago

Hm, thanks for reporting @matt-dalton it looks interesting!

I don't have any ideas what it could be 🤔 @IvanIhnatsiuk have you see anything similar?

@matt-dalton did you follow https://kirillzyusko.github.io/react-native-bundle-splitter/docs/recipes/jest-testing-guide (I think most likely you did, but just want to be sure that we are on the same page).

matt-dalton commented 3 months ago

Thanks for the response!

I have done that, here's my babel config:

module.exports = {
    presets: ['module:@react-native/babel-preset'],
    plugins: [
        ['jest-hoist'],
        ['react-native-reanimated/plugin'],
        ['babel-plugin-idx'],
        [
            'module-resolver',
            {
                root: ['./App'],
                extensions: ['.js', '.ts', '.tsx', '.ios.js', '.android.js'],
            },
        ],
    ],
    env: {
        production: {
            plugins: ['transform-remove-console'],
        },
        test: {
            plugins: ['dynamic-import-node'],
        },
    },
}

I actually raised the issue that lead to those docs last year! Seems I'm the annoying guy finding issues with the tests.

kirillzyusko commented 3 months ago

I actually raised the issue that lead to those docs last year!

Ah, right, exactly!

Seems I'm the annoying guy finding issues with the tests.

Ha-ha, no, you are not 🙂

I'll try to search for solutions - may I ask you to provide a simple reproduction example? I'm not on a project where we use react-native-bundle-splitter and updating previous project to latest deps will take a big effort. So if you can provide a reproduction example - that would be amazing!

matt-dalton commented 3 months ago

Unfortunately I'm not allowed to share the actual project I'm working on. I'm not sure if the upgrade is a critical part of it - some version of the components enough may be enough to trigger it. Let me see if I can trigger it on a simpler project somehow. Do you by any chance know anywhere with suitable initial boilerplate? e.g. do you have examples in the codebase that might work?

kirillzyusko commented 3 months ago

@matt-dalton I have only this project - https://github.com/kirillzyusko/react-native-bundle-splitter-example

But it's also uses old dependencies so it'll require some effort to reproduce a problem.

Also can you try to remove setTimeout from here https://github.com/kirillzyusko/react-native-bundle-splitter/blob/master/src/map.ts#L16? Maybe it causes some issues? 🤔

matt-dalton commented 3 months ago

Hmm tried removing (using my transformed code below) and didn't fix it unfortunately Screenshot 2024-04-05 at 15 23 19

I did try many many combinations of things to progress timers, so would be surprised if it is a setTimeout

kirillzyusko commented 2 months ago

@matt-dalton yeah, I see. Okay, another attempt - can you add logger here: https://github.com/kirillzyusko/react-native-bundle-splitter/blob/master/src/optimized.tsx#L33 and https://github.com/kirillzyusko/react-native-bundle-splitter/blob/master/src/optimized.tsx#L40 and https://github.com/kirillzyusko/react-native-bundle-splitter/blob/master/src/optimized.tsx#L43 (conosle.log(0, this.component), console.log(1, this.component) and console.log(2, this.state.isComponentAvailable, BundleComponent)), run a single test and put the output here?

Just trying to figure out where it's stopping to work 🤔

matt-dalton commented 2 months ago

Thanks @kirillzyusko ...sorry took me a bit to get to it.

Some extra detail which I didn't realise up front...the problem occurs in the problematic test only when another test is run first. So it's the second of the 2 tests that fails...so could be related to what happens after a first test is cleaned up.

As such I've provided logging as requested from both tests (you'll see a console.log denoting when one starts)

  console.log
    start of passing test

      at Object.log (App/Navigation/Navigators/RootNavigator/__tests__/RootNavigator.test.tsx:152:21)

  console.log
    2 false null

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    2 false null

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    0 null

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    0 null

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    0 null

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    2 true [Function (anonymous)]

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    1 [Function (anonymous)]

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:117:37)

  console.log
    0 null

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    2 true {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    1 {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:117:37)

  console.log
    2 true [Function (anonymous)]

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    2 true {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    0 [Function (anonymous)]

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    1 [Function (anonymous)]

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:109:41)

  console.log
    0 [Function (anonymous)]

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    0 {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    1 {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:109:41)

  console.log
    0 {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    2 true [Function (anonymous)]

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    2 true {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    2 true undefined

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    0 [Function (anonymous)]

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    1 [Function (anonymous)]

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:109:41)

  console.log
    0 [Function (anonymous)]

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    0 undefined

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    1 undefined

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:109:41)

  console.log
    0 undefined

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    0 {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    1 {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:109:41)

  console.log
    0 {
      '$$typeof': Symbol(react.memo),
      type: [Function (anonymous)],
      compare: null
    }

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    start of failing test

      at Object.log (App/Navigation/Navigators/RootNavigator/__tests__/RootNavigator.test.tsx:198:21)

  console.log
    2 false null

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    0 null

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    0 null

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:105:29)

  console.log
    2 true [Function (anonymous)]

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

  console.log
    1 [Function (anonymous)]

      at OptimizedComponent.log (node_modules/react-native-bundle-splitter/dist/optimized.js:117:37)

The afterEach for these tests is:

import { fireEvent, cleanup, act, waitFor } from '@testing-library/react-native'

afterEach(() => {
        jest.runOnlyPendingTimers()
        cleanup()
        jest.useRealTimers()
        jest.clearAllMocks()
    })

Also just to rule out any problems with logging...I'm using the dist post-build node_modules version of the lib so couldn't log exactly where you said. Here's what I've added:

kirillzyusko commented 4 weeks ago

@matt-dalton Sorry for long answer - I think you added a logger in correct place.

For me this statement looks very strange:

console.log
    2 true undefined

      at OptimizedComponent.log [as render] (node_modules/react-native-bundle-splitter/dist/optimized.js:129:21)

So we executed a logic and received a component, but we got undefined 🤯

To debug it further I would try:

add screenName to logger - it's very hard to understand which screen produced undefined...
can you try to use loader: () => import('Screens/SignUpScreen'), - this is the recommended syntax now

I think now we need to figure out why undefined gets produced. I suspect it comes from here: https://github.com/kirillzyusko/react-native-bundle-splitter/blob/master/src/map.ts#L35 but not sure till the end 🤔

Regarding "start of failing test" test - for me it looks strange why componentDidMount was called two times. Can it be because of concurrent React?

kirillzyusko / react-native-bundle-splitter

After upgrading to React Native 0.73 & Jest 29, bundle splitter seems to cause rendering issues in inner components (in tests) #63