test: add response end timers

lib/s3routes/routesUtils.js

@@ -43,6 +43,9 @@ function okHeaderResponse(headers, response, httpCode, log) {
     log.debug('response http code', { httpCode });
     response.writeHead(httpCode);
     return response.end(() => {
+        console.log('=========================================');
+        console.log('RESPONSE ENDED:', Date.now());
+        console.log('=========================================');
         log.end().info('responded to request', {
             httpCode: response.statusCode,
         });
@@ -72,6 +75,9 @@ const XMLResponseBackend = {
         log.debug('response http code', { httpCode: 200 });
         log.trace('xml response', { xml });
         return response.end(xml, 'utf8', () => {
+            console.log('=========================================');
+            console.log('RESPONSE ENDED:', Date.now());
+            console.log('=========================================');
             log.end().info('responded with XML', {
                 httpCode: response.statusCode,
             });
@@ -110,6 +116,9 @@ const XMLResponseBackend = {
                            { 'Content-Type': 'application/xml',
                              'Content-Length': bytesSent });
         return response.end(xmlStr, 'utf8', () => {
+            console.log('=========================================');
+            console.log('RESPONSE ENDED:', Date.now());
+            console.log('=========================================');
             log.end().info('responded with error XML', {
                 httpCode: response.statusCode,
             });
@@ -140,6 +149,9 @@ const JSONResponseBackend = {
         log.debug('response http code', { httpCode: 200 });
         log.trace('json response', { json });
         return response.end(json, 'utf8', () => {
+            console.log('=========================================');
+            console.log('RESPONSE ENDED:', Date.now());
+            console.log('=========================================');
             log.end().info('responded with JSON', {
                 httpCode: response.statusCode,
             });
@@ -171,6 +183,9 @@ const JSONResponseBackend = {
                            { 'Content-Type': 'application/json',
                              'Content-Length': bytesSent });
         return response.end(jsonStr, 'utf8', () => {
+            console.log('=========================================');
+            console.log('RESPONSE ENDED:', Date.now());
+            console.log('=========================================');
             log.end().info('responded with error JSON', {
                 httpCode: response.statusCode,
             });
@@ -244,6 +259,9 @@ function okContentHeadersResponse(overrideParams, resHeaders,
 function retrieveData(locations, dataRetrievalFn,
     response, logger, errorHandlerFn) {
     if (locations.length === 0) {
+        console.log('=========================================');
+        console.log('RESPONSE ENDED:', Date.now());
+        console.log('=========================================');
         return response.end();
     }
     if (errorHandlerFn === undefined) {
@@ -375,6 +393,9 @@ const routesUtils = {
                 undefined, log);
         }
         return response.end(() => {
+            console.log('=========================================');
+            console.log('RESPONSE ENDED:', Date.now());
+            console.log('=========================================');
             log.end().info('responded with content headers', {
                 httpCode: response.statusCode,
             });
@@ -408,12 +429,18 @@ const routesUtils = {
         }
         if (dataLocations === null) {
             return response.end(() => {
+                console.log('=========================================');
+                console.log('RESPONSE ENDED:', Date.now());
+                console.log('=========================================');
                 log.end().info('responded with only metadata', {
                     httpCode: response.statusCode,
                 });
             });
         }
         response.on('finish', () => {
+            console.log('=========================================');
+            console.log('RESPONSE ENDED:', Date.now());
+            console.log('=========================================');
             log.end().info('responded with streamed content', {
                 httpCode: response.statusCode,
             });
@@ -501,6 +528,9 @@ const routesUtils = {
         );
 
         return response.end(html.join(''), 'utf8', () => {
+            console.log('=========================================');
+            console.log('RESPONSE ENDED:', Date.now());
+            console.log('=========================================');
             log.end().info('responded with error html', {
                 httpCode: response.statusCode,
             });
@@ -522,6 +552,9 @@ const routesUtils = {
         response.setHeader('x-amz-error-message', err.description);
         response.writeHead(err.code);
         return response.end(() => {
+            console.log('=========================================');
+            console.log('RESPONSE ENDED:', Date.now());
+            console.log('=========================================');
             log.end().info('responded with error headers', {
                 httpCode: response.statusCode,
             });