Skip to content

Commit 803ddcf

Browse files
committed
fixup! CLDSRV-750: add Server Access Logs
1 parent 058ee31 commit 803ddcf

4 files changed

Lines changed: 48 additions & 40 deletions

File tree

lib/Config.js

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -575,7 +575,7 @@ function parseIntegrityChecks(config) {
575575
}
576576

577577
function parseServerAccessLogs(config) {
578-
let res = {
578+
const res = {
579579
enabled: true,
580580
outputFile: './logs/server-access.log',
581581
};

lib/metadata/metadataUtils.js

Lines changed: 18 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,22 @@ const { onlyOwnerAllowed } = require('../../constants');
1010
const { actionNeedQuotaCheck, actionWithDataDeletion } = require('arsenal/build/lib/policyEvaluator/RequestContext');
1111
const { processBytesToWrite, validateQuotas } = require('../api/apiUtils/quotas/quotaUtils');
1212

13+
function storeServerAccessLogInfo(request, authInfo, bucket) {
14+
if (request &&
15+
authInfo &&
16+
bucket &&
17+
bucket.getBucketLoggingStatus() &&
18+
bucket.getBucketLoggingStatus().getLoggingEnabled()) {
19+
/* eslint-disable no-param-reassign */
20+
request.serverAccessLog.enabled = true;
21+
request.serverAccessLog.bucketOwner = bucket.getOwner();
22+
request.serverAccessLog.bucketName = bucket.getName();
23+
request.serverAccessLog.authInfo = authInfo;
24+
request.serverAccessLog.loggingEnabled = bucket.getBucketLoggingStatus().getLoggingEnabled();
25+
/* eslint-enable no-param-reassign */
26+
}
27+
}
28+
1329
/** getNullVersionFromMaster - retrieves the null version
1430
* metadata via retrieving the master key
1531
*
@@ -274,14 +290,7 @@ function standardMetadataValidateBucketAndObj(params, actionImplicitDenies, log,
274290
contentLength, withVersionId, log, err => next(err, bucket, objMD));
275291
},
276292
], (err, bucket, objMD) => {
277-
if (bucket.getBucketLoggingStatus() && bucket.getBucketLoggingStatus().getLoggingEnabled()) {
278-
request.serverAccessLog.enabled = true;
279-
request.serverAccessLog.bucketOwner = bucket.getOwner();
280-
request.serverAccessLog.bucketName = bucketName;
281-
request.serverAccessLog.authInfo = authInfo;
282-
request.serverAccessLog.loggingEnabled = bucket.getBucketLoggingStatus().getLoggingEnabled();
283-
}
284-
293+
storeServerAccessLogInfo(request, authInfo, bucket);
285294
if (err) {
286295
// still return bucket for cors headers
287296
return callback(err, bucket);
@@ -304,6 +313,7 @@ function standardMetadataValidateBucketAndObj(params, actionImplicitDenies, log,
304313
function standardMetadataValidateBucket(params, actionImplicitDenies, log, callback) {
305314
const { bucketName } = params;
306315
return metadata.getBucket(bucketName, log, (err, bucket) => {
316+
storeServerAccessLogInfo(params.request, params.authInfo, bucket);
307317
if (err) {
308318
// if some implicit actionImplicitDenies, return AccessDenied before
309319
// leaking any state information
@@ -314,14 +324,6 @@ function standardMetadataValidateBucket(params, actionImplicitDenies, log, callb
314324
return callback(err);
315325
}
316326
const validationError = validateBucket(bucket, params, log, actionImplicitDenies);
317-
if (bucket.getBucketLoggingStatus() && bucket.getBucketLoggingStatus().getLoggingEnabled()) {
318-
params.request.serverAccessLog.enabled = true;
319-
params.request.serverAccessLog.bucketOwner = bucket.getOwner();
320-
params.request.serverAccessLog.bucketName = bucketName;
321-
params.request.serverAccessLog.authInfo = params.authInfo;
322-
params.request.serverAccessLog.authInfo = params.authInfo;
323-
params.request.serverAccessLog.loggingEnabled = bucket.getBucketLoggingStatus().getLoggingEnabled();
324-
}
325327
return callback(validationError, bucket);
326328
});
327329
}

lib/server.js

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -123,13 +123,16 @@ class S3Server {
123123
monitoringClient.httpActiveRequests.inc();
124124
const requestStartTime = process.hrtime.bigint();
125125

126+
// eslint-disable-next-line no-param-reassign
126127
req.serverAccessLog = {
127128
enabled: false,
128129
startTime: requestStartTime,
129130
};
131+
// eslint-disable-next-line no-param-reassign
130132
res.serverAccessLog = {};
131133

132134
res.on('finish', () => {
135+
// eslint-disable-next-line no-param-reassign
133136
req.serverAccessLog.endTime = process.hrtime.bigint();
134137
logServerAccess(req.serverAccessLog, req, res);
135138
});

lib/utilities/serverAccesssLogger.js

Lines changed: 26 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -2,13 +2,14 @@ const { Werelogs } = require('werelogs');
22
const { config } = require('../Config');
33
const fs = require('fs');
44
const path = require('path');
5+
const logger = require('./utilities/logger');
56

67
const DEFAULT_OUTPUT_FILE = './logs/api-operations.log';
78
const SERVER_ACCESS_LOG_FORMAT_VERSION = '0';
89

910
function createServerAccessLogger() {
1011
if (!config.serverAccessLogs || !config.serverAccessLogs.enabled) {
11-
console.warn("ServerAccessLogs disabled returning no-op logger");
12+
logger.warn('ServerAccessLogs disabled returning no-op logger');
1213
return {
1314
info: () => { },
1415
debug: () => { },
@@ -28,10 +29,10 @@ function createServerAccessLogger() {
2829
fs.mkdirSync(logDir, { recursive: true });
2930
}
3031
} catch (error) {
31-
// Fall back to console-only logging if directory creation fails
32-
console.warn('Failed to create ServerAccess log directory, falling back to console logging:', error.message);
32+
// Fall back to logger-only logging if directory creation fails
33+
logger.warn('Failed to create ServerAccess log directory, falling back to console logging:', error.message);
3334

34-
let apiWerelogs = new Werelogs({
35+
const apiWerelogs = new Werelogs({
3536
level: config.serverAccessLogs.logLevel || 'info',
3637
dump: config.serverAccessLogs.dumpLevel || 'error',
3738
streams: [
@@ -47,16 +48,16 @@ function createServerAccessLogger() {
4748

4849
// Handle stream errors
4950
serverAccessLogStream.on('error', error => {
50-
console.error('ServerAccessLogger log file stream error:', error);
51+
logger.error('ServerAccessLogger log file stream error:', error);
5152
});
5253

5354
// Create the API-specific Werelogs instance - file output only
54-
apiWerelogs = new Werelogs({
55+
const apiWerelogs = new Werelogs({
5556
level: config.serverAccessLogs.logLevel || 'info',
5657
dump: config.serverAccessLogs.dumpLevel || 'error',
5758
streams: [{ level: 'trace', stream: serverAccessLogStream }]
5859
});
59-
console.info("ServerAccessLogger created successfully");
60+
logger.info('ServerAccessLogger created successfully');
6061
return new apiWerelogs.Logger('ServerAccessLogger');
6162
}
6263

@@ -73,14 +74,14 @@ var serverAccessLogger = {
7374
try {
7475
serverAccessLogger = createServerAccessLogger();
7576
} catch (error) {
76-
console.error('Failed to create ServiceAccessLogger, using no-op logger:', error);
77+
logger.error('Failed to create ServiceAccessLogger, using no-op logger:', error);
7778
}
7879

7980
function getRemoteIPFromRequest(request) {
8081
let remoteIP = null;
8182
if (request.headers) {
8283
// Check for forwarded IP headers (proxy/load balancer scenarios)
83-
headerRemoteIP = request.headers['x-forwarded-for'] ||
84+
const headerRemoteIP = request.headers['x-forwarded-for'] ||
8485
request.headers['x-real-ip'] ||
8586
request.headers['x-client-ip'] ||
8687
request.headers['cf-connecting-ip']; // Cloudflare
@@ -93,7 +94,7 @@ function getRemoteIPFromRequest(request) {
9394

9495
// Fallback to connection remote address if no forwarded headers
9596
if (!remoteIP) {
96-
connIP = (request.connection && request.connection.remoteAddress) ||
97+
const connIP = (request.connection && request.connection.remoteAddress) ||
9798
(request.socket && request.socket.remoteAddress) ||
9899
(request.ip);
99100
if (connIP) {
@@ -175,11 +176,11 @@ function getOperation(req) {
175176
// 'websiteHead': '',
176177
});
177178

178-
return `REST.${req.method}.${methodToResType[req.apiMethod] ? methodToResType[req.apiMethod] : 'UNKNOWN'}`
179+
return `REST.${req.method}.${methodToResType[req.apiMethod] ? methodToResType[req.apiMethod] : 'UNKNOWN'}`;
179180
}
180181

181182
function getRequester(authInfo) {
182-
let requester = null;
183+
const requester = null;
183184
if (authInfo) {
184185
if (authInfo.isRequesterPublicUser && authInfo.isRequesterPublicUser()) {
185186
return requester; // Unauthenticated requests
@@ -220,12 +221,12 @@ function getObjectSize(request, response) {
220221
// If it is a PUT get the Content-Length from the request, if it is a GET get it from the response.
221222
if (request && response && objectSizeGetMethods[request.apiMethod]) {
222223
const len = response.getHeader('Content-Length');
223-
return len ? len : null;
224+
return len || null;
224225
}
225226

226227
if (request && objectSizePutMethods[request.apiMethod]) {
227228
const len = request.getHeader('Content-Length');
228-
return len ? len : null;
229+
return len || null;
229230
}
230231

231232
return null;
@@ -237,15 +238,15 @@ function getBytesSent(res) {
237238
}
238239

239240
const len = res.getHeader('Content-Length');
240-
return len ? len : null;
241+
return len || null;
241242
}
242243

243244
function calculateTotalTime(startTime, endTime) {
244245
if (!startTime || !endTime) {
245246
return null;
246247
}
247248

248-
return ((endTime - startTime) / 1_000_000n).toString()
249+
return ((endTime - startTime) / 1_000_000n).toString();
249250
}
250251

251252
function calculateTurnAroundTime(startTurnAroundTime, endTurnAroundTime) {
@@ -257,9 +258,9 @@ function calculateTurnAroundTime(startTurnAroundTime, endTurnAroundTime) {
257258
}
258259

259260
function logServerAccess(params, req, res) {
260-
params.errorCode = res.serverAccessLog.errorCode;
261-
params.endTurnAroundTime = res.serverAccessLog.endTurnAroundTime;
262-
params.requestID = res.serverAccessLog.requestID;
261+
const errorCode = res.serverAccessLog.errorCode;
262+
const endTurnAroundTime = res.serverAccessLog.endTurnAroundTime;
263+
const requestID = res.serverAccessLog.requestID;
263264
const authInfo = params.authInfo;
264265

265266
serverAccessLogger.info('SERVER_ACCESS_LOG', {
@@ -269,15 +270,16 @@ function logServerAccess(params, req, res) {
269270
startTime: params.startTime ? params.startTime.toString() : null,
270271
remoteIP: getRemoteIPFromRequest(req),
271272
requester: getRequester(authInfo),
272-
req_id: params.requestID ? params.requestID : null, // requestID in AWS
273+
// eslint-disable-next-line camelcase
274+
req_id: requestID || null, // requestID in AWS
273275
operation: getOperation(req),
274276
requestURI: getURI(req),
275277
HTTPStatus: res.statusCode ? res.statusCode : null,
276-
errorCode: params.errorCode ? params.errorCode : null,
278+
errorCode: errorCode || null,
277279
bytesSent: getBytesSent(res),
278280
objectSize: getObjectSize(req, res),
279281
totalTime: calculateTotalTime(params.startTime, params.endTime),
280-
turnAroundTime: calculateTurnAroundTime(params.startTurnAroundTime, params.endTurnAroundTime),
282+
turnAroundTime: calculateTurnAroundTime(params.startTurnAroundTime, endTurnAroundTime),
281283
referer: req.headers.referer ? req.headers.referer : null,
282284
userAgent: req.headers['user-agent'] ? req.headers['user-agent'] : null,
283285
versionID: req.query.versionId ? req.query.versionId : null, // query inserted by arsenal.
@@ -297,8 +299,9 @@ function logServerAccess(params, req, res) {
297299
loggingTargetBucket: params.loggingEnabled ? params.loggingEnabled.TargetBucket : null,
298300
loggingTargetPrefix: params.loggingEnabled ? params.loggingEnabled.TargetPrefix : null,
299301
raftSessionID: null,
302+
// eslint-disable-next-line camelcase
300303
aws_access_key_id: authInfo ? authInfo.getAccessKey() : null,
301-
})
304+
});
302305
}
303306

304307
module.exports = {

0 commit comments

Comments
 (0)