From 314a6b96165f223c580d5fb2209c9ea2d7a302eb Mon Sep 17 00:00:00 2001 From: Leif Henriksen Date: Fri, 16 Jan 2026 19:22:25 +0100 Subject: [PATCH 1/4] CLDSRV-821: record and write backbeat server access log data --- lib/routes/routeBackbeat.js | 38 ++++++- lib/utilities/serverAccessLogger.js | 8 +- tests/unit/utils/serverAccessLogger.js | 146 +++++++++++++++++++++++++ 3 files changed, 189 insertions(+), 3 deletions(-) diff --git a/lib/routes/routeBackbeat.js b/lib/routes/routeBackbeat.js index 0f1adfb423..1d25dff0b2 100644 --- a/lib/routes/routeBackbeat.js +++ b/lib/routes/routeBackbeat.js @@ -114,6 +114,10 @@ function _respondWithHeaders(response, payload, extraHeaders, log, callback) { 'content-type': 'application/json', 'content-length': Buffer.byteLength(body), }, extraHeaders); + if (response.serverAccessLog) { + // eslint-disable-next-line no-param-reassign + response.serverAccessLog.bytesSent = Buffer.byteLength(body); + } response.writeHead(200, httpHeaders); response.end(body, 'utf8', () => { log.end().info('responded with payload', { @@ -1572,6 +1576,10 @@ function routeBackbeat(clientIP, request, response, log) { const contentLength = request.headers['x-amz-decoded-content-length'] || request.headers['content-length']; // eslint-disable-next-line no-param-reassign request.parsedContentLength = Number.parseInt(contentLength?.toString() ?? '', 10); + + log.debug('routing request'); + _normalizeBackbeatRequest(request); + log.addDefaultFields({ clientIP, url: request.url, @@ -1582,9 +1590,17 @@ function routeBackbeat(clientIP, request, response, log) { bytesReceived: request.parsedContentLength || 0, bodyLength: parseInt(request.headers['content-length'], 10) || 0, }); + if (request.serverAccessLog) { + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.bucketName = request.bucketName; + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.objectKey = request.objectKey; + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.backbeat = true; + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.analyticsAction = 'BACKBEAT_INVALID'; + } - log.debug('routing request'); - _normalizeBackbeatRequest(request); const requestContexts = prepareRequestContexts('objectReplicate', request); if (request.resourceType === 'expiration' || request.resourceType === 'batchdelete') { @@ -1642,6 +1658,16 @@ function routeBackbeat(clientIP, request, response, log) { const isObjectRequest = _isObjectRequest(request); + if (request.serverAccessLog) { + let route = backbeatRoutes[request.method][request.resourceType]; + if (useMultipleBackend && request.resourceType !== 'multiplebackendmetadata') { + route = backbeatRoutes[request.method][request.resourceType][request.query.operation]; + } + + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.analyticsAction = route?.name ?? 'BACKBEAT_INVALID'; + } + return async.waterfall([ next => auth.server.doAuth( request, log, (err, userInfo, authorizationResults, streamingV4Params, infos) => { @@ -1652,6 +1678,14 @@ function routeBackbeat(clientIP, request, response, log) { objectKey: request.objectKey, }); } + if (request.serverAccessLog && userInfo) { + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.authInfo = userInfo; + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.analyticsAccountName = userInfo.getAccountDisplayName(); + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.analyticsUserName = userInfo.getIAMdisplayName(); + } // eslint-disable-next-line no-param-reassign request.accountQuotas = infos?.accountQuota; return next(err, userInfo, authorizationResults); diff --git a/lib/utilities/serverAccessLogger.js b/lib/utilities/serverAccessLogger.js index 333dc09a92..1fa37619d9 100644 --- a/lib/utilities/serverAccessLogger.js +++ b/lib/utilities/serverAccessLogger.js @@ -257,6 +257,10 @@ const methodToResType = Object.freeze({ function getOperation(req) { const resourceType = methodToResType[req.apiMethod]; + + if (req.serverAccessLog && req.serverAccessLog.backbeat) { + return `REST.${req.method}.BACKBEAT`; + } if (!resourceType) { process.emitWarning('Unknown apiMethod for server access log', { type: 'ServerAccessLogWarning', @@ -457,7 +461,9 @@ function logServerAccess(req, res) { // Scality server access logs extra fields logFormatVersion: SERVER_ACCESS_LOG_FORMAT_VERSION, - loggingEnabled: params.enabled ?? undefined, + // 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), loggingTargetBucket: params.loggingEnabled?.TargetBucket ?? undefined, loggingTargetPrefix: params.loggingEnabled?.TargetPrefix ?? undefined, awsAccessKeyID: authInfo?.getAccessKey() ?? undefined, diff --git a/tests/unit/utils/serverAccessLogger.js b/tests/unit/utils/serverAccessLogger.js index 7c6973c5ad..642f55ba57 100644 --- a/tests/unit/utils/serverAccessLogger.js +++ b/tests/unit/utils/serverAccessLogger.js @@ -196,6 +196,68 @@ describe('serverAccessLogger utility functions', () => { const result = getOperation(req); assert.strictEqual(result, 'REST.GET.UNKNOWN'); }); + + it('should return REST.GET.BACKBEAT when backbeat is enabled for GET', () => { + const req = { + method: 'GET', + apiMethod: 'objectGet', + serverAccessLog: { backbeat: true }, + }; + const result = getOperation(req); + assert.strictEqual(result, 'REST.GET.BACKBEAT'); + }); + + it('should return REST.PUT.BACKBEAT when backbeat is enabled for PUT', () => { + const req = { + method: 'PUT', + apiMethod: 'objectPut', + serverAccessLog: { backbeat: true }, + }; + const result = getOperation(req); + assert.strictEqual(result, 'REST.PUT.BACKBEAT'); + }); + + it('should return REST.DELETE.BACKBEAT when backbeat is enabled for DELETE', () => { + const req = { + method: 'DELETE', + apiMethod: 'objectDelete', + serverAccessLog: { backbeat: true }, + }; + const result = getOperation(req); + assert.strictEqual(result, 'REST.DELETE.BACKBEAT'); + }); + + it('should return REST.POST.BACKBEAT when backbeat is enabled for POST', () => { + const req = { + method: 'POST', + apiMethod: 'completeMultipartUpload', + serverAccessLog: { backbeat: true }, + }; + const result = getOperation(req); + assert.strictEqual(result, 'REST.POST.BACKBEAT'); + }); + + it('should prioritize backbeat over normal apiMethod mapping', () => { + const req = { + method: 'GET', + apiMethod: 'bucketGetVersioning', + serverAccessLog: { backbeat: true }, + }; + const result = getOperation(req); + // Should return BACKBEAT instead of normal REST.GET.VERSIONING + assert.strictEqual(result, 'REST.GET.BACKBEAT'); + }); + + it('should return REST.method.BACKBEAT even with unknown apiMethod', () => { + const req = { + method: 'GET', + apiMethod: 'unknownMethod', + serverAccessLog: { backbeat: true }, + }; + const result = getOperation(req); + // Should return BACKBEAT instead of UNKNOWN + assert.strictEqual(result, 'REST.GET.BACKBEAT'); + }); }); describe('getRequester', () => { @@ -1146,6 +1208,90 @@ describe('serverAccessLogger utility functions', () => { assert.strictEqual('bytesReceived' in loggedData, false); assert.strictEqual('contentLength' in loggedData, false); }); + + it('should log with loggingEnabled false when backbeat is enabled', () => { + setServerAccessLogger(mockLogger); + const req = { + serverAccessLog: { + backbeat: true, + enabled: true, + }, + method: 'GET', + apiMethod: 'objectGet', + 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()); + + // Verify loggingEnabled is false in the logged data + assert.strictEqual(loggedData.loggingEnabled, false); + }); + + it('should log REST.GET.BACKBEAT operation when backbeat is enabled', () => { + setServerAccessLogger(mockLogger); + const req = { + serverAccessLog: { + backbeat: true, + }, + method: 'GET', + apiMethod: 'objectGet', + 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()); + + // Verify operation is REST.GET.BACKBEAT + assert.strictEqual(loggedData.operation, 'REST.GET.BACKBEAT'); + }); + + it('should override loggingEnabled when backbeat is enabled with logging config', () => { + 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()); + + // Verify loggingEnabled is false (overridden by backbeat) + assert.strictEqual(loggedData.loggingEnabled, false); + // But TargetBucket and TargetPrefix should still be logged + assert.strictEqual(loggedData.loggingTargetBucket, 'log-bucket'); + assert.strictEqual(loggedData.loggingTargetPrefix, 'logs/'); + }); }); }); From beca28e5d02f7f4377df51ebb60bef494de92709 Mon Sep 17 00:00:00 2001 From: Leif Henriksen Date: Fri, 16 Jan 2026 19:48:21 +0100 Subject: [PATCH 2/4] CLDSRV-821: update server_access_log.schema.json action field description --- schema/server_access_log.schema.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/schema/server_access_log.schema.json b/schema/server_access_log.schema.json index a103f95551..8e7a1a4717 100644 --- a/schema/server_access_log.schema.json +++ b/schema/server_access_log.schema.json @@ -20,7 +20,7 @@ "minimum": 0 }, "action": { - "description": "S3 API action name.", + "description": "S3 API action name or the Backbeat route.", "type": "string" }, "accountName": { From eafb44cb82254959ddf6701e940e02210f73da16 Mon Sep 17 00:00:00 2001 From: Leif Henriksen Date: Fri, 16 Jan 2026 18:08:58 +0100 Subject: [PATCH 3/4] CLDSRV-821: log backbeat routes --- lib/server.js | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/lib/server.js b/lib/server.js index 3ac1d0a297..abb9fae2e8 100644 --- a/lib/server.js +++ b/lib/server.js @@ -126,11 +126,13 @@ class S3Server { monitoringClient.httpActiveRequests.inc(); const requestStartTime = process.hrtime.bigint(); - // Skip server access logs for heartbeat and backbeat. + // Skip server access logs for heartbeat. const isLoggingEnabled = _config.serverAccessLogs && (_config.serverAccessLogs.mode === serverAccessLogsModes.LOG_ONLY || _config.serverAccessLogs.mode === serverAccessLogsModes.ENABLED); - if (isLoggingEnabled && !req.url.startsWith('/_/')) { + const isInternalRoute = req.url.startsWith('/_'); + const isBackbeatRoute = req.url.startsWith('/_/backbeat/'); + if (isLoggingEnabled && (!isInternalRoute || isBackbeatRoute)) { // eslint-disable-next-line no-param-reassign req.serverAccessLog = { enabled: false, From f204ad44ecd3b3e1349412ab8064f4accc08bdd2 Mon Sep 17 00:00:00 2001 From: Leif Henriksen Date: Thu, 22 Jan 2026 14:42:05 +0100 Subject: [PATCH 4/4] CLDSRV-821: bump package.json version to 9.2.18 --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index eea7358ad4..a79e4e2a77 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "@zenko/cloudserver", - "version": "9.2.17", + "version": "9.2.18", "description": "Zenko CloudServer, an open-source Node.js implementation of a server handling the Amazon S3 protocol", "main": "index.js", "engines": {