NetworkLogger issue - Multiple "Error - Request has not been opened" non-fatal error reports when using SDK 14.1.0

[leonardorib]

Minimal reproducer

https://github.com/leonardorib/InstabugNetworkLoggerIssue

Steps

I recommend looking into the reproducer since it's already done. But here are the steps I'm following there:

1. On a clean RN 0.77.0 project with Instabug 14.1.0, make sure to have Instabug initialized and that NetworkLogger is enabled.
2. Perform a connectivity check with NetInfo like NetInfo.fetch. The first time you do it after app open it should trigger the issue.

This does not happen on 14.0.0.

In order for the bug to be visible and reported to Instabug you need to be on a release build, because this is an Unhandled promise rejection. Alternatively if you want to see it in DEV, you can include logs in the react-native file that throws that error. In the minimal repro I provided I'm including a patch doing that so you can use it to see it in dev.

Details and investigation

After trying out upgrade from Instabug 14.0.0 to 14.1.0 we started to see a bunch of
non-fatal errors on the "Crashes" section on our dashboard for the release build with the following message:

Error - Request has not been opened

The error is thrown from this react-native file: https://github.com/facebook/react-native/blob/110450105e140d0846c63d3d15f356beefaeb020/packages/react-native/Libraries/Network/XMLHttpRequest.js#L540. I verified by manually insertting logs there in my node_modules/eract-native.

Reverting back to 14.0.0 solves it. We stop getting those.

After some debugging I found that when Instabug's Network Logger is enabled, some http requests from the connectivity checks done with @react-native-community/netinfo (a pretty standard package to check for network status) start to throw that error. So disabling the Network Logger on 14.1.0 also solves it.

The first underlying request it does when you try like NetInfo.fetch will trigger that. And you can't catch it. You can simulate the first request by recalling NetInfo.configure to reset it's state.

Potential dangerous change from 14.0.0 to 14.1.0 that is probably the cause

I looked at the changes from 14.0 to 14.1 and found something that can cause issues.

React-native original XMLHttpRequest implementation

This is the original XMLHttpRequest send method implementation from react-native:
https://github.com/facebook/react-native/blob/110450105e140d0846c63d3d15f356beefaeb020/packages/react-native/Libraries/Network/XMLHttpRequest.js#L538

Where send has this signature:

send: (data: any): void

How Instabug 14.0.0 overrides it

This is the override done by Instabug 14.0.0 on the XhrNetworkInterceptor when you have the Network Logger enabled:

Instabug-React-Native/src/utils/XhrNetworkInterceptor.ts

Line 94 in 6692f7b

XMLHttpRequest.prototype.send = function (data) {

Method is still

send: (data: any): void

How Instabug 14.1.0 overrides it

This is it on Instabug 14.1.0:

Instabug-React-Native/src/utils/XhrNetworkInterceptor.ts

Line 178 in 2b094ca

XMLHttpRequest.prototype.send = async function (data) {

So now the method turns into

send: async (data: any): Promise<void>

because it is doing:

async function (data) {
  // ...
  const traceparent = await getTraceparentHeader(cloneNetwork); // <--- awaiting this
  if (traceparent) {
    this.setRequestHeader('Traceparent', traceparent);
  }
  //...
}

So something that is originally sync is now being overriden with an async operation
that can have some delay before resolving.

This can break stuff that was relying on the sync behavior.

So I tried manually doing this on 14.1.0:

diff --git a/node_modules/instabug-reactnative/src/utils/XhrNetworkInterceptor.ts b/node_modules/instabug-reactnative/src/utils/XhrNetworkInterceptor.ts
index 4443940..1862b36 100644
--- a/node_modules/instabug-reactnative/src/utils/XhrNetworkInterceptor.ts
+++ b/node_modules/instabug-reactnative/src/utils/XhrNetworkInterceptor.ts
@@ -175,7 +175,7 @@ export default {
       originalXHRSetRequestHeader.apply(this, [header, value]);
     };

-    XMLHttpRequest.prototype.send = async function (data) {
+    XMLHttpRequest.prototype.send = function (data) {
       const cloneNetwork = JSON.parse(JSON.stringify(network));
       cloneNetwork.requestBody = data ? data : '';

@@ -310,10 +310,10 @@ export default {
       }

       cloneNetwork.startTime = Date.now();
-      const traceparent = await getTraceparentHeader(cloneNetwork);
-      if (traceparent) {
-        this.setRequestHeader('Traceparent', traceparent);
-      }
+      // const traceparent = await getTraceparentHeader(cloneNetwork);
+      // if (traceparent) {
+      //   this.setRequestHeader('Traceparent', traceparent);
+      // }
       originalXHRSend.apply(this, [data]);
     };
     isInterceptorEnabled = true;

Which is basically only removing the new "await call" in there and making it a sync function again. And it fixes the issue. Can't repro anymore even with NetworkLogger enabled after doing that.

[stale]

This issue has been automatically marked as pending feedback because we need additional information to be able to investigate it further. It will be closed in 7 days if it remains inactive. Thank you for your contributions.

[leonardorib]

This issue has been automatically marked as pending feedback because we need additional information to be able to investigate it further. It will be closed in 7 days if it remains inactive. Thank you for your contributions.

Please can you guys let me know what additional information you need? Since there is a minimal reproducer repository for the issue.

[MoKamall]

@leonardorib Thanks for the detailed feedback, and reproducer! We will be looking into this one, and we will get back to you as soon as possible.

[stale]

This issue has been automatically marked as pending feedback because we need additional information to be able to investigate it further. It will be closed in 7 days if it remains inactive. Thank you for your contributions.

[gcottrell1]

we are also seeing this in production

[bobinrinder]

@gcottrell1 We got a snapshot from Instabug for this, try it out: npm install [email protected]
They said they would make a 14.1 release for RN in April.

[stale]

This issue has been automatically marked as pending feedback because we need additional information to be able to investigate it further. It will be closed in 7 days if it remains inactive. Thank you for your contributions.

[stale]

This issue has been automatically marked as pending feedback because we need additional information to be able to investigate it further. It will be closed in 7 days if it remains inactive. Thank you for your contributions.

[stale]

This issue has been automatically closed since we haven't heard back from you. Please feel free to re-open the issue if you have more information to add.

[leethree]

We are seeing the same issue. I think it's unsafe to overwrite the built in send function with async. This will certainly cause timing issues because some operation could depend on this function to return synchronously.