Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[DevTools Bug] Could not find node with id "18" in commit tree #23283

Closed
wolfcomp opened this issue Feb 12, 2022 · 19 comments · Fixed by #24031
Closed

[DevTools Bug] Could not find node with id "18" in commit tree #23283

wolfcomp opened this issue Feb 12, 2022 · 19 comments · Fixed by #24031
Assignees
Labels
Component: Developer Tools Status: Unconfirmed A potential issue that we haven't yet confirmed as a bug Type: Bug

Comments

@wolfcomp
Copy link

Website or app

https://github.com/ModelSaber/ModelSaber.Main

Repro steps

Just try and load the 2/5 and 3/5 report from a reload and start profiling instance.

Change REACT_APP_API_URL to https://apimodelsaber.rainemods.io in order to launch the app without needing the full .NET 6 environment and the corresponding data in the postgres database.

How often does this bug happen?

Every time

DevTools package (automated)

react-devtools-extensions

DevTools version (automated)

4.23.0-e28a0db22

Error message (automated)

Could not find node with id "18" in commit tree

Error call stack (automated)

at chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:25574:13
    at Map.forEach (<anonymous>)
    at RankedChartBuilder_getChartData (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:25570:24)
    at ProfilingCache_ProfilingCache.getRankedChartData (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:25686:11)
    at CommitRankedAutoSizer (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:43680:32)
    at gi (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:15400:7)
    at zj (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:16741:7)
    at jl (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:19201:86)
    at il (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:18756:11)
    at hl (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:18748:23)

Error component stack (automated)

at CommitRankedAutoSizer (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:43659:34)
    at div
    at div
    at div
    at SettingsModalContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:35975:3)
    at Profiler_Profiler (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:53276:34)
    at ErrorBoundary_ErrorBoundary (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37375:5)
    at div
    at div
    at ThemeProvider (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37518:3)
    at PortaledContent (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37548:5)
    at div
    at div
    at div
    at ThemeProvider (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37518:3)
    at TimelineContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:42700:3)
    at ProfilerContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:42146:3)
    at TreeContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:30256:3)
    at SettingsContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:30878:3)
    at ModalDialogContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37927:3)
    at DevTools_DevTools (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:53807:3)

GitHub query string (automated)

https://api.github.com/search/issues?q=Could not find node with id  in commit tree in:title is:issue is:open is:public label:"Component: Developer Tools" repo:facebook/react
@wolfcomp wolfcomp added Component: Developer Tools Status: Unconfirmed A potential issue that we haven't yet confirmed as a bug Type: Bug labels Feb 12, 2022
@lunaruan
Copy link
Contributor

Hey! Thanks so much for reporting! I tried going through your repro steps but I got this error
image

Could you let me know how to fix this so I can start your app or could you maybe make a smaller repro (perhaps in codesandbox) so it's easier for me to test? Thanks!

@wolfcomp
Copy link
Author

I could possibly setup the dev server to run in Debug mode instead of Release so all of the development scripts are running for React.

I'm also a little confused why you are getting postcss errors when that comes from react-scripts.

@wolfcomp
Copy link
Author

If you try and load, https://modelsaber.rainemods.io/ you should get access to the profiler on the page now.

@wolfcomp
Copy link
Author

Update from my side.
Tested the same thing on my laptop I use for work, and it seems to not be happening there.
Will test more on the pc that causes the error and see if it's possible that it has a corrupt install of the extension.

@wolfcomp
Copy link
Author

Update again.
It seems to revolve around Suspense that causes the crash, and it's only on the Ranked tab and not Flamegraph tab.

@ImanMahmoudinasab
Copy link

I have the same issue.

Uncaught Error: Could not find node with id "13" in commit tree

Version
4.23.0 (1/24/2022)

more info:

The error was thrown at chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:25574:13
    at Map.forEach (<anonymous>)
    at RankedChartBuilder_getChartData (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:25570:24)
    at ProfilingCache_ProfilingCache.getRankedChartData (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:25686:11)
    at CommitRankedAutoSizer (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:43680:32)
    at gi (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:15400:7)
    at zj (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:16741:7)
    at jl (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:19201:86)
    at il (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:18756:11)
    at hl (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:18748:23)
