Skip to content

Commit 9404507

Browse files
committed
CLDSRV-750: add Server Access Logs
1 parent d013306 commit 9404507

File tree

6 files changed

+337
-1
lines changed

6 files changed

+337
-1
lines changed

config.json

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -149,5 +149,9 @@
149149
},
150150
"integrityChecks": {
151151
"objectPutRetention": true
152+
},
153+
"serverAccessLogs": {
154+
"enabled": true,
155+
"outputFile": "./logs/server-access.log"
152156
}
153157
}

lib/Config.js

Lines changed: 22 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -574,6 +574,27 @@ function parseIntegrityChecks(config) {
574574
return integrityChecks;
575575
}
576576

577+
function parseServerAccessLogs(config) {
578+
let res = {
579+
enabled: true,
580+
outputFile: './logs/server-access.log',
581+
};
582+
583+
if (config && config.serverAccessLogs) {
584+
if ('enabled' in config.serverAccessLogs) {
585+
assert(typeof config.serverAccessLogs.enabled === 'boolean');
586+
res.enabled = config.serverAccessLogs.enabled;
587+
}
588+
589+
if ('outputFile' in config.serverAccessLogs) {
590+
assert(typeof config.serverAccessLogs.outputFile === 'string');
591+
res.outputFile = config.serverAccessLogs.outputFile;
592+
}
593+
}
594+
595+
return res;
596+
}
597+
577598
/**
578599
* Reads from a config file and returns the content as a config object
579600
*/
@@ -1785,7 +1806,7 @@ class Config extends EventEmitter {
17851806
}
17861807
}
17871808
this.integrityChecks = parseIntegrityChecks(config);
1788-
1809+
this.serverAccessLogs = parseServerAccessLogs(config);
17891810
/**
17901811
* S3C-10336: PutObject max size of 5GB is new in 9.5.1
17911812
* Provides a way to bypass the new validation if it breaks customer workflows

lib/api/api.js

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -264,6 +264,8 @@ const api = {
264264
});
265265

266266
request.on('end', () => {
267+
request.serverAccessLog.startTurnAroundTime = process.hrtime.bigint();
268+
267269
if (bodyLength > MAX_BODY_LENGTH) {
268270
log.error('body length is too long for request type',
269271
{ bodyLength });

lib/metadata/metadataUtils.js

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -274,6 +274,14 @@ function standardMetadataValidateBucketAndObj(params, actionImplicitDenies, log,
274274
contentLength, withVersionId, log, err => next(err, bucket, objMD));
275275
},
276276
], (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+
277285
if (err) {
278286
// still return bucket for cors headers
279287
return callback(err, bucket);
@@ -306,6 +314,14 @@ function standardMetadataValidateBucket(params, actionImplicitDenies, log, callb
306314
return callback(err);
307315
}
308316
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+
}
309325
return callback(validationError, bucket);
310326
});
311327
}

lib/server.js

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,7 @@ const {
2626

2727
const HttpAgent = require('agentkeepalive');
2828
const QuotaService = require('./utilization/instance');
29+
const { logServerAccess } = require('./utilities/serverAccesssLogger');
2930
const { parseLC, MultipleBackendGateway } = arsenal.storage.data;
3031
const websiteEndpoints = _config.websiteEndpoints;
3132
let client = dataWrapper.client;
@@ -122,6 +123,19 @@ class S3Server {
122123
monitoringClient.httpActiveRequests.inc();
123124
const requestStartTime = process.hrtime.bigint();
124125

126+
req.serverAccessLog = {
127+
enabled: false,
128+
startTime: requestStartTime,
129+
};
130+
res.serverAccessLog = {};
131+
132+
res.on('finish', () => {
133+
req.serverAccessLog.endTime = process.hrtime.bigint();
134+
req.serverAccessLog.errorCode = res.serverAccessLog.errorCode;
135+
req.serverAccessLog.endTurnAroundTime = res.serverAccessLog.endTurnAroundTime;
136+
logServerAccess(req.serverAccessLog, req, res);
137+
});
138+
125139
// disable nagle algorithm
126140
req.socket.setNoDelay();
127141
res.on('close', () => {
Lines changed: 279 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,279 @@
1+
const { Werelogs } = require('werelogs');
2+
const { config } = require('../Config');
3+
const fs = require('fs');
4+
const path = require('path');
5+
6+
const DEFAULT_OUTPUT_FILE = './logs/api-operations.log';
7+
8+
function createServerAccessLogger() {
9+
if (!config.serverAccessLogs || !config.serverAccessLogs.enabled) {
10+
console.warn("ServerAccessLogs disabled returning no-op logger");
11+
return {
12+
info: () => { },
13+
debug: () => { },
14+
warn: () => { },
15+
error: () => { },
16+
trace: () => { },
17+
fatal: () => { },
18+
};
19+
}
20+
21+
// Ensure logs directory exists
22+
const outputFile = config.serverAccessLogs.outputFile || DEFAULT_OUTPUT_FILE;
23+
const logDir = path.dirname(outputFile);
24+
25+
try {
26+
if (!fs.existsSync(logDir)) {
27+
fs.mkdirSync(logDir, { recursive: true });
28+
}
29+
} catch (error) {
30+
// Fall back to console-only logging if directory creation fails
31+
console.warn('Failed to create ServerAccess log directory, falling back to console logging:', error.message);
32+
33+
let apiWerelogs = new Werelogs({
34+
level: config.serverAccessLogs.logLevel || 'info',
35+
dump: config.serverAccessLogs.dumpLevel || 'error',
36+
streams: [
37+
{ level: 'trace', stream: process.stdout }
38+
]
39+
});
40+
41+
return new apiWerelogs.Logger('ServerAccessLogger');
42+
}
43+
44+
// Create file stream for API logs
45+
const serverAccessLogStream = fs.createWriteStream(outputFile, { flags: 'a' });
46+
47+
// Handle stream errors
48+
serverAccessLogStream.on('error', error => {
49+
console.error('ServerAccessLogger log file stream error:', error);
50+
});
51+
52+
// Create the API-specific Werelogs instance - file output only
53+
apiWerelogs = new Werelogs({
54+
level: config.serverAccessLogs.logLevel || 'info',
55+
dump: config.serverAccessLogs.dumpLevel || 'error',
56+
streams: [{ level: 'trace', stream: serverAccessLogStream }]
57+
});
58+
console.info("ServerAccessLogger created successfully");
59+
return new apiWerelogs.Logger('ServerAccessLogger');
60+
}
61+
62+
var serverAccessLogger = {
63+
info: () => { },
64+
debug: () => { },
65+
warn: () => { },
66+
error: () => { },
67+
trace: () => { },
68+
fatal: () => { },
69+
};
70+
71+
72+
try {
73+
serverAccessLogger = createServerAccessLogger();
74+
} catch (error) {
75+
console.error('Failed to create ServiceAccessLogger, using no-op logger:', error);
76+
}
77+
78+
function getRemoteIPFromRequest(request) {
79+
let remoteIP = '-';
80+
if (request.headers) {
81+
// Check for forwarded IP headers (proxy/load balancer scenarios)
82+
remoteIP = request.headers['x-forwarded-for'] ||
83+
request.headers['x-real-ip'] ||
84+
request.headers['x-client-ip'] ||
85+
request.headers['cf-connecting-ip']; // Cloudflare
86+
87+
// x-forwarded-for can contain multiple IPs, take the first one
88+
if (remoteIP && remoteIP.includes(',')) {
89+
remoteIP = remoteIP.split(',')[0].trim();
90+
}
91+
}
92+
93+
// Fallback to connection remote address if no forwarded headers
94+
if (!remoteIP || remoteIP === '-') {
95+
remoteIP = (request.connection && request.connection.remoteAddress) ||
96+
(request.socket && request.socket.remoteAddress) ||
97+
(request.ip) ||
98+
'-';
99+
}
100+
101+
return remoteIP;
102+
}
103+
104+
function getOperation(req) {
105+
const methodToResType = Object.freeze({
106+
'bucketDelete': 'BUCKET',
107+
'bucketDeleteCors': 'BUCKET',
108+
'bucketDeleteEncryption': 'BUCKET',
109+
'bucketDeleteWebsite': 'BUCKET',
110+
'bucketGet': 'BUCKET',
111+
'bucketGetACL': 'BUCKET',
112+
'bucketGetCors': 'BUCKET',
113+
'bucketGetObjectLock': 'BUCKET',
114+
'bucketGetVersioning': 'VERSIONING',
115+
'bucketGetWebsite': 'BUCKET',
116+
'bucketGetLocation': 'BUCKET',
117+
'bucketGetEncryption': 'BUCKET',
118+
'bucketHead': 'BUCKET',
119+
'bucketPut': 'BUCKET',
120+
'bucketPutACL': 'BUCKET',
121+
'bucketPutCors': 'BUCKET',
122+
'bucketPutVersioning': 'VERSIONING',
123+
'bucketPutTagging': 'BUCKET',
124+
'bucketDeleteTagging': 'BUCKET',
125+
'bucketGetTagging': 'BUCKET',
126+
'bucketPutWebsite': 'BUCKET',
127+
'bucketPutReplication': 'BUCKET',
128+
'bucketGetReplication': 'BUCKET',
129+
'bucketDeleteReplication': 'BUCKET',
130+
'bucketDeleteQuota': 'BUCKET',
131+
'bucketPutLifecycle': 'BUCKET',
132+
'bucketUpdateQuota': 'BUCKET',
133+
'bucketGetLifecycle': 'BUCKET',
134+
'bucketDeleteLifecycle': 'BUCKET',
135+
'bucketPutPolicy': 'BUCKETPOLICY',
136+
'bucketGetPolicy': 'BUCKETPOLICY',
137+
'bucketGetQuota': 'BUCKET',
138+
'bucketDeletePolicy': 'BUCKETPOLICY',
139+
'bucketPutObjectLock': 'BUCKET',
140+
'bucketPutNotification': 'BUCKET',
141+
'bucketGetNotification': 'BUCKET',
142+
'bucketPutEncryption': 'BUCKET',
143+
'bucketPutLogging': 'LOGGING_STATUS',
144+
'bucketGetLogging': 'LOGGING_STATUS',
145+
// 'corsPreflight': '',
146+
'completeMultipartUpload': 'OBJECT',
147+
'initiateMultipartUpload': 'OBJECT',
148+
'listMultipartUploads': 'OBJECT',
149+
'listParts': 'OBJECT',
150+
'metadataSearch': 'OBJECT',
151+
'multiObjectDelete': 'OBJECT',
152+
'multipartDelete': 'OBJECT',
153+
'objectDelete': 'OBJECT',
154+
'objectDeleteTagging': 'OBJECT',
155+
'objectGet': 'OBJECT',
156+
'objectGetACL': 'OBJECT',
157+
'objectGetLegalHold': 'OBJECT',
158+
'objectGetRetention': 'OBJECT',
159+
'objectGetTagging': 'OBJECT',
160+
'objectCopy': 'OBJECT',
161+
'objectHead': 'OBJECT',
162+
'objectPut': 'OBJECT',
163+
'objectPutACL': 'OBJECT',
164+
'objectPutLegalHold': 'OBJECT',
165+
'objectPutTagging': 'OBJECT',
166+
'objectPutPart': 'OBJECT',
167+
'objectPutCopyPart': 'OBJECT',
168+
'objectPutRetention': 'OBJECT',
169+
'objectRestore': 'OBJECT',
170+
// 'serviceGet': '',
171+
// 'websiteGet': '',
172+
// 'websiteHead': '',
173+
});
174+
175+
return `REST.${req.method}.${methodToResType[req.apiMethod] ? methodToResType[req.apiMethod] : 'UNKNOWN'}`
176+
}
177+
178+
function getRequester(authInfo) {
179+
let requester = '-';
180+
if (authInfo) {
181+
if (authInfo.isRequesterPublicUser && authInfo.isRequesterPublicUser()) {
182+
return requester; // Unauthenticated requests
183+
} else if (authInfo.isRequesterAnIAMUser && authInfo.isRequesterAnIAMUser()) {
184+
// IAM user: include IAM user name and account
185+
const iamUserName = authInfo.getIAMdisplayName ? authInfo.getIAMdisplayName() : '';
186+
const accountName = authInfo.getAccountDisplayName ? authInfo.getAccountDisplayName() : '';
187+
return iamUserName && accountName ? `${iamUserName}:${accountName}` : authInfo.getCanonicalID();
188+
} else if (authInfo.getCanonicalID) {
189+
// Regular user: canonical user ID
190+
return authInfo.getCanonicalID();
191+
}
192+
}
193+
return requester;
194+
}
195+
196+
function getURI(request) {
197+
let requestURI = '-';
198+
if (request) {
199+
const method = request.method || 'UNKNOWN';
200+
const url = request.url || request.originalUrl || '/';
201+
const httpVersion = request.httpVersion || '1.1';
202+
requestURI = `${method} ${url} HTTP/${httpVersion}`;
203+
}
204+
return requestURI;
205+
}
206+
207+
function getObjectSize(request) {
208+
const objectSizeMethods = Object.freeze({
209+
'objectPut': true,
210+
'objectPutPart': true,
211+
'objectGet': true,
212+
});
213+
214+
if (request && objectSizeMethods[request.apiMethod]) {
215+
const len = request.getHeader('Content-Length');
216+
return len ? len : '-';
217+
}
218+
219+
return '-';
220+
}
221+
222+
function getBytesSent(res) {
223+
if (!res) {
224+
return '-';
225+
}
226+
if (res.getHeader('Content-Length')) {
227+
return res.getHeader('Content-Length');
228+
}
229+
return '-';
230+
}
231+
232+
function logServerAccess(params, req, res) {
233+
if (!params.enabled) {
234+
return;
235+
}
236+
237+
console.log(params)
238+
239+
serverAccessLogger.info('SERVER_ACCESS_LOG', {
240+
// AWS fields.
241+
bucketOwner: params.bucketOwner,
242+
bucket: params.bucketName,
243+
startTime: params.startTime.toString(),
244+
remoteIP: getRemoteIPFromRequest(req),
245+
requester: getRequester(params.authInfo),
246+
// // requestID: '-', // From wherelogs.
247+
operation: getOperation(req),
248+
requestURI: getURI(req),
249+
HTTPStatus: res.statusCode,
250+
errorCode: params.errorCode ? params.errorCode : '-',
251+
bytesSent: getBytesSent(res),
252+
objectSize: getObjectSize(req),
253+
totalTime: (Number(params.endTime - params.startTime) / 1_000_000).toString(),
254+
turnAroundTime: (Number(params.endTurnAroundTime - params.startTurnAroundTime) / 1_000_000).toString(),
255+
referer: req.headers.referer ? req.headers.referer : '-',
256+
userAgent: req.headers['user-agent'] ? req.headers['user-agent'] : '-',
257+
versionID: req.query.versionId ? req.query.versionId : '-', // query inserted by arsenal.
258+
hostID: '-', // NOT IMPLEMENTED
259+
signatureVersion: params.authInfo.getAuthVersion(),
260+
cipherSuite: req.socket.encrypted ? req.socket.getCipher()['standardName'] : '-',
261+
authenticationType: params.authInfo.getAuthType(),
262+
hostHeader: req.headers.host ? req.headers.host : '-',
263+
// From https://nodejs.org/api/tls.html#tlssocketgetcipher
264+
tlsVersion: req.socket.encrypted ? req.socket.getCipher()['version'] : '-',
265+
accessPointARN: '-', // NOT IMPLEMENTED
266+
aclRequired: '-', // ???
267+
// Scality extra fields.
268+
logFormatVersion: '-',
269+
loggingEnabled: true,
270+
loggingTargetBucket: params.loggingEnabled.TargetBucket,
271+
loggingTargetPrefix: params.loggingEnabled.TargetPrefix,
272+
raftSessionID: '-',
273+
aws_access_key_id: params.authInfo.getAccessKey() ? params.authInfo.getAccessKey() : '-',
274+
})
275+
}
276+
277+
module.exports = {
278+
logServerAccess,
279+
};

0 commit comments

Comments
 (0)