Skip to content

Commit 01f6e7e

Browse files
leif-scalityleif-scality
committed
Merge remote-tracking branch 'origin/improvement/CLDSRV-821-add-backbeat-calls-to-logs' into w/9.3/improvement/CLDSRV-821-add-backbeat-calls-to-logs
2 parents baa4fc8 + f204ad4 commit 01f6e7e

File tree

5 files changed

+194
-6
lines changed

5 files changed

+194
-6
lines changed

‎lib/routes/routeBackbeat.js‎

Lines changed: 36 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -114,6 +114,10 @@ function _respondWithHeaders(response, payload, extraHeaders, log, callback) {
114114
'content-type': 'application/json',
115115
'content-length': Buffer.byteLength(body),
116116
}, extraHeaders);
117+
if (response.serverAccessLog) {
118+
// eslint-disable-next-line no-param-reassign
119+
response.serverAccessLog.bytesSent = Buffer.byteLength(body);
120+
}
117121
response.writeHead(200, httpHeaders);
118122
response.end(body, 'utf8', () => {
119123
log.end().info('responded with payload', {
@@ -1607,6 +1611,10 @@ function routeBackbeat(clientIP, request, response, log) {
16071611
const contentLength = request.headers['x-amz-decoded-content-length'] || request.headers['content-length'];
16081612
// eslint-disable-next-line no-param-reassign
16091613
request.parsedContentLength = Number.parseInt(contentLength?.toString() ?? '', 10);
1614+
1615+
log.debug('routing request');
1616+
_normalizeBackbeatRequest(request);
1617+
16101618
log.addDefaultFields({
16111619
clientIP,
16121620
url: request.url,
@@ -1617,9 +1625,17 @@ function routeBackbeat(clientIP, request, response, log) {
16171625
bytesReceived: request.parsedContentLength || 0,
16181626
bodyLength: parseInt(request.headers['content-length'], 10) || 0,
16191627
});
1628+
if (request.serverAccessLog) {
1629+
// eslint-disable-next-line no-param-reassign
1630+
request.serverAccessLog.bucketName = request.bucketName;
1631+
// eslint-disable-next-line no-param-reassign
1632+
request.serverAccessLog.objectKey = request.objectKey;
1633+
// eslint-disable-next-line no-param-reassign
1634+
request.serverAccessLog.backbeat = true;
1635+
// eslint-disable-next-line no-param-reassign
1636+
request.serverAccessLog.analyticsAction = 'BACKBEAT_INVALID';
1637+
}
16201638

1621-
log.debug('routing request');
1622-
_normalizeBackbeatRequest(request);
16231639
const requestContexts = prepareRequestContexts('objectReplicate', request);
16241640

16251641
if (request.resourceType === 'expiration' || request.resourceType === 'batchdelete') {
@@ -1677,6 +1693,16 @@ function routeBackbeat(clientIP, request, response, log) {
16771693

16781694
const isObjectRequest = _isObjectRequest(request);
16791695

1696+
if (request.serverAccessLog) {
1697+
let route = backbeatRoutes[request.method][request.resourceType];
1698+
if (useMultipleBackend && request.resourceType !== 'multiplebackendmetadata') {
1699+
route = backbeatRoutes[request.method][request.resourceType][request.query.operation];
1700+
}
1701+
1702+
// eslint-disable-next-line no-param-reassign
1703+
request.serverAccessLog.analyticsAction = route?.name ?? 'BACKBEAT_INVALID';
1704+
}
1705+
16801706
return async.waterfall([
16811707
next => auth.server.doAuth(
16821708
request, log, (err, userInfo, authorizationResults, streamingV4Params, infos) => {
@@ -1687,6 +1713,14 @@ function routeBackbeat(clientIP, request, response, log) {
16871713
objectKey: request.objectKey,
16881714
});
16891715
}
1716+
if (request.serverAccessLog && userInfo) {
1717+
// eslint-disable-next-line no-param-reassign
1718+
request.serverAccessLog.authInfo = userInfo;
1719+
// eslint-disable-next-line no-param-reassign
1720+
request.serverAccessLog.analyticsAccountName = userInfo.getAccountDisplayName();
1721+
// eslint-disable-next-line no-param-reassign
1722+
request.serverAccessLog.analyticsUserName = userInfo.getIAMdisplayName();
1723+
}
16901724
// eslint-disable-next-line no-param-reassign
16911725
request.accountQuotas = infos?.accountQuota;
16921726
return next(err, userInfo, authorizationResults);

‎lib/server.js‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -126,11 +126,13 @@ class S3Server {
126126
monitoringClient.httpActiveRequests.inc();
127127
const requestStartTime = process.hrtime.bigint();
128128

129-
// Skip server access logs for heartbeat and backbeat.
129+
// Skip server access logs for heartbeat.
130130
const isLoggingEnabled = _config.serverAccessLogs
131131
&& (_config.serverAccessLogs.mode === serverAccessLogsModes.LOG_ONLY
132132
|| _config.serverAccessLogs.mode === serverAccessLogsModes.ENABLED);
133-
if (isLoggingEnabled && !req.url.startsWith('/_/')) {
133+
const isInternalRoute = req.url.startsWith('/_');
134+
const isBackbeatRoute = req.url.startsWith('/_/backbeat/');
135+
if (isLoggingEnabled && (!isInternalRoute || isBackbeatRoute)) {
134136
// eslint-disable-next-line no-param-reassign
135137
req.serverAccessLog = {
136138
enabled: false,

‎lib/utilities/serverAccessLogger.js‎

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -257,6 +257,10 @@ const methodToResType = Object.freeze({
257257

258258
function getOperation(req) {
259259
const resourceType = methodToResType[req.apiMethod];
260+
261+
if (req.serverAccessLog && req.serverAccessLog.backbeat) {
262+
return `REST.${req.method}.BACKBEAT`;
263+
}
260264
if (!resourceType) {
261265
process.emitWarning('Unknown apiMethod for server access log', {
262266
type: 'ServerAccessLogWarning',
@@ -457,7 +461,9 @@ function logServerAccess(req, res) {
457461
458462
// Scality server access logs extra fields
459463
logFormatVersion: SERVER_ACCESS_LOG_FORMAT_VERSION,
460-
loggingEnabled: params.enabled ?? undefined,
464+
// If backbeat is enabled, we set loggingEnabled to false
465+
// to prevent backbeat requests from getting to log courier.
466+
loggingEnabled: params.backbeat ? false : (params.enabled ?? undefined),
461467
loggingTargetBucket: params.loggingEnabled?.TargetBucket ?? undefined,
462468
loggingTargetPrefix: params.loggingEnabled?.TargetPrefix ?? undefined,
463469
awsAccessKeyID: authInfo?.getAccessKey() ?? undefined,

‎schema/server_access_log.schema.json‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -20,7 +20,7 @@
2020
"minimum": 0
2121
},
2222
"action": {
23-
"description": "S3 API action name.",
23+
"description": "S3 API action name or the Backbeat route.",
2424
"type": "string"
2525
},
2626
"accountName": {

‎tests/unit/utils/serverAccessLogger.js‎

Lines changed: 146 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -196,6 +196,68 @@ describe('serverAccessLogger utility functions', () => {
196196
const result = getOperation(req);
197197
assert.strictEqual(result, 'REST.GET.UNKNOWN');
198198
});
199+
200+
it('should return REST.GET.BACKBEAT when backbeat is enabled for GET', () => {
201+
const req = {
202+
method: 'GET',
203+
apiMethod: 'objectGet',
204+
serverAccessLog: { backbeat: true },
205+
};
206+
const result = getOperation(req);
207+
assert.strictEqual(result, 'REST.GET.BACKBEAT');
208+
});
209+
210+
it('should return REST.PUT.BACKBEAT when backbeat is enabled for PUT', () => {
211+
const req = {
212+
method: 'PUT',
213+
apiMethod: 'objectPut',
214+
serverAccessLog: { backbeat: true },
215+
};
216+
const result = getOperation(req);
217+
assert.strictEqual(result, 'REST.PUT.BACKBEAT');
218+
});
219+
220+
it('should return REST.DELETE.BACKBEAT when backbeat is enabled for DELETE', () => {
221+
const req = {
222+
method: 'DELETE',
223+
apiMethod: 'objectDelete',
224+
serverAccessLog: { backbeat: true },
225+
};
226+
const result = getOperation(req);
227+
assert.strictEqual(result, 'REST.DELETE.BACKBEAT');
228+
});
229+
230+
it('should return REST.POST.BACKBEAT when backbeat is enabled for POST', () => {
231+
const req = {
232+
method: 'POST',
233+
apiMethod: 'completeMultipartUpload',
234+
serverAccessLog: { backbeat: true },
235+
};
236+
const result = getOperation(req);
237+
assert.strictEqual(result, 'REST.POST.BACKBEAT');
238+
});
239+
240+
it('should prioritize backbeat over normal apiMethod mapping', () => {
241+
const req = {
242+
method: 'GET',
243+
apiMethod: 'bucketGetVersioning',
244+
serverAccessLog: { backbeat: true },
245+
};
246+
const result = getOperation(req);
247+
// Should return BACKBEAT instead of normal REST.GET.VERSIONING
248+
assert.strictEqual(result, 'REST.GET.BACKBEAT');
249+
});
250+
251+
it('should return REST.method.BACKBEAT even with unknown apiMethod', () => {
252+
const req = {
253+
method: 'GET',
254+
apiMethod: 'unknownMethod',
255+
serverAccessLog: { backbeat: true },
256+
};
257+
const result = getOperation(req);
258+
// Should return BACKBEAT instead of UNKNOWN
259+
assert.strictEqual(result, 'REST.GET.BACKBEAT');
260+
});
199261
});
200262

201263
describe('getRequester', () => {
@@ -1146,6 +1208,90 @@ describe('serverAccessLogger utility functions', () => {
11461208
assert.strictEqual('bytesReceived' in loggedData, false);
11471209
assert.strictEqual('contentLength' in loggedData, false);
11481210
});
1211+
1212+
it('should log with loggingEnabled false when backbeat is enabled', () => {
1213+
setServerAccessLogger(mockLogger);
1214+
const req = {
1215+
serverAccessLog: {
1216+
backbeat: true,
1217+
enabled: true,
1218+
},
1219+
method: 'GET',
1220+
apiMethod: 'objectGet',
1221+
headers: {},
1222+
socket: {},
1223+
};
1224+
const res = {
1225+
serverAccessLog: {},
1226+
getHeader: () => null,
1227+
};
1228+
1229+
logServerAccess(req, res);
1230+
1231+
assert.strictEqual(mockLogger.write.callCount, 1);
1232+
const loggedData = JSON.parse(mockLogger.write.firstCall.args[0].trim());
1233+
1234+
// Verify loggingEnabled is false in the logged data
1235+
assert.strictEqual(loggedData.loggingEnabled, false);
1236+
});
1237+
1238+
it('should log REST.GET.BACKBEAT operation when backbeat is enabled', () => {
1239+
setServerAccessLogger(mockLogger);
1240+
const req = {
1241+
serverAccessLog: {
1242+
backbeat: true,
1243+
},
1244+
method: 'GET',
1245+
apiMethod: 'objectGet',
1246+
headers: {},
1247+
socket: {},
1248+
};
1249+
const res = {
1250+
serverAccessLog: {},
1251+
getHeader: () => null,
1252+
};
1253+
1254+
logServerAccess(req, res);
1255+
1256+
assert.strictEqual(mockLogger.write.callCount, 1);
1257+
const loggedData = JSON.parse(mockLogger.write.firstCall.args[0].trim());
1258+
1259+
// Verify operation is REST.GET.BACKBEAT
1260+
assert.strictEqual(loggedData.operation, 'REST.GET.BACKBEAT');
1261+
});
1262+
1263+
it('should override loggingEnabled when backbeat is enabled with logging config', () => {
1264+
setServerAccessLogger(mockLogger);
1265+
const req = {
1266+
serverAccessLog: {
1267+
backbeat: true,
1268+
enabled: true,
1269+
loggingEnabled: {
1270+
TargetBucket: 'log-bucket',
1271+
TargetPrefix: 'logs/',
1272+
},
1273+
},
1274+
method: 'PUT',
1275+
apiMethod: 'objectPut',
1276+
headers: {},
1277+
socket: {},
1278+
};
1279+
const res = {
1280+
serverAccessLog: {},
1281+
getHeader: () => null,
1282+
};
1283+
1284+
logServerAccess(req, res);
1285+
1286+
assert.strictEqual(mockLogger.write.callCount, 1);
1287+
const loggedData = JSON.parse(mockLogger.write.firstCall.args[0].trim());
1288+
1289+
// Verify loggingEnabled is false (overridden by backbeat)
1290+
assert.strictEqual(loggedData.loggingEnabled, false);
1291+
// But TargetBucket and TargetPrefix should still be logged
1292+
assert.strictEqual(loggedData.loggingTargetBucket, 'log-bucket');
1293+
assert.strictEqual(loggedData.loggingTargetPrefix, 'logs/');
1294+
});
11491295
});
11501296
});
11511297

0 commit comments

Comments
 (0)