CLDSRV-750: fix startTime and elapsed_ms

Author: leif-scality

lib/server.js

@@ -129,6 +129,7 @@ class S3Server {
             req.serverAccessLog = {
                 enabled: false,
                 startTime: requestStartTime,
+                startTimeUnixMS: Date.now(),
             };
 
             // eslint-disable-next-line no-param-reassign
@@ -137,10 +138,9 @@ class S3Server {
             res.on('finish', () => {
                 // eslint-disable-next-line no-param-reassign
                 req.serverAccessLog.endTime = process.hrtime.bigint();
-                logServerAccess(req, res);
             });
         }
-
+        
         // disable nagle algorithm
         req.socket.setNoDelay();
         res.on('close', () => {
@@ -150,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,

lib/utilities/serverAccessLogger.js

@@ -282,11 +282,12 @@ function logServerAccess(req, res) {
         bodyLength: parseInt(req.headers['content-length'], 10) || 0,
         contentLength: req.parsedContentLength || 0,
         // eslint-disable-next-line camelcase
-        elapsed_ms: params.startTime && params.endTime ? Number(params.endTime - params.startTime) / 1_000_000 : null,
+        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.startTime ? params.startTime.toString() : null, // AWS "Time" field
+        startTime: params.startTimeUnixMS || null, // AWS "Time" field
         requester: getRequester(authInfo),
         operation: getOperation(req),
         requestURI: getURI(req),