search

getsentry / sentry-javascript

Official Sentry SDKs for JavaScript
https://sentry.io
MIT License
8.02k stars 1.59k forks source link

Replay tunnel fails due to empty envelope #13453

Open johnathanludwig opened 3 months ago

johnathanludwig commented 3 months ago

Is there an existing issue for this?

How do you use Sentry?

Sentry Saas (sentry.io)

Which SDK are you using?

@sentry/sveltekit

SDK Version

8.26.0

Framework Version

Sveltekit 2.5.18

Link to Sentry event

No response

Reproduction Example/SDK Setup

Using the example provided from the documentation does not work with replay requests. The docs show using an array buffer. This works well with traces, however for replays the code error on parsing piece. In this case the envelopeBytes is 0 and envelope empty.

https://docs.sentry.io/platforms/javascript/troubleshooting/#dealing-with-ad-blockers 

const SENTRY_HOST = "oXXXXXX.ingest.sentry.io";
const SENTRY_PROJECT_IDS = ["123456"];

export const POST: RequestHandler = async ({ request }) => {
  try {
    const envelopeBytes = await request.arrayBuffer();
    const envelope = new TextDecoder().decode(envelopeBytes);
    console.log(envelopeBytes, envelope);
    const piece = envelope.split('\n')[0];
    const header = JSON.parse(piece);
    const dsn = new URL(header['dsn']);
    const project_id = dsn.pathname?.replace('/', '');

    if (dsn.hostname !== SENTRY_HOST) {
      throw new Error(`Invalid sentry hostname: ${dsn.hostname}`);
    }

    if (!project_id || !SENTRY_PROJECT_IDS.has(project_id)) {
      throw new Error(`Invalid sentry project id: ${project_id}`);
    }

    const upstream_sentry_url = `https://${SENTRY_HOST}/api/${project_id}/envelope/`;
    await fetch(upstream_sentry_url, {
      method: 'POST',
      body: envelopeBytes,
    });

    return json({}, { status: 200 });
  } catch (error) {
    console.error('error tunneling to sentry', error);
    return json({ error: 'error tunneling to sentry' }, { status: 500 });
  }
};

Steps to Reproduce

  1. Create an API route, eg /api/errors/+server.ts.
  2. Export a POST api.
  3. Configure sentry client to tunnel through /api/errors.

Expected Result

The replays get sent to sentry successfully.

Actual Result

Traces are tunneled. Replays result in this error:

// console.log(envelopeBytes, envelope);
ArrayBuffer { [Uint8Contents]: <>, byteLength: 0 }

error tunneling to sentry SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at POST (/src/routes/api/errors/+server.ts:17:25)
    at async Module.render_endpoint (/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/runtime/server/endpoint.js:49:18)
    at async resolve (/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/runtime/server/respond.js:454:17)
    at async documentPolicy (/src/lib/hooks/document-policy.ts:6:20)
    at async /node_modules/.pnpm/@sentry+sveltekit@8.26.0_@opentelemetry+api@1.9.0_@opentelemetry+core@1.25.1_@opentelemetry+a_gixmxtpq6bgq6uyfpgkkbh5rvy/node_modules/@sentry/sveltekit/build/cjs/server/handle.js:140:21
    at async instrumentHandle (/node_modules/.pnpm/@sentry+sveltekit@8.26.0_@opentelemetry+api@1.9.0_@opentelemetry+core@1.25.1_@opentelemetry+a_gixmxtpq6bgq6uyfpgkkbh5rvy/node_modules/@sentry/sveltekit/build/cjs/server/handle.js:128:27)
    at async Module.respond (/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/runtime/server/respond.js:330:20)
    at async file:///node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/exports/vite/dev/index.js:524:22
andreiborza commented 3 months ago

Hello, thanks for writing in.

The envelopes should not be empty for replays. You could add a guard to exit out early if envelopeBytes is empty, but I'm curious why you're getting empty envelopes to begin with.

Please set debug: true in Sentry.init and paste your logs.

johnathanludwig commented 3 months ago

Yes the body of the request is there so I'm not sure why I can't get anything out of it on the server side.

Image

Client side debug: https://gist.github.com/johnathanludwig/1bcefb76f2609a2b44eb3820dbdea26e

