diff --git a/.github/docker/config.s3c.json b/.github/docker/config.s3c.json index d66017ca59..82a10a0006 100644 --- a/.github/docker/config.s3c.json +++ b/.github/docker/config.s3c.json @@ -61,5 +61,9 @@ "host": "localhost:6000" } ], - "enableVeeamRoute": false + "enableVeeamRoute": false, + "serverAccessLogs": { + "enabled": true, + "outputFile": "/logs/server-access.log" + } } diff --git a/.github/docker/docker-compose.yaml b/.github/docker/docker-compose.yaml index 45ff96a977..19a891105f 100644 --- a/.github/docker/docker-compose.yaml +++ b/.github/docker/docker-compose.yaml @@ -46,6 +46,7 @@ services: - S3QUOTA - QUOTA_ENABLE_INFLIGHTS - S3_VERSION_ID_ENCODING_TYPE + - S3_ENABLE_SERVER_ACCESS_LOGS=true env_file: - creds.env depends_on: diff --git a/config.json b/config.json index d7eee74035..d36f9a915e 100644 --- a/config.json +++ b/config.json @@ -149,5 +149,9 @@ }, "integrityChecks": { "objectPutRetention": true + }, + "serverAccessLogs": { + "enabled": false, + "outputFile": "/logs/server-access.log" } } diff --git a/lib/Config.js b/lib/Config.js index 3dea761b30..bf637ed387 100644 --- a/lib/Config.js +++ b/lib/Config.js @@ -574,6 +574,33 @@ function parseIntegrityChecks(config) { return integrityChecks; } +function parseServerAccessLogs(config) { + const res = { + enabled: false, + outputFile: '/logs/server-access.log', + }; + + if (config && config.serverAccessLogs) { + if ('enabled' in config.serverAccessLogs) { + assert(typeof config.serverAccessLogs.enabled === 'boolean', + 'bad config: serverAccessLogs.enabled is not a boolean'); + res.enabled = config.serverAccessLogs.enabled; + } + + if ('outputFile' in config.serverAccessLogs) { + assert(typeof config.serverAccessLogs.outputFile === 'string', + 'bad config: serverAccessLogs.outputFile is not a string'); + res.outputFile = config.serverAccessLogs.outputFile; + } + } + + if (process.env.S3_ENABLE_SERVER_ACCESS_LOGS === 'true') { + res.enabled = true; + } + + return res; +} + /** * Reads from a config file and returns the content as a config object */ @@ -1785,7 +1812,7 @@ class Config extends EventEmitter { } } this.integrityChecks = parseIntegrityChecks(config); - + this.serverAccessLogs = parseServerAccessLogs(config); /** * S3C-10336: PutObject max size of 5GB is new in 9.5.1 * Provides a way to bypass the new validation if it breaks customer workflows diff --git a/lib/api/api.js b/lib/api/api.js index 6ab4fcc77f..8f427e2fb3 100644 --- a/lib/api/api.js +++ b/lib/api/api.js @@ -173,6 +173,10 @@ const api = { objectKey: request.objectKey, }); } + if (request.serverAccessLog) { + request.serverAccessLog.objectKey = request.objectKey; + request.serverAccessLog.analyticsAction = actionLog; + } let returnTagCount = true; const validationRes = validateQueryAndHeaders(request, log); @@ -219,6 +223,9 @@ const api = { return async.waterfall([ next => auth.server.doAuth( request, log, (err, userInfo, authorizationResults, streamingV4Params, infos) => { + if (request.serverAccessLog) { + request.serverAccessLog.authInfo = userInfo; + } if (err) { // VaultClient returns standard errors, but the route requires // Arsenal errors @@ -237,6 +244,10 @@ const api = { authNames.sessionName = userInfo.getShortid().split(':')[1]; } log.addDefaultFields(authNames); + if (request.serverAccessLog) { + request.serverAccessLog.analyticsAccountName = authNames.accountName; + request.serverAccessLog.analyticsUserName = authNames.userName; + } if (apiMethod === 'objectPut' || apiMethod === 'objectPutPart') { return next(null, userInfo, authorizationResults, streamingV4Params, infos); } @@ -264,6 +275,10 @@ const api = { }); request.on('end', () => { + if (request.serverAccessLog) { + request.serverAccessLog.startTurnAroundTime = process.hrtime.bigint(); + } + if (bodyLength > MAX_BODY_LENGTH) { log.error('body length is too long for request type', { bodyLength }); diff --git a/lib/api/bucketDeleteCors.js b/lib/api/bucketDeleteCors.js index b08b6c0f13..b0fc2bae68 100644 --- a/lib/api/bucketDeleteCors.js +++ b/lib/api/bucketDeleteCors.js @@ -1,14 +1,11 @@ -const { errors } = require('arsenal'); - -const bucketShield = require('./apiUtils/bucket/bucketShield'); const collectCorsHeaders = require('../utilities/collectCorsHeaders'); -const { isBucketAuthorized } = - require('./apiUtils/authorization/permissionChecks'); const metadata = require('../metadata/wrapper'); +const { standardMetadataValidateBucket } = require('../metadata/metadataUtils'); const { pushMetric } = require('../utapi/utilities'); const monitoring = require('../utilities/monitoringHandler'); -const requestType = 'bucketDeleteCors'; +const REQUEST_TYPE = 'bucketDeleteCors'; +const METRICS_ACTION = 'deleteBucketCors'; /** * Bucket Delete CORS - Delete bucket cors configuration @@ -20,44 +17,27 @@ const requestType = 'bucketDeleteCors'; */ function bucketDeleteCors(authInfo, request, log, callback) { const bucketName = request.bucketName; - const canonicalID = authInfo.getCanonicalID(); - - return metadata.getBucket(bucketName, log, (err, bucket) => { - const corsHeaders = collectCorsHeaders(request.headers.origin, - request.method, bucket); + const metadataValParams = { + authInfo, + bucketName, + requestType: REQUEST_TYPE, + request, + }; + + return standardMetadataValidateBucket(metadataValParams, request.actionImplicitDenies, log, (err, bucket) => { + const corsHeaders = collectCorsHeaders(request.headers.origin, request.method, bucket); if (err) { - log.debug('metadata getbucket failed', { error: err }); - monitoring.promMetrics('DELETE', bucketName, 400, - 'deleteBucketCors'); + monitoring.promMetrics('DELETE', bucketName, err.code, METRICS_ACTION); + if (err?.is?.AccessDenied) { + return callback(err, corsHeaders); + } return callback(err); } - if (bucketShield(bucket, requestType)) { - monitoring.promMetrics('DELETE', bucketName, 400, - 'deleteBucketCors'); - return callback(errors.NoSuchBucket); - } - log.trace('found bucket in metadata'); - - if (!isBucketAuthorized(bucket, request.apiMethods || requestType, canonicalID, - authInfo, log, request, request.actionImplicitDenies)) { - log.debug('access denied for user on bucket', { - requestType, - method: 'bucketDeleteCors', - }); - monitoring.promMetrics('DELETE', bucketName, 403, - 'deleteBucketCors'); - return callback(errors.AccessDenied, corsHeaders); - } const cors = bucket.getCors(); if (!cors) { - log.trace('no existing cors configuration', { - method: 'bucketDeleteCors', - }); - pushMetric('deleteBucketCors', log, { - authInfo, - bucket: bucketName, - }); + log.trace('no existing cors configuration', { method: REQUEST_TYPE }); + pushMetric(METRICS_ACTION, log, { authInfo, bucket: bucketName }); return callback(null, corsHeaders); } @@ -65,17 +45,12 @@ function bucketDeleteCors(authInfo, request, log, callback) { bucket.setCors(null); return metadata.updateBucket(bucketName, bucket, log, err => { if (err) { - monitoring.promMetrics('DELETE', bucketName, 400, - 'deleteBucketCors'); + monitoring.promMetrics('DELETE', bucketName, err.code, METRICS_ACTION); return callback(err, corsHeaders); } - pushMetric('deleteBucketCors', log, { - authInfo, - bucket: bucketName, - }); - monitoring.promMetrics( - 'DELETE', bucketName, '204', 'deleteBucketCors'); - return callback(err, corsHeaders); + pushMetric(METRICS_ACTION, log, { authInfo, bucket: bucketName }); + monitoring.promMetrics('DELETE', bucketName, '204', METRICS_ACTION); + return callback(null , corsHeaders); }); }); } diff --git a/lib/api/bucketDeleteWebsite.js b/lib/api/bucketDeleteWebsite.js index 2f83391871..7d817dd87c 100644 --- a/lib/api/bucketDeleteWebsite.js +++ b/lib/api/bucketDeleteWebsite.js @@ -1,55 +1,35 @@ -const { errors } = require('arsenal'); - -const bucketShield = require('./apiUtils/bucket/bucketShield'); const collectCorsHeaders = require('../utilities/collectCorsHeaders'); -const { isBucketAuthorized } = - require('./apiUtils/authorization/permissionChecks'); const metadata = require('../metadata/wrapper'); +const { standardMetadataValidateBucket } = require('../metadata/metadataUtils'); const { pushMetric } = require('../utapi/utilities'); const monitoring = require('../utilities/monitoringHandler'); -const requestType = 'bucketDeleteWebsite'; +const REQUEST_TYPE = 'bucketDeleteWebsite'; +const METRICS_ACTION = 'deleteBucketWebsite'; function bucketDeleteWebsite(authInfo, request, log, callback) { const bucketName = request.bucketName; - const canonicalID = authInfo.getCanonicalID(); - - return metadata.getBucket(bucketName, log, (err, bucket) => { - const corsHeaders = collectCorsHeaders(request.headers.origin, - request.method, bucket); + const metadataValParams = { + authInfo, + bucketName, + requestType: REQUEST_TYPE, + request, + }; + + return standardMetadataValidateBucket(metadataValParams, request.actionImplicitDenies, log, (err, bucket) => { + const corsHeaders = collectCorsHeaders(request.headers.origin, request.method, bucket); if (err) { - log.debug('metadata getbucket failed', { error: err }); - monitoring.promMetrics( - 'DELETE', bucketName, err.code, 'deleteBucketWebsite'); + monitoring.promMetrics('DELETE', bucketName, err.code, REQUEST_TYPE); + if (err?.is?.AccessDenied) { + return callback(err, corsHeaders); + } return callback(err); } - if (bucketShield(bucket, requestType)) { - monitoring.promMetrics( - 'DELETE', bucketName, 404, 'deleteBucketWebsite'); - return callback(errors.NoSuchBucket); - } - log.trace('found bucket in metadata'); - - if (!isBucketAuthorized(bucket, request.apiMethods || requestType, canonicalID, - authInfo, log, request, request.actionImplicitDenies)) { - log.debug('access denied for user on bucket', { - requestType, - method: 'bucketDeleteWebsite', - }); - monitoring.promMetrics( - 'DELETE', bucketName, 403, 'deleteBucketWebsite'); - return callback(errors.AccessDenied, corsHeaders); - } const websiteConfig = bucket.getWebsiteConfiguration(); if (!websiteConfig) { - log.trace('no existing website configuration', { - method: 'bucketDeleteWebsite', - }); - pushMetric('deleteBucketWebsite', log, { - authInfo, - bucket: bucketName, - }); + log.trace('no existing website configuration', { method: REQUEST_TYPE }); + pushMetric(METRICS_ACTION, log, { authInfo, bucket: bucketName }); return callback(null, corsHeaders); } @@ -57,16 +37,11 @@ function bucketDeleteWebsite(authInfo, request, log, callback) { bucket.setWebsiteConfiguration(null); return metadata.updateBucket(bucketName, bucket, log, err => { if (err) { - monitoring.promMetrics( - 'DELETE', bucketName, err.code, 'deleteBucketWebsite'); + monitoring.promMetrics('DELETE', bucketName, err.code, METRICS_ACTION); return callback(err, corsHeaders); } - pushMetric('deleteBucketWebsite', log, { - authInfo, - bucket: bucketName, - }); - monitoring.promMetrics( - 'DELETE', bucketName, '200', 'deleteBucketWebsite'); + pushMetric(METRICS_ACTION, log, { authInfo, bucket: bucketName }); + monitoring.promMetrics('DELETE', bucketName, '200', METRICS_ACTION); return callback(null, corsHeaders); }); }); diff --git a/lib/api/bucketGetCors.js b/lib/api/bucketGetCors.js index a59b57d451..8c13132fb7 100644 --- a/lib/api/bucketGetCors.js +++ b/lib/api/bucketGetCors.js @@ -1,15 +1,12 @@ const { errors } = require('arsenal'); - -const bucketShield = require('./apiUtils/bucket/bucketShield'); const collectCorsHeaders = require('../utilities/collectCorsHeaders'); const { convertToXml } = require('./apiUtils/bucket/bucketCors'); -const { isBucketAuthorized } = - require('./apiUtils/authorization/permissionChecks'); -const metadata = require('../metadata/wrapper'); +const { standardMetadataValidateBucket } = require('../metadata/metadataUtils'); const { pushMetric } = require('../utapi/utilities'); const monitoring = require('../utilities/monitoringHandler'); -const requestType = 'bucketGetCors'; +const REQUEST_TYPE = 'bucketGetCors'; +const METRICS_ACTION = 'getBucketCors'; /** * Bucket Get CORS - Get bucket cors configuration @@ -21,52 +18,34 @@ const requestType = 'bucketGetCors'; */ function bucketGetCors(authInfo, request, log, callback) { const bucketName = request.bucketName; - const canonicalID = authInfo.getCanonicalID(); - - metadata.getBucket(bucketName, log, (err, bucket) => { + const metadataValParams = { + authInfo, + bucketName, + requestType: REQUEST_TYPE, + request, + }; + + return standardMetadataValidateBucket(metadataValParams, request.actionImplicitDenies, log, (err, bucket) => { + const corsHeaders = collectCorsHeaders(request.headers.origin, request.method, bucket); if (err) { - log.debug('metadata getbucket failed', { error: err }); - monitoring.promMetrics( - 'GET', bucketName, err.code, 'getBucketCors'); + monitoring.promMetrics('GET', bucketName, err.code, METRICS_ACTION); + if (err?.is?.AccessDenied) { + return callback(err, corsHeaders); + } return callback(err); } - if (bucketShield(bucket, requestType)) { - monitoring.promMetrics( - 'GET', bucketName, 404, 'getBucketCors'); - return callback(errors.NoSuchBucket); - } - log.trace('found bucket in metadata'); - const corsHeaders = collectCorsHeaders(request.headers.origin, - request.method, bucket); - - if (!isBucketAuthorized(bucket, request.apiMethods || requestType, canonicalID, - authInfo, log, request, request.actionImplicitDenies)) { - log.debug('access denied for user on bucket', { - requestType, - method: 'bucketGetCors', - }); - monitoring.promMetrics( - 'GET', bucketName, 403, 'getBucketCors'); - return callback(errors.AccessDenied, null, corsHeaders); - } const cors = bucket.getCors(); if (!cors) { - log.debug('cors configuration does not exist', { - method: 'bucketGetCors', - }); - monitoring.promMetrics( - 'GET', bucketName, 404, 'getBucketCors'); + log.debug('cors configuration does not exist', { method: REQUEST_TYPE }); + monitoring.promMetrics('GET', bucketName, 404, METRICS_ACTION); return callback(errors.NoSuchCORSConfiguration, null, corsHeaders); } log.trace('converting cors configuration to xml'); const xml = convertToXml(cors); - pushMetric('getBucketCors', log, { - authInfo, - bucket: bucketName, - }); - monitoring.promMetrics('GET', bucketName, '200', 'getBucketCors'); + pushMetric(METRICS_ACTION, log, { authInfo, bucket: bucketName }); + monitoring.promMetrics('GET', bucketName, '200', METRICS_ACTION); return callback(null, xml, corsHeaders); }); } diff --git a/lib/api/bucketGetLocation.js b/lib/api/bucketGetLocation.js index 75aac4a29b..83e0f3b601 100644 --- a/lib/api/bucketGetLocation.js +++ b/lib/api/bucketGetLocation.js @@ -1,15 +1,12 @@ -const { errors, s3middleware } = require('arsenal'); - -const bucketShield = require('./apiUtils/bucket/bucketShield'); -const { isBucketAuthorized } = - require('./apiUtils/authorization/permissionChecks'); -const metadata = require('../metadata/wrapper'); +const { s3middleware } = require('arsenal'); +const { standardMetadataValidateBucket } = require('../metadata/metadataUtils'); const { pushMetric } = require('../utapi/utilities'); const escapeForXml = s3middleware.escapeForXml; const collectCorsHeaders = require('../utilities/collectCorsHeaders'); const monitoring = require('../utilities/monitoringHandler'); -const requestType = 'bucketGetLocation'; +const REQUEST_TYPE = 'bucketGetLocation'; +const METRICS_ACTION = 'getBucketLocation'; /** * Bucket Get Location - Get bucket locationConstraint configuration @@ -19,56 +16,38 @@ const requestType = 'bucketGetLocation'; * @param {function} callback - callback to server * @return {undefined} */ - function bucketGetLocation(authInfo, request, log, callback) { const bucketName = request.bucketName; - const canonicalID = authInfo.getCanonicalID(); - - return metadata.getBucket(bucketName, log, (err, bucket) => { + const metadataValParams = { + authInfo, + bucketName, + requestType: request.apiMethod || REQUEST_TYPE, + request, + }; + + return standardMetadataValidateBucket(metadataValParams, request.actionImplicitDenies, log, (err, bucket) => { + const corsHeaders = collectCorsHeaders(request.headers.origin, request.method, bucket); if (err) { - log.debug('metadata getbucket failed', { error: err }); - monitoring.promMetrics( - 'GET', bucketName, err.code, 'getBucketLocation'); + monitoring.promMetrics('GET', bucketName, err.code, METRICS_ACTION); + if (err?.is?.AccessDenied) { + return callback(err, corsHeaders); + } return callback(err); } - if (bucketShield(bucket, requestType)) { - monitoring.promMetrics( - 'GET', bucketName, 404, 'getBucketLocation'); - return callback(errors.NoSuchBucket); - } - log.trace('found bucket in metadata'); - - const corsHeaders = collectCorsHeaders(request.headers.origin, - request.method, bucket); - - if (!isBucketAuthorized(bucket, request.apiMethods || requestType, canonicalID, - authInfo, log, request, request.actionImplicitDenies)) { - log.debug('access denied for account on bucket', { - requestType, - method: 'bucketGetLocation', - }); - monitoring.promMetrics( - 'GET', bucketName, 403, 'getBucketLocation'); - return callback(errors.AccessDenied, null, corsHeaders); - } let locationConstraint = bucket.getLocationConstraint(); if (!locationConstraint || locationConstraint === 'us-east-1') { - // AWS returns empty string if no region has been - // provided or for us-east-1 - // Note: AWS JS SDK sends a request with locationConstraint us-east-1 - // if no locationConstraint provided. + // AWS returns empty string if no region has been + // provided or for us-east-1 + // Note: AWS JS SDK sends a request with locationConstraint us-east-1 + // if no locationConstraint provided. locationConstraint = ''; } const xml = ` ` + `${escapeForXml(locationConstraint)}`; - pushMetric('getBucketLocation', log, { - authInfo, - bucket: bucketName, - }); - monitoring.promMetrics( - 'GET', bucketName, '200', 'getBucketLocation'); + pushMetric(METRICS_ACTION, log, { authInfo, bucket: bucketName }); + monitoring.promMetrics('GET', bucketName, '200', METRICS_ACTION); return callback(null, xml, corsHeaders); }); } diff --git a/lib/api/bucketGetLogging.js b/lib/api/bucketGetLogging.js index cf6804642f..e1e30820df 100644 --- a/lib/api/bucketGetLogging.js +++ b/lib/api/bucketGetLogging.js @@ -2,6 +2,8 @@ const { standardMetadataValidateBucket } = require('../metadata/metadataUtils'); const { checkExpectedBucketOwner } = require('./apiUtils/authorization/bucketOwner'); const monitoring = require('../utilities/monitoringHandler'); const { waterfall } = require('async'); +const { config } = require('../Config'); +const { errorInstances } = require('arsenal'); const BucketLoggingStatusNotFoundBody = '\n' + ''; @@ -9,6 +11,10 @@ const BucketLoggingStatusNotFoundBody = '\ function bucketGetLogging(authInfo, request, log, callback) { log.debug('processing request', { method: 'bucketGetLogging' }); + if (!config.serverAccessLogs || !config.serverAccessLogs.enabled) { + return callback(errorInstances.NotImplemented); + } + const bucketName = request.bucketName; const metadataValParams = { authInfo, diff --git a/lib/api/bucketGetWebsite.js b/lib/api/bucketGetWebsite.js index 35093fa457..0f20333c3d 100644 --- a/lib/api/bucketGetWebsite.js +++ b/lib/api/bucketGetWebsite.js @@ -1,15 +1,13 @@ const { errors } = require('arsenal'); -const bucketShield = require('./apiUtils/bucket/bucketShield'); const { convertToXml } = require('./apiUtils/bucket/bucketWebsite'); const collectCorsHeaders = require('../utilities/collectCorsHeaders'); -const { isBucketAuthorized } = - require('./apiUtils/authorization/permissionChecks'); -const metadata = require('../metadata/wrapper'); +const { standardMetadataValidateBucket } = require('../metadata/metadataUtils'); const { pushMetric } = require('../utapi/utilities'); const monitoring = require('../utilities/monitoringHandler'); -const requestType = 'bucketGetWebsite'; +const REQUEST_TYPE = 'bucketGetWebsite'; +const METRICS_ACTION = 'getBucketWebsite'; /** * Bucket Get Website - Get bucket website configuration @@ -21,54 +19,34 @@ const requestType = 'bucketGetWebsite'; */ function bucketGetWebsite(authInfo, request, log, callback) { const bucketName = request.bucketName; - const canonicalID = authInfo.getCanonicalID(); - - metadata.getBucket(bucketName, log, (err, bucket) => { + const metadataValParams = { + authInfo, + bucketName, + requestType: request.apiMethod || REQUEST_TYPE, + request, + }; + + return standardMetadataValidateBucket(metadataValParams, request.actionImplicitDenies, log, (err, bucket) => { + const corsHeaders = collectCorsHeaders(request.headers.origin, request.method, bucket); if (err) { - log.debug('metadata getbucket failed', { error: err }); - monitoring.promMetrics( - 'GET', bucketName, err.code, 'getBucketWebsite'); + monitoring.promMetrics('GET', bucketName, err.code, METRICS_ACTION); + if (err?.is?.AccessDenied) { + return callback(err, corsHeaders); + } return callback(err); } - if (bucketShield(bucket, requestType)) { - monitoring.promMetrics( - 'GET', bucketName, 404, 'getBucketWebsite'); - return callback(errors.NoSuchBucket); - } - log.trace('found bucket in metadata'); - - const corsHeaders = collectCorsHeaders(request.headers.origin, - request.method, bucket); - if (!isBucketAuthorized(bucket, request.apiMethods || requestType, canonicalID, - authInfo, log, request, request.actionImplicitDenies)) { - log.debug('access denied for user on bucket', { - requestType, - method: 'bucketGetWebsite', - }); - monitoring.promMetrics( - 'GET', bucketName, 403, 'getBucketWebsite'); - return callback(errors.AccessDenied, null, corsHeaders); - } const websiteConfig = bucket.getWebsiteConfiguration(); if (!websiteConfig) { - log.debug('bucket website configuration does not exist', { - method: 'bucketGetWebsite', - }); - monitoring.promMetrics( - 'GET', bucketName, 404, 'getBucketWebsite'); - return callback(errors.NoSuchWebsiteConfiguration, null, - corsHeaders); + log.debug('bucket website configuration does not exist', { method: REQUEST_TYPE }); + monitoring.promMetrics('GET', bucketName, 404, METRICS_ACTION); + return callback(errors.NoSuchWebsiteConfiguration, null, corsHeaders); } log.trace('converting website configuration to xml'); const xml = convertToXml(websiteConfig); - pushMetric('getBucketWebsite', log, { - authInfo, - bucket: bucketName, - }); - monitoring.promMetrics( - 'GET', bucketName, '200', 'getBucketWebsite'); + pushMetric(METRICS_ACTION, log, { authInfo, bucket: bucketName }); + monitoring.promMetrics('GET', bucketName, '200', METRICS_ACTION); return callback(null, xml, corsHeaders); }); } diff --git a/lib/api/bucketPutCors.js b/lib/api/bucketPutCors.js index 03a34430de..2cc05d25ad 100644 --- a/lib/api/bucketPutCors.js +++ b/lib/api/bucketPutCors.js @@ -1,16 +1,15 @@ const async = require('async'); const { errors, errorInstances } = require('arsenal'); -const bucketShield = require('./apiUtils/bucket/bucketShield'); const collectCorsHeaders = require('../utilities/collectCorsHeaders'); -const { isBucketAuthorized } = - require('./apiUtils/authorization/permissionChecks'); const metadata = require('../metadata/wrapper'); +const { standardMetadataValidateBucket } = require('../metadata/metadataUtils'); const { parseCorsXml } = require('./apiUtils/bucket/bucketCors'); const { pushMetric } = require('../utapi/utilities'); const monitoring = require('../utilities/monitoringHandler'); -const requestType = 'bucketPutCors'; +const REQUEST_TYPE = 'bucketPutCors'; +const METRICS_ACTION = 'putBucketCors'; /** * Bucket Put Cors - Adds cors rules to bucket @@ -22,73 +21,59 @@ const requestType = 'bucketPutCors'; */ function bucketPutCors(authInfo, request, log, callback) { log.debug('processing request', { method: 'bucketPutCors' }); - const { bucketName } = request; - const canonicalID = authInfo.getCanonicalID(); + const bucketName = request.bucketName; + const metadataValParams = { + authInfo, + bucketName, + requestType: request.apiMethod || REQUEST_TYPE, + request, + }; if (!request.post) { log.debug('CORS xml body is missing', - { error: errors.MissingRequestBodyError }); - monitoring.promMetrics('PUT', bucketName, 400, 'putBucketCors'); + { error: errors.MissingRequestBodyError }); + monitoring.promMetrics('PUT', bucketName, 400, METRICS_ACTION); return callback(errors.MissingRequestBodyError); } if (parseInt(request.headers['content-length'], 10) > 65536) { const errMsg = 'The CORS XML document is limited to 64 KB in size.'; log.debug(errMsg, { error: errors.MalformedXML }); - monitoring.promMetrics('PUT', bucketName, 400, 'putBucketCors'); + monitoring.promMetrics('PUT', bucketName, 400, METRICS_ACTION); return callback(errorInstances.MalformedXML.customizeDescription(errMsg)); } return async.waterfall([ - function parseXmlBody(next) { + next => { log.trace('parsing cors rules'); return parseCorsXml(request.post, log, next); }, - function getBucketfromMetadata(rules, next) { - metadata.getBucket(bucketName, log, (err, bucket) => { + (rules, next) => standardMetadataValidateBucket(metadataValParams, request.actionImplicitDenies, log, + (err, bucket) => { + const corsHeaders = collectCorsHeaders(request.headers.origin, request.method, bucket); if (err) { - log.debug('metadata getbucket failed', { error: err }); + monitoring.promMetrics('PUT', bucketName, err.code, METRICS_ACTION); + if (err?.is?.AccessDenied) { + return next(err, corsHeaders); + } return next(err); } - if (bucketShield(bucket, requestType)) { - return next(errors.NoSuchBucket); - } - log.trace('found bucket in metadata'); - // get corsHeaders before CORSConfiguration is updated - const corsHeaders = collectCorsHeaders(request.headers.origin, - request.method, bucket); + return next(null, bucket, rules, corsHeaders); - }); - }, - function validateBucketAuthorization(bucket, rules, corsHeaders, next) { - if (!isBucketAuthorized(bucket, request.apiMethods || requestType, canonicalID, - authInfo, log, request, request.actionImplicitDenies)) { - log.debug('access denied for account on bucket', { - requestType, - }); - return next(errors.AccessDenied, corsHeaders); - } - return next(null, bucket, rules, corsHeaders); - }, - function updateBucketMetadata(bucket, rules, corsHeaders, next) { - log.trace('updating bucket cors rules in metadata'); + }), + (bucket, rules, corsHeaders, next) => { bucket.setCors(rules); - metadata.updateBucket(bucketName, bucket, log, err => - next(err, corsHeaders)); + return metadata.updateBucket(bucketName, bucket, log, err => next(err, corsHeaders)); }, ], (err, corsHeaders) => { if (err) { - log.trace('error processing request', { error: err, - method: 'bucketPutCors' }); - monitoring.promMetrics('PUT', bucketName, err.code, - 'putBucketCors'); + log.trace('error processing request', { error: err, method: 'bucketPutCors' }); + monitoring.promMetrics('PUT', bucketName, err.code, METRICS_ACTION); + return callback(err, corsHeaders); } - pushMetric('putBucketCors', log, { - authInfo, - bucket: bucketName, - }); - monitoring.promMetrics('PUT', bucketName, '200', 'putBucketCors'); - return callback(err, corsHeaders); + pushMetric(METRICS_ACTION, log, { authInfo, bucket: bucketName }); + monitoring.promMetrics('PUT', bucketName, '200', METRICS_ACTION); + return callback(null, corsHeaders); }); } diff --git a/lib/api/bucketPutLogging.js b/lib/api/bucketPutLogging.js index 01e62afebf..c3c45e1eb3 100644 --- a/lib/api/bucketPutLogging.js +++ b/lib/api/bucketPutLogging.js @@ -5,10 +5,15 @@ const BucketLoggingStatus = require('arsenal').models.BucketLoggingStatus; const metadata = require('../metadata/wrapper'); const monitoring = require('../utilities/monitoringHandler'); const { errorInstances } = require('arsenal'); +const { config } = require('../Config'); function bucketPutLogging(authInfo, request, log, callback) { log.debug('processing request', { method: 'bucketPutLogging' }); + if (!config.serverAccessLogs || !config.serverAccessLogs.enabled) { + return callback(errorInstances.NotImplemented); + } + const bucketName = request.bucketName; const parsed = BucketLoggingStatus.fromXML(request.post); if (parsed.error) { diff --git a/lib/api/bucketPutWebsite.js b/lib/api/bucketPutWebsite.js index 5b546a743b..b7110a8a11 100644 --- a/lib/api/bucketPutWebsite.js +++ b/lib/api/bucketPutWebsite.js @@ -1,16 +1,15 @@ const async = require('async'); const { errors } = require('arsenal'); -const bucketShield = require('./apiUtils/bucket/bucketShield'); const collectCorsHeaders = require('../utilities/collectCorsHeaders'); -const { isBucketAuthorized } = - require('./apiUtils/authorization/permissionChecks'); const metadata = require('../metadata/wrapper'); +const { standardMetadataValidateBucket } = require('../metadata/metadataUtils'); const { parseWebsiteConfigXml } = require('./apiUtils/bucket/bucketWebsite'); const { pushMetric } = require('../utapi/utilities'); const monitoring = require('../utilities/monitoringHandler'); -const requestType = 'bucketPutWebsite'; +const REQUEST_TYPE = 'bucketPutWebsite'; +const METRICS_ACTION = 'putBucketWebsite'; /** * Bucket Put Website - Create bucket website configuration @@ -21,68 +20,55 @@ const requestType = 'bucketPutWebsite'; * @return {undefined} */ function bucketPutWebsite(authInfo, request, log, callback) { - log.debug('processing request', { method: 'bucketPutWebsite' }); - const { bucketName } = request; - const canonicalID = authInfo.getCanonicalID(); + log.debug('processing request', { method: REQUEST_TYPE }); + const bucketName = request.bucketName; + const metadataValParams = { + authInfo, + bucketName, + requestType: request.apiMethod || REQUEST_TYPE, + request, + }; if (!request.post) { - monitoring.promMetrics( - 'PUT', bucketName, 400, 'putBucketWebsite'); + monitoring.promMetrics('PUT', bucketName, 400, METRICS_ACTION); return callback(errors.MissingRequestBodyError); } + return async.waterfall([ - function parseXmlBody(next) { + next => { log.trace('parsing website configuration'); return parseWebsiteConfigXml(request.post, log, next); }, - function getBucketfromMetadata(config, next) { - metadata.getBucket(bucketName, log, (err, bucket) => { + (config, next) => standardMetadataValidateBucket(metadataValParams, request.actionImplicitDenies, log, + (err, bucket) => { + const corsHeaders = collectCorsHeaders(request.headers.origin, request.method, bucket); if (err) { - log.debug('metadata getbucket failed', { error: err }); + monitoring.promMetrics('PUT', bucketName, err.code, METRICS_ACTION); + if (err?.is?.AccessDenied) { + return next(err, corsHeaders); + } return next(err); } - if (bucketShield(bucket, requestType)) { - return next(errors.NoSuchBucket); - } - log.trace('found bucket in metadata'); - return next(null, bucket, config); - }); - }, - function validateBucketAuthorization(bucket, config, next) { - if (!isBucketAuthorized(bucket, request.apiMethods || requestType, canonicalID, - authInfo, log, request, request.actionImplicitDenies)) { - log.debug('access denied for user on bucket', { - requestType, - method: 'bucketPutWebsite', - }); - return next(errors.AccessDenied, bucket); - } - return next(null, bucket, config); - }, - function updateBucketMetadata(bucket, config, next) { + + return next(null, bucket, config, corsHeaders); + }), + (bucket, config, corsHeaders, next) => { log.trace('updating bucket website configuration in metadata'); bucket.setWebsiteConfiguration(config); - metadata.updateBucket(bucketName, bucket, log, err => { - next(err, bucket); + return metadata.updateBucket(bucketName, bucket, log, err => { + next(err, corsHeaders); }); - }, - ], (err, bucket) => { - const corsHeaders = collectCorsHeaders(request.headers.origin, - request.method, bucket); + } + ], (err, corsHeaders) => { if (err) { - log.trace('error processing request', { error: err, - method: 'bucketPutWebsite' }); - monitoring.promMetrics( - 'PUT', bucketName, err.code, 'putBucketWebsite'); - } else { - pushMetric('putBucketWebsite', log, { - authInfo, - bucket: bucketName, - }); - monitoring.promMetrics( - 'PUT', bucketName, '200', 'putBucketWebsite'); + log.trace('error processing request', { error: err, method: REQUEST_TYPE }); + monitoring.promMetrics('PUT', bucketName, err.code, METRICS_ACTION); + return callback(err, corsHeaders); } - return callback(err, corsHeaders); + + pushMetric(METRICS_ACTION, log, { authInfo, bucket: bucketName }); + monitoring.promMetrics('PUT', bucketName, '200', METRICS_ACTION); + return callback(null, corsHeaders); }); } diff --git a/lib/api/multipartDelete.js b/lib/api/multipartDelete.js index 5580573492..48146774b7 100644 --- a/lib/api/multipartDelete.js +++ b/lib/api/multipartDelete.js @@ -55,6 +55,10 @@ function multipartDelete(authInfo, request, log, callback) { log.addDefaultFields({ bytesDeleted: partSizeSum, }); + if (request.serverAccessLog) { + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.analyticsBytesDeleted = partSizeSum; + } } return callback(null, corsHeaders); }, request); diff --git a/lib/api/objectDelete.js b/lib/api/objectDelete.js index 112a4b721f..6a6956806e 100644 --- a/lib/api/objectDelete.js +++ b/lib/api/objectDelete.js @@ -111,6 +111,10 @@ function objectDeleteInternal(authInfo, request, log, isExpiration, cb) { log.end().addDefaultFields({ bytesDeleted: objMD['content-length'], }); + if (request.serverAccessLog) { + // eslint-disable-next-line no-param-reassign + request.serverAccessLog.analyticsBytesDeleted = objMD['content-length']; + } } return next(null, bucketMD, objMD); }); diff --git a/lib/metadata/metadataUtils.js b/lib/metadata/metadataUtils.js index 442af70e0a..ea0b3adb38 100644 --- a/lib/metadata/metadataUtils.js +++ b/lib/metadata/metadataUtils.js @@ -10,6 +10,28 @@ const { onlyOwnerAllowed } = require('../../constants'); const { actionNeedQuotaCheck, actionWithDataDeletion } = require('arsenal/build/lib/policyEvaluator/RequestContext'); const { processBytesToWrite, validateQuotas } = require('../api/apiUtils/quotas/quotaUtils'); +function storeServerAccessLogInfo(request, bucket, raftSessionId) { + /* eslint-disable no-param-reassign */ + + if (!request || !request.serverAccessLog) { + return; + } + + request.serverAccessLog.raftSessionID = raftSessionId; + + if (bucket) { + request.serverAccessLog.bucketOwner = bucket.getOwner(); + request.serverAccessLog.bucketName = bucket.getName(); + } + + if (bucket && bucket.getBucketLoggingStatus() && bucket.getBucketLoggingStatus().getLoggingEnabled()) { + request.serverAccessLog.enabled = true; + request.serverAccessLog.loggingEnabled = bucket.getBucketLoggingStatus().getLoggingEnabled(); + } + + /* eslint-enable no-param-reassign */ +} + /** getNullVersionFromMaster - retrieves the null version * metadata via retrieving the master key * @@ -196,19 +218,20 @@ function standardMetadataValidateBucketAndObj(params, actionImplicitDenies, log, if (getDeleteMarker) { getOptions.getDeleteMarker = true; } - return metadata.getBucketAndObjectMD(bucketName, objectKey, getOptions, log, (err, getResult) => { - if (err) { - // if some implicit iamAuthzResults, return AccessDenied - // before leaking any state information - if (actionImplicitDenies && Object.values(actionImplicitDenies).some(v => v === true)) { - return next(errors.AccessDenied); + return metadata.getBucketAndObjectMD(bucketName, objectKey, getOptions, log, + (err, getResult, raftSessionId) => { + if (err) { + // if some implicit iamAuthzResults, return AccessDenied + // before leaking any state information + if (actionImplicitDenies && Object.values(actionImplicitDenies).some(v => v === true)) { + return next(errors.AccessDenied); + } + return next(err); } - return next(err); - } - return next(null, getResult); - }); + return next(null, getResult, raftSessionId); + }); }, - (getResult, next) => { + (getResult, raftSessionId, next) => { const bucket = getResult.bucket ? BucketInfo.deSerialize(getResult.bucket) : undefined; if (!bucket) { @@ -216,30 +239,30 @@ function standardMetadataValidateBucketAndObj(params, actionImplicitDenies, log, bucket: bucketName, method: 'metadataValidateBucketAndObj', }); - return next(errors.NoSuchBucket); + return next(errors.NoSuchBucket, raftSessionId); } const validationError = validateBucket(bucket, params, log, actionImplicitDenies); if (validationError) { - return next(validationError, bucket); + return next(validationError, bucket, raftSessionId); } const objMD = getResult.obj ? JSON.parse(getResult.obj) : undefined; if (!objMD && versionId === 'null') { return getNullVersionFromMaster(bucketName, objectKey, log, - (err, nullVer) => next(err, bucket, nullVer)); + (err, nullVer) => next(err, bucket, nullVer, raftSessionId)); } - return next(null, bucket, objMD); + return next(null, bucket, objMD, raftSessionId); }, - (bucket, objMD, next) => { + (bucket, objMD, raftSessionId, next) => { const objMetadata = objMD; const canonicalID = authInfo.getCanonicalID(); if (!isObjAuthorized(bucket, objMetadata, requestType, canonicalID, authInfo, log, request, actionImplicitDenies)) { log.debug('access denied for user on object', { requestType }); - return next(errors.AccessDenied, bucket); + return next(errors.AccessDenied, bucket, undefined, raftSessionId); } if (!objMetadata) { - return next(null, bucket, objMetadata); + return next(null, bucket, objMetadata, raftSessionId); } let returnTagCount = false; @@ -256,9 +279,9 @@ function standardMetadataValidateBucketAndObj(params, actionImplicitDenies, log, objMetadata.returnTagCount = returnTagCount; } - return next(null, bucket, objMetadata); + return next(null, bucket, objMetadata, raftSessionId); }, - (bucket, objMD, next) => { + (bucket, objMD, raftSessionId, next) => { const needQuotaCheck = requestType => requestType.some(type => actionNeedQuotaCheck[type] || actionWithDataDeletion[type]); const checkQuota = params.checkQuota === undefined ? needQuotaCheck(requestType) : params.checkQuota; @@ -266,14 +289,15 @@ function standardMetadataValidateBucketAndObj(params, actionImplicitDenies, log, // In this case, the storage space was already accounted for when the RestoreObject API call // was made, so we don't need to add any inflight, but quota must be evaluated. if (!checkQuota) { - return next(null, bucket, objMD); + return next(null, bucket, objMD, raftSessionId); } const contentLength = processBytesToWrite(request.apiMethod, bucket, versionId, request?.parsedContentLength || 0, objMD, params.destObjMD); return validateQuotas(request, bucket, request.accountQuotas, requestType, request.apiMethod, - contentLength, withVersionId, log, err => next(err, bucket, objMD)); + contentLength, withVersionId, log, err => next(err, bucket, objMD, raftSessionId)); }, - ], (err, bucket, objMD) => { + ], (err, bucket, objMD, raftSessionId) => { + storeServerAccessLogInfo(request, bucket, raftSessionId); if (err) { // still return bucket for cors headers return callback(err, bucket); @@ -295,7 +319,8 @@ function standardMetadataValidateBucketAndObj(params, actionImplicitDenies, log, */ function standardMetadataValidateBucket(params, actionImplicitDenies, log, callback) { const { bucketName } = params; - return metadata.getBucket(bucketName, log, (err, bucket) => { + return metadata.getBucket(bucketName, log, (err, bucket, raftSessionId) => { + storeServerAccessLogInfo(params.request, bucket, raftSessionId); if (err) { // if some implicit actionImplicitDenies, return AccessDenied before // leaking any state information diff --git a/lib/server.js b/lib/server.js index 89bcd6f906..0dee25e813 100644 --- a/lib/server.js +++ b/lib/server.js @@ -26,6 +26,7 @@ const { const HttpAgent = require('agentkeepalive'); const QuotaService = require('./utilization/instance'); +const { logServerAccess } = require('./utilities/serverAccessLogger'); const { parseLC, MultipleBackendGateway } = arsenal.storage.data; const websiteEndpoints = _config.websiteEndpoints; let client = dataWrapper.client; @@ -122,6 +123,24 @@ class S3Server { monitoringClient.httpActiveRequests.inc(); const requestStartTime = process.hrtime.bigint(); + // Skip server access logs for heartbeat and backbeat. + if (!req.url.startsWith('/_/')) { + // eslint-disable-next-line no-param-reassign + req.serverAccessLog = { + enabled: false, + startTime: requestStartTime, + startTimeUnixMS: Date.now(), + }; + + // eslint-disable-next-line no-param-reassign + res.serverAccessLog = {}; + + res.on('finish', () => { + // eslint-disable-next-line no-param-reassign + req.serverAccessLog.endTime = process.hrtime.bigint(); + }); + } + // disable nagle algorithm req.socket.setNoDelay(); res.on('close', () => { @@ -131,6 +150,12 @@ class S3Server { }); const monitorEndOfRequest = () => { + if(req.serverAccessLog) { + // eslint-disable-next-line no-param-reassign + req.serverAccessLog.onCloseEndTime = process.hrtime.bigint(); + logServerAccess(req, res); + } + const responseTimeInNs = Number(process.hrtime.bigint() - requestStartTime); const labels = { method: req.method, diff --git a/lib/utilities/serverAccessLogger.js b/lib/utilities/serverAccessLogger.js new file mode 100644 index 0000000000..15b72bc30b --- /dev/null +++ b/lib/utilities/serverAccessLogger.js @@ -0,0 +1,332 @@ +const { Werelogs } = require('werelogs'); +const { config } = require('../Config'); +const fs = require('fs'); +const path = require('path'); +const logger = require('./logger'); + +const DEFAULT_OUTPUT_FILE = '/logs/api-operations.log'; +const SERVER_ACCESS_LOG_FORMAT_VERSION = '0'; + +function createServerAccessLogger() { + if (!config.serverAccessLogs || !config.serverAccessLogs.enabled) { + logger.warn('ServerAccessLogs disabled returning no-op logger'); + return { + info: () => { }, + debug: () => { }, + warn: () => { }, + error: () => { }, + trace: () => { }, + fatal: () => { }, + }; + } + + // Ensure logs directory exists + const outputFile = config.serverAccessLogs.outputFile || DEFAULT_OUTPUT_FILE; + const logDir = path.dirname(outputFile); + + try { + if (!fs.existsSync(logDir)) { + fs.mkdirSync(logDir, { recursive: true }); + } + } catch (error) { + // Fall back to logger-only logging if directory creation fails + logger.warn('Failed to create ServerAccess log directory, falling back to console logging:', error.message); + + const apiWerelogs = new Werelogs({ + level: config.serverAccessLogs.logLevel || 'info', + dump: config.serverAccessLogs.dumpLevel || 'error', + streams: [ + { level: 'trace', stream: process.stdout } + ] + }); + + return new apiWerelogs.Logger('ServerAccessLogger'); + } + + // Create file stream for API logs + const serverAccessLogStream = fs.createWriteStream(outputFile, { flags: 'a' }); + + // Handle stream errors + serverAccessLogStream.on('error', error => { + logger.error('ServerAccessLogger log file stream error:', error); + }); + + // Create the API-specific Werelogs instance - file output only + const apiWerelogs = new Werelogs({ + level: config.serverAccessLogs.logLevel || 'info', + dump: config.serverAccessLogs.dumpLevel || 'error', + streams: [{ level: 'trace', stream: serverAccessLogStream }] + }); + logger.info('ServerAccessLogger created successfully'); + return new apiWerelogs.Logger('ServerAccessLogger'); +} + +var serverAccessLogger = { + info: () => { }, + debug: () => { }, + warn: () => { }, + error: () => { }, + trace: () => { }, + fatal: () => { }, +}; + + +try { + serverAccessLogger = createServerAccessLogger(); +} catch (error) { + logger.error('Failed to create ServiceAccessLogger, using no-op logger:', error); +} + +function getRemoteIPFromRequest(request) { + let remoteIP = null; + if (request.headers) { + // Check for forwarded IP headers (proxy/load balancer scenarios) + const headerRemoteIP = request.headers['x-forwarded-for'] || + request.headers['x-real-ip'] || + request.headers['x-client-ip'] || + request.headers['cf-connecting-ip']; // Cloudflare + + // x-forwarded-for can contain multiple IPs, take the first one + if (headerRemoteIP) { + remoteIP = headerRemoteIP.includes(',') ? headerRemoteIP.split(',')[0].trim() : headerRemoteIP; + } + } + + // Fallback to connection remote address if no forwarded headers + if (!remoteIP) { + const connIP = (request.connection && request.connection.remoteAddress) || + (request.socket && request.socket.remoteAddress) || + (request.ip); + if (connIP) { + remoteIP = connIP; + } + } + + return remoteIP; +} + +function getOperation(req) { + const methodToResType = Object.freeze({ + 'bucketDelete': 'BUCKET', + 'bucketDeleteCors': 'BUCKET', + 'bucketDeleteEncryption': 'BUCKET', + 'bucketDeleteWebsite': 'BUCKET', + 'bucketGet': 'BUCKET', + 'bucketGetACL': 'BUCKET', + 'bucketGetCors': 'BUCKET', + 'bucketGetObjectLock': 'BUCKET', + 'bucketGetVersioning': 'VERSIONING', + 'bucketGetWebsite': 'BUCKET', + 'bucketGetLocation': 'BUCKET', + 'bucketGetEncryption': 'BUCKET', + 'bucketHead': 'BUCKET', + 'bucketPut': 'BUCKET', + 'bucketPutACL': 'BUCKET', + 'bucketPutCors': 'BUCKET', + 'bucketPutVersioning': 'VERSIONING', + 'bucketPutTagging': 'BUCKET', + 'bucketDeleteTagging': 'BUCKET', + 'bucketGetTagging': 'BUCKET', + 'bucketPutWebsite': 'BUCKET', + 'bucketPutReplication': 'BUCKET', + 'bucketGetReplication': 'BUCKET', + 'bucketDeleteReplication': 'BUCKET', + 'bucketDeleteQuota': 'BUCKET', + 'bucketPutLifecycle': 'BUCKET', + 'bucketUpdateQuota': 'BUCKET', + 'bucketGetLifecycle': 'BUCKET', + 'bucketDeleteLifecycle': 'BUCKET', + 'bucketPutPolicy': 'BUCKETPOLICY', + 'bucketGetPolicy': 'BUCKETPOLICY', + 'bucketGetQuota': 'BUCKET', + 'bucketDeletePolicy': 'BUCKETPOLICY', + 'bucketPutObjectLock': 'BUCKET', + 'bucketPutNotification': 'BUCKET', + 'bucketGetNotification': 'BUCKET', + 'bucketPutEncryption': 'BUCKET', + 'bucketPutLogging': 'LOGGING_STATUS', + 'bucketGetLogging': 'LOGGING_STATUS', + // 'corsPreflight': '', + 'completeMultipartUpload': 'OBJECT', + 'initiateMultipartUpload': 'OBJECT', + 'listMultipartUploads': 'OBJECT', + 'listParts': 'OBJECT', + 'metadataSearch': 'OBJECT', + 'multiObjectDelete': 'OBJECT', + 'multipartDelete': 'OBJECT', + 'objectDelete': 'OBJECT', + 'objectDeleteTagging': 'OBJECT', + 'objectGet': 'OBJECT', + 'objectGetACL': 'OBJECT', + 'objectGetLegalHold': 'OBJECT', + 'objectGetRetention': 'OBJECT', + 'objectGetTagging': 'OBJECT', + 'objectCopy': 'OBJECT', + 'objectHead': 'OBJECT', + 'objectPut': 'OBJECT', + 'objectPutACL': 'OBJECT', + 'objectPutLegalHold': 'OBJECT', + 'objectPutTagging': 'OBJECT', + 'objectPutPart': 'OBJECT', + 'objectPutCopyPart': 'OBJECT', + 'objectPutRetention': 'OBJECT', + 'objectRestore': 'OBJECT', + // 'serviceGet': '', + // 'websiteGet': '', + // 'websiteHead': '', + }); + + return `REST.${req.method}.${methodToResType[req.apiMethod] ? methodToResType[req.apiMethod] : 'UNKNOWN'}`; +} + +function getRequester(authInfo) { + const requester = null; + if (authInfo) { + if (authInfo.isRequesterPublicUser && authInfo.isRequesterPublicUser()) { + return requester; // Unauthenticated requests + } else if (authInfo.isRequesterAnIAMUser && authInfo.isRequesterAnIAMUser()) { + // IAM user: include IAM user name and account + const iamUserName = authInfo.getIAMdisplayName ? authInfo.getIAMdisplayName() : ''; + const accountName = authInfo.getAccountDisplayName ? authInfo.getAccountDisplayName() : ''; + return iamUserName && accountName ? `${iamUserName}:${accountName}` : authInfo.getCanonicalID(); + } else if (authInfo.getCanonicalID) { + // Regular user: canonical user ID + return authInfo.getCanonicalID(); + } + } + return requester; +} + +function getURI(request) { + let requestURI = null; + if (request) { + const method = request.method || 'UNKNOWN'; + const url = request.url || request.originalUrl || '/'; + const httpVersion = request.httpVersion || '1.1'; + requestURI = `${method} ${url} HTTP/${httpVersion}`; + } + return requestURI; +} + +function getObjectSize(request, response) { + const objectSizePutMethods = Object.freeze({ + 'objectPut': true, + 'objectPutPart': true, + }); + + const objectSizeGetMethods = Object.freeze({ + 'objectGet': true, + }); + + // If it is a PUT get the Content-Length from the request, if it is a GET get it from the response. + if (request && response && objectSizeGetMethods[request.apiMethod]) { + const len = response.getHeader('Content-Length'); + return len || null; + } + + if (request && objectSizePutMethods[request.apiMethod]) { + const len = request.headers['content-length']; + return len || null; + } + + return null; +} + +function getBytesSent(res, bytesSent) { + if (bytesSent) { + return bytesSent; + } + + if (!res) { + return null; + } + + const len = res.getHeader('Content-Length'); + return len || null; +} + +function calculateTotalTime(startTime, endTime) { + if (!startTime || !endTime) { + return null; + } + + return ((endTime - startTime) / 1_000_000n).toString(); +} + +function calculateTurnAroundTime(startTurnAroundTime, endTurnAroundTime) { + if (!startTurnAroundTime || !endTurnAroundTime) { + return null; + } + + return ((endTurnAroundTime - startTurnAroundTime) / 1_000_000n).toString(); +} + +function logServerAccess(req, res) { + 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 authInfo = params.authInfo; + + serverAccessLogger.info('', { + // Analytics + action: params.analyticsAction || null, + accountName: params.analyticsAccountName || null, + accountDisplayName: authInfo ? authInfo.getAccountDisplayName() : null, + userName: params.analyticsUserName || null, + clientPort: req.socket.remotePort || null, + httpMethod: req.method || null, + bytesDeleted: params.analyticsBytesDeleted || null, + bytesReceived: req.parsedContentLength || 0, + bodyLength: parseInt(req.headers['content-length'], 10) || 0, + contentLength: req.parsedContentLength || 0, + // eslint-disable-next-line camelcase + elapsed_ms: params.startTime && params.onCloseEndTime ? + Number(params.onCloseEndTime - params.startTime) / 1_000_000 : null, + httpURL: req.url || null, + + // AWS access server logs fields https://docs.aws.amazon.com/AmazonS3/latest/userguide/LogFormat.html + startTime: params.startTimeUnixMS || null, // AWS "Time" field + requester: getRequester(authInfo), + operation: getOperation(req), + requestURI: getURI(req), + errorCode: errorCode || null, + objectSize: getObjectSize(req, res), + totalTime: calculateTotalTime(params.startTime, params.endTime), + turnAroundTime: calculateTurnAroundTime(params.startTurnAroundTime, endTurnAroundTime), + referer: req.headers.referer || null, + userAgent: req.headers['user-agent'] || null, + versionID: req.query ? req.query.versionId || null : null, + signatureVersion: authInfo ? authInfo.getAuthVersion() : null, + cipherSuite: req.socket.encrypted ? req.socket.getCipher()['standardName'] : null, + authenticationType: authInfo ? authInfo.getAuthType() : null, + hostHeader: req.headers.host || null, + tlsVersion: req.socket.encrypted ? req.socket.getCipher()['version'] : null, + aclRequired: null, // TODO: CLDSRV-774 + // hostID: null, // NOT IMPLEMENTED + // accessPointARN: null, // NOT IMPLEMENTED + + // Shared between AWS access server logs and Analytics logs + bucketOwner: params.bucketOwner || null, + bucketName: params.bucketName || null, // AWS "Bucket" field + // eslint-disable-next-line camelcase + req_id: requestID || null, // AWS "Request ID" field + bytesSent: getBytesSent(res, bytesSent), + clientIP: getRemoteIPFromRequest(req), // AWS 'Remote IP' field + httpCode: res.statusCode || null, // AWS "HTTP Status" field + objectKey: params.objectKey || null, // AWS "Key" field + + // Scality server access logs extra fields + logFormatVersion: SERVER_ACCESS_LOG_FORMAT_VERSION, + loggingEnabled: params.enabled, + loggingTargetBucket: params.loggingEnabled ? params.loggingEnabled.TargetBucket : null, + loggingTargetPrefix: params.loggingEnabled ? params.loggingEnabled.TargetPrefix : null, + awsAccessKeyID: authInfo ? authInfo.getAccessKey() : null, + raftSessionID: params.raftSessionID || null, + }); +} + +module.exports = { + logServerAccess, +}; diff --git a/package.json b/package.json index a7899a0054..b880707b82 100644 --- a/package.json +++ b/package.json @@ -21,7 +21,7 @@ "dependencies": { "@azure/storage-blob": "^12.28.0", "@hapi/joi": "^17.1.1", - "arsenal": "git+https://github.com/scality/Arsenal#8.2.37", + "arsenal": "git+https://github.com/scality/Arsenal#improvement/ARSN-531-export-server-access-log-fields", "async": "2.6.4", "aws-sdk": "^2.1692.0", "bucketclient": "scality/bucketclient#8.2.7", diff --git a/tests/functional/config.json b/tests/functional/config.json index 24e61986f5..bffebe2ac6 100644 --- a/tests/functional/config.json +++ b/tests/functional/config.json @@ -6,5 +6,9 @@ "localCache": { "host": "127.0.0.1", "port": 6379 + }, + "serverAccessLogs": { + "enabled": true, + "outputFile": "/logs/server-access.log" } } diff --git a/tests/unit/api/bucketGetLogging.js b/tests/unit/api/bucketGetLogging.js index 34d3bcfcc1..b61a2b1d38 100644 --- a/tests/unit/api/bucketGetLogging.js +++ b/tests/unit/api/bucketGetLogging.js @@ -11,6 +11,9 @@ const otherAuthInfo = makeAuthInfo('accessKey2'); const bucketName = 'bucketgetloggingtest'; const targetBucket = 'loggingbucket'; const namespace = 'default'; +const { config } = require('../../../lib/Config'); + +config.serverAccessLogs.enabled = true; const testBucketPutRequest = { bucketName, diff --git a/tests/unit/api/bucketPutLogging.js b/tests/unit/api/bucketPutLogging.js index 0f94147620..66949ca331 100644 --- a/tests/unit/api/bucketPutLogging.js +++ b/tests/unit/api/bucketPutLogging.js @@ -10,6 +10,9 @@ const otherAuthInfo = makeAuthInfo('accessKey2'); const bucketName = 'bucketputloggingtest'; const targetBucket = 'loggingbucket'; const namespace = 'default'; +const { config } = require('../../../lib/Config'); + +config.serverAccessLogs.enabled = true; const testBucketPutRequest = { bucketName, diff --git a/yarn.lock b/yarn.lock index e1b4a475a6..ea6c088605 100644 --- a/yarn.lock +++ b/yarn.lock @@ -1451,32 +1451,37 @@ arraybuffer.prototype.slice@^1.0.4: optionalDependencies: ioctl "^2.0.2" -"arsenal@git+https://github.com/scality/Arsenal#8.2.37": - version "8.2.37" - resolved "git+https://github.com/scality/Arsenal#a000b510e641b819f86d91371f638f1cbc57144f" +"arsenal@git+https://github.com/scality/Arsenal#8.2.4": + version "8.2.4" + resolved "git+https://github.com/scality/Arsenal#96ef6a3e26d7528f877300606586759f1da6d0cd" dependencies: - "@azure/identity" "^4.13.0" - "@azure/storage-blob" "^12.28.0" + "@azure/identity" "^4.5.0" + "@azure/storage-blob" "^12.25.0" + "@eslint/plugin-kit" "^0.2.3" "@js-sdsl/ordered-set" "^4.4.2" "@scality/hdclient" "^1.3.1" + "@types/async" "^3.2.24" + "@types/utf8" "^3.0.3" JSONStream "^1.3.5" - agentkeepalive "^4.6.0" + agentkeepalive "^4.5.0" ajv "6.12.3" async "~2.6.4" aws-sdk "^2.1691.0" backo "^1.1.0" base-x "3.0.8" base62 "^2.0.2" - debug "^4.4.3" + bson "^6.8.0" + debug "^4.3.7" + diskusage "^1.2.0" fcntl "github:scality/node-fcntl#0.3.0" httpagent scality/httpagent#1.1.0 - https-proxy-agent "^7.0.6" - ioredis "^5.8.1" + https-proxy-agent "^7.0.5" + ioredis "^5.4.1" ipaddr.js "^2.2.0" - joi "^18.0.1" + joi "^17.13.3" level "~5.0.1" level-sublevel "~6.6.5" - mongodb "^6.20.0" + mongodb "^6.11.0" node-forge "^1.3.1" prom-client "^15.1.3" simple-glob "^0.2.0" @@ -1490,37 +1495,32 @@ arraybuffer.prototype.slice@^1.0.4: optionalDependencies: ioctl "^2.0.2" -"arsenal@git+https://github.com/scality/Arsenal#8.2.4": - version "8.2.4" - resolved "git+https://github.com/scality/Arsenal#96ef6a3e26d7528f877300606586759f1da6d0cd" +"arsenal@git+https://github.com/scality/Arsenal#improvement/ARSN-531-export-server-access-log-fields": + version "8.2.37" + resolved "git+https://github.com/scality/Arsenal#6c46d6c6207cf379825582c4f579b7ffa6b12bfa" dependencies: - "@azure/identity" "^4.5.0" - "@azure/storage-blob" "^12.25.0" - "@eslint/plugin-kit" "^0.2.3" + "@azure/identity" "^4.13.0" + "@azure/storage-blob" "^12.28.0" "@js-sdsl/ordered-set" "^4.4.2" "@scality/hdclient" "^1.3.1" - "@types/async" "^3.2.24" - "@types/utf8" "^3.0.3" JSONStream "^1.3.5" - agentkeepalive "^4.5.0" + agentkeepalive "^4.6.0" ajv "6.12.3" async "~2.6.4" aws-sdk "^2.1691.0" backo "^1.1.0" base-x "3.0.8" base62 "^2.0.2" - bson "^6.8.0" - debug "^4.3.7" - diskusage "^1.2.0" + debug "^4.4.3" fcntl "github:scality/node-fcntl#0.3.0" httpagent scality/httpagent#1.1.0 - https-proxy-agent "^7.0.5" - ioredis "^5.4.1" + https-proxy-agent "^7.0.6" + ioredis "^5.8.1" ipaddr.js "^2.2.0" - joi "^17.13.3" + joi "^18.0.1" level "~5.0.1" level-sublevel "~6.6.5" - mongodb "^6.11.0" + mongodb "^6.20.0" node-forge "^1.3.1" prom-client "^15.1.3" simple-glob "^0.2.0"