showPreparingDocs applies display: none and gets into a race with React 18's rendering cycle

[snowystinger]

Describe the bug Storybook's preparing docs gets into a race with React 18's rendering cycle. This can lead to bounding client rects being all zeros and cause flake in tests that need to measure during the useLayoutEffect phase. There is also a second effect, the document.body's userAgent stylesheet margin of 8px is also not removed early enough. So not only are measured values 0, but positioning calculations become off by 8px. @tmeasday

To Reproduce When running a story how Chromatic does, for example https://5f0dd5ad2b5fc10022a2e320-ugizaypgfl.chromatic.com/iframe.html and then opening the js console and running

__STORYBOOK_ADDONS_CHANNEL__.emit('setCurrentStory', { storyId: 'menutrigger--direction-start-end' });

You can see that the overlay position is wrong (Happens to coworkers with Intel based Mac's, happens in chromatic, does not seem to happen to ARM based Mac's).

I made a smaller reproduction using CRA + npx storybook init here: https://github.com/snowystinger/storybook-timing

npm i
npm run storybook

go to localhost:6006/iframe.html

__STORYBOOK_ADDONS_CHANNEL__.emit('setCurrentStory', { storyId: 'example--demo' });

There is one thing that was necessary to push it into the race condition reliably, which was to add the same typekit script we have. This is a blocking script, so I suspect you could accomplish the same race on any machine by adding a blocking script of variable time length. It's in .storybook/preview-head.html https://github.com/snowystinger/storybook-timing/blob/main/.storybook/preview-head.html

System Machine that reproduces:

  System:
    OS: macOS 12.3.1
    CPU: (16) x64 Intel(R) Core(TM) i9-9880H CPU @ 2.30GHz
  Binaries:
    Node: 16.14.0 - ~/.nvm/versions/node/v16.14.0/bin/node
    Yarn: 1.22.18 - ~/.nvm/versions/node/v16.14.0/bin/yarn
    npm: 8.3.1 - ~/.nvm/versions/node/v16.14.0/bin/npm
  Browsers:
    Chrome: 101.0.4951.64
  npmPackages:
    @storybook/addon-actions: ^6.5.5 => 6.5.5 
    @storybook/addon-essentials: ^6.5.5 => 6.5.5 
    @storybook/addon-interactions: ^6.5.5 => 6.5.5 
    @storybook/addon-links: ^6.5.5 => 6.5.5 
    @storybook/builder-webpack5: ^6.5.5 => 6.5.5 
    @storybook/manager-webpack5: ^6.5.5 => 6.5.5 
    @storybook/node-logger: ^6.5.5 => 6.5.5 
    @storybook/preset-create-react-app: ^4.1.1 => 4.1.1 
    @storybook/react: ^6.5.5 => 6.5.5 
    @storybook/testing-library: ^0.0.11 => 0.0.11 

Machine that does NOT reproduce:

  System:
    OS: macOS 12.3.1
    CPU: (10) arm64 Apple M1 Max
  Binaries:
    Node: 16.13.2 - ~/.nvm/versions/node/v16.13.2/bin/node
    Yarn: 1.22.17 - /opt/homebrew/bin/yarn
    npm: 8.1.2 - ~/.nvm/versions/node/v16.13.2/bin/npm
  Browsers:
    Chrome: 101.0.4951.64
  npmPackages:
    @storybook/addon-actions: ^6.5.5 => 6.5.5 
    @storybook/addon-essentials: ^6.5.5 => 6.5.5 
    @storybook/addon-interactions: ^6.5.5 => 6.5.5 
    @storybook/addon-links: ^6.5.5 => 6.5.5 
    @storybook/builder-webpack5: ^6.5.5 => 6.5.5 
    @storybook/manager-webpack5: ^6.5.5 => 6.5.5 
    @storybook/node-logger: ^6.5.5 => 6.5.5 
    @storybook/preset-create-react-app: ^4.1.1 => 4.1.1 
    @storybook/react: ^6.5.5 => 6.5.5 
    @storybook/testing-library: ^0.0.11 => 0.0.11 

Additional context Here's our workaround for the time being https://github.com/adobe/react-spectrum/pull/3165/files

We think this the problem area https://github.com/storybookjs/storybook/blob/main/lib/preview-web/src/WebView.ts#L168

Note, we don't use docs in Chromatic and I've turned it off in the example repo.

[tmeasday]

Hi @snowystinger. Thanks for the reproduction.

A couple of observations, right off the bat.

1. I am on an ARM mac. I see the original bug, but the reproduction isn't reproducing here (I assume the issue is the bounding box logged in useLayoutEffect is different to the one logged in useEffect?)

2. It is super weird that showPreparingDocs is getting called at all, given this is a story. I will dig into why this is happening. However, I might have guessed that showPreparingStory should have been called, which has similar behaviour to showPreparingDocs, so I am not sure if fixing that will resolve the issue.

3. I put in log points on showPreparingDocs, showPreparingStory and showMode in the reproduction and I see:

(Note it doesn't reproduce here). Would be interesting to see what's logged in the case it does reproduce.

4. I did the same in the original issue (which does reproduce for me), and saw this:

I think what's happening here is simply that the JS bundle that includes the story (https://5f0dd5ad2b5fc10022a2e320-ugizaypgfl.chromatic.com/5.1f4938b8.iframe.bundle.js in case 4. above) takes longer than 100ms to parse + execute. So the spinner appears very briefly and the story renders behind it.

In story view mode we do take steps to ensure that the #root element where the story renders is not display: none during rendering, so thinking it through, it is possible the behaviour will be differently if the story spinner is displayed instead of the docs one.

[shilman]

Whoopee!! I just released https://github.com/storybookjs/storybook/releases/tag/v6.5.7-alpha.0 containing PR #18370 that references this issue. Upgrade today to the @prerelease NPM tag to try it out!

npx sb upgrade --prerelease

Closing this issue. Please re-open if you think there's still more to do.

[shilman]

Zoinks!! I just released https://github.com/storybookjs/storybook/releases/tag/v6.5.7 containing PR #18370 that references this issue. Upgrade today to the @latest NPM tag to try it out!

npx sb upgrade

[shilman]

Ermahgerd!! I just released https://github.com/storybookjs/storybook/releases/tag/v7.0.0-alpha.0 containing PR #18370 that references this issue. Upgrade today to the @future NPM tag to try it out!

npx sb upgrade --prerelease