Server side:

Sentry Logger [log]: [Tracing] Starting sampled root span
  op: http.server
  name: GET /(unprotected)/login
  ID: 4e95db40cdd3ecc2
Sentry Logger [log]: [Tracing] Finishing "http.server" root span "GET /(unprotected)/login" with ID 4e95db40cdd3ecc2
Sentry Logger [log]: SpanExporter exported 1 spans, 0 unsent spans remaining
Sentry Logger [log]: [Tracing] Starting sampled root span
  op: http.server
  name: POST /api/errors
  ID: 4d39a562acc53f42
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for HTTP POST: true
Sentry Logger [log]: [Tracing] Starting sampled span
  op: < unknown op >
  name: HTTP POST
  ID: b8cf5def993c2314
  parent ID: 4d39a562acc53f42
  root ID: 4d39a562acc53f42
  root op: http.server
  root description: POST /api/errors
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" span "HTTP POST" with ID b8cf5def993c2314
Sentry Logger [log]: SpanExporter has 1 unsent spans remaining
Sentry Logger [log]: [Tracing] Finishing "http.server" root span "POST /api/errors" with ID 4d39a562acc53f42
Sentry Logger [log]: SpanExporter exported 2 spans, 0 unsent spans remaining
Sentry Logger [log]: Flushing client reports based on interval.
Sentry Logger [log]: Flushing outcomes...
Sentry Logger [log]: No outcomes to send
Sentry Logger [log]: [Tracing] Starting sampled root span
  op: http.server
  name: POST /api/errors
  ID: 3bc95f07de7ced89
error tunneling to sentry SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at POST (/Users/johnathanludwig/git/frontend/apps/web/src/routes/api/errors/+server.ts:16:25)
    at async Module.render_endpoint (/Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/runtime/server/endpoint.js:49:18)
    at async resolve (/Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/runtime/server/respond.js:454:17)
    at async /Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sentry+sveltekit@8.26.0_@opentelemetry+api@1.9.0_@opentelemetry+core@1.25.1_@opentelemetry+a_gixmxtpq6bgq6uyfpgkkbh5rvy/node_modules/@sentry/sveltekit/build/cjs/server/handle.js:140:21
    at async instrumentHandle (/Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sentry+sveltekit@8.26.0_@opentelemetry+api@1.9.0_@opentelemetry+core@1.25.1_@opentelemetry+a_gixmxtpq6bgq6uyfpgkkbh5rvy/node_modules/@sentry/sveltekit/build/cjs/server/handle.js:128:27)
    at async Module.respond (/Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/runtime/server/respond.js:330:20)
    at async file:///Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/exports/vite/dev/index.js:524:22
Sentry Logger [log]: [Tracing] Finishing "http.server" root span "POST /api/errors" with ID 3bc95f07de7ced89
Sentry Logger [log]: SpanExporter exported 1 spans, 0 unsent spans remaining
andreiborza commented 3 months ago

Could you please amend the server side debug log with the logs that occur on app startup?

Also, does this happen if you disable compression?

Sentry.replayIntegration({
  useCompression: false,
});
johnathanludwig commented 3 months ago

Disabling compression does resolve the issue. Thank you for the help with that.

Here are the server startup logs when compression was still enabled:

Sentry Logger [log]: Initializing Sentry: process: 19324, thread: main.
Sentry Logger [log]: Integration installed: InboundFilters
Sentry Logger [log]: Integration installed: FunctionToString
Sentry Logger [log]: Integration installed: LinkedErrors
Sentry Logger [log]: Integration installed: RequestData
Sentry Logger [log]: Integration installed: Console
Sentry Logger [log]: Integration installed: Http
Sentry Logger [log]: Integration installed: NodeFetch
Sentry Logger [log]: Integration installed: OnUncaughtException
Sentry Logger [log]: Integration installed: OnUnhandledRejection
Sentry Logger [log]: Integration installed: ContextLines
Sentry Logger [log]: Integration installed: LocalVariablesAsync
Sentry Logger [log]: Integration installed: Context
Sentry Logger [log]: Integration installed: Modules
Sentry Logger [log]: Integration installed: Express
Sentry Logger [log]: Integration installed: Fastify
Sentry Logger [log]: Integration installed: Graphql
Sentry Logger [log]: Integration installed: Mongo
Sentry Logger [log]: Integration installed: Mongoose
Sentry Logger [log]: Integration installed: Mysql
Sentry Logger [log]: Integration installed: Mysql2
Sentry Logger [log]: Integration installed: Redis
Sentry Logger [log]: Integration installed: Postgres
Sentry Logger [log]: Integration installed: Nest
Sentry Logger [log]: Integration installed: Hapi
Sentry Logger [log]: Integration installed: Koa
Sentry Logger [log]: Integration installed: Connect
Sentry Logger [log]: Integration installed: RewriteFrames
Sentry Logger [log]: Integration installed: ProfilingIntegration
Sentry Logger [log]: Running in CommonJS mode.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for diag v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for trace v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for context v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for propagation v1.9.0.
Sentry Logger [log]: [Tracing] Starting sampled root span
  op: http.server
  name: GET /(unprotected)/login
  ID: 6cd4b34ad8046c2e
