facebook / hermes

A JavaScript engine optimized for running React Native.
https://hermesengine.dev/
MIT License
9.79k stars 628 forks source link

Strange hermes debug jumps and var state #23820 #1087

Open mgscreativa opened 1 year ago

mgscreativa commented 1 year ago

Minimal reproducible example

https://github.com/mgscreativa/heremes-test-expo-go

Summary

I’m using hermes debugging working, but the debugger behaviour is really strange. My workspace is as follows:

For testing hermes debugging I have created a complete new and clean app with npx create-expo-app@latest --template tabs, I have also uploaded the app to GitHub here GitHub - mgscreativa/heremes-test-expo-go: heremes-test-expo-go 1

Accessing chrome debugger by pressing j in terminal I can see the hermes instance running and also can browse the project files and set some breakpoints in code but the debugger behaviour is really strange, ie:

I have tested the same result in:

Have attached a two videos showing the process I’m following

Linux, Android Emu API 33

Peek 2023-08-04 12-16

Linux, iOS expo go

Peek 2023-08-04 12-21ios

Production code project

In this third video I'm showing the behaviour I get using a more complex project that I'm working on. I'll describe the strange behaviour:

Peek 2023-08-04 12-53-3

What Am I doing wrong? Should I configure anything else?

PS: Flipper 0.210.0 has the same behavior, tested on macos

Environment

expo-env-info 1.0.5 environment info: System: OS: Linux 5.15 Linux Mint 21.2 (Victoria) Shell: 5.1.16 - /bin/bash Binaries: Node: 16.13.1 - ~/.nvm/versions/node/v16.13.1/bin/node Yarn: 1.22.19 - ~/.nvm/versions/node/v16.13.1/bin/yarn npm: 9.8.1 - ~/.nvm/versions/node/v16.13.1/bin/npm Watchman: 20230430.125247.0 - /usr/local/bin/watchman SDKs: Android SDK: API Levels: 33 Build Tools: 30.0.3, 33.0.0 System Images: android-30 | Google APIs Intel x86 Atom, android-30 | Google Play Intel x86_64 Atom, android-32 | Google APIs Intel x86_64 Atom, android-33 | Google APIs Intel x86_64 Atom npmPackages: expo: ~49.0.5 => 49.0.6 react: 18.2.0 => 18.2.0 react-dom: 18.2.0 => 18.2.0 react-native: 0.72.3 => 0.72.3 react-native-web: ~0.19.6 => 0.19.7 npmGlobalPackages: eas-cli: 3.18.3 expo-cli: 6.3.10 Expo Workflow: managed

mgscreativa commented 1 year ago

Bump... any comments from devs?

tmikov commented 1 year ago

Hi, it is very difficult for us to debug something with complex dependencies. Can this be reproduced with a bare RN application?

mgscreativa commented 1 year ago

@tmikov cool! will create a bare RN test repo and check this issue in iOS and Android and let you know

byCedric commented 1 year ago

Did you open the debugger after making various code changes? If so, I think at least the breakpoints being set in different locations (and the code stopping on different parts) is due to an issue with Debugger.scriptParsed issue.

@tmikov Basically what's happening is that on every change (during a HMR session), the new bundle is parsed as new script. When the debugger connects, it receives all versions of the same bundle in the wrong order (from new to old) and possibly confusing the debugger a bit here.

Breakpoints in general are handled client-side on the debugger right now. Chrome devtools is trying to match the breakpoints by source map, and with the bug I just described, might result in some weird behavior.

I tested this issue a bit on the expo/expo repository, you can see a test PR to prevent this exact use case here. But, this PR probably breaks some things, that's why we probably aren't going to merge it.

Hope this helps!

mattbfb commented 1 year ago

@byCedric that's an interesting case, thanks for sharing. It's true that right now a quick reload after making an edit does simply start running the new JS bundle alongside the old one (as opposed to a full reload that restarts the JS VM with just the updated code), but that should still be usable in theory.

I believe the most common way Chrome Dev Tools sets breakpoints is via setBreakpointByURL, which specifies where to set a breakpoint by file name (as opposed to using the ID that scriptParsed uses to identify source/maps), and will end up triggering multiple breakpoints when there are multiple copies of the script running simultaneously. This should still be able to report accurate locations when pausing, as the specific pause location (and corresponding source/map that should be used) is indicated by ID, rather than URL, allowing Chrome Dev Tools to display the correct one of the multiple versions of the script being run.

If your PR does improve pause locations, perhaps there's either a bug in scriptID management, or a different sequence of events is playing out than what I described.

Either way, I'd be curious to know if the code reloading issue is what @mgscreativa is running into, and if they're able to repro in the plain RN setup.

byCedric commented 1 year ago

@mattbfb I'll do some more testing on my end as well. But, here is a short overview from what I can see through the Protocol Monitor (Chrome DevTools experiment, but very useful).

