Internal error when trying to measure app start time

Question

Internal error when trying to measure app start time

hannojg opened this issue 2 years ago · 4 comments

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:

iOS
Android

Packages

Which packages are affected by the issue?

@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

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

Answer 1 · 2023-01-27T18:17:22.000Z

Hello ! I did have the same bug and error, on a screen with the same props (interactive=true) having lot of re-renders @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 🤞

Answer 2 · 2023-02-24T03:02:43.000Z

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

Answer 3 · 2023-08-03T11:54:13.000Z

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