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

Sentry NodeJS setUser per request #13205

Closed
3 tasks done
sbriceland opened this issue Aug 2, 2024 · 13 comments
Closed
3 tasks done

Sentry NodeJS setUser per request #13205

sbriceland opened this issue Aug 2, 2024 · 13 comments
Assignees
Labels
Package: node Issues related to the Sentry Node SDK Type: Bug

Comments

@sbriceland
Copy link

sbriceland commented Aug 2, 2024

Is there an existing issue for this?

How do you use Sentry?

Sentry Saas (sentry.io)

Which SDK are you using?

@sentry/node

SDK Version

8.20.0

Framework Version

@sentry/node

Link to Sentry event

No response

Reproduction Example/SDK Setup

How to set User per request in Node?

From Scopes Documentation:

For instance, a web server might handle multiple requests at the same time, and each request may have different scope data to apply to its events.

The isolation scope is used to isolate events from each other. For example, each request in a web server might get its own isolation scope, so that events from one request don't interfere with events from another request. In most cases, you'll want to put data that should be applied to your events on the isolation scope - which is also why all Sentry.setXXX methods, like Sentry.setTag(), will write data onto the currently active isolation scope. A classic example for data that belongs on the isolation scope is a user - each request may have a different user, so you want to make sure that the user is set on the isolation scope

... The documentation matches exactly the behavior needed. However, it simply does not work.

  • make an authenticated request, lookup user details, call setUser
  • make an unauthenticated request, do not call to setUser for this request (scope) because we don't have one, and throw an error manually

Problems

  • The manually thrown error will report the User from the previous authenticated request.
  • The same problem exists for spans.
  • This is intentionally simple, but we've seen many errors report the wrong user

This example using Express should demonstrate...

import * as Sentry from '@sentry/node';
import bodyParser from 'body-parser';
import express, { Application, NextFunction, Request, Response, Router } from 'express';

Sentry.init({
    dsn: undefined, // not needed for local debugging to reveal the issue
    beforeSend: (event, hint, ...args) => {
        const { type, contexts, exception, extra, tags, message, user, request } = event;
        console.dir(
            {
                whoami: 'sentry:beforeSend',
                event: { type, contexts, exception, extra, tags, message, user, request },
                hint,
                args
            },
            { depth: null }
        );
        return event;
    },
    skipOpenTelemetrySetup: true
});

const app: Application = express();

const router = Router();

router.use(bodyParser.urlencoded({ extended: true, limit: '500kb' }));
router.use(bodyParser.json({ limit: '500kb' }));

const Users: { id: string; email: string; name: string }[] = [
    { id: '1', email: 'foo@example.com', name: 'foo example' },
    { id: '2', email: 'foo2@example.com', name: 'foo example2' },
    { id: '3', email: 'foo3@example.com', name: 'foo example3' },
    { id: '4', email: 'foo4@example.com', name: 'foo example4' }
];

router.use('/users', function (req, res, next) {
    try {
        const authUser = Users.find((u) => u.id === req.headers['authorization']);
        if (authUser) {
            Sentry.setTag('Authenticated', true);
            Sentry.setUser(authUser);
            res.json(Users);
        } else {
            throw new Error('Authentication Error');
        }
    } catch (err) {
        next(err);
    }
});

app.use('/api', router);

app.use(function (err: Error, req: Request, res: Response, next: NextFunction) {
    const { method, originalUrl, params, query, body } = req;
    const { statusCode, locals } = res;

    Sentry.withScope((scope) => {
        scope.setExtras({
            request: { method, originalUrl, params, query, body },
            response: { statusCode, locals }
        });
        const eventId = Sentry.captureException(err);
        (res as { sentry?: string }).sentry = eventId;
    });

    next(err);
});

// Or just use this, which is identical to above, without `extras`
// Sentry.setupExpressErrorHandler(app);

const PORT = process.env.PORT || 3000
app.listen(PORT, () => {
    console.log(`API running @ http://localhost:${PORT}`);
});

Steps to Reproduce

Send the following requests:

# make an "authenticated" request
curl --header "authorization: 1" --header "content-type: application/json" http://localhost:3000/api/users

# subsequently make an unauthenticated request
curl --header "authorization: 798798798798" --header "content-type: application/json" http://localhost:3000/api/users

Expected Result

Logs show different user context. Also, this is only a very simple issue. We've seen many users mis reported in our Prod environment. So it would seem that Scopes are not isolated to a request.

Actual Result

same user for requests with different auth

@github-actions github-actions bot added the Package: browser Issues related to the Sentry Browser SDK label Aug 2, 2024
@sbriceland
Copy link
Author

sbriceland commented Aug 2, 2024

Also, not sure why this has package:browser tag. I am pretty sure i typed @sentry/node 🤷

@mydea mydea added Package: node Issues related to the Sentry Node SDK and removed Package: browser Issues related to the Sentry Browser SDK labels Aug 5, 2024
@andreiborza
Copy link
Member

Hey, thanks for filing this and providing extensive reproduction steps. We are looking into this and will get back to you.

@sbriceland
Copy link
Author

sbriceland commented Aug 5, 2024

Thanks @andreiborza !

To take the above example a step forward, I have tweaked the demo API and sample test script to illustrate that when authenticated requests are handled in parallel, the User reported for the Sentry issue is often incorrect.

To confirm that Sentry reports an incorrect User when handling multiple authenticated requests, try running the following example API:

import * as Sentry from '@sentry/node';
import bodyParser from 'body-parser';
import express, { Application, NextFunction, Request, Response, Router } from 'express';

Sentry.init({
    dsn: 'XXX',
    release: 'sentry-scope-testing',
    environment: 'local',
    skipOpenTelemetrySetup: true
});

const app: Application = express();

const router = Router();

router.use(bodyParser.urlencoded({ extended: true, limit: '500kb' }));
router.use(bodyParser.json({ limit: '500kb' }));

const Users: { id: string; email: string; name: string }[] = [
    { id: '1', email: 'foo@example.com', name: 'foo example' },
    { id: '2', email: 'foo2@example.com', name: 'foo example2' },
    { id: '3', email: 'foo3@example.com', name: 'foo example3' },
    { id: '4', email: 'foo4@example.com', name: 'foo example4' }
];

const sleep = async (ms: number) => new Promise((resolve) => setTimeout(resolve, ms));
router.use('/users', function (req, res, next) {
    try {
        const reqUser = Users.find((u) => u.id === req.headers['authorization']);
        if (reqUser) {
            Sentry.setTag('Authenticated', true);
            Sentry.setUser(reqUser);
            const randomNum = Math.random() * 3000;
            sleep(randomNum).then(() => {
                Sentry.withScope((scope) => {
                    // extras will include correct User.
                    // This allows a reference point to check the reported Issue User and the Additional Data reqUser
                    // Our tests confirm that this is often wrong when the api is dealing with requests in parallel
                    scope.setExtras({ reqUser, randomNum });
                    Sentry.captureMessage('sentry-scope-testing!');
                });
                res.json(Users);
            });
        } else {
            throw new Error('Authentication Error');
        }
    } catch (err) {
        next(err);
    }
});

app.use('/api', router);

app.use(function (err: Error, req: Request, res: Response, next: NextFunction) {
    const { method, originalUrl, params, query, body } = req;
    const { statusCode, locals } = res;

    Sentry.withScope((scope) => {
        scope.setExtras({
            request: { method, originalUrl, params, query, body },
            response: { statusCode, locals }
        });
        const eventId = Sentry.captureException(err);
        (res as { sentry?: string }).sentry = eventId;
    });

    next(err);
});

// Or just use this, which is identical to above, without `extras`
// Sentry.setupExpressErrorHandler(app);

const PORT = process.env.PORT || 3000;
app.listen(PORT, () => {
    console.log(`API running @ http://localhost:${PORT}`);
});

After starting the above server, create (& run) a shell script containing the following commands to invoke some authenticated requests in parallel:

curl --header "authorization: 4" --header "content-type: application/json" http://localhost:3000/api/users &
curl --header "authorization: 2" --header "content-type: application/json" http://localhost:3000/api/users &
curl --header "authorization: 3" --header "content-type: application/json" http://localhost:3000/api/users &
curl --header "authorization: 4" --header "content-type: application/json" http://localhost:3000/api/users &
curl --header "authorization: 3" --header "content-type: application/json" http://localhost:3000/api/users &
curl --header "authorization: 3" --header "content-type: application/json" http://localhost:3000/api/users &
curl --header "authorization: 2" --header "content-type: application/json" http://localhost:3000/api/users &
curl --header "authorization: 2" --header "content-type: application/json" http://localhost:3000/api/users &
curl --header "authorization: 4" --header "content-type: application/json" http://localhost:3000/api/users &
curl --header "authorization: 2" --header "content-type: application/json" http://localhost:3000/api/users &
wait

@sbriceland
Copy link
Author

Here's a repo for ease of running my above mentioned examples: https://github.com/sbriceland/sentry-debug

@andreiborza
Copy link
Member

Awesome, thank you for providing even more detail :)

@andreiborza
Copy link
Member

andreiborza commented Aug 12, 2024

Hey, had another look and indeed this is an issue IF skipOpenTelemetrySetup istrue. Is there a reason for skipping otel?

If you have your own Otel setup, please see https://docs.sentry.io/platforms/javascript/guides/node/opentelemetry/custom-setup/ on how to set that up properly.

The scope isolation should work then.

@terasaka2k
Copy link

terasaka2k commented Aug 12, 2024

dsn: undefined, // not needed for local debugging to reveal the issue

I don't know this is the root cause, defaultIntegrations including httpIntegration are skipped if dsn is omitted.

if (isEnabled(client)) {
client.init();
}

@sbriceland
Copy link
Author

@andreiborza - we do need skipOpenTelemetrySetup to be set to true. Just as the documentation suggests, we have an existing OTEL setup. Furthermore, we tried many different ways to include Sentry in our OTEL setup. However, the SentrySampler conflicts with behavior needed for our separate OTEL tracing. This is covered in these two discussions:

The documentation in Sentry has improved to get through some of the hurdles mentioned, but we were able to figure out the correct setup of OTEL + Sentry. The problem isn't getting it working, it's that the SentrySampler forces OTEL TraceProvider to use the sentry configured Sample Rate for all span processors.

@sbriceland
Copy link
Author

@terasaka2k - I thought that could have been an issue. So, I ended up putting together a more robust reproduction example in a repo: https://github.com/sbriceland/sentry-debug. More importantly, I made the DSN configurable so that we could test the case of sending reports up to Sentry just in case: https://github.com/sbriceland/sentry-debug/blob/main/src/server.ts#L5. We still experienced the same issues with a valid DSN.

@andreiborza
Copy link
Member

@sbriceland thank you for elaborating this (and thus documenting it for future users coming across this issue).

As the issue isn't really with setUser, but OTEL + Sentry in general I'm going to close this issue. Further discussion can happen in the aforementioned issues.

@terasaka2k
Copy link

terasaka2k commented Aug 13, 2024

Not sure this is the problem only in the sample codes, but just to be sure, the setup must follow https://docs.sentry.io/platforms/javascript/guides/node/install/esm/ (or similar) so that httpIntegration works correctly for incoming requests.
c.f. https://gist.github.com/terasaka2k/214dcea3aeed4566b5e93a818025e9f1

@sbriceland
Copy link
Author

@andreiborza - This is a bug with scopes though right? I'm not sure why opting out of Sentry's open telemetry would cause something like Scopes to be unreliable across requests.

@mydea
Copy link
Member

mydea commented Sep 17, 2024

FYI the problem here is most likely that the automatic request isolation happens after middlewares run. I added docs for this here: getsentry/sentry-docs#11378, we may investigate if we can somehow fix this but I don't know if we'll find a way -so for now you'll need to wrap this manually.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Package: node Issues related to the Sentry Node SDK Type: Bug
Projects
Archived in project
Development

No branches or pull requests

4 participants