Sentry Logger [log]: [Tracing] Finishing "http.server" root span "GET /(unprotected)/login" with ID 6cd4b34ad8046c2e
Sentry Logger [log]: SpanExporter exported 1 spans, 0 unsent spans remaining
Sentry Logger [log]: [Tracing] Starting sampled root span
  op: http.server
  name: POST /api/errors
  ID: d587828578ab7951
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for HTTP POST: true
Sentry Logger [log]: [Tracing] Starting sampled span
  op: < unknown op >
  name: HTTP POST
  ID: 51e6c9757e8effd3
  parent ID: d587828578ab7951
  root ID: d587828578ab7951
  root op: http.server
  root description: POST /api/errors
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" span "HTTP POST" with ID 51e6c9757e8effd3
Sentry Logger [log]: SpanExporter has 1 unsent spans remaining
Sentry Logger [log]: [Tracing] Finishing "http.server" root span "POST /api/errors" with ID d587828578ab7951
Sentry Logger [log]: SpanExporter exported 2 spans, 0 unsent spans remaining
Sentry Logger [log]: [Tracing] Starting sampled root span
  op: http.server
  name: POST /api/errors
  ID: 4592d3baeb001a91
error tunneling to sentry SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at POST (/Users/johnathanludwig/git/frontend/apps/web/src/routes/api/errors/+server.ts:16:25)
    at async Module.render_endpoint (/Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/runtime/server/endpoint.js:49:18)
    at async resolve (/Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/runtime/server/respond.js:454:17)
    at async /Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sentry+sveltekit@8.26.0_@opentelemetry+api@1.9.0_@opentelemetry+core@1.25.1_@opentelemetry+a_gixmxtpq6bgq6uyfpgkkbh5rvy/node_modules/@sentry/sveltekit/build/cjs/server/handle.js:140:21
    at async instrumentHandle (/Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sentry+sveltekit@8.26.0_@opentelemetry+api@1.9.0_@opentelemetry+core@1.25.1_@opentelemetry+a_gixmxtpq6bgq6uyfpgkkbh5rvy/node_modules/@sentry/sveltekit/build/cjs/server/handle.js:128:27)
    at async Module.respond (/Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/runtime/server/respond.js:330:20)
    at async file:///Users/johnathanludwig/git/frontend/node_modules/.pnpm/@sveltejs+kit@2.5.18_@sveltejs+vite-plugin-svelte@3.1.1_svelte@4.2.18_vite@5.3.3_@types+node@_l5lnugt2i4tpym4dqtslohvg24/node_modules/@sveltejs/kit/src/exports/vite/dev/index.js:524:22
Sentry Logger [log]: [Tracing] Finishing "http.server" root span "POST /api/errors" with ID 4592d3baeb001a91
Sentry Logger [log]: SpanExporter exported 1 spans, 0 unsent spans remaining
andreiborza commented 3 months ago

Right, so TextDecoder can't deal with compressed zlib data. We'll have to update our docs to show how to deal with that.

For now, I suggest to either turn compression off or adapt your tunnel route to deal with the compressed data. Here's an example from our integration tests.

johnathanludwig commented 3 months ago

Great, thanks for the help!

andreiborza commented 3 months ago

Let's keep this open, I added it to our backlog so we can work on it.