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

Expo 50: Events are processed on device, but never sent to Sentry (worked on SDK 49) #3698

Closed
6 tasks
csvan opened this issue Mar 20, 2024 · 9 comments
Closed
6 tasks

Comments

@csvan
Copy link

csvan commented Mar 20, 2024

OS:

  • Windows
  • [ x ] MacOS
  • Linux

Platform:

  • iOS
  • [ x ] Android

SDK:

  • [ x ] @sentry/react-native (>= 1.0.0)
  • react-native-sentry (<= 0.43.2)

SDK version: 5.20.0

react-native version: 0.0.0

Are you using Expo?

  • [ x ] Yes (SDK 50)
  • No

Are you using sentry.io or on-premise?

  • sentry.io (SaaS)
  • [ x ] on-premise (24.3.0)

If you are using sentry.io, please post a link to your issue so we can take a look:

[Link to issue]

Configuration:

(@sentry/react-native)

Sentry.init({
  beforeSend: (event) => {
    event.tags = {
      ...(event.tags || {}),
      app: 'my-app',
    };
    return event;
  },
  integrations: [
    new Sentry.ReactNativeTracing({
      routingInstrumentation,
    }),
  ],
  debug: true,
  dsn: 'https://xxxx@onprem.domain/sentry/6',
});

or

(react-native-sentry)

Sentry.config(
  'https://...@sentry.io/...'
  // other options
 ).install();

I have the following issue:

We have configured @sentry/react-native on an Expo SDK 50 app according to the provided instructions. However, while debug shows that events are (seemingly) being processed, nothing is sent upstream. We have manually added several instances of e.g. Sentry.captureMessage('Hello world!') and Sentry.captureException(new Error('some error')) in the code, and we even get warnings at times that Sentry dedupes events when these are being run repeatedly (again, showing that Sentry is seemingly working and picking them up).

Opening the Expo JS debugger and inspecting the Network tab, we can see that Sentry is (I guess correctly) calling the symbolicate endpoint on localhost when these checkpoints are invoked. However, there are no network calls made to our Sentry instance, possibly ruling out a direct communication issue. The events are simply never sent.

To rule out that this is isolated to running locally with Metro, we also did a Preview build using EAS and installed this on a physical device on a public network. Again, as far as we can tell nothing is sent - no events are showing up in our Sentry instance.

If the error is on our side, it would be very helpful to know how we can debug this, if at all.

Finally, this DID work during a previous trial we did on SDK 49, before the new setup instructions for SDK 50

Steps to reproduce:

  • Install Sentry react-native SDK as per instructions
  • Try to capture an event.

Actual result:

Sentry processes event in app, but never sends them to Sentry

Expected result:

The processed events should be correctly submitted to Sentry

@csvan
Copy link
Author

csvan commented Mar 20, 2024

As an addition - we also enabled automatic instrumentation with tracesSampleRate: 1.0 to check if this is isolated to error reporting. It isn't. With debug: true the logs are full of activity about transactions being processed, but again, inspecting the JS Debugger we can see that no data is ever sent to Sentry.

 LOG  Sentry Logger [log]: [Tracing] starting navigation transaction - Route Change
 LOG  Sentry Logger [log]: Starting heartbeat
 LOG  Sentry Logger [log]: pinging Heartbeat -> current counter: 0
 LOG  Sentry Logger [log]: [ReactNativeTracing] Starting navigation transaction "Route Change" on scope
 LOG  Sentry Logger [log]: [Tracing] pushActivity: 96884dd02e8c92dd
 LOG  Sentry Logger [log]: [Tracing] new activities count 1
 LOG  Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'POST xxxxx' (b572104f090dc148).
 LOG  Sentry Logger [log]: [Tracing] finishing IdleTransaction 2024-03-20T18:24:04.941Z navigation

@csvan csvan changed the title Expo: Events are processed on device, but never sent to Sentry server (worked on SDK 49) Expo 50: Events are processed on device, but never sent to Sentry (worked on SDK 49) Mar 21, 2024
@krystofwoldrich
Copy link
Member

Hi @csvan,
thank you for the message and the details.

You should be able to see the request to Sentry in the network tab. Sadly, I'm unable to reproduce it.

Could you share the exact steps to reproduce the issue? Or share the sample app you created to test this?

@csvan
Copy link
Author

csvan commented Mar 21, 2024

Working in a corporate environment, so sadly cannot share anything as of now. The steps are unfortunately not more than following the setup instructions as per the documentation for now.

Just to be clear - should this work even when running locally with Metro? Also, can we somehow manually trigger a sending? Anything else we can do to debug?

