Exceptions from not sampled transactions are added to non-related transactions

[geraldosalazar16]

Is there an existing issue for this?

• I have checked for existing issues https://github.com/getsentry/sentry-javascript/issues
• I have reviewed the documentation https://docs.sentry.io/
• I am using the latest SDK release https://github.com/getsentry/sentry-javascript/releases

How do you use Sentry?

Sentry Saas (sentry.io)

Which package are you using?

@sentry/node

SDK Version

6.19.6

Framework Version

6.19.6

Link to Sentry event

No response

Steps to Reproduce

I am trying to understand how to use transactions on a high concurrency environment (the server is going to get a lot of request that are going to overlap with each other). So I created a sandbox to test my use case this is what I did

I created a very simple Nest JS project with a single GET endpoint. This endpoint takes 1 second to return a response. I also started a transaction every time the endpoint is hit. The endpoint will randomly fail and in that case I will send an exception to Sentry. My main goal is to test what happens if there is an exception in a transaction that was not selected for sampling (I set the tracesSampleRate to 0.5 in the init method)
So to test this I used K6 and ran k6 run --vus 10 --duration 2s k6.js so I will get 10 requests concurrently.
Here is the link to the repo
https://github.com/geraldosalazar16/sentry-concurrency

Expected Result

Well the expected result is that those exceptions will get related to some transaction (even if it did not happened during that transaction) I am not sure if this is intended or a bug. I see multiple exceptions linked to one transaction

Actual Result

I am not sure what the behaviour should be for exceptions captured during a non traced transaction but it is very confusing (at least to me) the way they show right now

[AbhiPrasad]

Hey, thanks for writing in!

We recommend using something like domains or async_hooks to isolate async resources in a high concurrency environment. For example, you can see how our express request handler uses domains under the hood to ensure things are separated properly:

sentry-javascript/packages/node/src/handlers.ts

Lines 420 to 455 in c518955

	const local = domain.create();
	local.add(req);
	local.add(res);
	local.on('error', next);
	local.run(() => {
	const currentHub = getCurrentHub();
	currentHub.configureScope(scope => {
	scope.addEventProcessor((event: Event) => parseRequest(event, req, options));
	const client = currentHub.getClient<NodeClient>();
	if (isAutoSessionTrackingEnabled(client)) {
	const scope = currentHub.getScope();
	if (scope) {
	// Set `status` of `RequestSession` to Ok, at the beginning of the request
	scope.setRequestSession({ status: 'ok' });
	}
	}
	});
	res.once('finish', () => {
	const client = currentHub.getClient<NodeClient>();
	if (isAutoSessionTrackingEnabled(client)) {
	setImmediate(() => {
	// eslint-disable-next-line @typescript-eslint/no-unsafe-member-access
	if (client && (client as any)._captureRequestSession) {
	// Calling _captureRequestSession to capture request session at the end of the request by incrementing
	// the correct SessionAggregates bucket i.e. crashed, errored or exited
	// eslint-disable-next-line @typescript-eslint/no-unsafe-member-access
	(client as any)._captureRequestSession();
	}
	});
	}
	});
	next();
	});

[github-actions]

This issue has gone three weeks without activity. In another week, I will close it.

But! If you comment or otherwise update it, I will reset the clock, and if you label it Status: Backlog or Status: In Progress, I will leave it alone ... forever!

---

"A weed is but an unloved flower." ― Ella Wheeler Wilcox 🥀

[nealoke]

@AbhiPrasad I'm having some issues trying to understand how I can implement this properly. I have two things that are happening namely HTTP requests coming in and internal cron jobs running. I'm using NestJS but found that the @ntegral/nestjs-sentry is not the right fit for my situation and a bit outdated.

Desired outcome

What I'm trying to achieve is to have logs that are related to a single request or process like a cron job to be sent along when an error occurs. Currently all of the logs from my cron job are being sent whenever a HTTP request is throwing an error. So they are not relevant.

When not running any cron job the scoping is going fine and it will only send relevant logs of only the request when an error occurs. This is because I'm using the Sentry.Handlers.requestHandler() as middleware on my express server.

Setup

Without going into detail, I have a service that gives me the current process context, this context is used in other services and is setup using async_hooks.

ProcessContextService

@Injectable()
export class ProcessContextService {
	/**
	 * Determine type of the current context that is used
	 */
	getType() {
		if (RequestContext.currentContext) {
			return 'request';
		}

		if (ManualProcessContext.currentContext) {
			return 'process';
		}
	}

