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

metro-file-map: Got unexpected null error (in onTimeout) #1015

Closed
renchap opened this issue Jun 25, 2023 · 5 comments
Closed

metro-file-map: Got unexpected null error (in onTimeout) #1015

renchap opened this issue Jun 25, 2023 · 5 comments
Assignees
Labels

Comments

@renchap
Copy link

renchap commented Jun 25, 2023

Do you want to request a feature or report a bug?
Bug report

What is the current behavior?
This started to happen after updating from RN 0.71 to 0.72.

Metro crashes with the following error:

/Users/renchap/dev/notos/node_modules/.pnpm/nullthrows@1.1.1/node_modules/nullthrows/nullthrows.js:9
  throw error;
  ^

Error: Got unexpected null
    at nullthrows (/Users/renchap/dev/notos/node_modules/.pnpm/nullthrows@1.1.1/node_modules/nullthrows/nullthrows.js:7:15)
    at Timeout.emitChange [as _onTimeout] (/Users/renchap/dev/notos/node_modules/.pnpm/metro-file-map@0.76.5/node_modules/metro-file-map/src/index.js:823:48)
    at listOnTimeout (node:internal/timers:569:17)
    at process.processTimers (node:internal/timers:512:7) {
  framesToPop: 1
}

This seems to be happening what I start a build, or when I run pnpm.

This was not happening when running RN 0.71 (Metro 0.73.9).

If the current behavior is a bug, please provide the steps to reproduce and a minimal repository on GitHub that we can yarn install and yarn test.
I do not have a repro, this happens randomly

What is the expected behavior?
Metro does not crash

Please provide your exact Metro configuration and mention your Metro, node, yarn/npm version and operating system.
Metro 0.76.5 in a pnpm monorepo

  • Standard RN configuration, but using unstable_enableSymlinks: true, due to pnpm
  • Node 18.16.0
  • pnpm 8.6.2
  • macOS 13.4.1
@robhogan robhogan added the bug label Jul 5, 2023
@robhogan robhogan self-assigned this Jul 5, 2023
@robhogan
Copy link
Contributor

robhogan commented Jul 5, 2023

Thanks for the report. I've seen this a very intermittently as well - just noting for now that the offending assertion is this one

hmrPerfLogger.start({timestamp: nullthrows(eventStartTimestamp)});

So eventStartTimestamp is null for some reason, possibly a parallel Fast Refresh race - pretty sure it's unrelated to unstable_enableSymlinks or PNPM. We'll backport a fix once we pin this down.

@angusryer
Copy link

I have this issue consistently since upgrading to 0.72.4 from 0.71.6. I also have unstable_enableSymlinks = true, and have watchman configured to watch folders outside the yarn workspace my RN project is in.

I use a custom bash script that detects existing instances of metro and launches a new instance if necessary before building and running the Android and iOS emulator/sim (in that order, by chance). This error always occurs while the Android emulator is connected and building on-device.

It doesn't happen if I launch the sims manually.

I'm running metro v0.76.7.

Here's the output from npx react-native info:

System:
  OS: macOS 13.5.1
  CPU: (8) arm64 Apple M1
  Memory: 135.63 MB / 16.00 GB
  Shell:
    version: "5.9"
    path: /bin/zsh
Binaries:
  Node:
    version: 18.16.1
    path: ~/.nvm/versions/node/v18.16.1/bin/node
  Yarn:
    version: 3.2.2
    path: ~/.yarn/bin/yarn
  npm:
    version: 9.5.1
    path: ~/.nvm/versions/node/v18.16.1/bin/npm
  Watchman:
    version: 2023.07.10.00
    path: /opt/homebrew/bin/watchman
Managers:
  CocoaPods:
    version: 1.12.1
    path: /Users/angusryer/.rvm/gems/ruby-2.7.5/bin/pod
SDKs:
  iOS SDK:
    Platforms:
      - DriverKit 22.1
      - iOS 16.1
      - macOS 13.0
      - tvOS 16.1
      - watchOS 9.1
  Android SDK:
    Android NDK: 22.1.7171670
IDEs:
  Android Studio: 2022.3 AI-223.8836.35.2231.10671973
  Xcode:
    version: 14.1/14B47b
    path: /usr/bin/xcodebuild
Languages:
  Java:
    version: 11.0.19
    path: /usr/bin/javac
  Ruby:
    version: 2.7.5
    path: /Users/angusryer/.rvm/rubies/ruby-2.7.5/bin/ruby
npmPackages:
  "@react-native-community/cli": Not Found
  react:
    installed: 18.2.0
    wanted: 18.2.0
  react-native:
    installed: 0.72.4
    wanted: 0.72.4
  react-native-macos: Not Found
npmGlobalPackages:
  "*react-native*": Not Found
Android:
  hermesEnabled: true
  newArchEnabled: false
iOS:
  hermesEnabled: true
  newArchEnabled: false

@yangm97
Copy link

yangm97 commented Sep 11, 2023