@krystofwoldrich
Copy link
Member

@csvan Thank you, I misunderstood, I thought you tried it in a new empty app.

Yes, it works in Expo Go, native builds with Metro, and release builds.

Are you migrating from sentry-expo to @sentry/react-native?

The Sentry.captureException/Message are the best to try sending an event to Sentry.

I would recommend using Logcat as that will give you more insides into the sending process.

iOS is working as expected? Or your app is only for Android?

@csvan
Copy link
Author

csvan commented Mar 21, 2024

We run both Android and iOS, neither is working.

Are you migrating from sentry-expo to @sentry/react-native?

We have tried both in separate trials on this project - we initially used sentry-expo which worked. Since this was only a test (and we didn't want to get stuck on deprecated sentry-expo), we then removed it completely before implementing the new, more permanent @sentry/react-native solution recommended as of Expo 50.

I would recommend using Logcat as that will give you more insides into the sending process.

Dug through logcat but sadly I cannot find much there either. However, intercepting events in beforeSend I can see that they all have localhost:8081 as URL. Would that be indicative of a problem, e.g. that events are all sent to localhost and not to Sentry?

Here is an example event:

{
  "breadcrumbs": [
    {
      "category": "app.lifecycle",
      "data": [
        Object
      ],
      "level": "info",
      "timestamp": 1711056070.354,
      "type": "session"
    },
    {
      "category": "app.lifecycle",
      "data": [
        Object
      ],
      "level": "info",
      "timestamp": 1711056070.355,
      "type": "navigation"
    },
    {
      "category": "network.event",
      "data": [
        Object
      ],
      "level": "info",
      "timestamp": 1711056070.357,
      "type": "system"
    },
    {
      "category": "network.event",
      "data": [
        Object
      ],
      "level": "info",
      "timestamp": 1711056070.357,
      "type": "system"
    },
    {
      "category": "app.lifecycle",
      "data": [
        Object
      ],
      "level": "info",
      "timestamp": 1711056070.357,
      "type": "session"
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: Breadcrumbs",
      "timestamp": 1711056070.358
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: Dedupe",
      "timestamp": 1711056070.358
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: HttpContext",
      "timestamp": 1711056070.358
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: Release",
      "timestamp": 1711056070.358
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: EventOrigin",
      "timestamp": 1711056070.358
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: SdkInfo",
      "timestamp": 1711056070.359
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: ReactNativeInfo",
      "timestamp": 1711056070.359
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: DebugSymbolicator",
      "timestamp": 1711056070.359
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: RewriteFrames",
      "timestamp": 1711056070.359
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: DeviceContext",
      "timestamp": 1711056070.359
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: ModulesLoader",
      "timestamp": 1711056070.359
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [ReactNativeTracing] Native frames instrumentation initialized.",
      "timestamp": 1711056070.36
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Setting idle transaction on scope. Span ID: 8b12d7409e2afcb5",
      "timestamp": 1711056070.36
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] starting navigation transaction - Route Change",
      "timestamp": 1711056070.361
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Starting heartbeat",
      "timestamp": 1711056070.362
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: pinging Heartbeat -> current counter: 0",
      "timestamp": 1711056070.362
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [ReactNativeTracing] Starting navigation transaction \"Route Change\" on scope",
      "timestamp": 1711056070.362
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: ReactNativeTracing",
      "timestamp": 1711056070.362
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] pushActivity: 874cfad8e1a9c8cd",
      "timestamp": 1711056070.507
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] new activities count 1",
      "timestamp": 1711056070.507
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] Starting 'ui.react.mount' span on transaction '<Root>' (8b12d7409e2afcb5).",
      "timestamp": 1711056070.507
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "[object Object]",
      "timestamp": 1711056070.508
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "[object Object]",
      "timestamp": 1711056070.508
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "[object Object]",
      "timestamp": 1711056070.508
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] popActivity 874cfad8e1a9c8cd",
      "timestamp": 1711056070.514
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] new activities count 0",
      "timestamp": 1711056070.515
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: ReactNativeProfiler",
      "timestamp": 1711056070.515
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: Integration installed: TouchEventBoundary",
      "timestamp": 1711056070.516
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Logging Boot",
      "timestamp": 1711056070.519
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] pushActivity: 8465c70616980659",
      "timestamp": 1711056070.579
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] new activities count 1",
      "timestamp": 1711056070.579
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'POST http://localhost:8081/symbolicate' (8b12d7409e2afcb5).",
      "timestamp": 1711056070.58
    },
    {
      "category": "xhr",
      "data": [
        Object
      ],
      "level": "info",
      "timestamp": 1711056070.723,
      "type": "http"
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] popActivity 8465c70616980659",
      "timestamp": 1711056070.723
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] new activities count 0",
      "timestamp": 1711056070.724
    },
    {
      "category": "navigation",
      "data": [
        Object
      ],
      "level": "info",
      "message": "Navigation to (pages)",
      "timestamp": 1711056070.746,
      "type": "navigation"
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Getting session info with token token-for--A",
      "timestamp": 1711056070.754
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] pushActivity: 893452d9a2184b42",
      "timestamp": 1711056070.755
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] new activities count 1",
      "timestamp": 1711056070.763
    },
    {
      "category": "console",
      "data": [
        Object
      ],
      "level": "debug",
      "message": "Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'GET https://apidomain.mycorp.com/mock/entity/sessioninfo/V1_4' (8b12d7409e2afcb5).",
      "timestamp": 1711056070.771
    }
  ],
  "contexts": {
    "app": {
      "app_build": "27",
      "app_identifier": "com.mycorp.cup.mobile.mycorp.pub.charging.devclient",
      "app_name": "Truck Charging (DEVCLIENT)",
      "app_start_time": "2024-03-21T20:47:40.777Z",
      "app_version": "1.0.6",
      "in_foreground": true,
      "permissions": [
        Object
      ],
      "view_names": [
        Array
      ]
    },
    "device": {
      "archs": [
        Array
      ],
      "battery_level": 100,
      "battery_temperature": 25,
      "boot_time": "2024-03-21T19:59:08.989Z",
      "brand": "google",
      "charging": false,
      "connection_type": "cellular",
      "family": "sdk_gphone64_arm64",
      "free_memory": 971563008,
      "free_storage": 3634704384,
      "id": "21676f95-cf39-49f2-a599-8d70463e95c2",
      "language": "en",
      "locale": "en_US",
      "low_memory": false,
      "manufacturer": "Google",
      "memory_size": 3126251520,
      "model": "sdk_gphone64_arm64",
      "model_id": "UE1A.230829.036.A1",
      "online": true,
      "orientation": "portrait",
      "processor_count": 4,
      "processor_frequency": 0,
      "screen_density": 3.5,
      "screen_dpi": 560,
      "screen_height_pixels": 2892,
      "screen_width_pixels": 1440,
      "simulator": true,
      "storage_size": 6228115456,
      "timezone": "Europe/Stockholm"
    },
    "os": {
      "build": "UE1A.230829.036.A1",
      "kernel_version": "6.1.23-android14-4-00257-g7e35917775b8-ab9964412",
      "name": "Android",
      "rooted": false,
      "version": "14"
    },
    "react_native_context": {
      "expo": true,
      "fabric": false,
      "hermes_debug_info": true,
      "hermes_version": "for RN 0.73.5",
      "js_engine": "hermes",
      "react_native_version": "0.73.5",
      "turbo_module": false
    },
    "trace": {
      "data": [
        Object
      ],
      "op": "navigation",
      "origin": "manual",
      "span_id": "8b12d7409e2afcb5",
      "tags": [
        Object
      ],
      "trace_id": "525e501813574c2fb1d170f0c00d311a"
    }
  },
  "dist": "27",
  "environment": "MOCK",
  "event_id": "0ca45f2885ca4c4887fee073d35ee973",
  "fingerprint": [],
  "level": "info",
  "message": "Booting app",
  "platform": "javascript",
  "release": "com.mycorp.cup.mobile.mycorp.pub.charging.devclient@1.0.6+27",
  "request": {
    "headers": {},
    "url": "http://localhost:8081/"
  },
  "sdk": {
    "integrations": [
      "ReactNativeErrorHandlers",
      "NativeLinkedErrors",
      "InboundFilters",
      "FunctionToString",
      "Breadcrumbs",
      "Dedupe",
      "HttpContext",
      "Release",
      "EventOrigin",
      "SdkInfo",
      "ReactNativeInfo",
      "DebugSymbolicator",
      "RewriteFrames",
      "DeviceContext",
      "ModulesLoader",
      "ReactNativeTracing",
      "ReactNativeProfiler",
      "TouchEventBoundary"
    ],
    "name": "sentry.javascript.react-native",
    "packages": [
      [
        Object
      ]
    ],
    "version": "5.20.0"
  },
  "sdkProcessingMetadata": {
    "dynamicSamplingContext": {
      "environment": "MOCK",
      "public_key": "xxxx",
      "sample_rate": "1",
      "sampled": "true",
      "trace_id": "525e501813574c2fb1d170f0c00d311a",
      "transaction": "Route Change"
    }
  },
  "tags": {
    "event.environment": "javascript",
    "event.origin": "javascript",
    "hermes": "true",
    "routing.route.name": "(pages)",
    "transaction": "Route Change"
  },
  "threads": {
    "values": {}
  },
  "timestamp": 1711056070.525,
  "user": {
    "id": "21676f95-cf39-49f2-a599-8d70463e95c2"
  }
}