	/**
	 * Get the contents of the current context
	 */
	getContents() {
		const type = this.getType();

		// Via HTTP
		if (type === 'request') {
			const req: Request = RequestContext.currentContext.req;
			return req.meta;
		}

		// Manually created (cron jobs, ...)
		else if (type === 'process') {
			return ManualProcessContext.currentContext;
		}
	}
}

ManualProcessContext

import { Injectable } from '@nestjs/common';
import { AsyncLocalStorage } from 'async_hooks';
import cuid from 'cuid';

import { ProcessContextContents } from './process-context.service';

@Injectable()
export class ManualProcessContext {
	static cls = new AsyncLocalStorage<ProcessContextContents>();

	static get currentContext() {
		return this.cls.getStore();
	}

	static create() {
		const id = cuid();
		this.cls.enterWith({ contextId: id });
		return id;
	}

	constructor() { }
}

LoggerService

import { Injectable, LoggerService as NestLoggerService } from '@nestjs/common';
import { addBreadcrumb } from '@sentry/node';

@Injectable()
export class LoggerService implements NestLoggerService {
	// ...

	public log(message: any, context?: string): any {
		// ... 

		addBreadcrumb({ message, level: 'info' });

		// ...
	}

	// ... 
}

Cron job example

import { Injectable } from '@nestjs/common';
import { Cron, CronExpression } from '@nestjs/schedule';

@Injectable()
export class TaskSchedulerService {
	// ...

	@Cron(CronExpression.EVERY_10_SECONDS)
	async throwError() {
		this.logger.log('Should only be sent when an error in this cron job occurs');
		throw new Error('Cron job erroring');
	}
}

Question

How can I implement similar logic so that logs are properly scoped for my cron jobs like it is done for HTTP requests?

[AbhiPrasad]

@nealoke you'll have to use domains to isolate context, which is what the Sentry.Handlers.requestHandler does under the hood.

sentry-javascript/packages/node/src/handlers.ts

