Propagate Sentry scope

[segevfiner]

Sentry keeps async local scope using the legacy domain module, it seems to get lost across pump buffering, propagate it explicitly using AsyncResource, and use withScope to create a copy of the async local scope instead of a blank one.

[segevfiner]

Not sure if the withScope change is actually needed, the Sentry SDK might know to merge them when passed like this but their docs aren't the best...

[aandrewww]

Thanks for the PR
I don't have free time right now, but I'll review it in a few weeks.

[jesushernandez]

Shouldn't the forEach close after this?

[segevfiner]

Yep 😬

[jesushernandez]

@segevfiner cheers! By the way, we're currently using this library to add additional contextual data to sentry errors (from the logger). As it stands, none of the data is being sent to sentry. Is this the actual problem this PR is addressing?

[segevfiner]

Possibly. This fixes an issue where the Sentry SDK isolated its context to the async scope using the domain module (Which uses async_hooks internally), which caused it to not propagate scope that was set using it. It is used when using the requestHandler middleware and maybe in other cases.

[glensc]

@jesushernandez you should create issue of your problem with steps to reproduce to make the problem visible.

[jesushernandez]

I'll try to reproduce today and get back to you!

[glensc]

@segevfiner can you re-test it too? or maybe even write jest test?

[segevfiner]

P.S. CI is failing due to a too old EOL version of node in the used CircleCI base image that has an npm version that doesn't even work properly anymore. The package.json states Node 10 as a minimum though while the README.md says 6.

Only Node 14 and above is maintained ATM https://nodejs.org/en/about/releases/

[glensc]

Fixed badge:

• 62471b5

[segevfiner]

It still seems to work by testing it manually.

Testing this automatically is a bit difficult, as we will need to create some express/connect setup with Sentry.Handlers.requestHandler() that can be unit tested, since this only takes effect when using Sentry.Handlers.requestHandlerm which sets up a domain. Without it, it seems that Sentry scopes are sync, so by trying to test this automatically, I revealed another issue. I tried this test:

// Refactor me plz ;P
test('Scope propogation', async () => {
  const options = {
    level: "info"
  };
  const mockSend = jest.fn(() => Promise.resolve());
  const stream = createWriteStream({dsn: SENTRY_DSN, transport() { return {send: mockSend, flush: jest.fn(() => Promise.resolve(true))}; }});
  const logger = pinoLogger(options, stream);

  Sentry.withScope((scope) => {
    scope.setTag('test', 'foobar');

    logger.error('test');
  });

  await new Promise<void>((resolve, reject) => {
    setImmediate(() => {
      try {
        expect(mockSend.mock.calls.length).toBe(1);
        resolve();
      } catch (error) {
        reject(error);
      }
    });
  });
});

And it only works if I apply the following change:

diff --git a/src/transport.ts b/src/transport.ts
index ea3bf0e..f229e30 100644
--- a/src/transport.ts
+++ b/src/transport.ts
@@ -162,14 +162,14 @@ export class PinoSentryTransport {
     if (this.isSentryException(severity)) {
       const error = message instanceof Error ? message : new ExtendedError({ message, stack });
 
+      Sentry.captureException(error, scope);
       setImmediate(() => {
-        Sentry.captureException(error, scope);
         cb();
       });
     } else {
       // Capturing Messages
+      Sentry.captureMessage(message, scope);
       setImmediate(() => {
-        Sentry.captureMessage(message, scope);
         cb();
       });
     }

The Sentry SDK is already async internally so it is safe to just call it directly like that AFAIK. Not sure about cb so I left that in a setImmediate

[glensc]

I don't think using Sentry.withScope() is a good idea. I guess the decorateScope was created for that purpose to add data to current context? According to docs, withScope creates new scope, not attaching to current logging scope

• https://github.com/getsentry/sentry-javascript/blob/7e044b13b996275207a1244116f8b58f27ef88bb/packages/hub/src/hub.ts#L148-L158

altho I see the problem, using decorateScope maybe difficult to add new context in any part of the codebase if it's declaration is in logger constructor...

altho maybe something like this can be handy:

• https://stackabuse.com/using-async-hooks-for-request-context-handling-in-node-js/

[segevfiner]

It clones the current scope and creates a new one that will be reverted once the withScope callback returns. It is how Sentry documents to use itself, and as such users expect this to work. Using async_hooks is something for the Sentry SDK to figure out, they currently only do so via the deprecated domain module while using requestHandler but not otherwise.

[glensc]

@jesushernandez can you test does this brach solve your problem?

something like:

yarn add https://github.com/swimmio/pino-sentry#propogate-scope

or

npm install https://github.com/swimmio/pino-sentry#propogate-scope

if not, can you also test the diff that @segevfiner indicated:

• Propagate Sentry scope #46 (comment)

[glensc]

I think here's nothing else to do, so merging.