expo / sentry-expo

MIT License
202 stars 83 forks source link

App boot causes infinite stream of logs #368

Closed daankennes closed 10 months ago

daankennes commented 1 year ago

Summary

Upon booting the app, Sentry starts logging the almost exact same message ad infinitum. Moreover, I cannot seem to log any error to the platform. I do not receive an error message. If I log the same error twice, I do get a message saying the error will not be logged since it is a duplicate. However, nothing is registered on the online dashboard.

Android Bundling complete 127ms LOG Sentry Logger [log]: Integration installed: ModulesLoader LOG Sentry Logger [log]: Unhandled promise rejections will be caught by Sentry. LOG Sentry Logger [log]: Integration installed: ReactNativeErrorHandlers LOG Sentry Logger [log]: Integration installed: Release LOG Sentry Logger [log]: Integration installed: InboundFilters LOG Sentry Logger [log]: Integration installed: FunctionToString LOG Sentry Logger [log]: Integration installed: Breadcrumbs LOG Sentry Logger [log]: Integration installed: LinkedErrors LOG Sentry Logger [log]: Integration installed: Dedupe LOG Sentry Logger [log]: Integration installed: HttpContext LOG Sentry Logger [log]: Integration installed: EventOrigin LOG Sentry Logger [log]: Integration installed: SdkInfo LOG Sentry Logger [log]: Integration installed: ReactNativeInfo LOG Sentry Logger [log]: Integration installed: DebugSymbolicator LOG Sentry Logger [log]: Integration installed: RewriteFrames LOG Sentry Logger [log]: Integration installed: DeviceContext LOG Sentry Logger [log]: [ReactNativeTracing] Native frames instrumentation initialized. LOG Sentry Logger [log]: [ReactNativeTracing] Not instrumenting route changes as routingInstrumentation has not been set. LOG Sentry Logger [log]: Integration installed: ReactNativeTracing LOG Sentry Logger [log]: Integration installed: ExpoBareIntegration LOG Sentry Logger [log]: Setting idle transaction on scope. Span ID: 9142c1a9d5307885 LOG Sentry Logger [log]: [Tracing] starting ui.load transaction - App Start LOG Sentry Logger [log]: Starting heartbeat LOG Sentry Logger [log]: pinging Heartbeat -> current counter: 0 LOG Sentry Logger [log]: [ReactNativeTracing] Starting ui.load transaction "App Start" on scope LOG Sentry Logger [log]: [Tracing] Starting 'app.start.cold' span on transaction 'App Start' (9142c1a9d5307885). LOG Sentry Logger [log]: [Tracing] pushActivity: 8ef104db542dc6f9 LOG Sentry Logger [log]: [Tracing] new activities count 1 LOG Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (9142c1a9d5307885). LOG Sentry Logger [log]: [Tracing] pushActivity: b5e2749e48bba387 LOG Sentry Logger [log]: [Tracing] new activities count 2 LOG Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (9142c1a9d5307885). LOG Sentry Logger [log]: [Tracing] popActivity 8ef104db542dc6f9 LOG Sentry Logger [log]: [Tracing] new activities count 1 LOG Sentry Logger [log]: [Tracing] pushActivity: 95ea3934837b6113 LOG Sentry Logger [log]: [Tracing] new activities count 2 LOG Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (9142c1a9d5307885). LOG Sentry Logger [log]: [Tracing] popActivity 95ea3934837b6113 LOG Sentry Logger [log]: [Tracing] new activities count 1 LOG Sentry Logger [log]: [Tracing] pushActivity: 84df209395328a77 LOG Sentry Logger [log]: [Tracing] new activities count 2 LOG Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (9142c1a9d5307885). [...going on...]

Managed or bare workflow? If you have ios/ or android/ directories in your project, the answer is bare!

managed

What platform(s) does this occur on?

Android

SDK Version (managed workflow only)

49

Environment

expo-env-info 1.0.5 environment info: System: OS: Windows 10 10.0.22621 Binaries: Node: 16.18.1 - C:\Program Files\nodejs\node.EXE Yarn: 1.22.19 - ~\AppData\Roaming\npm\yarn.CMD npm: 9.7.1 - C:\Program Files\nodejs\npm.CMD IDEs: Android Studio: AI-213.7172.25.2113.9123335 npmPackages: expo: ~49.0.8 => 49.0.9 react: 18.2.0 => 18.2.0 react-native: 0.72.4 => 0.72.4 Expo Workflow: managed

Reproducible demo or steps to reproduce from a blank project

Configuration: `import * as Sentry from 'sentry-expo';

Sentry.init({ dsn: 'xxx', enableInExpoDevelopment: true, debug: true, tracesSampleRate: 1.0, });`

(sentry-expo is also included in the Expo config plugins array)