@csvan
Copy link
Author

csvan commented Mar 22, 2024

@krystofwoldrich we have made som progress - it works in Expo Go, but not in Dev or Release builds. This applies both to emulators and physical devices. The main difference is still that when using Expo Go, we actually see the events being sent, whereas this does not happen in the other builds. The overall logs between the two otherwise look largely the same.

We don't really do anything magical or special in either our dev or release builds, but do you see something that could potentially interfere there?

Just brainstorming here, but I am thinking about this part of the docs (https://docs.sentry.io/platforms/react-native/):

Offline storage of events
Android: Offline caching when a device is offline; we send a report once the application is restarted
iOS: Offline caching when a device is unable to connect; we send a report once we receive another event

Could there be something in those builds that "fools" Sentry into thinking the device is offline or the like, so that events just get stored up but never sent? For example, I see this in the logs when running Expo Go:

'Sentry Logger [info]:', 'Offline caching, native errors features are not available in Expo Go.'
'Sentry Logger [info]:', 'Use EAS Build / Native Release Build to test these features.'

UPDATE: I tried removing all plugins and other non-essential custom stuff for our dev builds (including the Sentry plugin) to make sure those changes did not interfere with Sentry. Unfortunately, it still does not work.

@krystofwoldrich
Copy link
Member

I can see that they all have localhost:8081 as URL.

The request property contains related request information to the event, it doesn't relate to the request sending the event.

it works in Expo Go

That confirms, as you mentioned that the issue is in the native layers.

Could there be something in those builds that "fools" Sentry into thinking the device is offline or the like, so that events just get stored up but never sent?

When the debug: true, this is passed to the native layers and you should be able to see debug messages about processing and sending/storing/discarding the envelopes.

Do you see Sentry native logs in logcat or only the ones from ReactNativeJS?

@csvan
Copy link
Author

csvan commented Mar 25, 2024

@krystofwoldrich thanks for the reply, I indeed think I found something logcat (dev build on a physical device):

com....company.pub.app.devclient  D  Request failed, API returned 400
com....company.pub.app.devclient  D  Failed to buffer the request body: Invalid gzip header
com....company.pub.app.devclient  D  The transport failed to send the envelope with response code 400
com....company.pub.app.devclient  E  Envelope submission failed
                                     java.lang.IllegalStateException: The transport failed to send the envelope with response code 400
                                     	at io.sentry.transport.AsyncHttpTransport$EnvelopeSender.flush(AsyncHttpTransport.java:303)
                                     	at io.sentry.transport.AsyncHttpTransport$EnvelopeSender.run(AsyncHttpTransport.java:227)
                                     	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
                                     	at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                     	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                     	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                     	at java.lang.Thread.run(Thread.java:1012)
com....company.pub.app.devclient  D  Marking envelope submission result: false

Looking at the logs on our Sentry backend, it's the same error:

Got bad response from sentry 400 Failed to buffer the request body: Invalid gzip header [UNSERIALIZABLE]

This appears to be a constant for ALL outgoing envelopes.

UPDATE:

If it helps, this server also accepts gzip compressed content from @sentry/react (compressed Replays) without issue.

I inspected the incoming requests and the headers are these (redacted for company stuff):

{
  "headers": {
    "x-forwarded-proto": "https",
    "x-forwarded-port": "443",
    "content-length": "5304",
    "user-agent": "sentry.java.android.react-native/7.5.0",
    "content-type": "application/x-sentry-envelope",
    "x-amz-cf-id": "lklvofE7Ax9L3socIAVnyRjiE_yp3hLCCtep22nvXganXJmxo7G7TQ==",
    "accept": "application/json",
    "via": "HTTP/1.1 AmazonAPIGateway",
    "content-encoding": "gzip",
    "accept-encoding": "gzip"
  }
}

@csvan
Copy link
Author

csvan commented Mar 25, 2024

@krystofwoldrich issue is resolved. The problem was that our reverse proxy decompressed the gzip packages sent by the React Native client but kept the content-encoding: gzip header. This led to Sentry throwing when trying to decode it since it was no longer gzipped.

A lot of thanks for your help and patience in trying to track this down!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Archived in project
Archived in project
Development

No branches or pull requests

2 participants