From bb78f69fe0473751023f72d0dc1e4aa5bdd77c78 Mon Sep 17 00:00:00 2001 From: Blayne Chard Date: Thu, 17 Oct 2024 12:46:52 +1300 Subject: [PATCH 1/4] fix(lambda-tiler): correctly log fetch requests --- packages/lambda-tiler/src/index.ts | 8 +++++--- packages/shared/src/file.system.ts | 5 +++-- packages/shared/src/log.ts | 7 +++++++ 3 files changed, 15 insertions(+), 5 deletions(-) diff --git a/packages/lambda-tiler/src/index.ts b/packages/lambda-tiler/src/index.ts index f14ffbd38..3fb8a7a1e 100644 --- a/packages/lambda-tiler/src/index.ts +++ b/packages/lambda-tiler/src/index.ts @@ -1,4 +1,4 @@ -import { FsaCache, FsaLog, LogConfig } from '@basemaps/shared'; +import { FsaCache, FsaLog, LogConfig, LogStorage } from '@basemaps/shared'; import { LambdaHttpRequest, LambdaHttpResponse, lf } from '@linzjs/lambda'; import { tileAttributionGet } from './routes/attribution.js'; @@ -35,12 +35,13 @@ function randomTrace(req: LambdaHttpRequest): void { // 1% trace if (rand < 0.01) req.log.level = 'trace'; // 5% debug - else if (rand < 0.04) req.log.level = 'debug'; + else if (rand < 0.25) req.log.level = 'debug'; // everything else info else req.log.level = 'info'; } handler.router.hook('request', (req) => { + LogStorage.enterWith({ log: req.log }); FsaLog.reset(); randomTrace(req); @@ -49,7 +50,8 @@ handler.router.hook('request', (req) => { }); handler.router.hook('response', (req, res) => { - req.set('requestCount', FsaLog.requests.length); + req.set('fetchCount', FsaLog.count); + req.set('fetches', FsaLog.requests); req.set('cacheSize', FsaCache.size); // Force access-control-allow-origin to everything res.header('access-control-allow-origin', '*'); diff --git a/packages/shared/src/file.system.ts b/packages/shared/src/file.system.ts index 63d49fdc8..c48b9a38c 100644 --- a/packages/shared/src/file.system.ts +++ b/packages/shared/src/file.system.ts @@ -45,7 +45,7 @@ applyS3MiddleWare(s3Fs); const credentials = new AwsS3CredentialProvider(); credentials.onFileSystemCreated = (acc: AwsCredentialConfig, fs: FileSystem): void => { - LogConfig.get().debug({ prefix: acc.prefix, roleArn: acc.roleArn }, 'FileSystem:Register'); + LogConfig.get().info({ prefix: acc.prefix, roleArn: acc.roleArn }, 'FileSystem:Register'); applyS3MiddleWare(fs as FsAwsS3); fsa.register(acc.prefix, fs); }; @@ -81,9 +81,10 @@ export const FsaLog = { this.requests.push(requestId); const startTime = performance.now(); const res = await next(req); - LogConfig.get().trace( + LogConfig.get().debug( { source: req.source.url.href, + sourceHost: req.source.url.hostname, offset: req.offset, length: req.length, requestId, diff --git a/packages/shared/src/log.ts b/packages/shared/src/log.ts index 15b70476f..b18df2bf8 100644 --- a/packages/shared/src/log.ts +++ b/packages/shared/src/log.ts @@ -1,3 +1,5 @@ +import { AsyncLocalStorage } from 'node:async_hooks'; + import pino from 'pino'; import { PrettyTransform } from 'pretty-json-log'; @@ -29,6 +31,9 @@ const defaultOpts = { level: 'debug' }; export const LogConfig = { /** Get the currently configured logger */ get(): LogType { + const localStorage = LogStorage.getStore()?.log; + if (localStorage) return localStorage; + if (currentLog == null) { currentLog = process.stdout.isTTY ? pino.default(defaultOpts, PrettyTransform.stream()) @@ -46,3 +51,5 @@ export const LogConfig = { LogConfig.get().level = 'silent'; }, }; + +export const LogStorage = new AsyncLocalStorage<{ log: LogType }>(); From 56ad68a07a289adbd1ac3fce63f95d4ed2fde808 Mon Sep 17 00:00:00 2001 From: Blayne Chard Date: Thu, 17 Oct 2024 13:03:41 +1300 Subject: [PATCH 2/4] refactor: add missing export --- packages/shared/src/index.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/shared/src/index.ts b/packages/shared/src/index.ts index 68b3c0ce4..8f7bf6eef 100644 --- a/packages/shared/src/index.ts +++ b/packages/shared/src/index.ts @@ -8,7 +8,7 @@ export { ConfigProviderDynamo } from './dynamo/dynamo.config.js'; export { Fsa as fsa, FsaCache, FsaChunk, FsaLog, stringToUrlFolder, urlToString } from './file.system.js'; export { Fqdn } from './file.system.middleware.js'; export { getImageryCenterZoom, getPreviewQuery, getPreviewUrl, PreviewSize } from './imagery.url.js'; -export { LogConfig, LogType } from './log.js'; +export { LogConfig, LogStorage, LogType } from './log.js'; export { LoggerFatalError } from './logger.fatal.error.js'; export { toQueryString } from './url.js'; export * from './util.js'; From fa7305389e843f6dae400ad9a7a371555367ac99 Mon Sep 17 00:00:00 2001 From: Blayne Chard Date: Thu, 17 Oct 2024 13:04:43 +1300 Subject: [PATCH 3/4] docs: add text explaining the .getStore --- packages/shared/src/log.ts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/packages/shared/src/log.ts b/packages/shared/src/log.ts index b18df2bf8..fecdcaae2 100644 --- a/packages/shared/src/log.ts +++ b/packages/shared/src/log.ts @@ -31,6 +31,8 @@ const defaultOpts = { level: 'debug' }; export const LogConfig = { /** Get the currently configured logger */ get(): LogType { + // If this .get() is called inside a async function eg a HTTP request + // use the logger from the async context if it has one const localStorage = LogStorage.getStore()?.log; if (localStorage) return localStorage; From 8a737ff8f4444038e38f4bf2e5e0f8d3e7059c4e Mon Sep 17 00:00:00 2001 From: Blayne Chard Date: Fri, 18 Oct 2024 11:20:02 +1300 Subject: [PATCH 4/4] Update packages/lambda-tiler/src/index.ts Co-authored-by: Wentao Kuang --- packages/lambda-tiler/src/index.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/lambda-tiler/src/index.ts b/packages/lambda-tiler/src/index.ts index 3fb8a7a1e..050a21dec 100644 --- a/packages/lambda-tiler/src/index.ts +++ b/packages/lambda-tiler/src/index.ts @@ -34,7 +34,7 @@ function randomTrace(req: LambdaHttpRequest): void { const rand = Math.random(); // 1% trace if (rand < 0.01) req.log.level = 'trace'; - // 5% debug + // 25% debug else if (rand < 0.25) req.log.level = 'debug'; // everything else info else req.log.level = 'info';