The error occurred at CommitRankedAutoSizer (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:43659:34)
    at div
    at div
    at div
    at SettingsModalContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:35975:3)
    at Profiler_Profiler (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:53276:34)
    at ErrorBoundary_ErrorBoundary (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37375:5)
    at div
    at div
    at ThemeProvider (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37518:3)
    at PortaledContent (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37548:5)
    at div
    at div
    at div
    at ThemeProvider (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37518:3)
    at TimelineContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:42700:3)
    at ProfilerContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:42146:3)
    at TreeContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:30256:3)
    at SettingsContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:30878:3)
    at ModalDialogContextController (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:37927:3)
    at DevTools_DevTools (chrome-extension://fmkadmapgofadopljbjfkapdkoienihi/build/main.js:53807:3)

it's only on the Ranked tab and not Flamegraph tab.

The same for me.

@ImanMahmoudinasab
Copy link

@lunaruan Any update on this issue? This issue stops us from debugging our app.

@lunaruan
Copy link
Contributor

Hey, could either of you give me access to the codebase where this crash is happening? Unfortunately without a code repro I'm unable to debug this issue

@wolfcomp
Copy link
Author

Code: https://github.com/ModelSaber/ModelSaber.Main
Website: https://modelsaber.rainemods.io

The react app is in ClientApp in the code base as it is running with an ASP.NET instance as the server

@bvaughn
Copy link
Contributor

bvaughn commented Mar 2, 2022

If you try and load, https://modelsaber.rainemods.io/ you should get access to the profiler on the page now.

I can repro the error being reported by @wolfcomp by:

  1. Reload and profile
  2. Click the "Ranked" tab
  3. Click on the 2nd commit

It is interesting/unexpected that this bug only happens when the Ranked tab is open. I think that means the error must be somewhere in getRankedChartData (or the code it calls) which does at least help narrow it down.

The specific error, which I'm able to consistently reproduce, is:

RankedChartBuilder.js - Uncaught Error: Could not find node with id "16" in commit tree

Digging in further, I see that this is a context consumer component (for the Router router). This component is also not filtered out of the tree– although it may be part of a suspended subtree.

@bvaughn
Copy link
Contributor

bvaughn commented Mar 3, 2022

@wolfcomp

I tried to checkout the main modelsaber repo and get the client running locally so I could narrow down the repro case, but it seems like the READMEs are missing some instructions for how to get things running (like how to start the Apollo server). Any pointers?


Edit 1: Looks like I need to install .NET and run build.sh in the main repo, for one.


Edit 2: Looks like systemctl is required after the dotnet build, and I don't have a Linux box. Maybe there's a launchctl equivalent– but really, I don't want to get bogged down in this GraphQL stuff. Is there some way to just stub out the backend response? I'll try to just hard code that.


Edit 3: I stubbed out the GraphQL server, and now I'm also seeing another error in the console: SyntaxError: Unexpected token < in JSON at position 0. This one seems to be non-fatal though so I'm going to ignore it.


Edit 4: I can still repro the error even if I stub the GraphQL responses as shown below:

GetModelCursors

{
  "data": {
    "modelCursors": [
      "p37bdvs7D0-RdRJe8vVTfA"
    ]
  }
}

GetModels

{
  "data": {
    "models": {
      "items": [],
      "pageInfo": {
        "endCursor": "p37bdvs7D0-RdRJe8vVTfA",
        "hasNextPage": true,
        "hasPreviousPage": false,
        "__typename": "PageInfo"
      },
      "__typename": "ModelConnection"
    }
  }
}

Edit 5: I have been able to reduce the client app to a pretty small shell while still reproducing the error:

App.tsx

import { Route, Routes } from "react-router";
const Home = lazy(() => import("./Home"));

function App(): any {
  return (
    <Routes>
      <Route path="/" element={<Home />} />
    </Routes>
  );
};

Home.tsx

function Home(): any {
    return null;
};

Edit 6: I have not been able to repro this in a Code Sandbox (codesandbox.io/s/nameless-monad-opbrrv) even though I'm using the same version of react, react-dom, react-router, and react-router-dom.


Edit 7: Seems like this is a key part of the repro:
Index.tsx

// This is required:
const GQLClient = lazy(() => import("./GQLClient"));

// This isn't sufficient to repro:
import GQLClient from "./components/GQLClient";

Not sure how to move this into Code Sandbox yet (getting a runtime error from the "graphql" package at the moment) but still looking.


Edit 8: I've got a repro (see below)

@bvaughn
Copy link
Contributor

bvaughn commented Mar 3, 2022

I've got a repro that's been reduced about far as I am able to reduce it:
https://codesandbox.io/s/nameless-monad-opbrrv

// Does repro the error

import React, { lazy, Suspense, useEffect } from "react";
import { render } from "react-dom";

function Component({ children = null }) {
  return children;
}

let resolveComponentA = null;
const LazyComponentA = lazy(() => new Promise(resolve => {
  resolveComponentA = () => {
    resolve({ default: Component });
  };
}));

let resolveComponentB = null;
const LazyComponentB = lazy(() => new Promise(resolve => {
  resolveComponentB = () => {
    resolve({ default: Component });
  };
}));

function Index() {
    useEffect(() => {
        setTimeout(() => {
            resolveComponentA();
        }, 500);
    }, []);

    return (
        <React.StrictMode>
            <Suspense fallback={null}>
                <LazyComponentA>
                    <App />
                </LazyComponentA>
            </Suspense>
        </React.StrictMode>
    );
}

function App() {
    useEffect(() => {
        setTimeout(() => {
            resolveComponentB();
        }, 500);
    }, []);

  return <LazyComponentB />;
}

render(<Index />, document.getElementById("root"));

Repro steps:

  1. Visit https://opbrrv.csb.app/
  2. Click reload-and-profile button
  3. Select the "ranked" chart
  4. Click the 2nd commit

Reliably throws:

Uncaught Error: Could not find node with id "9" in commit tree

I have tried (unsuccessfully so far) to replicate this repro in a Jest test:

// Does not repro the error

function Component({ children = null, label }) {
  return children;
}

let resolveComponentA = null;
const ComponentA = React.lazy(() => new Promise(resolve => {
  resolveComponentA = () => {
    resolve({ default: Component });
  };
}));

let resolveComponentB = null;
const ComponentB = React.lazy(() => new Promise(resolve => {
  resolveComponentB = () => {
    resolve({ default: Component });
  };
}));

function Index() {
  React.useEffect(() => {
    setTimeout(() => {
      resolveComponentA();
    }, 500);
  }, []);

  return (
    <React.StrictMode>
      <React.Suspense fallback={null}>
        <ComponentA label="A">
          <App />
        </ComponentA>
      </React.Suspense>
    </React.StrictMode>
  );
}

function App() {
  React.useEffect(() => {
    setTimeout(() => {
      resolveComponentB();
    }, 500);
  }, []);

  return <ComponentB label="B" />;
}

utils.act(() => store.profilerStore.startProfiling());
await utils.actAsync(async () => {
  legacyRender(<Index />, document.createElement('div'));
});
utils.act(() => store.profilerStore.stopProfiling());

const TestRenderer = utils.requireTestRenderer();
const rootID = store.roots[0];

let renderFinished = false;

function Validator({commitIndex, rootID}) {
  const commitTree = store.profilerStore.profilingCache.getCommitTree({
    commitIndex,
    rootID,
  });
  const chartData = store.profilerStore.profilingCache.getRankedChartData(
    {
      commitIndex,
      commitTree,
      rootID,
    },
  );

  renderFinished = true;

  return null;
}

for (let commitIndex = 0; commitIndex < 2; commitIndex++) {
  renderFinished = false;

  utils.act(() => {
    TestRenderer.create(
      <Validator commitIndex={commitIndex} rootID={rootID} />,
    );
  });

  expect(renderFinished).toBe(true);
}

@bvaughn
Copy link
Contributor

bvaughn commented Mar 3, 2022

Inspecting DevTools internals after this error has occurred, I can see that the Store contains the inner Component node:

[root]
  ▾ <Index>
    ▾ <Suspense>
      ▾ <Component>
        ▾ <App>
            <Component> <-- This one

But for some reason, the tree built up by the CommitTreeBuilder doesn't contain the inner Component node (or anything beneath the Suspense node):

1:  (4.2)
•2:Index  (1.899)
••4:Suspense  (0.399)

I have occasionally seen the Profiler not error (and the CommitTreeBuilder contains the node) but most of the time it throws. So there's either a flat out logic error or (worse but maybe more likely?) a race case here.


Update Looking closer, I see the Store processing three updates but the CommitTreeBuilder is only getting the first two operations arrays, even though the commit data corresponds to the last two:

Store onBridgeOperations -- Commit # 1
  operations: 1,1,15,5,73,110,100,101,120,8,83,117,115,112,101,110,115,101,1,1,11,0,1,1,1,4,1,2999,1,2,5,1,0,1,0,4,2,1199,1,4,12,2,2,2,0,7,4,1,4,4,299
  
  Store Add new root node 1
  Store Add node 2 (Index) as child of 1
  Store Add node 4 (Suspense) as child of 2
  Store Subtree mode Subtree with root 4 set to mode 1

  [root] (2)
    ▾ <Index> (2)
        <Suspense> (1)

Store onBridgeOperations -- Commit # 2
  operations: 1,1,0,4,4,199,4,2,1099,4,1,2899
  [root] (2)
    ▾ <Index> (2)
        <Suspense> (1)

Store onBridgeOperations -- Commit # 3
  operations: 1,1,14,9,67,111,109,112,111,110,101,110,116,3,65,112,112,1,7,5,4,2,1,0,4,7,599,1,8,5,7,2,2,0,4,8,199,1,9,5,8,8,1,0,4,9,0,4,4,699,4,2,1599,4,1,3399
  
  Store Add node 7 (Component) as child of 4
  Store Add node 8 (App) as child of 7
  Store Add node 9 (Component) as child of 8

  [root] (5)
    ▾ <Index> (5)
      ▾ <Suspense> (4)
        ▾ <Component> (3)
          ▾ <App> (2)
              <Component> (1)

---

CommitTreeBuilder updateTree  -- Commit # 1
  operations: 1,1,15,5,73,110,100,101,120,8,83,117,115,112,101,110,115,101,1,1,11,0,1,1,1,4,1,2999,1,2,5,1,0,1,0,4,2,1199,1,4,12,2,2,2,0,7,4,1,4,4,299
  CommitTreeBuilder Add new root fiber 1
  CommitTreeBuilder Update fiber 1 treeBaseDuration to 2.999
  CommitTreeBuilder Add fiber 2 (Index) as child of 1
  CommitTreeBuilder Update fiber 2 treeBaseDuration to 1.199
  CommitTreeBuilder Add fiber 4 (Suspense) as child of 2
  CommitTreeBuilder Subtree mode Subtree with root 4 set to mode 4
  CommitTreeBuilder Update fiber 4 treeBaseDuration to 0.299
   __printTree()
   1:  (2.999)
   •2:Index  (1.199)
   ••4:Suspense  (0.299)

CommitTreeBuilder updateTree  -- Commit # 2 (should be #3)
  operations: 1,1,0,4,4,199,4,2,1099,4,1,2899
  CommitTreeBuilder Update fiber 4 treeBaseDuration to 0.199
  CommitTreeBuilder Update fiber 2 treeBaseDuration to 1.099
  CommitTreeBuilder Update fiber 1 treeBaseDuration to 2.899
   __printTree()
   1:  (2.899)
   •2:Index  (1.099)
   ••4:Suspense  (0.199)

@bvaughn
Copy link
Contributor

bvaughn commented Mar 4, 2022

Picking back up on this thread today.
Screen Shot 2022-03-04 at 11 36 17 AM

The problem is definitely a misalignment between the operations arrays and the commit data. I think this might be because the backend is preemptively filtering out an "empty" commit (nothing that affects the profiler UI?) which causes the ranked builder to falter. Need to dig in a little more.


Edit 1: I think the issue might be that we filter "empty" commits (or commits that fall below a certain duration threshold) in one place – but we don't respect that filter in another (the chart builder). Need to look at this closer after lunch.

--

Edit 2: I think this is the culprit:

// Make sure at least one Fiber performed work during this commit.
// If not, don't send it to the frontend; showing an empty commit in the Profiler is confusing.
if (
currentCommitProfilingMetadata != null &&
currentCommitProfilingMetadata.durations.length > 0
) {

I'm not sure why it only affects ranked view yet though.


@ImanMahmoudinasab
Copy link

@lunaruan any progress on this bug?

@bvaughn bvaughn self-assigned this Mar 8, 2022
@bvaughn
Copy link
Contributor

bvaughn commented Mar 8, 2022

@ImanMahmoudinasab There is a trail of comments on the issue right above yours that show progress.

@bvaughn
Copy link
Contributor

bvaughn commented Mar 9, 2022

#24031 has the fix. Soon as it's reviewed (tomorrow?) we'll release it to NPM and the browsers.

@ImanMahmoudinasab
Copy link

@bvaughn Thank you for your great work!

@bvaughn
Copy link
Contributor

bvaughn commented Mar 10, 2022

4.24 release will be made today. Fix should roll out as soon as the release goes live.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Component: Developer Tools Status: Unconfirmed A potential issue that we haven't yet confirmed as a bug Type: Bug
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants