From 1337875c8970e271b66bee54512dbb82110ac67a Mon Sep 17 00:00:00 2001 From: Satya Swaroop Mohapatra Date: Mon, 6 Oct 2025 17:52:13 +0530 Subject: [PATCH 1/6] feat: add logs in asset service when forbidden --- api/src/services/assets.ts | 24 ++++++++++++++++++++++-- 1 file changed, 22 insertions(+), 2 deletions(-) diff --git a/api/src/services/assets.ts b/api/src/services/assets.ts index 8a7d1de6cc2cd..37a572a06f073 100644 --- a/api/src/services/assets.ts +++ b/api/src/services/assets.ts @@ -84,7 +84,17 @@ export class AssetsService { * with a wrong type. In case of directus_files where id is a uuid, we'll have to verify the * validity of the uuid ahead of time. */ - if (!isValidUuid(id)) throw new ForbiddenError(); + if (!isValidUuid(id)) { + console.warn(`[ForbiddenError:InvalidUUID] Invalid UUID provided`, { + id, + accountability: this.accountability, + action: 'read', + collection: 'directus_files', + timestamp: new Date().toISOString(), + }); + + throw new ForbiddenError({ reason: 'Invalid UUID provided' }); + } if (systemPublicKeys.includes(id) === false && this.accountability) { await validateAccess( @@ -102,7 +112,17 @@ export class AssetsService { const exists = await storage.location(file.storage).exists(file.filename_disk); - if (!exists) throw new ForbiddenError(); + if (!exists) { + console.warn(`[ForbiddenError:FileMissing] File missing in storage`, { + id, + filename: file.filename_disk, + storage: file.storage, + accountability: this.accountability, + timestamp: new Date().toISOString(), + }); + + throw new ForbiddenError({ reason: 'File does not exist in storage' }); + } if (range) { const missingRangeLimits = range.start === undefined && range.end === undefined; From d7761a1f0594a6b0191b92bc0110cc5321f886de Mon Sep 17 00:00:00 2001 From: Satya Swaroop Mohapatra Date: Tue, 7 Oct 2025 11:55:20 +0530 Subject: [PATCH 2/6] add logs on image transformations --- api/src/services/assets.ts | 77 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 77 insertions(+) diff --git a/api/src/services/assets.ts b/api/src/services/assets.ts index 37a572a06f073..124112526d0c2 100644 --- a/api/src/services/assets.ts +++ b/api/src/services/assets.ts @@ -171,6 +171,13 @@ export class AssetsService { if (type && transforms.length > 0 && SUPPORTED_IMAGE_TRANSFORM_FORMATS.includes(type)) { const maybeNewFormat = TransformationUtils.maybeExtractFormat(transforms); + console.warn(`[AssetTransform] Preparing transformation`, { + fileId: file.id, + originalName: file.filename_disk, + format: maybeNewFormat, + transforms, + }); + const assetFilename = path.basename(file.filename_disk, path.extname(file.filename_disk)) + getAssetSuffix(transforms) + @@ -183,6 +190,12 @@ export class AssetsService { } if (exists) { + console.warn(`[AssetTransform] Found cached transformed asset`, { + fileId: file.id, + storage: file.storage, + filename: assetFilename, + }); + const assetStream = () => storage.location(file.storage).read(assetFilename, { range }); return { @@ -192,6 +205,12 @@ export class AssetsService { }; } + console.warn(`[AssetTransform] No cached version found, generating new transformation`, { + fileId: file.id, + storage: file.storage, + transforms, + }); + // Check image size before transforming. Processing an image that's too large for the // system memory will kill the API. Sharp technically checks for this too in it's // limitInputPixels, but we should have that check applied before starting the read streams @@ -203,6 +222,13 @@ export class AssetsService { width > (env['ASSETS_TRANSFORM_IMAGE_MAX_DIMENSION'] as number) || height > (env['ASSETS_TRANSFORM_IMAGE_MAX_DIMENSION'] as number) ) { + console.warn(`[AssetTransform] Image too large or dimensions unavailable`, { + fileId: file.id, + width, + height, + storage: file.storage, + }); + logger.warn(`Image is too large to be transformed, or image size couldn't be determined.`); throw new IllegalAssetTransformationError({ invalidTransformations: ['width', 'height'] }); } @@ -210,6 +236,12 @@ export class AssetsService { const { queue, process } = sharp.counters(); if (queue + process > (env['ASSETS_TRANSFORM_MAX_CONCURRENT'] as number)) { + console.warn(`[AssetTransform] Transformation queue full, server too busy`, { + active: process, + pending: queue, + fileId: file.id, + }); + throw new ServiceUnavailableError({ service: 'files', reason: 'Server too busy', @@ -230,37 +262,82 @@ export class AssetsService { } } catch (error) { if (error instanceof Error && error.message.startsWith('Expected')) { + console.warn(`[AssetTransform] Error:`, { + fileId: file.id, + error: error.message, + }); + throw new InvalidQueryError({ reason: error.message }); } + console.warn(`[AssetTransform] Error:`, { + fileId: file.id, + error: error instanceof Error && error.message, + }); + throw error; } const readStream = await storage.location(file.storage).read(file.filename_disk, { range, version }); readStream.on('error', (e: Error) => { + console.warn(`[AssetTransform] Error:`, { + fileId: file.id, + filename: file.filename_disk, + error: e.message, + }); + logger.error(e, `Couldn't transform file ${file.id}`); readStream.unpipe(transformer); }); try { await storage.location(file.storage).write(assetFilename, readStream.pipe(transformer), type); + + console.warn(`[AssetTransform] Successfully wrote transformed asset`, { + fileId: file.id, + output: assetFilename, + storage: file.storage, + }); } catch (error) { + console.warn(`[AssetTransform] Error:`, { + fileId: file.id, + output: assetFilename, + storage: file.storage, + error: (error as Error).message, + }); + try { await storage.location(file.storage).delete(assetFilename); } catch { + console.warn(`[AssetTransform] Cleanup failed after write error`, { fileId: file.id }); // Ignored to prevent original error from being overwritten } if ((error as Error)?.message?.includes('timeout')) { + console.warn(`[AssetTransform] Error:`, { fileId: file.id, error: (error as Error).message }); + throw new ServiceUnavailableError({ service: 'assets', reason: `Transformation timed out` }); } else { + console.warn(`[AssetTransform] Error:`, { + fileId: file.id, + output: assetFilename, + storage: file.storage, + error: (error as Error).message, + }); + throw error; } } const assetStream = () => storage.location(file.storage).read(assetFilename, { range, version }); + console.warn(`[AssetTransform] Returning transformed asset stream`, { + fileId: file.id, + filename: assetFilename, + storage: file.storage, + }); + return { stream: deferStream ? assetStream : await assetStream(), stat: await storage.location(file.storage).stat(assetFilename), From 224042b7c3447dce36d3040ba33070b8ac7e806e Mon Sep 17 00:00:00 2001 From: Satya Swaroop Mohapatra Date: Tue, 7 Oct 2025 12:09:23 +0530 Subject: [PATCH 3/6] log envs and range values --- api/src/services/assets.ts | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/api/src/services/assets.ts b/api/src/services/assets.ts index 124112526d0c2..0ab2bb2f33970 100644 --- a/api/src/services/assets.ts +++ b/api/src/services/assets.ts @@ -79,6 +79,10 @@ export class AssetsService { const systemPublicKeys = Object.values(publicSettings || {}); + console.log('ENV:ASSETS_TRANSFORM_IMAGE_MAX_DIMENSION', env['ASSETS_TRANSFORM_IMAGE_MAX_DIMENSION']) + console.log('ENV:ASSETS_TRANSFORM_MAX_CONCURRENT', env['ASSETS_TRANSFORM_MAX_CONCURRENT']) + console.log('ENV:ASSETS_TRANSFORM_TIMEOUT', env['ASSETS_TRANSFORM_TIMEOUT']) + /** * This is a little annoying. Postgres will error out if you're trying to search in `where` * with a wrong type. In case of directus_files where id is a uuid, we'll have to verify the @@ -131,6 +135,14 @@ export class AssetsService { const endUnderflow = range.end !== undefined && range.end <= 0; if (missingRangeLimits || endBeforeStart || startOverflow || endUnderflow) { + console.warn(`[RangeNotSatisfiableError] Invalid range`, { + range, + fileId: file.id, + filename: file.filename_disk, + storage: file.storage, + accountability: this.accountability, + }); + throw new RangeNotSatisfiableError({ range }); } From 43be6144f111322e79712c60afbfdb862c31feae Mon Sep 17 00:00:00 2001 From: SujayPrabhu96 Date: Wed, 15 Oct 2025 10:59:51 +0530 Subject: [PATCH 4/6] add logs for monitoring socket connections --- packages/storage-driver-s3/src/index.ts | 24 +++++++++++++++++++++++- 1 file changed, 23 insertions(+), 1 deletion(-) diff --git a/packages/storage-driver-s3/src/index.ts b/packages/storage-driver-s3/src/index.ts index c1de565b9d717..67cc394ab429d 100644 --- a/packages/storage-driver-s3/src/index.ts +++ b/packages/storage-driver-s3/src/index.ts @@ -129,7 +129,29 @@ export class DriverS3 implements TusDriver { s3ClientConfig.forcePathStyle = this.config.forcePathStyle; } - return new S3Client(s3ClientConfig); + const client = new S3Client(s3ClientConfig); + + // Monitor socket pool status + const httpAgent = s3ClientConfig.requestHandler.httpAgent; + const httpsAgent = s3ClientConfig.requestHandler.httpsAgent; + + setInterval(() => { + const httpSockets = httpAgent?.sockets ? Object.keys(httpAgent.sockets).reduce((sum, key) => sum + httpAgent.sockets[key].length, 0) : 0; + const httpRequests = httpAgent?.requests ? Object.keys(httpAgent.requests).reduce((sum, key) => sum + httpAgent.requests[key].length, 0) : 0; + const httpsFree = httpsAgent?.freeSockets ? Object.keys(httpsAgent.freeSockets).reduce((sum, key) => sum + httpsAgent.freeSockets[key].length, 0) : 0; + const httpsSockets = httpsAgent?.sockets ? Object.keys(httpsAgent.sockets).reduce((sum, key) => sum + httpsAgent.sockets[key].length, 0) : 0; + const httpsRequests = httpsAgent?.requests ? Object.keys(httpsAgent.requests).reduce((sum, key) => sum + httpsAgent.requests[key].length, 0) : 0; + + console.log('[S3 SOCKET POOL]', JSON.stringify({ + timestamp: new Date().toISOString(), + http: { active: httpSockets, queued: httpRequests }, + https: { active: httpsSockets, free: httpsFree, queued: httpsRequests }, + maxSockets, + utilization: `${Math.round((httpsSockets / maxSockets) * 100)}%` + })); + }, 5000); + + return client; } private fullPath(filepath: string) { From 47c38953f5e7e92325e94da9ba1f8871f73225bc Mon Sep 17 00:00:00 2001 From: SujayPrabhu96 Date: Thu, 16 Oct 2025 17:25:13 +0530 Subject: [PATCH 5/6] reduce time interval to print socket logs --- packages/storage-driver-s3/src/index.ts | 47 +++++++++++++++++-------- 1 file changed, 32 insertions(+), 15 deletions(-) diff --git a/packages/storage-driver-s3/src/index.ts b/packages/storage-driver-s3/src/index.ts index 67cc394ab429d..87a083943fefd 100644 --- a/packages/storage-driver-s3/src/index.ts +++ b/packages/storage-driver-s3/src/index.ts @@ -132,24 +132,41 @@ export class DriverS3 implements TusDriver { const client = new S3Client(s3ClientConfig); // Monitor socket pool status - const httpAgent = s3ClientConfig.requestHandler.httpAgent; const httpsAgent = s3ClientConfig.requestHandler.httpsAgent; setInterval(() => { - const httpSockets = httpAgent?.sockets ? Object.keys(httpAgent.sockets).reduce((sum, key) => sum + httpAgent.sockets[key].length, 0) : 0; - const httpRequests = httpAgent?.requests ? Object.keys(httpAgent.requests).reduce((sum, key) => sum + httpAgent.requests[key].length, 0) : 0; - const httpsFree = httpsAgent?.freeSockets ? Object.keys(httpsAgent.freeSockets).reduce((sum, key) => sum + httpsAgent.freeSockets[key].length, 0) : 0; - const httpsSockets = httpsAgent?.sockets ? Object.keys(httpsAgent.sockets).reduce((sum, key) => sum + httpsAgent.sockets[key].length, 0) : 0; - const httpsRequests = httpsAgent?.requests ? Object.keys(httpsAgent.requests).reduce((sum, key) => sum + httpsAgent.requests[key].length, 0) : 0; - - console.log('[S3 SOCKET POOL]', JSON.stringify({ - timestamp: new Date().toISOString(), - http: { active: httpSockets, queued: httpRequests }, - https: { active: httpsSockets, free: httpsFree, queued: httpsRequests }, - maxSockets, - utilization: `${Math.round((httpsSockets / maxSockets) * 100)}%` - })); - }, 5000); + let httpsSockets = 0; + let httpsFree = 0; + let httpsRequests = 0; + + if (httpsAgent?.sockets) { + for (const key in httpsAgent.sockets) { + httpsSockets += httpsAgent.sockets[key]?.length || 0; + } + } + + if (httpsAgent?.freeSockets) { + for (const key in httpsAgent.freeSockets) { + httpsFree += httpsAgent.freeSockets[key]?.length || 0; + } + } + + if (httpsAgent?.requests) { + for (const key in httpsAgent.requests) { + httpsRequests += httpsAgent.requests[key]?.length || 0; + } + } + + // Only log if there's activity (reduce noise) + if (httpsSockets > 0 || httpsFree > 0 || httpsRequests > 0) { + console.log('[S3 SOCKET POOL]', JSON.stringify({ + timestamp: new Date().toISOString(), + https: { active: httpsSockets, free: httpsFree, queued: httpsRequests }, + maxSockets, + utilization: `${Math.round((httpsSockets / maxSockets) * 100)}%` + })); + } + }, 500); return client; } From 9f2ded0590615548a7ee79541e598ea1ac5469bf Mon Sep 17 00:00:00 2001 From: SujayPrabhu96 Date: Thu, 16 Oct 2025 18:12:54 +0530 Subject: [PATCH 6/6] made changes to socket logs --- packages/storage-driver-s3/src/index.ts | 60 +++++++++---------------- 1 file changed, 20 insertions(+), 40 deletions(-) diff --git a/packages/storage-driver-s3/src/index.ts b/packages/storage-driver-s3/src/index.ts index 87a083943fefd..853a69044d348 100644 --- a/packages/storage-driver-s3/src/index.ts +++ b/packages/storage-driver-s3/src/index.ts @@ -69,6 +69,8 @@ export class DriverS3 implements TusDriver { public maxMultipartParts = 10_000 as const; public minPartSize = 5_242_880 as const; // 5MiB public maxUploadSize = 5_497_558_138_880 as const; // 5TiB + private activeRequests = 0; + private queuedRequests = 0; constructor(config: DriverS3Config) { this.config = config; @@ -129,46 +131,7 @@ export class DriverS3 implements TusDriver { s3ClientConfig.forcePathStyle = this.config.forcePathStyle; } - const client = new S3Client(s3ClientConfig); - - // Monitor socket pool status - const httpsAgent = s3ClientConfig.requestHandler.httpsAgent; - - setInterval(() => { - let httpsSockets = 0; - let httpsFree = 0; - let httpsRequests = 0; - - if (httpsAgent?.sockets) { - for (const key in httpsAgent.sockets) { - httpsSockets += httpsAgent.sockets[key]?.length || 0; - } - } - - if (httpsAgent?.freeSockets) { - for (const key in httpsAgent.freeSockets) { - httpsFree += httpsAgent.freeSockets[key]?.length || 0; - } - } - - if (httpsAgent?.requests) { - for (const key in httpsAgent.requests) { - httpsRequests += httpsAgent.requests[key]?.length || 0; - } - } - - // Only log if there's activity (reduce noise) - if (httpsSockets > 0 || httpsFree > 0 || httpsRequests > 0) { - console.log('[S3 SOCKET POOL]', JSON.stringify({ - timestamp: new Date().toISOString(), - https: { active: httpsSockets, free: httpsFree, queued: httpsRequests }, - maxSockets, - utilization: `${Math.round((httpsSockets / maxSockets) * 100)}%` - })); - } - }, 500); - - return client; + return new S3Client(s3ClientConfig); } private fullPath(filepath: string) { @@ -197,6 +160,21 @@ export class DriverS3 implements TusDriver { } async stat(filepath: string) { + this.queuedRequests++; + // Log queue state + if (this.queuedRequests > 1 || this.activeRequests > 10) { + console.log('[S3 REQUEST QUEUE]', JSON.stringify({ + queued: this.queuedRequests, + active: this.activeRequests, + total: this.queuedRequests + this.activeRequests, + maxSockets: this.config.maxSockets ?? 500, + timestamp: new Date().toISOString() + })); + } + + this.queuedRequests--; + this.activeRequests++; + const { ContentLength, LastModified } = await this.client.send( new HeadObjectCommand({ Key: this.fullPath(filepath), @@ -204,6 +182,8 @@ export class DriverS3 implements TusDriver { }), ); + this.activeRequests--; + return { size: ContentLength as number, modified: LastModified as Date,