Skip to content

Commit

Permalink
ref(core): Renormalize event only after stringification errors (#4425)
Browse files Browse the repository at this point in the history
Since at least 5.19.1, we've had a bug[1] which causes events not to be able to be serialized for transmission, because they contain circular references. In theory, this should never happen, because all events go through a normalization process which [removes circular references](https://github.com/getsentry/sentry-javascript/blob/6abb46374763a49b60b883e1190d5dfda8eda842/packages/utils/src/object.ts#L338-L341). Nonetheless, the problem persists.

There are three possibilities:

1) The normalization function is somehow not getting called for certain events.

2) Data containing a circular reference is being added to the event between normalization and serialization.

3) The normalization function doesn't catch (and fix) all cases in which circular references exist.

In #3776, a debug flag was added which causes normalization to run twice, as a way to protect against possibility 1. As described in the above-linked issue, though, this hasn't solved the problem, at least not completely, as the serialization error is still occurring for some people.

This PR aims to improve on that initial debugging step, by making the following changes:

- The initial attempt at serialization is wrapped in a try-catch, so that any errors that arise can be collected _alongside_ the real event (as a `JSONStringifyError` tag and as a stacktrace in `event.extra`), rather than instead of it.

- Events which go through the initial normalization are tagged internally, so that if the serializer encounters an event which _doesn't_ have the tag, it can note that (as a `skippedNormalization` tag on the event). In theory this should never show up, but if it does, it points to possibility 1.

- Renormalization has been moved so that it's part of the serialization process itself. If this fixes the problem, that points to possibility 2.

- Renormalization has been wrapped in a try-catch, with a `JSON.stringify error after renormalization` event logged to Sentry (again with the error in `extra` data) in cases where it fails. This is another situation which should never happen, but if it does, it points to possibility 3.

Also, this is not specifically for debugging, but a bonus side effect of moving the renormalization to be part of serialization is that it allows us to only renormalize if theres's a problem, which eliminates a relatively computationally expensive operation in cases where it's not needed and therefore lets us ditch the debug flag. 

P.S. Disclaimer: I know this isn't all that pretty, but my assumption is that this will stay in the SDK for a release or two while we (hopefully) finally solve the mystery, and then be pulled back out before we ship v7.

[1] #2809
  • Loading branch information
lobsterkatie committed Jan 24, 2022
1 parent c224f9c commit 472cb0c
Show file tree
Hide file tree
Showing 3 changed files with 68 additions and 7 deletions.
5 changes: 1 addition & 4 deletions packages/core/src/baseclient.ts
Original file line number Diff line number Diff line change
Expand Up @@ -428,10 +428,7 @@ export abstract class BaseClient<B extends Backend, O extends Options> implement
normalized.contexts.trace = event.contexts.trace;
}

const { _experiments = {} } = this.getOptions();
if (_experiments.ensureNoCircularStructures) {
return normalize(normalized);
}
event.sdkProcessingMetadata = { ...event.sdkProcessingMetadata, baseClientNormalized: true };

This comment has been minimized.

Copy link
@klaussner

klaussner Mar 22, 2022