Sorry in advance for the longer comment, but I think it's good to go into details here. Here is a JSON dump of all events listed below (in chronological order from oldest > newest) events in case you want to investigate yourself.

Breakpoint.setBreakpointByUrl is just referring to the bundled code, and thus resolved from sourcemap prettified code to the bundle (which is client side AFAIK)

image

In some cases, chrome devtools seems to not resolve the code properly. In the screenshot below, you can see the devtools trying to bind to "line 9, col 4", which is incorrect if you compare it with the actual bundled script executed (also the original source code btw). Not sure why this happens, or if this is a race condition from parsing sourcemaps and eagerly setting breakpoints.

image

One of the reasons why I think some unexpected behavior is related to these different script instances can be seen here. Besides the setBreakpointByURL, there is also Debugger.getPossibleBreakpoints (which is currently unimplemented - but invoked by devtools to find non-bindable code).

The screenshot below shows that it's asking for "script 3" and "script 4", while the HMR session has 9 already. But, since that was sent as first Debugger.scriptParsed event, I think the devtools is overwriting those script versions in later scriptParsed events (such as the script 4 & 3 events)

image
Here is script 9 image
Here is script 4 image
Here is script 3 image

All of this was tested in a default template Expo app (yarn create expo ./test-devtools - to try it yourself).

byCedric commented 1 year ago

@mattbfb I've been able to reproduce the behavior I described above with the React Native Community CLI too. Here is the full JSON dump of the debugger.

Here is script 10 image
Here is script 3 image

Eventually, the different script IDs lead up to two breakpoints being bound. One in "script 10", at a wrong location, and one in "script 3" at the correct location for the outdated script.

Breakpoint at script 3, good location but outdated code image
Breakpoint at script 10, good code, but wrong location image
mattbfb commented 1 year ago

@byCedric thanks for that investigation with such thorough documentation!

I'll follow your steps and try to repro locally as well. I'm curious to learn more about a few things:

  1. If old versions of code are still running simultaneously with new code (e.g. if a breakpoint is set at an unusual point in old versions of the code, will it ever be hit?).
  2. If Chrome is displaying the latest version of the code. It does have some logic to match based on file name and choose the latest, but perhaps they're being sent in an order that confuses it, or it just doesn't handle them correctly in quick succession.
  3. Why the mid-line breakpoint expressions are showing in the screenshots. We don't answer Debugger.getPossibleBreakpoints today, but the screenshots have the breakpoint markers mid-line, showing the possible breakpoint locations as if that message was answered.
byCedric commented 1 year ago

@mattbfb No problem, happy to help.

  1. AFAIK, breakpoints are still binding, but to the wrong locations. This is equal to randomly binding breakpoints, resulting in some of these being hit and pausing the app in an unexpected position. Once hit, the bundle code is displayed and then paused on something usually at the top of the bundle.

  2. Chrome DevTools have something they call computeNonBreakableLines, which seems to be using the sourcemap as a reference. I'm not entirely sure how the source maps are handled within Chrome DevTools, but that might indeed affect this logic.

  3. The computeNonBreakableLines seems to try to map the source code to actual bundled code. If it doesn't have a match, it considers the breakpoint "unbindable". This makes sense for empty lines, which seems to be the only scenario where Chrome DevTools marks lines as unbindable. But, all of this still happens client side.

Hope this helps! I can also hop on a call if needed (I'm in the RN Discord).

mgscreativa commented 1 year ago

Thanks a lot @byCedric and @mattbfb for taking the time to review this! No step debugging is not debugging at all...

robozb commented 1 year ago

My experience with the topic above: https://github.com/expo/expo/issues/24273

dannysu commented 11 months ago

@mgscreativa, I don't know that we're actually making progress here. Were you ever able to reproduce using a bare RN app?

Also, I don't think you answered this question from @byCedric: "Did you open the debugger after making various code changes?"

We need a good set of repro in order for us to root cause the issue. Right now we don't have it.

@byCedric I'm not 100% sure the issue you talked about is causing this reported issue. But I landed a fix for Hermes CDP to make sure the scriptParsed ordering is always maintained: https://github.com/facebook/hermes/commit/f6aed0e0fe1e106fe22a65e701e35246515f0900

dariovr1 commented 11 months ago

@mgscreativa, I don't know that we're actually making progress here. Were you ever able to reproduce using a bare RN app?

Also, I don't think you answered this question from @byCedric: "Did you open the debugger after making various code changes?"

We need a good set of repro in order for us to root cause the issue. Right now we don't have it.

@byCedric I'm not 100% sure the issue you talked about is causing this reported issue. But I landed a fix for Hermes CDP to make sure the scriptParsed ordering is always maintained: f6aed0e

Good day, i have the same issue. Are you think that the problem is gone away with this fix?