In my case this bug seems to be triggered by operations in node_modules such as when you yarn add something.

robhogan added a commit to robhogan/metro that referenced this issue Sep 14, 2023
Summary:
Fixes a crash where a race in overlapping file change processing could occasionally throw "unexpected null".

Fixes facebook#1015

## Root cause
The problem logic is in some instrumentation code introduced in D40346848.

`metro-file-map` batches changes using `setInterval(emitChange, 30)`. The instrumentation attempted to record the time of the first event in a given batch, and then "reset the clock" when the batch is emitted to the consumer.

The problem occurred when an emit interval fell such that a non-empty `emitChange` occurred *during* the async `_processFile` step of a subsequent change. The first emit would reset the "start time" to `null`, and the second `emitChange` would fail at `nullthrows(eventStartTimestamp)`, because `eventStartTimestamp` is only set *before* `_processFile` starts (and only if already `null`).

The (over)writing of `eventStartTimestamp` was flawed, because we don't know at the start of change processing that this event is going to be the start of a batch - this only becomes clear when an event is subsequently enqueued for emit after file processing.

## This diff
This changes the recording of the start time such that we take a timestamp on every change, and record it as the batch start time on the creation of a new batch. We rearrange the various moving parts into a nullable object, so that "first event time" is tightly coupled to the batch it describes, and can never be `null` for a non-empty batch.

## Changelog
```
 * **[Fix]:** Fix "unexpected null" crash when handling a batch of file changes.
```

Differential Revision: D49272782
@robhogan
Copy link
Contributor

Confirmed that this is an intermittent race crash caused when dealing with many overlapping file change events (eg, a yarn operation, or native build). #1083 should fix it, and I'll backport that for supported RN versions.

@siddarthkay
Copy link

Hi @robhogan : Thanks for this fix!
I see this fix is already a part of react-native 0.73, Can you please let me know when this fix is planned to land in 0.72?
our project is currently using react-native 0.72.5

robhogan added a commit that referenced this issue Jan 9, 2024
Summary:
Pull Request resolved: #1083

Fixes a crash where a race in overlapping file change processing could occasionally throw "unexpected null".

Fixes #1015

## Root cause
The problem logic is in some instrumentation code introduced in D40346848.

`metro-file-map` batches changes using `setInterval(emitChange, 30)`. The instrumentation attempted to record the time of the first event in a given batch, and then "reset the clock" when the batch is emitted to the consumer.

The problem occurred when an emit interval fell such that a non-empty `emitChange` occurred *during* the async `_processFile` step of a subsequent change. The first emit would reset the "start time" to `null`, and the second `emitChange` would fail at `nullthrows(eventStartTimestamp)`, because `eventStartTimestamp` is only set *before* `_processFile` starts (and only if already `null`).

The (over)writing of `eventStartTimestamp` was flawed, because we don't know at the start of change processing that this event is going to be the start of a batch - this only becomes clear when an event is subsequently enqueued for emit after file processing.

## This diff
This changes the recording of the start time such that we take a timestamp on every change, and record it as the batch start time on the creation of a new batch. We rearrange the various moving parts into a nullable object, so that "first event time" is tightly coupled to the batch it describes, and can never be `null` for a non-empty batch.

## Changelog
```
 * **[Fix]:** Fix "unexpected null" crash when handling a batch of file changes.
```

Reviewed By: huntie

Differential Revision: D49272782

fbshipit-source-id: 8e1a4ebb6876fad982af3aa8a1922c6f14236040
robhogan added a commit that referenced this issue Jan 30, 2024
Summary:
Pull Request resolved: #1083

Fixes a crash where a race in overlapping file change processing could occasionally throw "unexpected null".

Fixes #1015

## Root cause
The problem logic is in some instrumentation code introduced in D40346848.

`metro-file-map` batches changes using `setInterval(emitChange, 30)`. The instrumentation attempted to record the time of the first event in a given batch, and then "reset the clock" when the batch is emitted to the consumer.

The problem occurred when an emit interval fell such that a non-empty `emitChange` occurred *during* the async `_processFile` step of a subsequent change. The first emit would reset the "start time" to `null`, and the second `emitChange` would fail at `nullthrows(eventStartTimestamp)`, because `eventStartTimestamp` is only set *before* `_processFile` starts (and only if already `null`).

The (over)writing of `eventStartTimestamp` was flawed, because we don't know at the start of change processing that this event is going to be the start of a batch - this only becomes clear when an event is subsequently enqueued for emit after file processing.

## This diff
This changes the recording of the start time such that we take a timestamp on every change, and record it as the batch start time on the creation of a new batch. We rearrange the various moving parts into a nullable object, so that "first event time" is tightly coupled to the batch it describes, and can never be `null` for a non-empty batch.

## Changelog
```
 * **[Fix]:** Fix "unexpected null" crash when handling a batch of file changes.
```

Reviewed By: huntie

Differential Revision: D49272782

fbshipit-source-id: 8e1a4ebb6876fad982af3aa8a1922c6f14236040
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

5 participants