CLDSRV-839: Add BATCH.DELETE.OBJECT lines

BourgoisMickael · BourgoisMickael · commit bb151e51a6e3 · 2026-01-27T03:14:27.000+01:00
Each key in a multi object delete has a line in logs

This line should be filtered out of access_logs for cloudserver aggregated table
in s3 analytics
diff --git a/lib/api/multiObjectDelete.js b/lib/api/multiObjectDelete.js
@@ -31,6 +31,7 @@ const versionIdUtils = versioning.VersionID;
 const { data } = require('../data/wrapper');
 const logger = require('../utilities/logger');
 const { processBytesToWrite, validateQuotas } = require('./apiUtils/quotas/quotaUtils');
+const { logBatchDeleteObject } = require('../utilities/serverAccessLogger');
 
 /*
    Format of xml request:
@@ -371,14 +372,24 @@ function getObjMetadataAndDelete(authInfo, canonicalID, request,
                             callback(err, objMD, deleteInfo, result.versionId));
                 },
             ], (err, objMD, deleteInfo, versionId) => {
+                const requestID = log.getSerializedUids();
+
                 if (err === skipError) {
+                    // Object doesn't exist - log without object size (AWS behavior)
+                    logBatchDeleteObject(request, requestID, entry.key, null, null);
                     return moveOn();
                 } else if (err === objectLockedError) {
                     errorResults.push({ entry, error: errors.AccessDenied, objectLocked: true });
+                    // Log locked object with size if available
+                    const objectSize = objMD && objMD['content-length'] ? objMD['content-length'] : null;
+                    logBatchDeleteObject(request, requestID, entry.key, objectSize, errors.AccessDenied);
                     return moveOn();
                 } else if (err) {
                     log.error('error deleting object', { error: err, entry });
                     errorResults.push({ entry, error: err });
+                    // Log error case with size if available
+                    const objectSize = objMD && objMD['content-length'] ? objMD['content-length'] : null;
+                    logBatchDeleteObject(request, requestID, entry.key, objectSize, err);
                     return moveOn();
                 }
                 if (deleteInfo.deleted && objMD['content-length']) {
@@ -408,6 +419,9 @@ function getObjMetadataAndDelete(authInfo, canonicalID, request,
                     entry, isDeleteMarker,
                     deleteMarkerVersionId,
                 });
+                // Log successful deletion with object size
+                const objectSize = objMD && objMD['content-length'] ? objMD['content-length'] : null;
+                logBatchDeleteObject(request, requestID, entry.key, objectSize, null);
                 return moveOn();
             });
         },
diff --git a/lib/utilities/serverAccessLogger.js b/lib/utilities/serverAccessLogger.js
@@ -395,69 +395,65 @@ function timestampToDateTime643(unixMS) {
     return (unixMS / 1000).toFixed(3);
 }
 
-function logServerAccess(req, res) {
-    if (!req.serverAccessLog || !res.serverAccessLog || !serverAccessLogger) {
-        return;
-    }
-
-    const params = req.serverAccessLog;
-    const errorCode = res.serverAccessLog.errorCode;
-    const endTurnAroundTime = res.serverAccessLog.endTurnAroundTime;
-    const requestID = res.serverAccessLog.requestID;
-    const bytesSent = res.serverAccessLog.bytesSent;
+/**
+ * Builds a log entry object with common fields
+ * @param {object} req - HTTP request object
+ * @param {object} params - Server access log parameters from req.serverAccessLog
+ * @param {object} options - Variable fields for the log entry
+ * @return {object} Log entry object
+ */
+function buildLogEntry(req, params, options) {
     const authInfo = params.authInfo;
 
-    serverAccessLogger.write(`${JSON.stringify({
+    return {
         // Werelog fields
         // logs.access_logs_ingest.timestamp in Clickhouse is of type DateTime so it expects seconds as an integer.
         time: Math.floor(Date.now() / 1000),
         hostname,
         pid: process.pid,
 
         // Analytics
-        action: params.analyticsAction ?? undefined,
+        action: options.action ?? undefined,
         accountName: params.analyticsAccountName ?? undefined,
         userName: params.analyticsUserName ?? undefined,
-        httpMethod: req.method ?? undefined,
-        bytesDeleted: params.analyticsBytesDeleted ?? undefined,
-        bytesReceived: Number.isInteger(req.parsedContentLength) ? req.parsedContentLength : undefined,
-        bodyLength: req.headers['content-length'] !== undefined
-            ? parseInt(req.headers['content-length'], 10)
-            : undefined,
-        contentLength: getObjectSize(req, res) ?? undefined,
+        httpMethod: options.httpMethod ?? undefined,
+        bytesDeleted: options.bytesDeleted ?? undefined,
+        bytesReceived: options.bytesReceived ?? undefined,
+        bodyLength: options.bodyLength ?? undefined,
+        contentLength: options.contentLength ?? undefined,
         // eslint-disable-next-line camelcase
-        elapsed_ms: calculateElapsedMS(params.startTime, params.onCloseEndTime) ?? undefined,
+        elapsed_ms: options.elapsed_ms ?? undefined,
 
         // AWS access server logs fields https://docs.aws.amazon.com/AmazonS3/latest/userguide/LogFormat.html
         startTime: timestampToDateTime643(params.startTimeUnixMS) ?? undefined, // AWS "Time" field
         requester: getRequester(authInfo) ?? undefined,
-        operation: getOperation(req),
-        requestURI: getURI(req) ?? undefined,
-        errorCode: errorCode ?? undefined,
-        objectSize: params.objectSize ?? getObjectSize(req, res) ?? undefined,
-        totalTime: calculateTotalTime(params.startTime, params.onFinishEndTime) ?? undefined,
-        turnAroundTime: calculateTurnAroundTime(params.startTurnAroundTime, endTurnAroundTime) ?? undefined,
-        referer: req.headers.referer ?? undefined,
-        userAgent: req.headers['user-agent'] ?? undefined,
-        versionID: req.query?.versionId ?? undefined,
+        operation: options.operation ?? undefined,
+        requestURI: options.requestURI ?? undefined,
+        errorCode: options.errorCode ?? undefined,
+        objectSize: options.objectSize ?? undefined,
+        totalTime: options.totalTime ?? undefined,
+        turnAroundTime: options.turnAroundTime ?? undefined,
+        referer: req.headers?.referer ?? undefined,
+        userAgent: req.headers?.['user-agent'] ?? undefined,
+        versionID: options.versionID ?? undefined,
         signatureVersion: authInfo?.getAuthVersion() ?? undefined,
-        cipherSuite: req.socket.encrypted ? req.socket.getCipher()['standardName'] : undefined,
+        cipherSuite: req.socket?.encrypted ? req.socket.getCipher()['standardName'] : undefined,
         authenticationType: authInfo?.getAuthType() ?? undefined,
-        hostHeader: req.headers.host ?? undefined,
-        tlsVersion: req.socket.encrypted ? req.socket.getCipher()['version'] : undefined,
-        aclRequired: undefined,  // TODO: CLDSRV-774
+        hostHeader: req.headers?.host ?? undefined,
+        tlsVersion: req.socket?.encrypted ? req.socket.getCipher()['version'] : undefined,
+        aclRequired: options.aclRequired ?? undefined,  // TODO: CLDSRV-774
         // hostID: undefined,         // NOT IMPLEMENTED
         // accessPointARN: undefined, // NOT IMPLEMENTED
 
         // Shared between AWS access server logs and Analytics logs
         bucketOwner: params.bucketOwner ?? undefined,
         bucketName: params.bucketName ?? undefined, // AWS "Bucket" field
         // eslint-disable-next-line camelcase
-        req_id: requestID ?? undefined, // AWS "Request ID" field
-        bytesSent: getBytesSent(res, bytesSent) ?? undefined,
+        req_id: options.requestID ?? undefined, // AWS "Request ID" field
+        bytesSent: options.bytesSent ?? undefined,
         clientIP: getRemoteIPFromRequest(req) ?? undefined,  // AWS 'Remote IP' field
-        httpCode: res.statusCode ?? undefined, // AWS "HTTP Status" field
-        objectKey: params.objectKey ?? undefined, // AWS "Key" field
+        httpCode: options.httpCode ?? undefined, // AWS "HTTP Status" field
+        objectKey: options.objectKey ?? undefined, // AWS "Key" field
 
         // Scality server access logs extra fields
         logFormatVersion: SERVER_ACCESS_LOG_FORMAT_VERSION,
@@ -472,11 +468,90 @@ function logServerAccess(req, res) {
         // Rate Limiting fields (only present when rate limited)
         rateLimited: params.rateLimited ?? undefined,
         rateLimitSource: params.rateLimitSource ?? undefined,
-    })}\n`);
+    };
+}
+
+/**
+ * Logs a BATCH.DELETE.OBJECT entry for individual object deletions in multi-object delete
+ * @param {object} req - HTTP request object
+ * @param {string} requestID - Request ID from the response
+ * @param {string} objectKey - Key of the object being deleted
+ * @param {number|null} objectSize - Size of the object, or null if object doesn't exist
+ * @param {Error|null} error - Error object if deletion failed, null if successful
+ * @return {undefined}
+ */
+function logBatchDeleteObject(req, requestID, objectKey, objectSize, error) {
+    if (!req.serverAccessLog || !serverAccessLogger) {
+        return;
+    }
+
+    const params = req.serverAccessLog;
+    let httpCode = 204;
+    let errorCode = undefined;
+
+    if (error) {
+        httpCode = error.code ? parseInt(error.code, 10) : 500;
+        errorCode = error.message || 'InternalError';
+    }
+
+    const logEntry = buildLogEntry(req, params, {
+        action: 'DeleteObject',
+        httpMethod: 'POST',
+        bytesDeleted: objectSize,
+        contentLength: objectSize,
+        operation: 'BATCH.DELETE.OBJECT',
+        objectSize,
+        httpCode,
+        errorCode,
+        objectKey,
+        requestID,
+    });
+
+    serverAccessLogger.write(`${JSON.stringify(logEntry)}\n`);
+}
+
+function logServerAccess(req, res) {
+    if (!req.serverAccessLog || !res.serverAccessLog || !serverAccessLogger) {
+        return;
+    }
+
+    const params = req.serverAccessLog;
+    const errorCode = res.serverAccessLog.errorCode;
+    const endTurnAroundTime = res.serverAccessLog.endTurnAroundTime;
+    const requestID = res.serverAccessLog.requestID;
+    const bytesSent = res.serverAccessLog.bytesSent;
+
+    const logEntry = buildLogEntry(req, params, {
+        action: params.analyticsAction,
+        httpMethod: req.method,
+        bytesDeleted: params.analyticsBytesDeleted,
+        bytesReceived: Number.isInteger(req.parsedContentLength) ? req.parsedContentLength : undefined,
+        bodyLength: req.headers['content-length'] !== undefined
+            ? parseInt(req.headers['content-length'], 10)
+            : undefined,
+        contentLength: getObjectSize(req, res),
+        // eslint-disable-next-line camelcase
+        elapsed_ms: calculateElapsedMS(params.startTime, params.onCloseEndTime),
+        operation: getOperation(req),
+        requestURI: getURI(req),
+        errorCode,
+        objectSize: params.objectSize ?? getObjectSize(req, res),
+        totalTime: calculateTotalTime(params.startTime, params.onFinishEndTime),
+        turnAroundTime: calculateTurnAroundTime(params.startTurnAroundTime, endTurnAroundTime),
+        versionID: req.query?.versionId,
+        aclRequired: undefined, // TODO: CLDSRV-774
+        requestID,
+        bytesSent: getBytesSent(res, bytesSent),
+        httpCode: res.statusCode,
+        objectKey: params.objectKey,
+    });
+
+    serverAccessLogger.write(`${JSON.stringify(logEntry)}\n`);
 }
 
 module.exports = {
     logServerAccess,
+    logBatchDeleteObject,
     setServerAccessLogger,
     ServerAccessLogger,
 
diff --git a/tests/functional/aws-node-sdk/test/serverAccessLogs/testServerAccessLogFile.js b/tests/functional/aws-node-sdk/test/serverAccessLogs/testServerAccessLogFile.js
@@ -1669,7 +1669,7 @@ describe('Server Access Logs - File Output', async () => {
                 };
             })(),
             (() => {
-                // This operation tests deleting multiple objects.
+                // This operation tests deleting multiple objects including a non-existent one.
                 const method = async () => {
                     await s3.createBucket({ Bucket: bucketName }).promise();
                     await s3.putObject({ Bucket: bucketName, Key: objectKey, Body: 'test data' }).promise();
@@ -1679,7 +1679,8 @@ describe('Server Access Logs - File Output', async () => {
                         Delete: {
                             Objects: [
                                 { Key: objectKey },
-                                { Key: `${objectKey}2` }
+                                { Key: `${objectKey}2` },
+                                { Key: `${objectKey}-non-existent` }
                             ]
                         }
                     }).promise();
@@ -1709,11 +1710,36 @@ describe('Server Access Logs - File Output', async () => {
                             objectKey: `${objectKey}2`,
                             httpMethod: 'PUT',
                         },
+                        {
+                            ...commonProperties,
+                            operation: 'BATCH.DELETE.OBJECT',
+                            action: 'DeleteObject',
+                            objectKey,
+                            httpCode: 204,
+                            httpMethod: 'POST',
+                        },
+                        {
+                            ...commonProperties,
+                            operation: 'BATCH.DELETE.OBJECT',
+                            action: 'DeleteObject',
+                            objectKey: `${objectKey}2`,
+                            httpCode: 204,
+                            httpMethod: 'POST',
+                        },
+                        {
+                            ...commonProperties,
+                            operation: 'BATCH.DELETE.OBJECT',
+                            action: 'DeleteObject',
+                            objectKey: `${objectKey}-non-existent`,
+                            httpCode: 204,
+                            httpMethod: 'POST',
+                        },
                         {
                             ...commonProperties,
                             operation: 'REST.POST.MULTI_OBJECT_DELETE',
                             action: 'DeleteObjects',
                             httpMethod: 'POST',
+                            objectKey: null,
                         }
                     ],
                 };