Manual error logging: `private static logToSentry(error: Error, info?: {componentStack: string}) { if (!(error instanceof NoInternetConnectionError) && !(error instanceof CanceledError)) { if (!DEV) { // I flipped this during testing console.log('logging to sentry'); Sentry.Native.captureException(error, this.getExtraInfo(info)); throw error; } else { console.debug('Sentry error logging disabled in development mode.'); } } }

private static getExtraInfo(info?: {componentStack: string}) {
    return {
        tags: {
            localTime: new Date().toString(),
            serverURL: store.getState().session.configuration?.server,
            serverVersion: store.getState().session.serverVersion,
            sessionState: store.getState().session.sessionState,
            ...(info && info.componentStack && {componentStack: info.componentStack}),
        },
    };
}`
daankennes commented 1 year ago

Update: my dsn was wrong. Issues now get registered to the dashboard. However, the endless stream of log is not resolved and I would except an error when a wrong dsn is used.

I noticed I get an error 'App start was never finished' now.

krystofwoldrich commented 1 year ago

I believe there is a troubleshooting guide for this problem here https://docs.expo.dev/guides/using-sentry/#troubleshooting

statico commented 1 year ago

I am also seeing this.

Sentry.init({
  dsn: appConfig.config.sentryDsn,
  environment: appConfig.environment,
  enableInExpoDevelopment: true,
  sampleRate: 1.0, // Track all sessions for now
  tracesSampleRate: 1.0,
  debug: true,
})

results in

 LOG  Sentry Logger [log]: [Tracing] popActivity 8bdaf3b25f86c5fe
 LOG  Sentry Logger [log]: [Tracing] new activities count 0
 LOG  Sentry Logger [log]: [Tracing] pushActivity: a69829ba0316d7b3
 LOG  Sentry Logger [log]: [Tracing] new activities count 1
 LOG  Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (b6806885f0113af8).
 LOG  Sentry Logger [log]: [Tracing] popActivity a69829ba0316d7b3
 LOG  Sentry Logger [log]: [Tracing] new activities count 0
 LOG  Sentry Logger [log]: [Tracing] pushActivity: 8567d2d80fec00a5
 LOG  Sentry Logger [log]: [Tracing] new activities count 1
 LOG  Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (b6806885f0113af8).
 LOG  Sentry Logger [log]: [Tracing] popActivity 8567d2d80fec00a5
 LOG  Sentry Logger [log]: [Tracing] new activities count 0
 LOG  Sentry Logger [log]: [Tracing] pushActivity: af8575f2ef0cfe77
 LOG  Sentry Logger [log]: [Tracing] new activities count 1
 LOG  Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (b6806885f0113af8).
 LOG  Sentry Logger [log]: [Tracing] popActivity af8575f2ef0cfe77
 LOG  Sentry Logger [log]: [Tracing] new activities count 0
 LOG  Sentry Logger [log]: [Tracing] pushActivity: 961923a8b25406cd
 LOG  Sentry Logger [log]: [Tracing] new activities count 1
 LOG  Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (b6806885f0113af8).
 LOG  Sentry Logger [log]: [Tracing] popActivity 961923a8b25406cd
 LOG  Sentry Logger [log]: [Tracing] new activities count 0
 LOG  Sentry Logger [log]: [Tracing] pushActivity: ad5165e2175ddb50
 LOG  Sentry Logger [log]: [Tracing] new activities count 1
 LOG  Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (b6806885f0113af8).
 LOG  Sentry Logger [log]: [Tracing] popActivity ad5165e2175ddb50
 LOG  Sentry Logger [log]: [Tracing] new activities count 0
 LOG  Sentry Logger [log]: [Tracing] pushActivity: 989fc2576d6cee01

package.json:

〉grep sentry package.json
    "@sentry/react-native": "4.15.2",
    "sentry-expo": "~6.2.0",
statico commented 1 year ago

Adding this to Sentry.init() seems to stop it from looping:

  integrations: [
    new Sentry.Native.ReactNativeTracing({
      enableAppStartTracking: false,
    }),
  ],
statico commented 1 year ago

Actually, this not only solves the looping, but without it Sentry doesn't send tracing at all:

const routingInstrumentation =
  new Sentry.Native.ReactNavigationV4Instrumentation()

Sentry.init({
  ...
  integrations: [
    new Sentry.Native.ReactNativeTracing({
      routingInstrumentation,
    }),
  ],
})

This is probably because we're still on Expo v48, not v49, and thus @sentry/react-native v4 instead of v5.

mehmetguloglu commented 1 year ago

This error is caused by the HTTP request tracking, which creates spans for log requests (Starting 'http.client' span on transaction...) to the development server. To fix this, stop creating spans by adding the following code snippet:

import * as Sentry from 'sentry-expo'; import Constants from 'expo-constants';

Sentry.init({ tracesSampleRate: 1.0, integrations: [ new Sentry.Native.ReactNativeTracing({ shouldCreateSpanForRequest: url => { return !DEV || !url.startsWith(http://${Constants.expoConfig.hostUri}/logs); }, }), ], });

https://docs.expo.dev/guides/using-sentry/#expo-dev-client-transactions-never-finish

weeksie commented 1 year ago

I'm still getting this and the above solutions do not stop the infinite loop. I'm on Expo 49 but still on react-navigation

LOG  Sentry Logger [log]: Integration installed: DebugSymbolicator
 LOG  Sentry Logger [log]: Integration installed: RewriteFrames
 LOG  Sentry Logger [log]: Integration installed: DeviceContext
 LOG  Sentry Logger [log]: [ReactNativeTracing] Native frames instrumentation initialized.
 LOG  Sentry Logger [log]: [ReactNativeTracing] Not instrumenting route changes as routingInstrumentation has not been set.
 LOG  Sentry Logger [log]: Integration installed: ReactNativeTracing
 LOG  Sentry Logger [log]: Integration installed: ExpoBareIntegration
 LOG  Sentry Logger [log]: Setting idle transaction on scope. Span ID: bc3f429aeb4aca98
 LOG  Sentry Logger [log]: [Tracing] starting ui.load transaction - App Start
 LOG  Sentry Logger [log]: Starting heartbeat
 LOG  Sentry Logger [log]: pinging Heartbeat -> current counter: 0
 LOG  Sentry Logger [log]: [ReactNativeTracing] Starting ui.load transaction "App Start" on scope
 LOG  Sentry Logger [log]: [Tracing] Starting 'app.start.cold' span on transaction 'App Start' (bc3f429aeb4aca98).
 LOG  Sentry Logger [log]: [Tracing] pushActivity: b8aefdcd3f2d10e7
 LOG  Sentry Logger [log]: [Tracing] new activities count 1
 LOG  Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (bc3f429aeb4aca98).
 LOG  Sentry Logger [log]: [Tracing] popActivity b8aefdcd3f2d10e7
 LOG  Sentry Logger [log]: [Tracing] new activities count 0
 LOG  Sentry Logger [log]: [Tracing] pushActivity: ba17cf8b92a48be9
 LOG  Sentry Logger [log]: [Tracing] new activities count 1
 LOG  Sentry Logger [log]: [Tracing] Starting 'http.client' span on transaction 'App Start' (bc3f429aeb4aca98).
 LOG  Sentry Logger [log]: [Tracing] popActivity ba17cf8b92a48be9
 LOG  Sentry Logger [log]: [Tracing] new activities count 0
...(forever)

I will note that this only happens on "cold start" after I've quit the simulator and restarted it.


Sentry.init({
    dsn: config.sentry.dsn,
    enableInExpoDevelopment: false,
    debug: true,
    tracesSampleRate: 1.0,
    integrations: [
        new Sentry.Native.ReactNativeTracing({
            shouldCreateSpanForRequest: (url) => {
                const shouldTrack = !isDev || !url.startsWith(`http://${Constants.expoConfig?.hostUri}/logs`);
                console.log({ shouldCreateSpanForRequest: shouldTrack });
                return shouldTrack;
            }
        })
    ]
});

That console.log never traces, so shouldCreateSpanForRequest seems like a red herring here.

/// edit:

When I call init on Sentry.Native (Sentry.Native.init({...) I get a trace, buuuuuuuuut I get an infinite stream of that trace even though shouldCreateSpanForRequest is returning false:

 LOG  {"shouldCreateSpanForRequest": false}
 LOG  {"shouldCreateSpanForRequest": false}
 LOG  {"shouldCreateSpanForRequest": false}
 LOG  {"shouldCreateSpanForRequest": false}
 LOG  {"shouldCreateSpanForRequest": false}
 LOG  {"shouldCreateSpanForRequest": false}
...

Hahaha, thanks for following me on this magical journey of discovery. I guess that method gets hit a lot. With enableAppStartTracking: false I am not getting the infinite loop anymore.

en fin, the solution for me was to follow the above instructions but to call Sentry.Native.init NOT Sentry.init

github-actions[bot] commented 10 months ago

This issue is stale because it has been open for 60 days with no activity. If there is no activity in the next 7 days, the issue will be closed.

github-actions[bot] commented 10 months ago

This issue was closed because it has been inactive for 7 days since being marked as stale. Please open a new issue if you believe you are encountering a related problem.

appsgenie commented 5 months ago

so what would be the best init option on expo Expo SDK 49? Should I use Sentry.Init() or Sentry.Native.init() ?