From 37eb8c17f5a4a784a3487721a5e5711a349ce406 Mon Sep 17 00:00:00 2001 From: Dimitrios Vasilas Date: Tue, 14 Apr 2026 13:12:41 +0300 Subject: [PATCH 1/2] CLDSRV-890: Log lifecycle expiration events in server access logs Lifecycle expiration deletions were suppressed from access logs. Add an expiration flag to distinguish them from other backbeat operations. For lifecycle expiration events: - Operation: S3.EXPIRE.OBJECT - Requester: ScalityS3LifecycleService - ClientIP/httpCode/timing/auth: undefined (log-courier will write - or "-") --- lib/routes/routeBackbeat.js | 10 ++ lib/utilities/serverAccessLogger.js | 29 +++- tests/unit/utils/serverAccessLogger.js | 228 +++++++++++++++++++++++++ 3 files changed, 264 insertions(+), 3 deletions(-) diff --git a/lib/routes/routeBackbeat.js b/lib/routes/routeBackbeat.js index 1d25dff0b2..cc65cce354 100644 --- a/lib/routes/routeBackbeat.js +++ b/lib/routes/routeBackbeat.js @@ -117,6 +117,8 @@ function _respondWithHeaders(response, payload, extraHeaders, log, callback) { if (response.serverAccessLog) { // eslint-disable-next-line no-param-reassign response.serverAccessLog.bytesSent = Buffer.byteLength(body); + // eslint-disable-next-line no-param-reassign + response.serverAccessLog.endTurnAroundTime = process.hrtime.bigint(); } response.writeHead(200, httpHeaders); response.end(body, 'utf8', () => { @@ -843,6 +845,10 @@ function putObject(request, response, log, callback) { } function deleteObjectFromExpiration(request, response, userInfo, log, callback) { + if (request.serverAccessLog) { + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.expiration = true; + } return objectDeleteInternal(userInfo, request, log, true, err => { if (err) { log.error('error deleting object from expiration', { @@ -1693,6 +1699,10 @@ function routeBackbeat(clientIP, request, response, log) { (userInfo, authorizationResults, next) => handleAuthorizationResults( request, authorizationResults, apiMethods[0], undefined, log, err => next(err, userInfo)), (userInfo, next) => { + if (request.serverAccessLog) { + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.startTurnAroundTime = process.hrtime.bigint(); + } // TODO: understand why non-object requests (batchdelete) were not authenticated if (!isObjectRequest) { return routeNonObjectRequest(request, response, userInfo, log, next); diff --git a/lib/utilities/serverAccessLogger.js b/lib/utilities/serverAccessLogger.js index 9dc5531dfc..25639c59ae 100644 --- a/lib/utilities/serverAccessLogger.js +++ b/lib/utilities/serverAccessLogger.js @@ -288,6 +288,9 @@ function getOperation(req) { const resourceType = methodToResType[req.apiMethod]; if (req.serverAccessLog && req.serverAccessLog.backbeat) { + if (req.serverAccessLog.expiration) { + return 'S3.EXPIRE.OBJECT'; + } return `REST.${req.method}.BACKBEAT`; } @@ -516,9 +519,9 @@ function buildLogEntry(req, params, options) { // Scality server access logs extra fields logFormatVersion: SERVER_ACCESS_LOG_FORMAT_VERSION, - // If backbeat is enabled, we set loggingEnabled to false - // to prevent backbeat requests from getting to log courier. - loggingEnabled: params.backbeat ? false : (params.enabled ?? undefined), + // For non-expiration backbeat requests, force loggingEnabled + // to false to prevent delivery to log courier. + loggingEnabled: (params.backbeat && !params.expiration) ? false : (params.enabled ?? undefined), loggingTargetBucket: params.loggingEnabled?.TargetBucket ?? undefined, loggingTargetPrefix: params.loggingEnabled?.TargetPrefix ?? undefined, awsAccessKeyID: authInfo?.getAccessKey() ?? undefined, @@ -604,6 +607,26 @@ function logServerAccess(req, res) { objectKey: params.objectKey, }); + // Lifecycle expiration is an internal operation. + // Null out HTTP-layer fields to match AWS access log format. + if (params.expiration) { + logEntry.requester = 'ScalityS3LifecycleService'; + logEntry.clientIP = undefined; + logEntry.requestURI = undefined; + logEntry.httpCode = undefined; + logEntry.bytesSent = undefined; + logEntry.totalTime = undefined; + logEntry.turnAroundTime = undefined; + logEntry.signatureVersion = undefined; + logEntry.cipherSuite = undefined; + logEntry.authenticationType = undefined; + logEntry.hostHeader = undefined; + logEntry.tlsVersion = undefined; + logEntry.referer = undefined; + logEntry.userAgent = undefined; + logEntry.versionId = undefined; + logEntry.awsAccessKeyID = undefined; + } if (params.internalLogRequestQueue && params.internalLogRequestQueue.length > 0) { if (logEntry.operation === 'REST.POST.MULTI_OBJECT_DELETE') { diff --git a/tests/unit/utils/serverAccessLogger.js b/tests/unit/utils/serverAccessLogger.js index 967a1d52bb..e9fbb307f9 100644 --- a/tests/unit/utils/serverAccessLogger.js +++ b/tests/unit/utils/serverAccessLogger.js @@ -276,6 +276,16 @@ describe('serverAccessLogger utility functions', () => { // Should return BACKBEAT instead of UNKNOWN assert.strictEqual(result, 'REST.GET.BACKBEAT'); }); + + it('should return S3.EXPIRE.OBJECT for lifecycle expiration requests', () => { + const req = { + method: 'DELETE', + apiMethod: 'objectDelete', + serverAccessLog: { backbeat: true, expiration: true }, + }; + const result = getOperation(req); + assert.strictEqual(result, 'S3.EXPIRE.OBJECT'); + }); }); describe('getRequester', () => { @@ -1412,6 +1422,224 @@ describe('serverAccessLogger utility functions', () => { assert.strictEqual(loggedData.loggingTargetBucket, 'log-bucket'); assert.strictEqual(loggedData.loggingTargetPrefix, 'logs/'); }); + + it('should pass through loggingEnabled for lifecycle expiration', () => { + setServerAccessLogger(mockLogger); + const req = { + serverAccessLog: { + backbeat: true, + expiration: true, + enabled: true, + loggingEnabled: { + TargetBucket: 'log-bucket', + TargetPrefix: 'logs/', + }, + }, + method: 'DELETE', + apiMethod: 'objectDelete', + headers: {}, + socket: {}, + }; + const res = { + serverAccessLog: {}, + getHeader: () => null, + }; + + logServerAccess(req, res); + + assert.strictEqual(mockLogger.write.callCount, 1); + const loggedData = JSON.parse(mockLogger.write.firstCall.args[0].trim()); + assert.strictEqual(loggedData.loggingEnabled, true); + assert.strictEqual(loggedData.loggingTargetBucket, 'log-bucket'); + assert.strictEqual(loggedData.loggingTargetPrefix, 'logs/'); + assert.strictEqual(loggedData.operation, 'S3.EXPIRE.OBJECT'); + }); + + it('should force loggingEnabled false for non-expiration backbeat', () => { + setServerAccessLogger(mockLogger); + const req = { + serverAccessLog: { + backbeat: true, + enabled: true, + loggingEnabled: { + TargetBucket: 'log-bucket', + TargetPrefix: 'logs/', + }, + }, + method: 'PUT', + apiMethod: 'objectPut', + headers: {}, + socket: {}, + }; + const res = { + serverAccessLog: {}, + getHeader: () => null, + }; + + logServerAccess(req, res); + + assert.strictEqual(mockLogger.write.callCount, 1); + const loggedData = JSON.parse(mockLogger.write.firstCall.args[0].trim()); + assert.strictEqual(loggedData.loggingEnabled, false); + }); + + it('should not deliver lifecycle expiration log when bucket has no logging config', () => { + setServerAccessLogger(mockLogger); + const req = { + serverAccessLog: { + backbeat: true, + expiration: true, + enabled: false, + }, + method: 'DELETE', + apiMethod: 'objectDelete', + headers: {}, + socket: {}, + }; + const res = { + serverAccessLog: {}, + getHeader: () => null, + }; + + logServerAccess(req, res); + + assert.strictEqual(mockLogger.write.callCount, 1); + const loggedData = JSON.parse(mockLogger.write.firstCall.args[0].trim()); + assert.strictEqual(loggedData.loggingEnabled, false); + }); + + it('should produce a complete log entry for lifecycle expiration', () => { + setServerAccessLogger(mockLogger); + const authInfo = { + getAccountDisplayName: () => 'lifecycleAccount', + getCanonicalID: () => 'lifecycle-canonical-id', + isRequesterPublicUser: () => false, + isRequesterAnIAMUser: () => false, + getAuthVersion: () => 'AWS4-HMAC-SHA256', + getAuthType: () => 'REST-HEADER', + getAccessKey: () => 'lifecycle-access-key', + }; + const startTime = process.hrtime.bigint(); + const startTurnAroundTime = startTime + 1_000_000n; + const endTurnAroundTime = startTurnAroundTime + 50_000_000n; + const onFinishEndTime = startTime + 100_000_000n; + const onCloseEndTime = startTime + 110_000_000n; + + const req = { + serverAccessLog: { + backbeat: true, + expiration: true, + enabled: true, + loggingEnabled: { + TargetBucket: 'log-bucket', + TargetPrefix: 'access-logs/', + }, + bucketOwner: 'bucket-owner-id', + bucketName: 'source-bucket', + objectKey: 'expired-object.txt', + authInfo, + analyticsAction: 'deleteObjectFromExpiration', + analyticsAccountName: 'lifecycleAccount', + analyticsUserName: '', + startTime, + startTimeUnixMS: Date.now(), + startTurnAroundTime, + onFinishEndTime, + onCloseEndTime, + objectSize: 1024, + analyticsBytesDeleted: 1024, + }, + method: 'DELETE', + apiMethod: 'objectDelete', + headers: { host: 'source-bucket.s3.amazonaws.com' }, + socket: {}, + }; + const res = { + serverAccessLog: { + endTurnAroundTime, + }, + statusCode: 200, + getHeader: () => null, + }; + + logServerAccess(req, res); + + assert.strictEqual(mockLogger.write.callCount, 1); + const loggedData = JSON.parse(mockLogger.write.firstCall.args[0].trim()); + + // Core expiration fields + assert.strictEqual(loggedData.operation, 'S3.EXPIRE.OBJECT'); + assert.strictEqual(loggedData.loggingEnabled, true); + assert.strictEqual(loggedData.loggingTargetBucket, 'log-bucket'); + assert.strictEqual(loggedData.loggingTargetPrefix, 'access-logs/'); + + // Bucket and object info + assert.strictEqual(loggedData.bucketOwner, 'bucket-owner-id'); + assert.strictEqual(loggedData.bucketName, 'source-bucket'); + assert.strictEqual(loggedData.objectKey, 'expired-object.txt'); + + // Requester is the lifecycle service, not the auth identity + assert.strictEqual(loggedData.requester, 'ScalityS3LifecycleService'); + + // Object size + assert.strictEqual(loggedData.objectSize, 1024); + assert.strictEqual(loggedData.bytesDeleted, 1024); + + // HTTP-layer fields are null (internal operation, not an HTTP request) + assert.strictEqual(loggedData.clientIP, undefined); + assert.strictEqual(loggedData.requestURI, undefined); + assert.strictEqual(loggedData.httpCode, undefined); + assert.strictEqual(loggedData.bytesSent, undefined); + assert.strictEqual(loggedData.totalTime, undefined); + assert.strictEqual(loggedData.turnAroundTime, undefined); + assert.strictEqual(loggedData.signatureVersion, undefined); + assert.strictEqual(loggedData.authenticationType, undefined); + assert.strictEqual(loggedData.hostHeader, undefined); + assert.strictEqual(loggedData.awsAccessKeyID, undefined); + }); + + it('should log lifecycle expiration with error code on failure', () => { + setServerAccessLogger(mockLogger); + const req = { + serverAccessLog: { + backbeat: true, + expiration: true, + enabled: true, + loggingEnabled: { + TargetBucket: 'log-bucket', + TargetPrefix: 'logs/', + }, + bucketOwner: 'bucket-owner-id', + bucketName: 'source-bucket', + objectKey: 'expired-object.txt', + startTime: process.hrtime.bigint(), + startTimeUnixMS: Date.now(), + }, + method: 'DELETE', + apiMethod: 'objectDelete', + headers: {}, + socket: {}, + }; + const res = { + serverAccessLog: { + errorCode: 'NoSuchKey', + endTurnAroundTime: process.hrtime.bigint(), + }, + statusCode: 404, + getHeader: () => null, + }; + + logServerAccess(req, res); + + assert.strictEqual(mockLogger.write.callCount, 1); + const loggedData = JSON.parse(mockLogger.write.firstCall.args[0].trim()); + assert.strictEqual(loggedData.operation, 'S3.EXPIRE.OBJECT'); + assert.strictEqual(loggedData.loggingEnabled, true); + assert.strictEqual(loggedData.requester, 'ScalityS3LifecycleService'); + assert.strictEqual(loggedData.errorCode, 'NoSuchKey'); + assert.strictEqual(loggedData.httpCode, undefined); + }); + }); }); From b90440f7c31f951c470db35019e104b724172d55 Mon Sep 17 00:00:00 2001 From: Dimitrios Vasilas Date: Fri, 17 Apr 2026 18:23:00 +0300 Subject: [PATCH 2/2] CLDSRV-890: Bump version to 9.2.37 --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index 2633ee786d..b4ae39b20d 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "@zenko/cloudserver", - "version": "9.2.36", + "version": "9.2.37", "description": "Zenko CloudServer, an open-source Node.js implementation of a server handling the Amazon S3 protocol", "main": "index.js", "engines": {