CodeCow/stack
1
0
Fork 0
mirror of https://github.com/stack-auth/stack.git synced 2026-06-13 21:01:21 +08:00
Code Issues Actions 2 Packages Projects Releases Wiki Activity

Log concurrent requests per process in OpenTelemetry

Browse Source
This commit is contained in:
Konstantin Wohlwend 2025-03-02 16:38:47 -08:00
parent 2ac8cb8542
commit b340be49ce
1 changed files with 83 additions and 76 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

159
apps/backend/src/route-handlers/smart-route-handler.tsx
View File

@ -57,6 +57,7 @@ function catchError(error: unknown, requestId: string): StatusError {
* multiple concurrent requests to be handled by the same instance.
*/
const processId = generateSecureRandomString(80);
let concurrentRequestsInProcess = 0;
/**
* Catches any errors thrown in the handler and returns a 500 response with the thrown error message. Also logs the
@ -64,87 +65,93 @@ const processId = generateSecureRandomString(80);
*/
export function handleApiRequest(handler: (req: NextRequest, options: any, requestId: string) => Promise<Response>): (req: NextRequest, options: any) => Promise<Response> {
return async (req: NextRequest, options: any) => {
const requestId = generateSecureRandomString(80);
return await traceSpan({
description: 'handling API request',
attributes: {
"stack.request.request-id": requestId,
"stack.request.method": req.method,
"stack.request.url": req.url,
"stack.process-id": processId,
},
}, async (span) => {
// Set Sentry scope to include request details
Sentry.setContext("stack-request", {
requestId: requestId,
method: req.method,
url: req.url,
query: Object.fromEntries(req.nextUrl.searchParams),
headers: Object.fromEntries(req.headers),
});
// During development, don't trash the console with logs from E2E tests
const disableExtendedLogging = getNodeEnvironment().includes('dev') && !!req.headers.get("x-stack-development-disable-extended-logging");
let hasRequestFinished = false;
try {
// censor long query parameters because they might contain sensitive data
const censoredUrl = new URL(req.url);
for (const [key, value] of censoredUrl.searchParams.entries()) {
if (value.length <= 8) {
continue;
}
censoredUrl.searchParams.set(key, value.slice(0, 4) + "--REDACTED--" + value.slice(-4));
}
// request duration warning
const warnAfterSeconds = 12;
runAsynchronously(async () => {
await wait(warnAfterSeconds * 1000);
if (!hasRequestFinished) {
captureError("request-timeout-watcher", new Error(`Request with ID ${requestId} to endpoint ${req.nextUrl.pathname} has been running for ${warnAfterSeconds} seconds. Try to keep requests short. The request may be cancelled by the serverless provider if it takes too long.`));
}
concurrentRequestsInProcess++;
try {
const requestId = generateSecureRandomString(80);
return await traceSpan({
description: 'handling API request',
attributes: {
"stack.request.request-id": requestId,
"stack.request.method": req.method,
"stack.request.url": req.url,
"stack.process.id": processId,
"stack.process.concurrent-requests": concurrentRequestsInProcess,
},
}, async (span) => {
// Set Sentry scope to include request details
Sentry.setContext("stack-request", {
requestId: requestId,
method: req.method,
url: req.url,
query: Object.fromEntries(req.nextUrl.searchParams),
headers: Object.fromEntries(req.headers),
});
if (!disableExtendedLogging) console.log(`[API REQ] [${requestId}] ${req.method} ${censoredUrl}`);
const timeStart = performance.now();
const res = await handler(req, options, requestId);
const time = (performance.now() - timeStart);
if ([301, 302].includes(res.status)) {
throw new StackAssertionError("HTTP status codes 301 and 302 should not be returned by our APIs because the behavior for non-GET methods is inconsistent across implementations. Use 303 (to rewrite method to GET) or 307/308 (to preserve the original method and data) instead.", { status: res.status, url: req.nextUrl, req, res });
}
if (!disableExtendedLogging) console.log(`[ RES] [${requestId}] ${req.method} ${censoredUrl}: ${res.status} (in ${time.toFixed(0)}ms)`);
return res;
} catch (e) {
let statusError: StatusError;
// During development, don't trash the console with logs from E2E tests
const disableExtendedLogging = getNodeEnvironment().includes('dev') && !!req.headers.get("x-stack-development-disable-extended-logging");
let hasRequestFinished = false;
try {
statusError = catchError(e, requestId);
// censor long query parameters because they might contain sensitive data
const censoredUrl = new URL(req.url);
for (const [key, value] of censoredUrl.searchParams.entries()) {
if (value.length <= 8) {
continue;
}
censoredUrl.searchParams.set(key, value.slice(0, 4) + "--REDACTED--" + value.slice(-4));
}
// request duration warning
const warnAfterSeconds = 12;
runAsynchronously(async () => {
await wait(warnAfterSeconds * 1000);
if (!hasRequestFinished) {
captureError("request-timeout-watcher", new Error(`Request with ID ${requestId} to endpoint ${req.nextUrl.pathname} has been running for ${warnAfterSeconds} seconds. Try to keep requests short. The request may be cancelled by the serverless provider if it takes too long.`));
}
});
if (!disableExtendedLogging) console.log(`[API REQ] [${requestId}] ${req.method} ${censoredUrl}`);
const timeStart = performance.now();
const res = await handler(req, options, requestId);
const time = (performance.now() - timeStart);
if ([301, 302].includes(res.status)) {
throw new StackAssertionError("HTTP status codes 301 and 302 should not be returned by our APIs because the behavior for non-GET methods is inconsistent across implementations. Use 303 (to rewrite method to GET) or 307/308 (to preserve the original method and data) instead.", { status: res.status, url: req.nextUrl, req, res });
}
if (!disableExtendedLogging) console.log(`[ RES] [${requestId}] ${req.method} ${censoredUrl}: ${res.status} (in ${time.toFixed(0)}ms)`);
return res;
} catch (e) {
if (!disableExtendedLogging) console.log(`[ EXC] [${requestId}] ${req.method} ${req.url}: Non-error caught (such as a redirect), will be re-thrown. Digest: ${(e as any)?.digest}`);
throw e;
let statusError: StatusError;
try {
statusError = catchError(e, requestId);
} catch (e) {
if (!disableExtendedLogging) console.log(`[ EXC] [${requestId}] ${req.method} ${req.url}: Non-error caught (such as a redirect), will be re-thrown. Digest: ${(e as any)?.digest}`);
throw e;
}
if (!disableExtendedLogging) console.log(`[ ERR] [${requestId}] ${req.method} ${req.url}: ${statusError.message}`);
if (!commonErrors.some(e => statusError instanceof e)) {
// HACK: Log a nicified version of the error instead of statusError to get around buggy Next.js pretty-printing
// https://www.reddit.com/r/nextjs/comments/1gkxdqe/comment/m19kxgn/?utm_source=share&utm_medium=web3x&utm_name=web3xcss&utm_term=1&utm_content=share_button
if (!disableExtendedLogging) console.debug(`For the error above with request ID ${requestId}, the full error is:`, errorToNiceString(statusError));
}
const res = await createResponse(req, requestId, {
statusCode: statusError.statusCode,
bodyType: "binary",
body: statusError.getBody(),
headers: {
...statusError.getHeaders(),
},
});
return res;
} finally {
hasRequestFinished = true;
}
if (!disableExtendedLogging) console.log(`[ ERR] [${requestId}] ${req.method} ${req.url}: ${statusError.message}`);
if (!commonErrors.some(e => statusError instanceof e)) {
// HACK: Log a nicified version of the error instead of statusError to get around buggy Next.js pretty-printing
// https://www.reddit.com/r/nextjs/comments/1gkxdqe/comment/m19kxgn/?utm_source=share&utm_medium=web3x&utm_name=web3xcss&utm_term=1&utm_content=share_button
if (!disableExtendedLogging) console.debug(`For the error above with request ID ${requestId}, the full error is:`, errorToNiceString(statusError));
}
const res = await createResponse(req, requestId, {
statusCode: statusError.statusCode,
bodyType: "binary",
body: statusError.getBody(),
headers: {
...statusError.getHeaders(),
},
});
return res;
} finally {
hasRequestFinished = true;
}
});
});
} finally {
concurrentRequestsInProcess--;
}
};
};