Lines 183 to 187 in f8b74f0

	const local = domain.create();
	local.add(req);
	local.add(res);
	local.run(() => {

[nealoke]

@AbhiPrasad thanks for the answer but for me it is still unclear 😢. I mean I see the using of domain but don't really know how to go from there. My main questions are:

1. Do I need to flush things myself?
2. Will Sentry know automatically the domain it is supposed to use when importing and using addBreadcrumb (like in my code)?
3. Where would I put this code? (can't be an interceptor as they don't run for cron jobs etc)
4. What needs to be in the .run method for it to work properly?
5. How will I terminate a domain when the cron job finishes executing? (I cant listen to finish like you do in the handler)

Thanks for your time and effort 🙏

[nealoke]

As mentioned by @AbhiPrasad, you indeed use the domain package like I'm doing here which works as intended. I don't understand why this is not mentioned in the documentation at all. Am I the only one that want's to track error's in cron jobs and queue handlers?

import { Injectable } from '@nestjs/common';
import { Cron, CronExpression } from '@nestjs/schedule';


@Injectable()
export class TaskSchedulerService {
	// ...

	@Cron(CronExpression.EVERY_10_SECONDS)
	async throwError() {
		const local = domain.create();
		local.run(() => {
			this.logger.log('Should only be sent when an error in this cron job occurs');
			throw new Error('this is an error');
		});
	}
}

Doesn't work like this

What I don't understand however is that the following doesn't work, I'm essentially doing the same thing but the result here is that nothing of the this.logger.log is present as breadcrumbs.

TaskSchedulerService

import { Injectable } from '@nestjs/common';
import { Cron, CronExpression } from '@nestjs/schedule';

@Injectable()
export class TaskSchedulerService {
	// ...

	@Cron(CronExpression.EVERY_10_SECONDS)
	@ProvideManualProcess()
	async throwError() {
		this.logger.log('Should only be sent when an error in this cron job occurs');
		throw new Error('this is an error');
	}
}

ProvideManualProcess

import * as domain from 'domain';

export const ProvideManualProcess = (): MethodDecorator => {
	return (target: any, propertyKey: string, descriptor: PropertyDescriptor) => {
		const originalMethod = descriptor.value;

		descriptor.value = async function (...args: any[]) {
			const local = domain.create();
			return local.run(() => {
				return originalMethod.apply(this, [...args]);
			});
		};

		return descriptor;
	};
};

[nealoke]

My previous solution wasn't great because as soon as I used async inside the .run method it wasn't capturing the this.logger.log being made. After another 5 or 6 hours I finally have the implementation that works properly by using domains.

Simplified solution

By using .enter it simply says that everything after it runs in the domain and we have no issues with async code

import { Injectable } from '@nestjs/common';
import { Cron, CronExpression } from '@nestjs/schedule';

@Injectable()
export class TaskSchedulerService {
	// ...

	@Cron(CronExpression.EVERY_10_SECONDS)
	@ProvideManualProcess()
	async throwError() {
		const local = domain.create();
		local.enter(); // From this point on, everything is in this domain
		this.logger.log('Should only be sent when an error in this cron job occurs');
		throw new Error('this is an error');
	}
}

With a decorator (ProvideManualProcess)

import * as domain from 'domain';

export const ProvideManualProcess = (): MethodDecorator => {
	return (target: any, propertyKey: string, descriptor: PropertyDescriptor) => {
		const originalMethod = descriptor.value;

		descriptor.value = async function (...args: any[]) {
			const local = domain.create();
			local.enter();
			return originalMethod.apply(this, [processId, ...args]);
		};

		return descriptor;
	};
};

[AbhiPrasad]

Hey thank you for your patience while we got around to looking at this!

To answer some questions:

Do I need to flush things myself?

In a temporary process you will to make sure Sentry has the time to flush events. You can use the Sentry.flush(timestamp) to accomplish this.

Will Sentry know automatically the domain it is supposed to use when importing and using addBreadcrumb (like in my code)?

Yup, Sentry will use the correct domain under the hood for this.

How will I terminate a domain when the cron job finishes executing? (I cant listen to finish like you do in the handler)

The domain should be garbage collected if you use domain.run or domain.bind.

I don't understand why this is not mentioned in the documentation at all

Something we need to do better with - opened a GH issue to track: getsentry/sentry-docs#6541

As for using async code inside a domain, you can use domain.bind to return a value from within the domain callback.

import * as domain from 'domain';

export const ProvideManualProcess = (): MethodDecorator => {
	return (target: any, propertyKey: string, descriptor: PropertyDescriptor) => {
		const originalMethod = descriptor.value;

		descriptor.value = async function (...args: any[]) {
			const local = domain.create();
                        return local.bind(() => originalMethod.apply(this, [processId, ...args]))();
		};

		return descriptor;
	};
};

What I'm curious about is this code - there is nothing async about it, so I can't see why it wouldn't work with domain.run().

import { Injectable } from '@nestjs/common';
import { Cron, CronExpression } from '@nestjs/schedule';


@Injectable()
export class TaskSchedulerService {
	// ...

	@Cron(CronExpression.EVERY_10_SECONDS)
	async throwError() {
		const local = domain.create();
		local.run(() => {
			this.logger.log('Should only be sent when an error in this cron job occurs');
			throw new Error('this is an error');
		});
	}
}

I would shy away from using domain.enter because it requires you to call domain.exit after the async task has ended.

[nealoke]

Thanks for the answer, and good that you made an issue for adjusting the docs. I can't be the only one 🙈

In a temporary process you will to make sure Sentry has the time to flush events. You can use the Sentry.flush(timestamp) to accomplish this.

In the example code, is there a place where I would need to call this then? For now I can see that everything is working as it should.

What I'm curious about is this code - there is nothing async about it, so I can't see why it wouldn't work with domain.run().

It is simplified code that's why there is no await or such in there. In my actual case there was.

I would shy away from using domain.enter because it requires you to call domain.exit after the async task has ended.

When I don't exit it but the process finished, it won't do it automatically?

[AbhiPrasad]

It is simplified code that's why there is no await or such in there. In my actual case there was.

domain.bind should work for you then!

When I don't exit it but the process finished, it won't do it automatically

Ah yes if the process will be finished it will all be cleaned up, so no problems there, use domain.enter() as you please!

[AbhiPrasad]

Our usage of the domain.bind API: https://github.com/search?q=repo%3Agetsentry%2Fsentry-javascript%20local.bind&type=code

[nealoke]

Our usage of the domain.bind API: https://github.com/search?q=repo%3Agetsentry%2Fsentry-javascript%20local.bind&type=code

This gives me nothing as result 😅

[AbhiPrasad]

sentry-javascript/packages/remix/src/utils/instrumentServer.ts

Line 399 in b589685

return local.bind(async () => {

sentry-javascript/packages/nextjs/src/server/wrapApiHandlerWithSentry.ts

Line 73 in b589685

const boundHandler = local.bind(async () => {