@lobsterkatie I was wondering why all events in my project have the skippedNormalization tag although they are passed through the normalization function (I'm using @sentry/node with the default options) and I think this line is the reason. Maybe I'm misinterpreting what this code does but shouldn't it be normalized.sdkProcessingMetadata = ... so that the baseClientNormalized flag is set in the returned and normalized event?

This comment has been minimized.

Copy link
@lobsterkatie

lobsterkatie Mar 25, 2022

Author Member

Uh... yeah. Wow, how did I and my reviewers and everyone for the last two months miss that? Yikes. That's vaguely embarrassing, LOL.

Thanks for pointing it out! I just pushed a PR to fix it (#4780).


return normalized;
}
Expand Down
51 changes: 49 additions & 2 deletions packages/core/src/request.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
import { Event, SdkInfo, SentryRequest, SentryRequestType, Session, SessionAggregates } from '@sentry/types';
import { dsnToString } from '@sentry/utils';
import { dsnToString, normalize } from '@sentry/utils';

import { APIDetails, getEnvelopeEndpointWithUrlEncodedAuth, getStoreEndpointWithUrlEncodedAuth } from './api';

Expand Down Expand Up @@ -58,11 +58,58 @@ export function eventToSentryRequest(event: Event, api: APIDetails): SentryReque
const { transactionSampling } = event.sdkProcessingMetadata || {};
const { method: samplingMethod, rate: sampleRate } = transactionSampling || {};

// TODO: Below is a temporary hack in order to debug a serialization error - see
// https://github.com/getsentry/sentry-javascript/issues/2809 and
// https://github.com/getsentry/sentry-javascript/pull/4425. TL;DR: even though we normalize all events (which should
// prevent this), something is causing `JSON.stringify` to throw a circular reference error.
//
// When it's time to remove it:
// 1. Delete everything between here and where the request object `req` is created, EXCEPT the line deleting
// `sdkProcessingMetadata`
// 2. Restore the original version of the request body, which is commented out
// 3. Search for `skippedNormalization` and pull out the companion hack in the browser playwright tests
enhanceEventWithSdkInfo(event, api.metadata.sdk);
event.tags = event.tags || {};
event.extra = event.extra || {};

// In theory, all events should be marked as having gone through normalization and so
// we should never set this tag
if (!(event.sdkProcessingMetadata && event.sdkProcessingMetadata.baseClientNormalized)) {
event.tags.skippedNormalization = true;
}

// prevent this data from being sent to sentry
// TODO: This is NOT part of the hack - DO NOT DELETE
delete event.sdkProcessingMetadata;

let body;
try {
// 99.9% of events should get through just fine - no change in behavior for them
body = JSON.stringify(event);
} catch (err) {
// Record data about the error without replacing original event data, then force renormalization
event.tags.JSONStringifyError = true;
event.extra.JSONStringifyError = err;
try {
body = JSON.stringify(normalize(event));
} catch (newErr) {
// At this point even renormalization hasn't worked, meaning something about the event data has gone very wrong.
// Time to cut our losses and record only the new error. With luck, even in the problematic cases we're trying to
// debug with this hack, we won't ever land here.
const innerErr = newErr as Error;
body = JSON.stringify({
message: 'JSON.stringify error after renormalization',
// setting `extra: { innerErr }` here for some reason results in an empty object, so unpack manually
extra: { message: innerErr.message, stack: innerErr.stack },
});
}
}

const req: SentryRequest = {
body: JSON.stringify(sdkInfo ? enhanceEventWithSdkInfo(event, api.metadata.sdk) : event),
// this is the relevant line of code before the hack was added, to make it easy to undo said hack once we've solved
// the mystery
// body: JSON.stringify(sdkInfo ? enhanceEventWithSdkInfo(event, api.metadata.sdk) : event),
body,
type: eventType,
url: useEnvelope
? getEnvelopeEndpointWithUrlEncodedAuth(api.dsn, api.tunnel)
Expand Down
19 changes: 18 additions & 1 deletion packages/integration-tests/utils/helpers.ts
Original file line number Diff line number Diff line change
Expand Up @@ -87,7 +87,24 @@ async function getMultipleRequests(
if (urlRgx.test(request.url())) {
try {
reqCount -= 1;
requestData.push(requestParser(request));

// TODO: This is to compensate for a temporary debugging hack which adds data the tests aren't anticipating to
// the request. The code can be restored to its original form (the commented-out line below) once that hack is
// removed. See https://github.com/getsentry/sentry-javascript/pull/4425.
const parsedRequest = requestParser(request);
if (parsedRequest.tags) {
if (parsedRequest.tags.skippedNormalization && Object.keys(parsedRequest.tags).length === 1) {
delete parsedRequest.tags;
} else {
delete parsedRequest.tags.skippedNormalization;
}
}
if (parsedRequest.extra && Object.keys(parsedRequest.extra).length === 0) {
delete parsedRequest.extra;
}
requestData.push(parsedRequest);
// requestData.push(requestParser(request));

if (reqCount === 0) {
resolve(requestData);
}
Expand Down

0 comments on commit 472cb0c

Please sign in to comment.