Internal error when trying to measure app start time

[hannojg]

Current behavior

• App starts, native calls are happening
• First PerformanceMeasureView gets mounted with interactive: true
• The component gets re-renders 2-3 times (I can see from the logs)
• Errors start to happen. I have attached a sequence of events:

 DEBUG  State: {
  "name": "Started",
  "destinationScreen": "__unknown_destination_screen__",
  "componentInstanceId": "__unknown_destination_screen__",
  "timestamp": {
    "jsTimestamp": 1670262555419,
    "nativeTimestamp": {
      "_h": 0,
      "_i": 0,
      "_j": null,
      "_k": null
    }
  },
  "operationsSnapshot": {
    "operationTimestamps": {}
  },
  "ongoingOperations": {
    "operationTimestamps": {}
  },
  "type": "app_boot"
}

 DEBUG  State: {
  "name": "Mounted",
  "destinationScreen": "SidebarLinks",
  "componentInstanceId": "0",
  "previousState": "Started",
  "timestamp": {
    "jsTimestamp": 1670262556730
  },
  "operationsSnapshot": {
    "operationTimestamps": {}
  },
  "ongoingOperations": {
    "operationTimestamps": {}
  }
}

 DEBUG  State: {
  "name": "Unmounted",
  "destinationScreen": "SidebarLinks",
  "componentInstanceId": "0",
  "previousState": "Mounted",
  "timestamp": {
    "jsTimestamp": 1670262557145
  },
  "operationsSnapshot": {
    "operationTimestamps": {}
  },
  "ongoingOperations": {
    "operationTimestamps": {}
  }
}
 DEBUG  State: {
  "name": "RenderAborted",
  "destinationScreen": "SidebarLinks",
  "componentInstanceId": "0",
  "previousState": "Mounted",
  "timestamp": {
    "jsTimestamp": 1670262557146
  },
  "operationsSnapshot": {
    "operationTimestamps": {}
  },
  "ongoingOperations": {
    "operationTimestamps": {}
  }
}

 ERROR  ScreenProfilerNotStartedError: No previous state was found for screen 'SidebarLinks' with componentInstanceId 0. This probably means that the navigation-start event was never recorded, while a subsequent render flow event was (render pass start, data operation profiling, etc.). You seem to have used some profiling API but likely forgot to use the 'useStartProfiler' hook to start the flow. Read the usage here: https://shopify.github.io/react-native-performance/fundamentals/measuring-render-times.
 ERROR  You have hit an internal error, please report this: https://github.com/Shopify/react-native-performance/issues/new
InvalidMountStateError: No matching Mounted state found for componentInstanceId 0 for screen SidebarLinks.
 ERROR  ScreenProfilerNotStartedError: No previous state was found for screen 'SidebarLinks' with componentInstanceId 0. This probably means that the navigation-start event was never recorded, while a subsequent render flow event was (render pass start, data operation profiling, etc.). You seem to have used some profiling API but likely forgot to use the 'useStartProfiler' hook to start the flow. Read the usage here: https://shopify.github.io/react-native-performance/fundamentals/measuring-render-times.
 ERROR  ScreenProfilerNotStartedError: No previous state was found for screen 'SidebarLinks' with componentInstanceId 0. This probably means that the navigation-start event was never recorded, while a subsequent render flow event was (render pass start, data operation profiling, etc.). You seem to have used some profiling API but likely forgot to use the 'useStartProfiler' hook to start the flow. Read the usage here: https://shopify.github.io/react-native-performance/fundamentals/measuring-render-times.
 INFO  Render Pass Report: {
  "reportId": "2EEFBA96-5EC2-4545-B7BB-5C639987F5C0",
  "resourceAcquisitionStatus": {
    "totalTimeMillis": 0,
    "components": {}
  },
  "flowInstanceId": "C25AC411-1315-494C-91B8-D6470F4AF056",
  "destinationScreen": "SidebarLinks",
  "flowStartTimeSinceEpochMillis": 1670262555419,
  "timeToBootJsMillis": 2623.050048828125,
  "timeToAbortMillis": 1727,
  "interactive": false
}

Expected behavior

It to work and not throw internal errors 🌝❤️

To Reproduce

I thinks it's pretty much related to the amount of re-renders happening before the first measurement can be processed? I can try to isolate the issue in a clean reproduction once I find the time. In the meantime you can try the branch of the project the issue is happening on: https://github.com/margelo/expensify-app-fork/tree/dev/better-performance-metrics

Platform:

• [x] iOS
• [x] Android

Packages

Which packages are affected by the issue?

• [x] @shopify/react-native-performance
• [ ] @shopify/react-native-performance-lists-profiler
• [ ] flipper-plugin-shopify-react-native-performance
• [ ] @shopify/react-native-performance-navigation
• [ ] @shopify/react-native-performance-navigation-bottom-tabs
• [ ] @shopify/react-native-performance-navigation-drawer

Environment

• [x] I've removed the packages that I don't use

package	version
@shopify/react-native-performance	4.1.2
@react-navigation/native	6.0.13
@react-navigation/stack	6.3.1
react-native	0.70.4

[nparigi-ledger]

Hello ! I did have the same bug and error, on a screen with the same props (interactive=true) having lot of re-renders :octocat: @hannojg I found a solution by making sure that was the parent of And i used ReactNavigationPerformanceView as parent of my screen component For now, it's working :crossed_fingers:

[jmorey28]

Is there any update on this? I'm seeing the same issue.

[aarkalyk]

@hannojg @jmorey28 managed to solve this issue by making the PerformanceProfiler outer most provider for the app root.

[SudoPlz]

For me this only happens when I hot reload.

Having the same problem even-though PerformanceProfiler is the outmost provider of the app root. My app is using wix's react-native-navigation though, so that may be a contributing factor.