From 163c5462368d2f59149c1d3d67d287c930e40824 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Mon, 1 Jun 2020 19:18:15 +0200
Subject: [PATCH 01/44] Replace log4js by pino as logger: - Logs to stdout,
 disabled while testing - Change log calls signature when needed - Use
 development version of camshaft - Removes unused log cofiguration - Bind
 request id to log req/res - Log req at the begining of the cycle and res at
 the end

---
 app.js                                        | 165 +++-----
 config/environments/development.js.example    |  19 +-
 config/environments/production.js.example     |  19 +-
 config/environments/staging.js.example        |  18 +-
 config/environments/test.js.example           |  19 +-
 lib/api/api-router.js                         |  26 +-
 lib/api/map/preview-template-controller.js    |   4 +-
 lib/api/middlewares/cache-channel-header.js   |   2 +-
 lib/api/middlewares/cache-control-header.js   |   2 +-
 .../middlewares/increment-map-view-count.js   |   2 +-
 lib/api/middlewares/last-modified-header.js   |   2 +-
 lib/api/middlewares/logger.js                 |  29 +-
 lib/api/middlewares/metrics.js                |   2 +-
 lib/api/middlewares/surrogate-key-header.js   |   2 +-
 lib/backends/analysis.js                      |  22 +-
 lib/models/cdb-request.js                     |  11 +-
 lib/server-options.js                         |   6 -
 package-lock.json                             | 399 +++++++++++++-----
 package.json                                  |   6 +-
 test/support/test-helper.js                   |   6 +-
 20 files changed, 398 insertions(+), 363 deletions(-)

diff --git a/app.js b/app.js
index ca72e3f0..7cbb6a74 100755
--- a/app.js
+++ b/app.js
@@ -1,28 +1,27 @@
 'use strict';
 
-var http = require('http');
-var https = require('https');
-var path = require('path');
-var fs = require('fs');
-var _ = require('underscore');
-var semver = require('semver');
+const http = require('http');
+const https = require('https');
+const path = require('path');
+const fs = require('fs');
+const semver = require('semver');
+const pino = require('pino');
+
 // TODO: research it it's still needed
 const setICUEnvVariable = require('./lib/utils/icu-data-env-setter');
 
-var log = console.log.bind(console);
-var logError = console.error.bind(console);
+global.logger = pino({ base: null, level: process.env.NODE_ENV === 'test' ? 'fatal' : 'info' }, pino.destination({ sync: false }));
 
-var nodejsVersion = process.versions.node;
 const { engines } = require('./package.json');
-if (!semver.satisfies(nodejsVersion, engines.node)) {
-    logError(`Node version ${nodejsVersion} is not supported, please use Node.js ${engines.node}.`);
+if (!semver.satisfies(process.versions.node, engines.node)) {
+    global.logger.fatal(new Error(`Node version ${process.versions.node} is not supported, please use Node.js ${engines.node}.`));
     process.exit(1);
 }
 
 // This function should be called before the require('yargs').
 setICUEnvVariable();
 
-var argv = require('yargs')
+const argv = require('yargs')
     .usage('Usage: node $0 <environment> [options]')
     .help('h')
     .example(
@@ -35,27 +34,26 @@ var argv = require('yargs')
     .describe('c', 'Load configuration from path')
     .argv;
 
-var environmentArg = argv._[0] || process.env.NODE_ENV || 'development';
-var configurationFile = path.resolve(argv.config || './config/environments/' + environmentArg + '.js');
+const environmentArg = argv._[0] || process.env.NODE_ENV || 'development';
+const configurationFile = path.resolve(argv.config || `./config/environments/${environmentArg}.js`);
+
 if (!fs.existsSync(configurationFile)) {
-    logError('Configuration file "%s" does not exist', configurationFile);
+    global.logger.fatal(new Error(`Configuration file ${configurationFile} does not exist`));
     process.exit(1);
 }
 
 global.environment = require(configurationFile);
-var ENVIRONMENT = argv._[0] || process.env.NODE_ENV || global.environment.environment;
+const ENVIRONMENT = argv._[0] || process.env.NODE_ENV || global.environment.environment;
 process.env.NODE_ENV = ENVIRONMENT;
 
-var availableEnvironments = {
+const availableEnvironments = {
     production: true,
     staging: true,
     development: true
 };
 
-// sanity check
 if (!availableEnvironments[ENVIRONMENT]) {
-    logError('node app.js [environment]');
-    logError('environments: %s', Object.keys(availableEnvironments).join(', '));
+    global.logger.fatal(new Error(`Invalid environment argument, valid ones: ${Object.keys(availableEnvironments).join(', ')}`));
     process.exit(1);
 }
 
@@ -66,65 +64,37 @@ if (global.environment.uv_threadpool_size) {
 
 // set global HTTP and HTTPS agent default configurations
 // ref https://nodejs.org/api/http.html#http_new_agent_options
-var agentOptions = _.defaults(global.environment.httpAgent || {}, {
+const agentOptions = Object.assign({
     keepAlive: false,
     keepAliveMsecs: 1000,
     maxSockets: Infinity,
     maxFreeSockets: 256
-});
+}, global.environment.httpAgent || {});
+
 http.globalAgent = new http.Agent(agentOptions);
 https.globalAgent = new https.Agent(agentOptions);
 
-global.log4js = require('log4js');
-var log4jsConfig = {
-    appenders: [],
-    replaceConsole: true
-};
-
-if (global.environment.log_filename) {
-    var logFilename = path.resolve(global.environment.log_filename);
-    var logDirectory = path.dirname(logFilename);
-    if (!fs.existsSync(logDirectory)) {
-        logError('Log filename directory does not exist: ' + logDirectory);
-        process.exit(1);
-    }
-    log('Logs will be written to ' + logFilename);
-    log4jsConfig.appenders.push(
-        { type: 'file', absolute: true, filename: logFilename }
-    );
-} else {
-    log4jsConfig.appenders.push(
-        { type: 'console', layout: { type: 'basic' } }
-    );
-}
-
-global.log4js.configure(log4jsConfig);
-global.logger = global.log4js.getLogger();
-
 // Include cartodb_windshaft only _after_ the "global" variable is set
 // See https://github.com/Vizzuality/Windshaft-cartodb/issues/28
-var cartodbWindshaft = require('./lib/server');
-var serverOptions = require('./lib/server-options');
+const cartodbWindshaft = require('./lib/server');
+const serverOptions = require('./lib/server-options');
 
-var server = cartodbWindshaft(serverOptions);
+const server = cartodbWindshaft(serverOptions);
 
-// Maximum number of connections for one process
-// 128 is a good number if you have up to 1024 filedescriptors
-// 4 is good if you have max 32 filedescriptors
-// 1 is good if you have max 16 filedescriptors
-var backlog = global.environment.maxConnections || 128;
+// Specify the maximum length of the queue of pending connections for the HTTP server.
+// The actual length will be determined by the OS through sysctl settings such as tcp_max_syn_backlog and somaxconn on Linux.
+// The default value of this parameter is 511 (not 512).
+// See: https://nodejs.org/docs/latest/api/net.html#net_server_listen
+const backlog = global.environment.maxConnections || 128;
 
-var listener = server.listen(serverOptions.bind.port, serverOptions.bind.host, backlog);
-
-var version = require('./package').version;
+const listener = server.listen(serverOptions.bind.port, serverOptions.bind.host, backlog);
+const version = require('./package').version;
 
 listener.on('listening', function () {
-    log('Using Node.js %s', process.version);
-    log('Using configuration file "%s"', configurationFile);
-    log(
-        'Windshaft tileserver %s started on %s:%s PID=%d (%s)',
-        version, serverOptions.bind.host, serverOptions.bind.port, process.pid, ENVIRONMENT
-    );
+    global.logger.info(`Using Node.js ${process.version}`);
+    global.logger.info(`Using configuration file ${configurationFile}`);
+    const { address, port } = listener.address();
+    global.logger.info(`Windshaft tileserver ${version} started on ${address}:${port} PID=${process.pid} (${ENVIRONMENT})`);
 });
 
 function getCPUUsage (oldUsage) {
@@ -159,22 +129,14 @@ setInterval(function cpuUsageMetrics () {
     });
 
     previousCPUUsage = CPUUsage;
-}, 5000);
+}, 5000).unref();
 
 setInterval(function () {
     var memoryUsage = process.memoryUsage();
     Object.keys(memoryUsage).forEach(function (k) {
         global.statsClient.gauge('windshaft.memory.' + k, memoryUsage[k]);
     });
-}, 5000);
-
-process.on('SIGHUP', function () {
-    global.log4js.clearAndShutdownAppenders(function () {
-        global.log4js.configure(log4jsConfig);
-        global.logger = global.log4js.getLogger();
-        log('Log files reloaded');
-    });
-});
+}, 5000).unref();
 
 if (global.gc) {
     var gcInterval = Number.isFinite(global.environment.gc_interval)
@@ -184,7 +146,7 @@ if (global.gc) {
     if (gcInterval > 0) {
         setInterval(function gcForcedCycle () {
             global.gc();
-        }, gcInterval);
+        }, gcInterval).unref();
     }
 }
 
@@ -227,41 +189,36 @@ function getGCTypeValue (type) {
     return value;
 }
 
-addHandlers(listener, global.logger, 45000);
+const exitProcess = pino.final(global.logger, (err, logger, listener, signal, killTimeout) => {
+    scheduleForcedExit(killTimeout, logger);
 
-function addHandlers (listener, logger, killTimeout) {
-    process.on('uncaughtException', exitProcess(listener, logger, killTimeout));
-    process.on('unhandledRejection', exitProcess(listener, logger, killTimeout));
-    process.on('ENOMEM', exitProcess(listener, logger, killTimeout));
-    process.on('SIGINT', exitProcess(listener, logger, killTimeout));
-    process.on('SIGTERM', exitProcess(listener, logger, killTimeout));
+    logger.info(`Process has received signal: ${signal}`);
+
+    let code = 0;
+
+    if (err) {
+        code = 1;
+        logger.fatal(err);
+    }
+
+    logger.info(`Process is going to exit with code: ${code}`);
+    listener.close(() => process.exit(code));
+});
+
+function addHandlers (listener, killTimeout) {
+    process.on('uncaughtException', (err) => exitProcess(err, listener, 'uncaughtException', killTimeout));
+    process.on('unhandledRejection', (err) => exitProcess(err, listener, 'unhandledRejection', killTimeout));
+    process.on('ENOMEM', (err) => exitProcess(err, listener, 'ENOMEM', killTimeout));
+    process.on('SIGINT', () => exitProcess(null, listener, 'SIGINT', killTimeout));
+    process.on('SIGTERM', () => exitProcess(null, listener, 'SIGINT', killTimeout));
 }
 
-function exitProcess (listener, logger, killTimeout) {
-    return function exitProcessFn (signal) {
-        scheduleForcedExit(killTimeout, logger);
-
-        let code = 0;
-
-        if (!['SIGINT', 'SIGTERM'].includes(signal)) {
-            const err = signal instanceof Error ? signal : new Error(signal);
-            signal = undefined;
-            code = 1;
-
-            logger.fatal(err);
-        } else {
-            logger.info(`Process has received signal: ${signal}`);
-        }
-
-        logger.info(`Process is going to exit with code: ${code}`);
-        listener.close(() => global.log4js.shutdown(() => process.exit(code)));
-    };
-}
+addHandlers(listener, 45000);
 
 function scheduleForcedExit (killTimeout, logger) {
     // Schedule exit if there is still ongoing work to deal with
     const killTimer = setTimeout(() => {
-        logger.info('Process didn\'t close on time. Force exit');
+        global.logger.info('Process didn\'t close on time. Force exit');
         process.exit(1);
     }, killTimeout);
 
diff --git a/config/environments/development.js.example b/config/environments/development.js.example
index dc1966eb..83dfddd8 100644
--- a/config/environments/development.js.example
+++ b/config/environments/development.js.example
@@ -67,9 +67,10 @@ var config = {
         http: 'http://{{=it.user}}.localhost.lan:{{=it.port}}/api/v1/map',
         https: 'http://localhost.lan:{{=it.port}}/user/{{=it.user}}/api/v1/map'
     }
-
-    // Maximum number of connections for one process
-    // 128 is a good value with a limit of 1024 open file descriptors
+    // Specify the maximum length of the queue of pending connections for the HTTP server.
+    // The actual length will be determined by the OS through sysctl settings such as tcp_max_syn_backlog and somaxconn on Linux.
+    // The default value of this parameter is 511 (not 512).
+    // See: https://nodejs.org/docs/latest/api/net.html#net_server_listen
     ,maxConnections:128
     // Maximum number of templates per user. Unlimited by default.
     ,maxUserTemplates:1024
@@ -82,12 +83,6 @@ var config = {
     ,socket_timeout: 600000
     ,enable_cors: true
     ,cache_enabled: true
-    ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler]) (:res[X-Tiler-Errors])'
-    // If log_filename is given logs will be written
-    // there, in append mode. Otherwise stdout is used (default).
-    // Log file will be re-opened on receiving the HUP signal
-    ,log_filename: undefined
-    ,log_windshaft: true
     // Templated database username for authorized user
     // Supported labels: 'user_id' (read from redis)
     ,postgres_auth_user: 'development_cartodb_user_<%= user_id %>'
@@ -262,12 +257,6 @@ var config = {
             // the template to use for adding the host header in the batch api requests
             hostHeaderTemplate: '{{=it.username}}.localhost.lan'
         },
-        logger: {
-            // If filename is given logs comming from analysis client  will be written
-            // there, in append mode. Otherwise 'log_filename' is used. Otherwise stdout is used (default).
-            // Log file will be re-opened on receiving the HUP signal
-            filename: undefined
-        },
         // Define max execution time in ms for analyses or tags
         // If analysis or tag are not found in redis this values will be used as default.
         limits: {
diff --git a/config/environments/production.js.example b/config/environments/production.js.example
index 36dd5f8e..e343a26f 100644
--- a/config/environments/production.js.example
+++ b/config/environments/production.js.example
@@ -67,9 +67,10 @@ var config = {
         http: 'http://{{=it.cdn_url}}/{{=it.user}}/api/v1/map',
         https: 'https://{{=it.cdn_url}}/{{=it.user}}/api/v1/map'
     }
-
-    // Maximum number of connections for one process
-    // 128 is a good value with a limit of 1024 open file descriptors
+    // Specify the maximum length of the queue of pending connections for the HTTP server.
+    // The actual length will be determined by the OS through sysctl settings such as tcp_max_syn_backlog and somaxconn on Linux.
+    // The default value of this parameter is 511 (not 512).
+    // See: https://nodejs.org/docs/latest/api/net.html#net_server_listen
     ,maxConnections:128
     // Maximum number of templates per user. Unlimited by default.
     ,maxUserTemplates:1024
@@ -82,12 +83,6 @@ var config = {
     ,socket_timeout: 600000
     ,enable_cors: true
     ,cache_enabled: true
-    ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler]) (:res[X-Tiler-Errors])'
-    // If log_filename is given logs will be written
-    // there, in append mode. Otherwise stdout is used (default).
-    // Log file will be re-opened on receiving the HUP signal
-    ,log_filename: 'logs/node-windshaft.log'
-    ,log_windshaft: true
     // Templated database username for authorized user
     // Supported labels: 'user_id' (read from redis)
     ,postgres_auth_user: 'cartodb_user_<%= user_id %>'
@@ -262,12 +257,6 @@ var config = {
             // the template to use for adding the host header in the batch api requests
             hostHeaderTemplate: '{{=it.username}}.localhost.lan'
         },
-        logger: {
-            // If filename is given logs comming from analysis client  will be written
-            // there, in append mode. Otherwise 'log_filename' is used. Otherwise stdout is used (default).
-            // Log file will be re-opened on receiving the HUP signal
-            filename: 'logs/node-windshaft-analysis.log'
-        },
         // Define max execution time in ms for analyses or tags
         // If analysis or tag are not found in redis this values will be used as default.
         limits: {
diff --git a/config/environments/staging.js.example b/config/environments/staging.js.example
index 34a9f53c..f8cd61c9 100644
--- a/config/environments/staging.js.example
+++ b/config/environments/staging.js.example
@@ -67,9 +67,9 @@ var config = {
         http: 'http://{{=it.cdn_url}}/{{=it.user}}/api/v1/map',
         https: 'https://{{=it.cdn_url}}/{{=it.user}}/api/v1/map'
     }
-
-    // Maximum number of connections for one process
-    // 128 is a good value with a limit of 1024 open file descriptors
+    // Specify the maximum length of the queue of pending connections for the HTTP server.
+    // The actual length will be determined by the OS through sysctl settings such as tcp_max_syn_backlog and somaxconn on Linux.
+    // The default value of this parameter is 511 (not 512).
     ,maxConnections:128
     // Maximum number of templates per user. Unlimited by default.
     ,maxUserTemplates:1024
@@ -82,12 +82,6 @@ var config = {
     ,socket_timeout: 600000
     ,enable_cors: true
     ,cache_enabled: true
-    ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler]) (:res[X-Tiler-Errors])'
-    // If log_filename is given logs will be written
-    // there, in append mode. Otherwise stdout is used (default).
-    // Log file will be re-opened on receiving the HUP signal
-    ,log_filename: 'logs/node-windshaft.log'
-    ,log_windshaft: true
     // Templated database username for authorized user
     // Supported labels: 'user_id' (read from redis)
     ,postgres_auth_user: 'cartodb_staging_user_<%= user_id %>'
@@ -262,12 +256,6 @@ var config = {
             // the template to use for adding the host header in the batch api requests
             hostHeaderTemplate: '{{=it.username}}.localhost.lan'
         },
-        logger: {
-            // If filename is given logs comming from analysis client  will be written
-            // there, in append mode. Otherwise 'log_filename' is used. Otherwise stdout is used (default).
-            // Log file will be re-opened on receiving the HUP signal
-            filename: 'logs/node-windshaft-analysis.log'
-        },
         // Define max execution time in ms for analyses or tags
         // If analysis or tag are not found in redis this values will be used as default.
         limits: {
diff --git a/config/environments/test.js.example b/config/environments/test.js.example
index e4a94d28..413620c2 100644
--- a/config/environments/test.js.example
+++ b/config/environments/test.js.example
@@ -67,9 +67,10 @@ var config = {
         http: 'http://{{=it.user}}.localhost.lan:{{=it.port}}/api/v1/map',
         https: 'https://{{=it.user}}.localhost.lan:{{=it.port}}/api/v1/map'
     }
-
-    // Maximum number of connections for one process
-    // 128 is a good value with a limit of 1024 open file descriptors
+    // Specify the maximum length of the queue of pending connections for the HTTP server.
+    // The actual length will be determined by the OS through sysctl settings such as tcp_max_syn_backlog and somaxconn on Linux.
+    // The default value of this parameter is 511 (not 512).
+    // See: https://nodejs.org/docs/latest/api/net.html#net_server_listen
     ,maxConnections:128
     // Maximum number of templates per user. Unlimited by default.
     ,maxUserTemplates:1024
@@ -82,12 +83,6 @@ var config = {
     ,socket_timeout: 600000
     ,enable_cors: true
     ,cache_enabled: false
-    ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler]) (:res[X-Tiler-Errors])'
-    // If log_filename is given logs will be written
-    // there, in append mode. Otherwise stdout is used (default).
-    // Log file will be re-opened on receiving the HUP signal
-    ,log_filename: '/tmp/node-windshaft.log'
-    ,log_windshaft: true
     // Templated database username for authorized user
     // Supported labels: 'user_id' (read from redis)
     ,postgres_auth_user: 'test_windshaft_cartodb_user_<%= user_id %>'
@@ -264,12 +259,6 @@ var config = {
             // the template to use for adding the host header in the batch api requests
             hostHeaderTemplate: '{{=it.username}}.localhost.lan'
         },
-        logger: {
-            // If filename is given logs comming from analysis client  will be written
-            // there, in append mode. Otherwise 'log_filename' is used. Otherwise stdout is used (default).
-            // Log file will be re-opened on receiving the HUP signal
-            filename: '/tmp/node-windshaft-analysis.log'
-        },
         // Define max execution time in ms for analyses or tags
         // If analysis or tag are not found in redis this values will be used as default.
         limits: {
diff --git a/lib/api/api-router.js b/lib/api/api-router.js
index 466a6b01..9ce4fa2d 100644
--- a/lib/api/api-router.js
+++ b/lib/api/api-router.js
@@ -83,15 +83,11 @@ module.exports = class ApiRouter {
             global.statsClient.gauge(keyPrefix + 'waiting', status.waiting);
         });
 
-        const windshaftLogger = environmentOptions.log_windshaft && global.log4js
-            ? global.log4js.getLogger('[windshaft]')
-            : null;
-
         const { rendererCache, tileBackend, attributesBackend, previewBackend, mapBackend, mapStore } = windshaftFactory({
             rendererOptions: serverOptions,
             redisPool,
             onTileErrorStrategy: getOnTileErrorStrategy({ enabled: environmentOptions.enabledFeatures.onTileErrorStrategy }),
-            logger: windshaftLogger
+            logger: global.logger
         });
 
         const rendererStatsReporter = new RendererStatsReporter(rendererCache, serverOptions.renderCache.statsInterval);
@@ -205,7 +201,7 @@ module.exports = class ApiRouter {
 
             middlewares.forEach(middleware => apiRouter.use(middleware()));
 
-            apiRouter.use(logger(this.serverOptions));
+            apiRouter.use(logger());
             apiRouter.use(initializeStatusCode());
             apiRouter.use(bodyParser.json());
             apiRouter.use(servedByHostHeader());
@@ -235,20 +231,14 @@ function createTemplateMaps ({ redisPool, surrogateKeysCache }) {
         max_user_templates: global.environment.maxUserTemplates
     });
 
-    function invalidateNamedMap (owner, templateName) {
-        var startTime = Date.now();
-        surrogateKeysCache.invalidate(new NamedMapsCacheEntry(owner, templateName), function (err) {
-            var logMessage = JSON.stringify({
-                username: owner,
-                type: 'named_map_invalidation',
-                elapsed: Date.now() - startTime,
-                error: err ? JSON.stringify(err.message) : undefined
-            });
+    function invalidateNamedMap (user, templateName) {
+        const startTime = Date.now();
+        surrogateKeysCache.invalidate(new NamedMapsCacheEntry(user, templateName), (err) => {
             if (err) {
-                global.logger.warn(logMessage);
-            } else {
-                global.logger.info(logMessage);
+                return global.logger.error(err);
             }
+
+            global.logger.info({ user, type: 'named_map_invalidation', elapsed: Date.now() - startTime });
         });
     }
 
diff --git a/lib/api/map/preview-template-controller.js b/lib/api/map/preview-template-controller.js
index d3c5884f..e9dc547d 100644
--- a/lib/api/map/preview-template-controller.js
+++ b/lib/api/map/preview-template-controller.js
@@ -347,7 +347,7 @@ function incrementMapViews ({ metadataBackend }) {
 
         mapConfigProvider.getMapConfig((err, mapConfig) => {
             if (err) {
-                global.logger.log(incrementMapViewsError({ user, err }));
+                global.logger.info(incrementMapViewsError({ user, err }));
                 return next();
             }
 
@@ -359,7 +359,7 @@ function incrementMapViews ({ metadataBackend }) {
 
             metadataBackend.incMapviewCount(user, statTag, (err) => {
                 if (err) {
-                    global.logger.log(incrementMapViewsError({ user, err }));
+                    global.logger.info(incrementMapViewsError({ user, err }));
                 }
 
                 next();
diff --git a/lib/api/middlewares/cache-channel-header.js b/lib/api/middlewares/cache-channel-header.js
index 03b3d2e1..c93cce57 100644
--- a/lib/api/middlewares/cache-channel-header.js
+++ b/lib/api/middlewares/cache-channel-header.js
@@ -10,7 +10,7 @@ module.exports = function setCacheChannelHeader () {
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                global.logger.warn('ERROR generating Cache Channel Header:', err);
+                global.logger.warn(err, 'ERROR generating Cache Channel Header');
                 return next();
             }
 
diff --git a/lib/api/middlewares/cache-control-header.js b/lib/api/middlewares/cache-control-header.js
index 4043668a..7afed19f 100644
--- a/lib/api/middlewares/cache-control-header.js
+++ b/lib/api/middlewares/cache-control-header.js
@@ -44,7 +44,7 @@ module.exports = function setCacheControlHeader ({
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                global.logger.warn('ERROR generating Cache Control Header:', err);
+                global.logger.warn(err, 'ERROR generating Cache Control Header');
                 return next();
             }
 
diff --git a/lib/api/middlewares/increment-map-view-count.js b/lib/api/middlewares/increment-map-view-count.js
index 18adb34c..7617375f 100644
--- a/lib/api/middlewares/increment-map-view-count.js
+++ b/lib/api/middlewares/increment-map-view-count.js
@@ -14,7 +14,7 @@ module.exports = function incrementMapViewCount (metadataBackend) {
             req.profiler.done('incMapviewCount');
 
             if (err) {
-                global.logger.log(`ERROR: failed to increment mapview count for user '${user}': ${err.message}`);
+                global.logger.warn(err, `ERROR: failed to increment mapview count for user '${user}'`);
             }
 
             next();
diff --git a/lib/api/middlewares/last-modified-header.js b/lib/api/middlewares/last-modified-header.js
index 4afd283f..8f1dd296 100644
--- a/lib/api/middlewares/last-modified-header.js
+++ b/lib/api/middlewares/last-modified-header.js
@@ -21,7 +21,7 @@ module.exports = function setLastModifiedHeader () {
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                global.logger.warn('ERROR generating Last Modified Header:', err);
+                global.logger.warn(err, 'ERROR generating Last Modified Header');
                 return next();
             }
 
diff --git a/lib/api/middlewares/logger.js b/lib/api/middlewares/logger.js
index da198d64..acebdb88 100644
--- a/lib/api/middlewares/logger.js
+++ b/lib/api/middlewares/logger.js
@@ -1,24 +1,15 @@
 'use strict';
 
-module.exports = function logger (options) {
-    if (!global.log4js || !options.log_format) {
-        return function dummyLoggerMiddleware (req, res, next) {
-            next();
-        };
-    }
+const uuid = require('uuid');
 
-    const opts = {
-        level: 'info',
-        // Allowing for unbuffered logging is mainly
-        // used to avoid hanging during unit testing.
-        // TODO: provide an explicit teardown function instead,
-        //       releasing any event handler or timer set by
-        //       this component.
-        buffer: !options.unbuffered_logging,
-        // optional log format
-        format: options.log_format
+module.exports = function logger () {
+    return function loggerMiddleware (req, res, next) {
+        const id = req.get('X-Request-Id') || uuid.v4();
+        res.locals.logger = global.logger.child({ id });
+
+        res.locals.logger.info(req);
+        res.on('finish', () => res.locals.logger.info(res));
+
+        next();
     };
-    const logger = global.log4js.getLogger();
-
-    return global.log4js.connectLogger(logger, opts);
 };
diff --git a/lib/api/middlewares/metrics.js b/lib/api/middlewares/metrics.js
index e5c36a01..4ac0ebf6 100644
--- a/lib/api/middlewares/metrics.js
+++ b/lib/api/middlewares/metrics.js
@@ -19,7 +19,7 @@ module.exports = function metrics ({ enabled, tags, metricsBackend, logger }) {
             const { event, attributes } = getEventData(req, res, tags);
 
             metricsBackend.send(event, attributes)
-                .catch((error) => logger.error(`Failed to publish event "${event}": ${error.message}`));
+                .catch((err) => logger.error(err, `Failed to publish event "${event}"`));
         });
 
         return next();
diff --git a/lib/api/middlewares/surrogate-key-header.js b/lib/api/middlewares/surrogate-key-header.js
index d46c95f8..a3b1e039 100644
--- a/lib/api/middlewares/surrogate-key-header.js
+++ b/lib/api/middlewares/surrogate-key-header.js
@@ -17,7 +17,7 @@ module.exports = function setSurrogateKeyHeader ({ surrogateKeysCache }) {
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                global.logger.warn('ERROR generating Surrogate Key Header:', err);
+                global.logger.warn(err, 'ERROR generating Surrogate Key Header');
                 return next();
             }
 
diff --git a/lib/backends/analysis.js b/lib/backends/analysis.js
index b33f928f..2844a028 100644
--- a/lib/backends/analysis.js
+++ b/lib/backends/analysis.js
@@ -2,7 +2,6 @@
 
 var _ = require('underscore');
 var camshaft = require('camshaft');
-var fs = require('fs');
 
 var REDIS_LIMITS = {
     DB: 5,
@@ -14,7 +13,6 @@ function AnalysisBackend (metadataBackend, options) {
     this.options = options || {};
     this.options.limits = this.options.limits || {};
     this.setBatchConfig(this.options.batch);
-    this.setLoggerConfig(this.options.logger);
 }
 
 module.exports = AnalysisBackend;
@@ -27,30 +25,12 @@ AnalysisBackend.prototype.setBatchConfig = function (options) {
     this.batchConfig = batchConfig;
 };
 
-AnalysisBackend.prototype.setLoggerConfig = function (options) {
-    this.loggerConfig = options || {};
-
-    if (this.loggerConfig.filename) {
-        this.stream = fs.createWriteStream(this.loggerConfig.filename, { flags: 'a', encoding: 'utf8' });
-
-        process.on('SIGHUP', function () {
-            if (this.stream) {
-                this.stream.destroy();
-            }
-
-            this.stream = fs.createWriteStream(this.loggerConfig.filename, { flags: 'a', encoding: 'utf8' });
-        }.bind(this));
-    }
-};
-
 AnalysisBackend.prototype.create = function (analysisConfiguration, analysisDefinition, callback) {
     analysisConfiguration.batch.endpoint = this.batchConfig.endpoint;
     analysisConfiguration.batch.inlineExecution = this.batchConfig.inlineExecution;
     analysisConfiguration.batch.hostHeaderTemplate = this.batchConfig.hostHeaderTemplate;
 
-    analysisConfiguration.logger = {
-        stream: this.stream ? this.stream : process.stdout
-    };
+    analysisConfiguration.logger = global.logger;
 
     this.getAnalysesLimits(analysisConfiguration.user, function (err, limits) {
         if (err) {}
diff --git a/lib/models/cdb-request.js b/lib/models/cdb-request.js
index d449db12..54b3db5c 100644
--- a/lib/models/cdb-request.js
+++ b/lib/models/cdb-request.js
@@ -10,17 +10,20 @@ module.exports = CdbRequest;
 
 CdbRequest.prototype.userByReq = function (req) {
     var host = req.headers.host || '';
+
     if (req.params.user) {
         return req.params.user;
     }
+
     var mat = host.match(this.RE_USER_FROM_HOST);
+
     if (!mat) {
-        global.logger.error("Pattern '%s' does not match hostname '%s'", this.RE_USER_FROM_HOST, host);
-        return;
+        return global.logger.error(new Error(`Pattern '${this.RE_USER_FROM_HOST}' does not match hostname '${host}'`));
     }
+
     if (mat.length !== 2) {
-        global.logger.error("Pattern '%s' gave unexpected matches against '%s': %s", this.RE_USER_FROM_HOST, host, mat);
-        return;
+        return global.logger.error(new Error(`Pattern '${this.RE_USER_FROM_HOST}' gave unexpected matches against '${host}': ${mat}`));
     }
+
     return mat[1];
 };
diff --git a/lib/server-options.js b/lib/server-options.js
index 8b3ced76..26b14714 100644
--- a/lib/server-options.js
+++ b/lib/server-options.js
@@ -52,9 +52,6 @@ var analysisConfig = _.defaults(global.environment.analysis || {}, {
         endpoint: 'http://127.0.0.1:8080/api/v2/sql/job',
         hostHeaderTemplate: '{{=it.username}}.localhost.lan'
     },
-    logger: {
-        filename: undefined
-    },
     limits: {}
 });
 
@@ -118,9 +115,6 @@ module.exports = {
             endpoint: analysisConfig.batch.endpoint,
             hostHeaderTemplate: analysisConfig.batch.hostHeaderTemplate
         },
-        logger: {
-            filename: analysisConfig.logger.filename
-        },
         limits: analysisConfig.limits
     },
     // Do not send unwatch on release. See http://github.com/CartoDB/Windshaft-cartodb/issues/161
diff --git a/package-lock.json b/package-lock.json
index c79666b4..4eb1f3c8 100644
--- a/package-lock.json
+++ b/package-lock.json
@@ -272,6 +272,12 @@
         "protobufjs": "^6.8.6"
       }
     },
+    "@hapi/bourne": {
+      "version": "2.0.0",
+      "resolved": "https://registry.npmjs.org/@hapi/bourne/-/bourne-2.0.0.tgz",
+      "integrity": "sha512-WEezM1FWztfbzqIUbsDzFRVMxSoLy3HugVcux6KDDtTqzPsLE8NDRHfXvev66aH1i2oOKKar3/XDjbvh/OUBdg==",
+      "dev": true
+    },
     "@mapbox/sphericalmercator": {
       "version": "1.1.0",
       "resolved": "https://registry.npmjs.org/@mapbox/sphericalmercator/-/sphericalmercator-1.1.0.tgz",
@@ -533,6 +539,61 @@
         "sprintf-js": "~1.0.2"
       }
     },
+    "args": {
+      "version": "5.0.1",
+      "resolved": "https://registry.npmjs.org/args/-/args-5.0.1.tgz",
+      "integrity": "sha512-1kqmFCFsPffavQFGt8OxJdIcETti99kySRUPMpOhaGjL6mRJn8HFU1OxKY5bMqfZKUwTQc1mZkAjmGYaVOHFtQ==",
+      "dev": true,
+      "requires": {
+        "camelcase": "5.0.0",
+        "chalk": "2.4.2",
+        "leven": "2.1.0",
+        "mri": "1.1.4"
+      },
+      "dependencies": {
+        "ansi-styles": {
+          "version": "3.2.1",
+          "resolved": "https://registry.npmjs.org/ansi-styles/-/ansi-styles-3.2.1.tgz",
+          "integrity": "sha512-VT0ZI6kZRdTh8YyJw3SMbYm/u+NqfsAxEpWO0Pf9sq8/e94WxxOpPKx9FR1FlyCtOVDNOQ+8ntlqFxiRc+r5qA==",
+          "dev": true,
+          "requires": {
+            "color-convert": "^1.9.0"
+          }
+        },
+        "camelcase": {
+          "version": "5.0.0",
+          "resolved": "https://registry.npmjs.org/camelcase/-/camelcase-5.0.0.tgz",
+          "integrity": "sha512-faqwZqnWxbxn+F1d399ygeamQNy3lPp/H9H6rNrqYh4FSVCtcY+3cub1MxA8o9mDd55mM8Aghuu/kuyYA6VTsA==",
+          "dev": true
+        },
+        "chalk": {
+          "version": "2.4.2",
+          "resolved": "https://registry.npmjs.org/chalk/-/chalk-2.4.2.tgz",
+          "integrity": "sha512-Mti+f9lpJNcwF4tWV8/OrTTtF1gZi+f8FqlyAdouralcFWFQWF2+NgCHShjkCb+IFBLq9buZwE1xckQU4peSuQ==",
+          "dev": true,
+          "requires": {
+            "ansi-styles": "^3.2.1",
+            "escape-string-regexp": "^1.0.5",
+            "supports-color": "^5.3.0"
+          }
+        },
+        "has-flag": {
+          "version": "3.0.0",
+          "resolved": "https://registry.npmjs.org/has-flag/-/has-flag-3.0.0.tgz",
+          "integrity": "sha1-tdRU3CGZriJWmfNGfloH87lVuv0=",
+          "dev": true
+        },
+        "supports-color": {
+          "version": "5.5.0",
+          "resolved": "https://registry.npmjs.org/supports-color/-/supports-color-5.5.0.tgz",
+          "integrity": "sha512-QjVjwdXIt408MIiAqCX4oUKsgU2EqAGzs2Ppkm4aQYbjm+ZEWEcW4SfFNTr4uMNZma0ey4f5lgLrkB0aX0QMow==",
+          "dev": true,
+          "requires": {
+            "has-flag": "^3.0.0"
+          }
+        }
+      }
+    },
     "array-flatten": {
       "version": "1.1.1",
       "resolved": "https://registry.npmjs.org/array-flatten/-/array-flatten-1.1.1.tgz",
@@ -593,6 +654,11 @@
       "resolved": "https://registry.npmjs.org/asynckit/-/asynckit-0.4.0.tgz",
       "integrity": "sha1-x57Zf380y48robyXkLzDZkdLS3k="
     },
+    "atomic-sleep": {
+      "version": "1.0.0",
+      "resolved": "https://registry.npmjs.org/atomic-sleep/-/atomic-sleep-1.0.0.tgz",
+      "integrity": "sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ=="
+    },
     "aws-sign2": {
       "version": "0.7.0",
       "resolved": "https://registry.npmjs.org/aws-sign2/-/aws-sign2-0.7.0.tgz",
@@ -701,17 +767,6 @@
       "resolved": "https://registry.npmjs.org/buffer-writer/-/buffer-writer-1.0.1.tgz",
       "integrity": "sha1-Iqk2kB4wKa/NdUfrRIfOtpejvwg="
     },
-    "bunyan": {
-      "version": "1.8.1",
-      "resolved": "https://registry.npmjs.org/bunyan/-/bunyan-1.8.1.tgz",
-      "integrity": "sha1-aMakpQLVYgvJ9y1nNoEMGxiYCX8=",
-      "requires": {
-        "dtrace-provider": "~0.6",
-        "moment": "^2.10.6",
-        "mv": "~2",
-        "safe-json-stringify": "~1"
-      }
-    },
     "bytes": {
       "version": "3.0.0",
       "resolved": "https://registry.npmjs.org/bytes/-/bytes-3.0.0.tgz",
@@ -741,16 +796,15 @@
       "integrity": "sha1-MvxLn82vhF/N9+c7uXysImHwqwo="
     },
     "camshaft": {
-      "version": "0.65.3",
-      "resolved": "https://registry.npmjs.org/camshaft/-/camshaft-0.65.3.tgz",
-      "integrity": "sha512-URr3gWV1QtUATYXQzCTTc7Z1sjlc4ZDTdm+qsOhrOll5ieU1BXkO8puIe8Ts7pwMHH2cLgEy1Ddh+a/V8QMt7A==",
+      "version": "github:cartodb/camshaft#8d8f62d3d98b4ac316d8444ac3f3f321c28040dc",
+      "from": "github:cartodb/camshaft#dgaubert/ch78389/camshaft-replace-logger-from-bunyan-to-pino",
       "requires": {
         "async": "^1.5.2",
-        "bunyan": "1.8.1",
         "cartodb-psql": "0.14.0",
         "cartodb-query-tables": "^0.6.1",
         "debug": "^3.1.0",
         "dot": "^1.0.3",
+        "pino": "^6.3.1",
         "request": "^2.85.0"
       },
       "dependencies": {
@@ -1102,6 +1156,12 @@
         "assert-plus": "^1.0.0"
       }
     },
+    "dateformat": {
+      "version": "3.0.3",
+      "resolved": "https://registry.npmjs.org/dateformat/-/dateformat-3.0.3.tgz",
+      "integrity": "sha512-jyCETtSl3VMZMWeRo7iY1FL19ges1t55hMo5yaam4Jrsm5EPL89UQkoQRyiI+Yf4k8r2ZpdngkV8hr1lIdjb3Q==",
+      "dev": true
+    },
     "debug": {
       "version": "3.1.0",
       "resolved": "https://registry.npmjs.org/debug/-/debug-3.1.0.tgz",
@@ -1236,15 +1296,6 @@
       "integrity": "sha1-ED01J/0xUo9AGIEwyEHv3XgmTlw=",
       "dev": true
     },
-    "dtrace-provider": {
-      "version": "0.6.0",
-      "resolved": "https://registry.npmjs.org/dtrace-provider/-/dtrace-provider-0.6.0.tgz",
-      "integrity": "sha1-CweNVReTfYcxAUUtkUZzdVe3XlE=",
-      "optional": true,
-      "requires": {
-        "nan": "^2.0.8"
-      }
-    },
     "duplexify": {
       "version": "3.7.1",
       "resolved": "https://registry.npmjs.org/duplexify/-/duplexify-3.7.1.tgz",
@@ -2022,6 +2073,16 @@
       "integrity": "sha1-PYpcZog6FqMMqGQ+hR8Zuqd5eRc=",
       "dev": true
     },
+    "fast-redact": {
+      "version": "2.0.0",
+      "resolved": "https://registry.npmjs.org/fast-redact/-/fast-redact-2.0.0.tgz",
+      "integrity": "sha512-zxpkULI9W9MNTK2sJ3BpPQrTEXFNESd2X6O1tXMFpK/XM0G5c5Rll2EVYZH2TqI3xRGK/VaJ+eEOt7pnENJpeA=="
+    },
+    "fast-safe-stringify": {
+      "version": "2.0.7",
+      "resolved": "https://registry.npmjs.org/fast-safe-stringify/-/fast-safe-stringify-2.0.7.tgz",
+      "integrity": "sha512-Utm6CdzT+6xsDk2m8S6uL8VHxNwI6Jub+e9NYTcAms28T84pTa25GJQV9j0CY0N1rM8hK4x6grpF2BQf+2qwVA=="
+    },
     "fast-text-encoding": {
       "version": "1.0.0",
       "resolved": "https://registry.npmjs.org/fast-text-encoding/-/fast-text-encoding-1.0.0.tgz",
@@ -2216,6 +2277,11 @@
         }
       }
     },
+    "flatstr": {
+      "version": "1.0.12",
+      "resolved": "https://registry.npmjs.org/flatstr/-/flatstr-1.0.12.tgz",
+      "integrity": "sha512-4zPxDyhCyiN2wIAtSLI6gc82/EjqZc1onI4Mz/l0pWrAlsSfYH/2ZIcU+e3oA2wDwbzIWNKwa23F8rh6+DRWkw=="
+    },
     "flatted": {
       "version": "2.0.1",
       "resolved": "https://registry.npmjs.org/flatted/-/flatted-2.0.1.tgz",
@@ -3406,11 +3472,6 @@
       "resolved": "https://registry.npmjs.org/is-utf8/-/is-utf8-0.2.1.tgz",
       "integrity": "sha1-Sw2hRCEE0bM2NA6AeX6GXPOffXI="
     },
-    "isarray": {
-      "version": "0.0.1",
-      "resolved": "https://registry.npmjs.org/isarray/-/isarray-0.0.1.tgz",
-      "integrity": "sha1-ihis/Kmo9Bd+Cav8YDiTmwXR7t8="
-    },
     "isexe": {
       "version": "2.0.0",
       "resolved": "https://registry.npmjs.org/isexe/-/isexe-2.0.0.tgz",
@@ -3556,6 +3617,18 @@
         "html-escaper": "^2.0.0"
       }
     },
+    "jmespath": {
+      "version": "0.15.0",
+      "resolved": "https://registry.npmjs.org/jmespath/-/jmespath-0.15.0.tgz",
+      "integrity": "sha1-o/Iiqarp+Wb10nx5ZRDigJF2Qhc=",
+      "dev": true
+    },
+    "joycon": {
+      "version": "2.2.5",
+      "resolved": "https://registry.npmjs.org/joycon/-/joycon-2.2.5.tgz",
+      "integrity": "sha512-YqvUxoOcVPnCp0VU1/56f+iKSdvIRJYPznH22BdXV3xMk75SFXhWeJkZ8C9XxUWt1b5x2X1SxuFygW1U0FmkEQ==",
+      "dev": true
+    },
     "js-base64": {
       "version": "2.5.1",
       "resolved": "https://registry.npmjs.org/js-base64/-/js-base64-2.5.1.tgz",
@@ -3665,6 +3738,12 @@
         "invert-kv": "^1.0.0"
       }
     },
+    "leven": {
+      "version": "2.1.0",
+      "resolved": "https://registry.npmjs.org/leven/-/leven-2.1.0.tgz",
+      "integrity": "sha1-wuep93IJTe6dNCAq6KzORoeHVYA=",
+      "dev": true
+    },
     "levn": {
       "version": "0.3.0",
       "resolved": "https://registry.npmjs.org/levn/-/levn-0.3.0.tgz",
@@ -3787,33 +3866,6 @@
         }
       }
     },
-    "log4js": {
-      "version": "github:cartodb/log4js-node#145d5f91e35e7fb14a6278cbf7a711ced6603727",
-      "from": "github:cartodb/log4js-node#cdb",
-      "requires": {
-        "async": "~0.2.0",
-        "readable-stream": "~1.0.2",
-        "semver": "~4.3.3",
-        "underscore": "1.8.2"
-      },
-      "dependencies": {
-        "async": {
-          "version": "0.2.10",
-          "resolved": "https://registry.npmjs.org/async/-/async-0.2.10.tgz",
-          "integrity": "sha1-trvgsGdLnXGXCMo43owjfLUmw9E="
-        },
-        "semver": {
-          "version": "4.3.6",
-          "resolved": "https://registry.npmjs.org/semver/-/semver-4.3.6.tgz",
-          "integrity": "sha1-MAvG4OhjdPe6YQaLWx7NV/xlMto="
-        },
-        "underscore": {
-          "version": "1.8.2",
-          "resolved": "https://registry.npmjs.org/underscore/-/underscore-1.8.2.tgz",
-          "integrity": "sha1-ZN8utZCJnelQeC83NRkLpC6/MR0="
-        }
-      }
-    },
     "long": {
       "version": "4.0.0",
       "resolved": "https://registry.npmjs.org/long/-/long-4.0.0.tgz",
@@ -4261,7 +4313,14 @@
     "moment": {
       "version": "2.22.1",
       "resolved": "https://registry.npmjs.org/moment/-/moment-2.22.1.tgz",
-      "integrity": "sha512-shJkRTSebXvsVqk56I+lkb2latjBs8I+pc2TzWc545y2iFnSjm7Wg0QMh+ZWcdSLQyGEau5jI8ocnmkyTgr9YQ=="
+      "integrity": "sha512-shJkRTSebXvsVqk56I+lkb2latjBs8I+pc2TzWc545y2iFnSjm7Wg0QMh+ZWcdSLQyGEau5jI8ocnmkyTgr9YQ==",
+      "dev": true
+    },
+    "mri": {
+      "version": "1.1.4",
+      "resolved": "https://registry.npmjs.org/mri/-/mri-1.1.4.tgz",
+      "integrity": "sha512-6y7IjGPm8AzlvoUrwAaw1tLnUBudaS3752vcd8JtrpGGQn+rXIe63LFVHm/YMwtqAuh+LJPCFdlLYPWM1nYn6w==",
+      "dev": true
     },
     "ms": {
       "version": "2.0.0",
@@ -4274,17 +4333,6 @@
       "integrity": "sha1-MHXOk7whuPq0PhvE2n6BFe0ee6s=",
       "dev": true
     },
-    "mv": {
-      "version": "2.1.1",
-      "resolved": "https://registry.npmjs.org/mv/-/mv-2.1.1.tgz",
-      "integrity": "sha1-rmzg1vbV4KT32JN5jQPB6pVZtqI=",
-      "optional": true,
-      "requires": {
-        "mkdirp": "~0.5.1",
-        "ncp": "~2.0.0",
-        "rimraf": "~2.4.0"
-      }
-    },
     "nan": {
       "version": "2.14.0",
       "resolved": "https://registry.npmjs.org/nan/-/nan-2.14.0.tgz",
@@ -4296,12 +4344,6 @@
       "integrity": "sha1-Sr6/7tdUHywnrPspvbvRXI1bpPc=",
       "dev": true
     },
-    "ncp": {
-      "version": "2.0.0",
-      "resolved": "https://registry.npmjs.org/ncp/-/ncp-2.0.0.tgz",
-      "integrity": "sha1-GVoh1sRuNh0vsSgbo4uR6d9727M=",
-      "optional": true
-    },
     "needle": {
       "version": "2.3.3",
       "resolved": "https://registry.npmjs.org/needle/-/needle-2.3.3.tgz",
@@ -4674,6 +4716,12 @@
             "ansi-regex": "^4.1.0"
           }
         },
+        "uuid": {
+          "version": "3.4.0",
+          "resolved": "https://registry.npmjs.org/uuid/-/uuid-3.4.0.tgz",
+          "integrity": "sha512-HjSDRw6gZE5JMggctHBcjVak08+KEVhSIiDzFnT9S9aegmp85S/bReBVTb4QTFaRNptJ9kuYaNhnbNEOkbKb/A==",
+          "dev": true
+        },
         "which-module": {
           "version": "2.0.0",
           "resolved": "https://registry.npmjs.org/which-module/-/which-module-2.0.0.tgz",
@@ -5154,6 +5202,101 @@
         "pinkie": "^2.0.0"
       }
     },
+    "pino": {
+      "version": "6.3.1",
+      "resolved": "https://registry.npmjs.org/pino/-/pino-6.3.1.tgz",
+      "integrity": "sha512-RgT010a5FfnxJ2AwB0TqcEuM+gNsnd08PZnCob98JSTLldLF0GMFJ/Z1VE/rdl5yJCqcoLwftmZSwSFY4/Hc2g==",
+      "requires": {
+        "fast-redact": "^2.0.0",
+        "fast-safe-stringify": "^2.0.7",
+        "flatstr": "^1.0.12",
+        "pino-std-serializers": "^2.4.2",
+        "quick-format-unescaped": "^4.0.1",
+        "sonic-boom": "^1.0.0"
+      }
+    },
+    "pino-pretty": {
+      "version": "4.0.0",
+      "resolved": "https://registry.npmjs.org/pino-pretty/-/pino-pretty-4.0.0.tgz",
+      "integrity": "sha512-YLy/n3dMXYWOodSm530gelkSAJGmEp29L9pqiycInlIae5FEJPWAkMRO3JFMbIFtjD2Ve4SH2aBcz2aRreGpBQ==",
+      "dev": true,
+      "requires": {
+        "@hapi/bourne": "^2.0.0",
+        "args": "^5.0.1",
+        "chalk": "^3.0.0",
+        "dateformat": "^3.0.3",
+        "fast-safe-stringify": "^2.0.7",
+        "jmespath": "^0.15.0",
+        "joycon": "^2.2.5",
+        "pump": "^3.0.0",
+        "readable-stream": "^3.6.0",
+        "split2": "^3.1.1",
+        "strip-json-comments": "^3.0.1"
+      },
+      "dependencies": {
+        "ansi-styles": {
+          "version": "4.2.1",
+          "resolved": "https://registry.npmjs.org/ansi-styles/-/ansi-styles-4.2.1.tgz",
+          "integrity": "sha512-9VGjrMsG1vePxcSweQsN20KY/c4zN0h9fLjqAbwbPfahM3t+NL+M9HC8xeXG2I8pX5NoamTGNuomEUFI7fcUjA==",
+          "dev": true,
+          "requires": {
+            "@types/color-name": "^1.1.1",
+            "color-convert": "^2.0.1"
+          }
+        },
+        "chalk": {
+          "version": "3.0.0",
+          "resolved": "https://registry.npmjs.org/chalk/-/chalk-3.0.0.tgz",
+          "integrity": "sha512-4D3B6Wf41KOYRFdszmDqMCGq5VV/uMAB273JILmO+3jAlh8X4qDtdtgCR3fxtbLEMzSx22QdhnDcJvu2u1fVwg==",
+          "dev": true,
+          "requires": {
+            "ansi-styles": "^4.1.0",
+            "supports-color": "^7.1.0"
+          }
+        },
+        "color-convert": {
+          "version": "2.0.1",
+          "resolved": "https://registry.npmjs.org/color-convert/-/color-convert-2.0.1.tgz",
+          "integrity": "sha512-RRECPsj7iu/xb5oKYcsFHSppFNnsj/52OVTRKb4zP5onXwVF3zVmmToNcOfGC+CRDpfK/U584fMg38ZHCaElKQ==",
+          "dev": true,
+          "requires": {
+            "color-name": "~1.1.4"
+          }
+        },
+        "color-name": {
+          "version": "1.1.4",
+          "resolved": "https://registry.npmjs.org/color-name/-/color-name-1.1.4.tgz",
+          "integrity": "sha512-dOy+3AuW3a2wNbZHIuMZpTcgjGuLU/uBL/ubcZF9OXbDo8ff4O8yVp5Bf0efS8uEoYo5q4Fx7dY9OgQGXgAsQA==",
+          "dev": true
+        },
+        "has-flag": {
+          "version": "4.0.0",
+          "resolved": "https://registry.npmjs.org/has-flag/-/has-flag-4.0.0.tgz",
+          "integrity": "sha512-EykJT/Q1KjTWctppgIAgfSO0tKVuZUjhgMr17kqTumMl6Afv3EISleU7qZUzoXDFTAHTDC4NOoG/ZxU3EvlMPQ==",
+          "dev": true
+        },
+        "strip-json-comments": {
+          "version": "3.1.0",
+          "resolved": "https://registry.npmjs.org/strip-json-comments/-/strip-json-comments-3.1.0.tgz",
+          "integrity": "sha512-e6/d0eBu7gHtdCqFt0xJr642LdToM5/cN4Qb9DbHjVx1CP5RyeM+zH7pbecEmDv/lBqb0QH+6Uqq75rxFPkM0w==",
+          "dev": true
+        },
+        "supports-color": {
+          "version": "7.1.0",
+          "resolved": "https://registry.npmjs.org/supports-color/-/supports-color-7.1.0.tgz",
+          "integrity": "sha512-oRSIpR8pxT1Wr2FquTNnGet79b3BWljqOuoW/h4oBhxJ/HUbX5nX6JSruTkvXDCFMwDPvsaTTbvMLKZWSy0R5g==",
+          "dev": true,
+          "requires": {
+            "has-flag": "^4.0.0"
+          }
+        }
+      }
+    },
+    "pino-std-serializers": {
+      "version": "2.4.2",
+      "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-2.4.2.tgz",
+      "integrity": "sha512-WaL504dO8eGs+vrK+j4BuQQq6GLKeCCcHaMB2ItygzVURcL1CycwNEUHTD/lHFHs/NL5qAz2UKrjYWXKSf4aMQ=="
+    },
     "pkg-dir": {
       "version": "2.0.0",
       "resolved": "https://registry.npmjs.org/pkg-dir/-/pkg-dir-2.0.0.tgz",
@@ -5305,6 +5448,16 @@
       "resolved": "https://registry.npmjs.org/pseudomap/-/pseudomap-1.0.2.tgz",
       "integrity": "sha1-8FKijacOYYkX7wqKw0wa5aaChrM="
     },
+    "pump": {
+      "version": "3.0.0",
+      "resolved": "https://registry.npmjs.org/pump/-/pump-3.0.0.tgz",
+      "integrity": "sha512-LwZy+p3SFs1Pytd/jYct4wpv49HiYCqd9Rlc5ZVdk0V+8Yzv6jR5Blk3TRmPL1ft69TxP0IMZGJ+WPFU2BFhww==",
+      "dev": true,
+      "requires": {
+        "end-of-stream": "^1.1.0",
+        "once": "^1.3.1"
+      }
+    },
     "punycode": {
       "version": "1.4.1",
       "resolved": "https://registry.npmjs.org/punycode/-/punycode-1.4.1.tgz",
@@ -5320,6 +5473,11 @@
       "resolved": "https://registry.npmjs.org/queue-async/-/queue-async-1.1.0.tgz",
       "integrity": "sha1-1fiOMv0B/uT22UbSHRer0WrGXzU="
     },
+    "quick-format-unescaped": {
+      "version": "4.0.1",
+      "resolved": "https://registry.npmjs.org/quick-format-unescaped/-/quick-format-unescaped-4.0.1.tgz",
+      "integrity": "sha512-RyYpQ6Q5/drsJyOhrWHYMWTedvjTIat+FTwv0K4yoUxzvekw2aRHMQJLlnvt8UantkZg2++bEzD9EdxXqkWf4A=="
+    },
     "range-parser": {
       "version": "1.2.1",
       "resolved": "https://registry.npmjs.org/range-parser/-/range-parser-1.2.1.tgz",
@@ -5374,14 +5532,14 @@
       }
     },
     "readable-stream": {
-      "version": "1.0.34",
-      "resolved": "https://registry.npmjs.org/readable-stream/-/readable-stream-1.0.34.tgz",
-      "integrity": "sha1-Elgg40vIQtLyqq+v5MKRbuMsFXw=",
+      "version": "3.6.0",
+      "resolved": "https://registry.npmjs.org/readable-stream/-/readable-stream-3.6.0.tgz",
+      "integrity": "sha512-BViHy7LKeTz4oNnkcLJ+lVSL6vpiFeX6/d3oSH8zCW7UxP2onchk+vTGB143xuFjHS3deTgkKoXXymXqymiIdA==",
+      "dev": true,
       "requires": {
-        "core-util-is": "~1.0.0",
-        "inherits": "~2.0.1",
-        "isarray": "0.0.1",
-        "string_decoder": "~0.10.x"
+        "inherits": "^2.0.3",
+        "string_decoder": "^1.1.1",
+        "util-deprecate": "^1.0.1"
       }
     },
     "readdirp": {
@@ -5495,6 +5653,13 @@
         "tough-cookie": "~2.3.3",
         "tunnel-agent": "^0.6.0",
         "uuid": "^3.1.0"
+      },
+      "dependencies": {
+        "uuid": {
+          "version": "3.4.0",
+          "resolved": "https://registry.npmjs.org/uuid/-/uuid-3.4.0.tgz",
+          "integrity": "sha512-HjSDRw6gZE5JMggctHBcjVak08+KEVhSIiDzFnT9S9aegmp85S/bReBVTb4QTFaRNptJ9kuYaNhnbNEOkbKb/A=="
+        }
       }
     },
     "require-directory": {
@@ -5555,30 +5720,6 @@
         }
       }
     },
-    "rimraf": {
-      "version": "2.4.5",
-      "resolved": "https://registry.npmjs.org/rimraf/-/rimraf-2.4.5.tgz",
-      "integrity": "sha1-7nEM5dk6j9uFb7Xqj/Di11k0sto=",
-      "optional": true,
-      "requires": {
-        "glob": "^6.0.1"
-      },
-      "dependencies": {
-        "glob": {
-          "version": "6.0.4",
-          "resolved": "https://registry.npmjs.org/glob/-/glob-6.0.4.tgz",
-          "integrity": "sha1-DwiGD2oVUSey+t1PnOJLGqtuTSI=",
-          "optional": true,
-          "requires": {
-            "inflight": "^1.0.4",
-            "inherits": "2",
-            "minimatch": "2 || 3",
-            "once": "^1.3.0",
-            "path-is-absolute": "^1.0.0"
-          }
-        }
-      }
-    },
     "run-async": {
       "version": "2.3.0",
       "resolved": "https://registry.npmjs.org/run-async/-/run-async-2.3.0.tgz",
@@ -5602,12 +5743,6 @@
       "resolved": "https://registry.npmjs.org/safe-buffer/-/safe-buffer-5.1.1.tgz",
       "integrity": "sha512-kKvNJn6Mm93gAczWVJg7wH+wGYWNrDHdWvpUmHyEsgCtIwwo3bqPtV4tR5tuPaUhTOo/kvhVwd8XwwOllGYkbg=="
     },
-    "safe-json-stringify": {
-      "version": "1.2.0",
-      "resolved": "https://registry.npmjs.org/safe-json-stringify/-/safe-json-stringify-1.2.0.tgz",
-      "integrity": "sha512-gH8eh2nZudPQO6TytOvbxnuhYBOvDBBLW52tz5q6X58lJcd/tkmqFR+5Z9adS8aJtURSXWThWy/xJtJwixErvg==",
-      "optional": true
-    },
     "safer-buffer": {
       "version": "2.1.2",
       "resolved": "https://registry.npmjs.org/safer-buffer/-/safer-buffer-2.1.2.tgz",
@@ -5747,6 +5882,15 @@
         }
       }
     },
+    "sonic-boom": {
+      "version": "1.0.1",
+      "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-1.0.1.tgz",
+      "integrity": "sha512-o9tx+bonVEXSaPtptyXQXpP8l6UV9Bi3im2geZskvWw2a/o/hrbWI7EBbbv+rOx6Hubnzun9GgH4WfbgEA3MFQ==",
+      "requires": {
+        "atomic-sleep": "^1.0.0",
+        "flatstr": "^1.0.12"
+      }
+    },
     "source-map": {
       "version": "0.5.7",
       "resolved": "https://registry.npmjs.org/source-map/-/source-map-0.5.7.tgz",
@@ -5827,6 +5971,15 @@
         "through": "2"
       }
     },
+    "split2": {
+      "version": "3.1.1",
+      "resolved": "https://registry.npmjs.org/split2/-/split2-3.1.1.tgz",
+      "integrity": "sha512-emNzr1s7ruq4N+1993yht631/JH+jaj0NYBosuKmLcq+JkGQ9MmTw1RB1fGaTCzUuseRIClrlSLHRNYGwWQ58Q==",
+      "dev": true,
+      "requires": {
+        "readable-stream": "^3.0.0"
+      }
+    },
     "sprintf-js": {
       "version": "1.0.3",
       "resolved": "https://registry.npmjs.org/sprintf-js/-/sprintf-js-1.0.3.tgz",
@@ -6100,9 +6253,21 @@
       }
     },
     "string_decoder": {
-      "version": "0.10.31",
-      "resolved": "https://registry.npmjs.org/string_decoder/-/string_decoder-0.10.31.tgz",
-      "integrity": "sha1-YuIDvEF2bGwoyfyEMB2rHFMQ+pQ="
+      "version": "1.3.0",
+      "resolved": "https://registry.npmjs.org/string_decoder/-/string_decoder-1.3.0.tgz",
+      "integrity": "sha512-hkRX8U1WjJFd8LsDJ2yQ/wWWxaopEsABU1XfkM8A+j0+85JAGppt16cr1Whg6KIbb4okU6Mql6BOj+uup/wKeA==",
+      "dev": true,
+      "requires": {
+        "safe-buffer": "~5.2.0"
+      },
+      "dependencies": {
+        "safe-buffer": {
+          "version": "5.2.1",
+          "resolved": "https://registry.npmjs.org/safe-buffer/-/safe-buffer-5.2.1.tgz",
+          "integrity": "sha512-rp3So07KcdmmKbGvgaNxQSJr7bGVSVk5S9Eq1F+ppbRo70+YeaDxkw5Dd8NPN+GD6bjnYm2VuPuCXmpuYvmCXQ==",
+          "dev": true
+        }
+      }
     },
     "strip-ansi": {
       "version": "3.0.1",
@@ -6581,9 +6746,9 @@
       "integrity": "sha1-n5VxD1CiZ5R7LMwSR0HBAoQn5xM="
     },
     "uuid": {
-      "version": "3.3.2",
-      "resolved": "https://registry.npmjs.org/uuid/-/uuid-3.3.2.tgz",
-      "integrity": "sha512-yXJmeNaw3DnnKAOKJE51sL/ZaYfWJRl1pK9dr19YFCu0ObS231AB1/LbqTKRAQ5kw8A90rA6fr4riOUpTZvQZA=="
+      "version": "8.1.0",
+      "resolved": "https://registry.npmjs.org/uuid/-/uuid-8.1.0.tgz",
+      "integrity": "sha512-CI18flHDznR0lq54xBycOVmphdCYnQLKn8abKn7PXUiKUGdEd+/l9LWNJmugXel4hXq7S+RMNl34ecyC9TntWg=="
     },
     "v8-compile-cache": {
       "version": "2.1.0",
diff --git a/package.json b/package.json
index 2520940b..4e656ff0 100644
--- a/package.json
+++ b/package.json
@@ -38,7 +38,7 @@
     "@google-cloud/pubsub": "1.5.0",
     "basic-auth": "2.0.0",
     "body-parser": "1.18.3",
-    "camshaft": "^0.65.3",
+    "camshaft": "github:cartodb/camshaft#dgaubert/ch78389/camshaft-replace-logger-from-bunyan-to-pino",
     "cartodb-psql": "0.14.0",
     "cartodb-query-tables": "^0.7.0",
     "cartodb-redis": "^3.0.0",
@@ -48,11 +48,11 @@
     "fastly-purge": "1.0.1",
     "gc-stats": "^1.4.0",
     "glob": "7.1.2",
-    "log4js": "github:cartodb/log4js-node#cdb",
     "lru-cache": "4.1.3",
     "lzma": "2.3.2",
     "node-statsd": "0.1.1",
     "on-headers": "1.0.1",
+    "pino": "^6.3.1",
     "queue-async": "1.1.0",
     "redis-mpool": "^0.8.0",
     "request": "2.87.0",
@@ -60,6 +60,7 @@
     "step-profiler": "0.3.0",
     "turbo-carto": "0.21.2",
     "underscore": "1.6.0",
+    "uuid": "^8.1.0",
     "windshaft": "^7.0.1",
     "yargs": "^15.3.1"
   },
@@ -75,6 +76,7 @@
     "moment": "2.22.1",
     "nock": "9.2.6",
     "nyc": "^14.1.1",
+    "pino-pretty": "^4.0.0",
     "redis": "2.8.0",
     "step": "1.0.0",
     "strftime": "0.10.0"
diff --git a/test/support/test-helper.js b/test/support/test-helper.js
index 9ec178f7..94f9dffa 100644
--- a/test/support/test-helper.js
+++ b/test/support/test-helper.js
@@ -14,7 +14,7 @@ var LZMA = require('lzma').LZMA;
 var lzmaWorker = new LZMA();
 
 var redis = require('redis');
-var log4js = require('log4js');
+const pino = require('pino');
 const setICUEnvVariable = require('../../lib/utils/icu-data-env-setter');
 
 // set environment specific variables
@@ -24,9 +24,7 @@ process.env.NODE_ENV = 'test';
 
 setICUEnvVariable();
 
-// don't output logs in test environment to reduce noise
-log4js.configure({ appenders: [] });
-global.logger = log4js.getLogger();
+global.logger = pino({ base: null, level: process.env.NODE_ENV === 'test' ? 'fatal' : 'info' }, pino.destination({ sync: false }));
 
 // Utility function to compress & encode LZMA
 function lzmaCompressToBase64 (payload, mode, callback) {

From 62d66f2dbc3b741846153d4429177cc8e473621f Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 2 Jun 2020 09:00:45 +0200
Subject: [PATCH 02/44] Do not use global logger in middlewares, use the one
 initialized in res.locals instead

---
 lib/api/api-router.js                           |  3 +--
 lib/api/map/anonymous-map-controller.js         |  1 -
 lib/api/map/preview-template-controller.js      | 11 +++--------
 lib/api/middlewares/cache-channel-header.js     |  4 ++--
 lib/api/middlewares/cache-control-header.js     |  4 ++--
 lib/api/middlewares/increment-map-view-count.js |  4 ++--
 lib/api/middlewares/last-modified-header.js     |  4 ++--
 lib/api/middlewares/logger.js                   |  6 +++---
 lib/api/middlewares/metrics.js                  |  4 +++-
 lib/api/middlewares/surrogate-key-header.js     |  4 ++--
 lib/api/template/named-template-controller.js   |  1 -
 11 files changed, 20 insertions(+), 26 deletions(-)

diff --git a/lib/api/api-router.js b/lib/api/api-router.js
index 9ce4fa2d..4356df5d 100644
--- a/lib/api/api-router.js
+++ b/lib/api/api-router.js
@@ -86,8 +86,7 @@ module.exports = class ApiRouter {
         const { rendererCache, tileBackend, attributesBackend, previewBackend, mapBackend, mapStore } = windshaftFactory({
             rendererOptions: serverOptions,
             redisPool,
-            onTileErrorStrategy: getOnTileErrorStrategy({ enabled: environmentOptions.enabledFeatures.onTileErrorStrategy }),
-            logger: global.logger
+            onTileErrorStrategy: getOnTileErrorStrategy({ enabled: environmentOptions.enabledFeatures.onTileErrorStrategy })
         });
 
         const rendererStatsReporter = new RendererStatsReporter(rendererCache, serverOptions.renderCache.statsInterval);
diff --git a/lib/api/map/anonymous-map-controller.js b/lib/api/map/anonymous-map-controller.js
index 46ed876a..85e9860a 100644
--- a/lib/api/map/anonymous-map-controller.js
+++ b/lib/api/map/anonymous-map-controller.js
@@ -95,7 +95,6 @@ module.exports = class AnonymousMapController {
             metrics({
                 enabled: this.config.pubSubMetrics.enabled,
                 metricsBackend: this.metricsBackend,
-                logger: global.logger,
                 tags: metricsTags
             }),
             credentials(),
diff --git a/lib/api/map/preview-template-controller.js b/lib/api/map/preview-template-controller.js
index e9dc547d..92d4380e 100644
--- a/lib/api/map/preview-template-controller.js
+++ b/lib/api/map/preview-template-controller.js
@@ -70,7 +70,6 @@ module.exports = class PreviewTemplateController {
             metrics({
                 enabled: this.config.pubSubMetrics.enabled,
                 metricsBackend: this.metricsBackend,
-                logger: global.logger,
                 tags: metricsTags
             }),
             credentials(),
@@ -337,17 +336,13 @@ function setContentTypeHeader () {
     };
 }
 
-function incrementMapViewsError (ctx) {
-    return `ERROR: failed to increment mapview count for user '${ctx.user}': ${ctx.err}`;
-}
-
 function incrementMapViews ({ metadataBackend }) {
     return function incrementMapViewsMiddleware (req, res, next) {
-        const { user, mapConfigProvider } = res.locals;
+        const { user, mapConfigProvider, logger } = res.locals;
 
         mapConfigProvider.getMapConfig((err, mapConfig) => {
             if (err) {
-                global.logger.info(incrementMapViewsError({ user, err }));
+                logger.warn(err, `ERROR: failed to increment mapview count for user '${user}'`);
                 return next();
             }
 
@@ -359,7 +354,7 @@ function incrementMapViews ({ metadataBackend }) {
 
             metadataBackend.incMapviewCount(user, statTag, (err) => {
                 if (err) {
-                    global.logger.info(incrementMapViewsError({ user, err }));
+                    logger.warn(err, `ERROR: failed to increment mapview count for user '${user}'`);
                 }
 
                 next();
diff --git a/lib/api/middlewares/cache-channel-header.js b/lib/api/middlewares/cache-channel-header.js
index c93cce57..66486392 100644
--- a/lib/api/middlewares/cache-channel-header.js
+++ b/lib/api/middlewares/cache-channel-header.js
@@ -6,11 +6,11 @@ module.exports = function setCacheChannelHeader () {
             return next();
         }
 
-        const { mapConfigProvider } = res.locals;
+        const { mapConfigProvider, logger } = res.locals;
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                global.logger.warn(err, 'ERROR generating Cache Channel Header');
+                logger.warn(err, 'ERROR generating Cache Channel Header');
                 return next();
             }
 
diff --git a/lib/api/middlewares/cache-control-header.js b/lib/api/middlewares/cache-control-header.js
index 7afed19f..18ec7728 100644
--- a/lib/api/middlewares/cache-control-header.js
+++ b/lib/api/middlewares/cache-control-header.js
@@ -40,11 +40,11 @@ module.exports = function setCacheControlHeader ({
             return next();
         }
 
-        const { mapConfigProvider = { getAffectedTables: callback => callback() } } = res.locals;
+        const { mapConfigProvider = { getAffectedTables: callback => callback() }, logger } = res.locals;
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                global.logger.warn(err, 'ERROR generating Cache Control Header');
+                logger.warn(err, 'ERROR generating Cache Control Header');
                 return next();
             }
 
diff --git a/lib/api/middlewares/increment-map-view-count.js b/lib/api/middlewares/increment-map-view-count.js
index 7617375f..1b71e8e3 100644
--- a/lib/api/middlewares/increment-map-view-count.js
+++ b/lib/api/middlewares/increment-map-view-count.js
@@ -2,7 +2,7 @@
 
 module.exports = function incrementMapViewCount (metadataBackend) {
     return function incrementMapViewCountMiddleware (req, res, next) {
-        const { mapConfig, user } = res.locals;
+        const { mapConfig, user, logger } = res.locals;
         const statTag = mapConfig.obj().stat_tag;
 
         if (statTag) {
@@ -14,7 +14,7 @@ module.exports = function incrementMapViewCount (metadataBackend) {
             req.profiler.done('incMapviewCount');
 
             if (err) {
-                global.logger.warn(err, `ERROR: failed to increment mapview count for user '${user}'`);
+                logger.warn(err, `ERROR: failed to increment mapview count for user '${user}'`);
             }
 
             next();
diff --git a/lib/api/middlewares/last-modified-header.js b/lib/api/middlewares/last-modified-header.js
index 8f1dd296..b68d7c31 100644
--- a/lib/api/middlewares/last-modified-header.js
+++ b/lib/api/middlewares/last-modified-header.js
@@ -6,7 +6,7 @@ module.exports = function setLastModifiedHeader () {
             return next();
         }
 
-        const { mapConfigProvider, cache_buster: cacheBuster } = res.locals;
+        const { mapConfigProvider, cache_buster: cacheBuster, logger } = res.locals;
 
         if (cacheBuster) {
             const cacheBusterTimestamp = parseInt(cacheBuster, 10);
@@ -21,7 +21,7 @@ module.exports = function setLastModifiedHeader () {
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                global.logger.warn(err, 'ERROR generating Last Modified Header');
+                logger.warn(err, 'ERROR generating Last Modified Header');
                 return next();
             }
 
diff --git a/lib/api/middlewares/logger.js b/lib/api/middlewares/logger.js
index acebdb88..f709383a 100644
--- a/lib/api/middlewares/logger.js
+++ b/lib/api/middlewares/logger.js
@@ -5,10 +5,10 @@ const uuid = require('uuid');
 module.exports = function logger () {
     return function loggerMiddleware (req, res, next) {
         const id = req.get('X-Request-Id') || uuid.v4();
-        res.locals.logger = global.logger.child({ id });
+        const logger = res.locals.logger = global.logger.child({ id });
 
-        res.locals.logger.info(req);
-        res.on('finish', () => res.locals.logger.info(res));
+        logger.info(req);
+        res.on('finish', () => logger.info(res));
 
         next();
     };
diff --git a/lib/api/middlewares/metrics.js b/lib/api/middlewares/metrics.js
index 4ac0ebf6..60478557 100644
--- a/lib/api/middlewares/metrics.js
+++ b/lib/api/middlewares/metrics.js
@@ -3,7 +3,7 @@
 const EVENT_VERSION = '1';
 const MAX_LENGTH = 100;
 
-module.exports = function metrics ({ enabled, tags, metricsBackend, logger }) {
+module.exports = function metrics ({ enabled, tags, metricsBackend }) {
     if (!enabled) {
         return function metricsDisabledMiddleware (req, res, next) {
             next();
@@ -15,6 +15,8 @@ module.exports = function metrics ({ enabled, tags, metricsBackend, logger }) {
     }
 
     return function metricsMiddleware (req, res, next) {
+        const { logger } = res.locals;
+
         res.on('finish', () => {
             const { event, attributes } = getEventData(req, res, tags);
 
diff --git a/lib/api/middlewares/surrogate-key-header.js b/lib/api/middlewares/surrogate-key-header.js
index a3b1e039..c1415038 100644
--- a/lib/api/middlewares/surrogate-key-header.js
+++ b/lib/api/middlewares/surrogate-key-header.js
@@ -5,7 +5,7 @@ const NamedMapMapConfigProvider = require('../../models/mapconfig/provider/named
 
 module.exports = function setSurrogateKeyHeader ({ surrogateKeysCache }) {
     return function setSurrogateKeyHeaderMiddleware (req, res, next) {
-        const { user, mapConfigProvider } = res.locals;
+        const { user, mapConfigProvider, logger } = res.locals;
 
         if (mapConfigProvider instanceof NamedMapMapConfigProvider) {
             surrogateKeysCache.tag(res, new NamedMapsCacheEntry(user, mapConfigProvider.getTemplateName()));
@@ -17,7 +17,7 @@ module.exports = function setSurrogateKeyHeader ({ surrogateKeysCache }) {
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                global.logger.warn(err, 'ERROR generating Surrogate Key Header');
+                logger.warn(err, 'ERROR generating Surrogate Key Header');
                 return next();
             }
 
diff --git a/lib/api/template/named-template-controller.js b/lib/api/template/named-template-controller.js
index 88270b89..79b39d7c 100644
--- a/lib/api/template/named-template-controller.js
+++ b/lib/api/template/named-template-controller.js
@@ -93,7 +93,6 @@ module.exports = class NamedMapController {
             metrics({
                 enabled: this.config.pubSubMetrics.enabled,
                 metricsBackend: this.metricsBackend,
-                logger: global.logger,
                 tags: metricsTags
             }),
             credentials(),

From 48c28aea0b9c56d0820782882fd7df37bdbedd27 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 2 Jun 2020 11:49:54 +0200
Subject: [PATCH 03/44] Do not bind logger to global object, now it's a part of
 serverOptions

---
 app.js                                        | 72 ++++++++-----------
 lib/api/api-router.js                         | 12 ++--
 lib/api/middlewares/logger.js                 | 10 +--
 lib/server-options.js                         |  5 +-
 lib/utils/logger.js                           | 48 +++++++++++++
 .../dynamic-styling-named-maps-test.js        |  4 +-
 test/acceptance/errors-with-context-test.js   |  4 +-
 test/support/test-helper.js                   | 10 ---
 8 files changed, 97 insertions(+), 68 deletions(-)
 create mode 100644 lib/utils/logger.js

diff --git a/app.js b/app.js
index 7cbb6a74..84bc3e3b 100755
--- a/app.js
+++ b/app.js
@@ -3,21 +3,11 @@
 const http = require('http');
 const https = require('https');
 const path = require('path');
-const fs = require('fs');
 const semver = require('semver');
-const pino = require('pino');
 
 // TODO: research it it's still needed
 const setICUEnvVariable = require('./lib/utils/icu-data-env-setter');
 
-global.logger = pino({ base: null, level: process.env.NODE_ENV === 'test' ? 'fatal' : 'info' }, pino.destination({ sync: false }));
-
-const { engines } = require('./package.json');
-if (!semver.satisfies(process.versions.node, engines.node)) {
-    global.logger.fatal(new Error(`Node version ${process.versions.node} is not supported, please use Node.js ${engines.node}.`));
-    process.exit(1);
-}
-
 // This function should be called before the require('yargs').
 setICUEnvVariable();
 
@@ -37,27 +27,9 @@ const argv = require('yargs')
 const environmentArg = argv._[0] || process.env.NODE_ENV || 'development';
 const configurationFile = path.resolve(argv.config || `./config/environments/${environmentArg}.js`);
 
-if (!fs.existsSync(configurationFile)) {
-    global.logger.fatal(new Error(`Configuration file ${configurationFile} does not exist`));
-    process.exit(1);
-}
-
 global.environment = require(configurationFile);
-const ENVIRONMENT = argv._[0] || process.env.NODE_ENV || global.environment.environment;
-process.env.NODE_ENV = ENVIRONMENT;
+process.env.NODE_ENV = argv._[0] || process.env.NODE_ENV || global.environment.environment;
 
-const availableEnvironments = {
-    production: true,
-    staging: true,
-    development: true
-};
-
-if (!availableEnvironments[ENVIRONMENT]) {
-    global.logger.fatal(new Error(`Invalid environment argument, valid ones: ${Object.keys(availableEnvironments).join(', ')}`));
-    process.exit(1);
-}
-
-process.env.NODE_ENV = ENVIRONMENT;
 if (global.environment.uv_threadpool_size) {
     process.env.UV_THREADPOOL_SIZE = global.environment.uv_threadpool_size;
 }
@@ -76,10 +48,28 @@ https.globalAgent = new https.Agent(agentOptions);
 
 // Include cartodb_windshaft only _after_ the "global" variable is set
 // See https://github.com/Vizzuality/Windshaft-cartodb/issues/28
-const cartodbWindshaft = require('./lib/server');
+const createServer = require('./lib/server');
 const serverOptions = require('./lib/server-options');
+const { logger } = serverOptions;
 
-const server = cartodbWindshaft(serverOptions);
+const availableEnvironments = {
+    production: true,
+    staging: true,
+    development: true
+};
+
+if (!availableEnvironments[process.env.NODE_ENV]) {
+    logger.fatal(new Error(`Invalid environment argument, valid ones: ${Object.keys(availableEnvironments).join(', ')}`));
+    process.exit(1);
+}
+
+const { engines } = require('./package.json');
+if (!semver.satisfies(process.versions.node, engines.node)) {
+    logger.fatal(new Error(`Node version ${process.versions.node} is not supported, please use Node.js ${engines.node}.`));
+    process.exit(1);
+}
+
+const server = createServer(serverOptions);
 
 // Specify the maximum length of the queue of pending connections for the HTTP server.
 // The actual length will be determined by the OS through sysctl settings such as tcp_max_syn_backlog and somaxconn on Linux.
@@ -91,10 +81,10 @@ const listener = server.listen(serverOptions.bind.port, serverOptions.bind.host,
 const version = require('./package').version;
 
 listener.on('listening', function () {
-    global.logger.info(`Using Node.js ${process.version}`);
-    global.logger.info(`Using configuration file ${configurationFile}`);
+    logger.info(`Using Node.js ${process.version}`);
+    logger.info(`Using configuration file ${configurationFile}`);
     const { address, port } = listener.address();
-    global.logger.info(`Windshaft tileserver ${version} started on ${address}:${port} PID=${process.pid} (${ENVIRONMENT})`);
+    logger.info(`Windshaft tileserver ${version} started on ${address}:${port} PID=${process.pid} (${process.env.NODE_ENV})`);
 });
 
 function getCPUUsage (oldUsage) {
@@ -189,19 +179,19 @@ function getGCTypeValue (type) {
     return value;
 }
 
-const exitProcess = pino.final(global.logger, (err, logger, listener, signal, killTimeout) => {
-    scheduleForcedExit(killTimeout, logger);
+const exitProcess = logger.finish((err, finalLogger, listener, signal, killTimeout) => {
+    scheduleForcedExit(killTimeout, finalLogger);
 
-    logger.info(`Process has received signal: ${signal}`);
+    finalLogger.info(`Process has received signal: ${signal}`);
 
     let code = 0;
 
     if (err) {
         code = 1;
-        logger.fatal(err);
+        finalLogger.fatal(err);
     }
 
-    logger.info(`Process is going to exit with code: ${code}`);
+    finalLogger.info(`Process is going to exit with code: ${code}`);
     listener.close(() => process.exit(code));
 });
 
@@ -215,10 +205,10 @@ function addHandlers (listener, killTimeout) {
 
 addHandlers(listener, 45000);
 
-function scheduleForcedExit (killTimeout, logger) {
+function scheduleForcedExit (killTimeout, finalLogger) {
     // Schedule exit if there is still ongoing work to deal with
     const killTimer = setTimeout(() => {
-        global.logger.info('Process didn\'t close on time. Force exit');
+        finalLogger.info('Process didn\'t close on time. Force exit');
         process.exit(1);
     }, killTimeout);
 
diff --git a/lib/api/api-router.js b/lib/api/api-router.js
index 4356df5d..bee3ef90 100644
--- a/lib/api/api-router.js
+++ b/lib/api/api-router.js
@@ -47,7 +47,7 @@ const LayergroupMetadata = require('../utils/layergroup-metadata');
 const RendererStatsReporter = require('../stats/reporter/renderer');
 
 const initializeStatusCode = require('./middlewares/initialize-status-code');
-const logger = require('./middlewares/logger');
+const initLogger = require('./middlewares/logger');
 const bodyParser = require('body-parser');
 const servedByHostHeader = require('./middlewares/served-by-host-header');
 const stats = require('./middlewares/stats');
@@ -97,7 +97,7 @@ module.exports = class ApiRouter {
 
         const surrogateKeysCacheBackends = createSurrogateKeysCacheBackends(serverOptions);
         const surrogateKeysCache = new SurrogateKeysCache(surrogateKeysCacheBackends);
-        const templateMaps = createTemplateMaps({ redisPool, surrogateKeysCache });
+        const templateMaps = createTemplateMaps({ redisPool, surrogateKeysCache, logger: this.serverOptions.logger });
 
         const analysisStatusBackend = new AnalysisStatusBackend();
         const analysisBackend = new AnalysisBackend(metadataBackend, serverOptions.analysis);
@@ -200,7 +200,7 @@ module.exports = class ApiRouter {
 
             middlewares.forEach(middleware => apiRouter.use(middleware()));
 
-            apiRouter.use(logger());
+            apiRouter.use(initLogger({ logger: this.serverOptions.logger }));
             apiRouter.use(initializeStatusCode());
             apiRouter.use(bodyParser.json());
             apiRouter.use(servedByHostHeader());
@@ -225,7 +225,7 @@ module.exports = class ApiRouter {
     }
 };
 
-function createTemplateMaps ({ redisPool, surrogateKeysCache }) {
+function createTemplateMaps ({ redisPool, surrogateKeysCache, logger }) {
     const templateMaps = new TemplateMaps(redisPool, {
         max_user_templates: global.environment.maxUserTemplates
     });
@@ -234,10 +234,10 @@ function createTemplateMaps ({ redisPool, surrogateKeysCache }) {
         const startTime = Date.now();
         surrogateKeysCache.invalidate(new NamedMapsCacheEntry(user, templateName), (err) => {
             if (err) {
-                return global.logger.error(err);
+                return logger.error(err);
             }
 
-            global.logger.info({ user, type: 'named_map_invalidation', elapsed: Date.now() - startTime });
+            logger.info({ user, type: 'named_map_invalidation', elapsed: Date.now() - startTime });
         });
     }
 
diff --git a/lib/api/middlewares/logger.js b/lib/api/middlewares/logger.js
index f709383a..93a02a03 100644
--- a/lib/api/middlewares/logger.js
+++ b/lib/api/middlewares/logger.js
@@ -2,13 +2,13 @@
 
 const uuid = require('uuid');
 
-module.exports = function logger () {
-    return function loggerMiddleware (req, res, next) {
+module.exports = function initLogger ({ logger }) {
+    return function initLoggerMiddleware (req, res, next) {
         const id = req.get('X-Request-Id') || uuid.v4();
-        const logger = res.locals.logger = global.logger.child({ id });
+        res.locals.logger = logger.child({ id });
 
-        logger.info(req);
-        res.on('finish', () => logger.info(res));
+        res.locals.logger.info(req);
+        res.on('finish', () => res.locals.logger.info(res));
 
         next();
     };
diff --git a/lib/server-options.js b/lib/server-options.js
index 26b14714..40306e67 100644
--- a/lib/server-options.js
+++ b/lib/server-options.js
@@ -3,6 +3,7 @@
 const fqdn = require('@carto/fqdn-sync');
 var _ = require('underscore');
 var OverviewsQueryRewriter = require('./utils/overviews-query-rewriter');
+const Logger = require('./utils/logger');
 
 var rendererConfig = _.defaults(global.environment.renderer || {}, {
     cache_ttl: 60000, // milliseconds
@@ -127,7 +128,7 @@ module.exports = {
     varnish_purge_enabled: global.environment.varnish.purge_enabled,
     fastly: global.environment.fastly || {},
     cache_enabled: global.environment.cache_enabled,
-    log_format: global.environment.log_format,
     useProfiler: global.environment.useProfiler,
-    pubSubMetrics: Object.assign({ enabled: false }, global.environment.pubSubMetrics)
+    pubSubMetrics: Object.assign({ enabled: false }, global.environment.pubSubMetrics),
+    logger: new Logger()
 };
diff --git a/lib/utils/logger.js b/lib/utils/logger.js
new file mode 100644
index 00000000..4d1340a7
--- /dev/null
+++ b/lib/utils/logger.js
@@ -0,0 +1,48 @@
+'use strict';
+
+const pino = require('pino');
+
+module.exports = class Logger {
+    constructor () {
+        const { LOG_LEVEL, NODE_ENV } = process.env;
+        const options = {
+            base: null, // Do not bind hostname, pid and friends by default
+            level: LOG_LEVEL || NODE_ENV === 'test' ? 'fatal' : 'info'
+        };
+        const dest = pino.destination({ sync: false });
+
+        this._logger = pino(options, dest);
+    }
+
+    trace (...args) {
+        this._logger.trace(...args);
+    }
+
+    debug (...args) {
+        this._logger.debug(...args);
+    }
+
+    info (...args) {
+        this._logger.info(...args);
+    }
+
+    warn (...args) {
+        this._logger.warn(...args);
+    }
+
+    error (...args) {
+        this._logger.error(...args);
+    }
+
+    fatal (...args) {
+        this._logger.fatal(...args);
+    }
+
+    child (...args) {
+        return this._logger.child(...args);
+    }
+
+    finish (callback) {
+        return pino.final(this._logger, callback);
+    }
+};
diff --git a/test/acceptance/dynamic-styling-named-maps-test.js b/test/acceptance/dynamic-styling-named-maps-test.js
index 48391640..881aaaaa 100644
--- a/test/acceptance/dynamic-styling-named-maps-test.js
+++ b/test/acceptance/dynamic-styling-named-maps-test.js
@@ -4,14 +4,14 @@ var assert = require('../support/assert');
 var step = require('step');
 var LayergroupToken = require('../../lib/models/layergroup-token');
 var testHelper = require('../support/test-helper');
-var CartodbWindshaft = require('../../lib/server');
+var createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 describe('dynamic styling for named maps', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     var keysToDelete;
diff --git a/test/acceptance/errors-with-context-test.js b/test/acceptance/errors-with-context-test.js
index 23e09e7a..5765c4b1 100644
--- a/test/acceptance/errors-with-context-test.js
+++ b/test/acceptance/errors-with-context-test.js
@@ -1,14 +1,14 @@
 'use strict';
 
 var assert = require('../support/assert');
-var CartodbWindshaft = require('../../lib/server');
+var createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 describe('error with context', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     var layerOK = {
diff --git a/test/support/test-helper.js b/test/support/test-helper.js
index 94f9dffa..29692cdd 100644
--- a/test/support/test-helper.js
+++ b/test/support/test-helper.js
@@ -1,12 +1,5 @@
 'use strict';
 
-/**
- * User: simon
- * Date: 30/08/2011
- * Time: 13:52
- * Desc: Loads test specific variables
- */
-
 var assert = require('assert');
 var fs = require('fs');
 var LZMA = require('lzma').LZMA;
@@ -14,7 +7,6 @@ var LZMA = require('lzma').LZMA;
 var lzmaWorker = new LZMA();
 
 var redis = require('redis');
-const pino = require('pino');
 const setICUEnvVariable = require('../../lib/utils/icu-data-env-setter');
 
 // set environment specific variables
@@ -24,8 +16,6 @@ process.env.NODE_ENV = 'test';
 
 setICUEnvVariable();
 
-global.logger = pino({ base: null, level: process.env.NODE_ENV === 'test' ? 'fatal' : 'info' }, pino.destination({ sync: false }));
-
 // Utility function to compress & encode LZMA
 function lzmaCompressToBase64 (payload, mode, callback) {
     lzmaWorker.compress(payload, mode,

From ffe19827fd85fd0e9e6708ec0c4f0696ffa0e129 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 2 Jun 2020 11:57:11 +0200
Subject: [PATCH 04/44] Rename factory and don't use the keyword 'new' to
 create server while testing

---
 test/acceptance/analysis/named-maps-test.js            |  4 ++--
 .../auth/authorization-basic-use-cases-test.js         |  4 ++--
 test/acceptance/cache/cache-headers-test.js            |  4 ++--
 .../cache/surrogate-keys-invalidation-test.js          |  4 ++--
 test/acceptance/health-check-test.js                   | 10 +++++-----
 test/acceptance/multilayer-server-test.js              |  4 ++--
 test/acceptance/multilayer-test.js                     | 10 +++++-----
 test/acceptance/named-layers-test.js                   |  4 ++--
 test/acceptance/named-layers-visibility-test.js        |  4 ++--
 test/acceptance/named-maps-authentication-test.js      |  4 ++--
 test/acceptance/named-maps-cache-test.js               |  4 ++--
 test/acceptance/named-maps-static-view-test.js         |  6 +++---
 test/acceptance/named-maps-stats-test.js               |  4 ++--
 test/acceptance/overviews-metadata-named-maps-test.js  |  4 ++--
 test/acceptance/overviews-metadata-test.js             |  6 +++---
 test/acceptance/regressions-test.js                    |  4 ++--
 test/acceptance/server-test.js                         |  6 +++---
 test/acceptance/templates-test.js                      |  4 ++--
 test/acceptance/turbo-carto/named-maps-test.js         |  4 ++--
 test/acceptance/widgets/named-maps-test.js             |  4 ++--
 test/support/test-client.js                            |  8 ++++----
 21 files changed, 53 insertions(+), 53 deletions(-)

diff --git a/test/acceptance/analysis/named-maps-test.js b/test/acceptance/analysis/named-maps-test.js
index d04beadd..a0181ffe 100644
--- a/test/acceptance/analysis/named-maps-test.js
+++ b/test/acceptance/analysis/named-maps-test.js
@@ -4,7 +4,7 @@ var assert = require('../../support/assert');
 
 var helper = require('../../support/test-helper');
 
-var CartodbWindshaft = require('../../../lib/server');
+const createServer = require('../../../lib/server');
 var serverOptions = require('../../../lib/server-options');
 var TestClient = require('../../support/test-client');
 
@@ -14,7 +14,7 @@ describe('named-maps analysis', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     var IMAGE_TOLERANCE_PER_MIL = 20;
diff --git a/test/acceptance/auth/authorization-basic-use-cases-test.js b/test/acceptance/auth/authorization-basic-use-cases-test.js
index 9e48077b..a58ad9ad 100644
--- a/test/acceptance/auth/authorization-basic-use-cases-test.js
+++ b/test/acceptance/auth/authorization-basic-use-cases-test.js
@@ -2,7 +2,7 @@
 
 const assert = require('../../support/assert');
 const testHelper = require('../../support/test-helper');
-const CartodbWindshaft = require('../../../lib/server');
+const createServer = require('../../../lib/server');
 const serverOptions = require('../../../lib/server-options');
 var LayergroupToken = require('../../../lib/models/layergroup-token');
 
@@ -47,7 +47,7 @@ describe('Basic authorization use cases', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     beforeEach(function () {
diff --git a/test/acceptance/cache/cache-headers-test.js b/test/acceptance/cache/cache-headers-test.js
index d96bada7..6a00a7eb 100644
--- a/test/acceptance/cache/cache-headers-test.js
+++ b/test/acceptance/cache/cache-headers-test.js
@@ -5,7 +5,7 @@ var testHelper = require('../../support/test-helper');
 var assert = require('../../support/assert');
 var qs = require('querystring');
 
-var CartodbWindshaft = require('../../../lib/server');
+const createServer = require('../../../lib/server');
 var serverOptions = require('../../../lib/server-options');
 
 var LayergroupToken = require('../../../lib/models/layergroup-token');
@@ -14,7 +14,7 @@ describe('get requests with cache headers', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
         server.setMaxListeners(0);
     });
 
diff --git a/test/acceptance/cache/surrogate-keys-invalidation-test.js b/test/acceptance/cache/surrogate-keys-invalidation-test.js
index 4e33947b..675dab1a 100644
--- a/test/acceptance/cache/surrogate-keys-invalidation-test.js
+++ b/test/acceptance/cache/surrogate-keys-invalidation-test.js
@@ -7,7 +7,7 @@ var step = require('step');
 var FastlyPurge = require('fastly-purge');
 var _ = require('underscore');
 var NamedMapsCacheEntry = require('../../../lib/cache/model/named-maps-entry');
-var CartodbWindshaft = require('../../../lib/server');
+const createServer = require('../../../lib/server');
 var nock = require('nock');
 
 describe('templates surrogate keys', function () {
@@ -33,7 +33,7 @@ describe('templates surrogate keys', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
         nock.disableNetConnect();
         nock.enableNetConnect(/(127.0.0.1|cartocdn.com)/);
     });
diff --git a/test/acceptance/health-check-test.js b/test/acceptance/health-check-test.js
index 53ac76f7..c08c626e 100644
--- a/test/acceptance/health-check-test.js
+++ b/test/acceptance/health-check-test.js
@@ -5,7 +5,7 @@ require('../support/test-helper');
 var fs = require('fs');
 
 var assert = require('../support/assert');
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 describe('health checks', function () {
@@ -41,7 +41,7 @@ describe('health checks', function () {
     };
 
     it('returns 200 and ok=true with enabled configuration', function (done) {
-        var server = new CartodbWindshaft(serverOptions);
+        var server = createServer(serverOptions);
 
         assert.response(server, healthCheckRequest, RESPONSE_OK, function (res, err) {
             assert.ok(!err);
@@ -62,7 +62,7 @@ describe('health checks', function () {
         fs.readFile = function (filename, callback) {
             callback(null, errorMessage);
         };
-        var server = new CartodbWindshaft(serverOptions);
+        var server = createServer(serverOptions);
 
         assert.response(server, healthCheckRequest, RESPONSE_FAIL, function (res, err) {
             fs.readFile = readFileFn;
@@ -82,7 +82,7 @@ describe('health checks', function () {
         fs.readFile = function (filename, callback) {
             callback(null, '');
         };
-        var server = new CartodbWindshaft(serverOptions);
+        var server = createServer(serverOptions);
 
         assert.response(server, healthCheckRequest, RESPONSE_FAIL, function (res, err) {
             fs.readFile = readFileFn;
@@ -100,7 +100,7 @@ describe('health checks', function () {
     it('not err if disabled file does not exist', function (done) {
         global.environment.disabled_file = '/tmp/ftreftrgtrccre';
 
-        var server = new CartodbWindshaft(serverOptions);
+        var server = createServer(serverOptions);
 
         assert.response(server, healthCheckRequest, RESPONSE_OK, function (res, err) {
             assert.ok(!err);
diff --git a/test/acceptance/multilayer-server-test.js b/test/acceptance/multilayer-server-test.js
index 04a281e1..5e621aa7 100644
--- a/test/acceptance/multilayer-server-test.js
+++ b/test/acceptance/multilayer-server-test.js
@@ -10,14 +10,14 @@ var LayergroupToken = require('../../lib/models/layergroup-token');
 
 var PgQueryRunner = require('../../lib/backends/pg-query-runner');
 var QueryTables = require('cartodb-query-tables').queryTables;
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 describe('tests from old api translated to multilayer', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
         server.setMaxListeners(0);
     });
 
diff --git a/test/acceptance/multilayer-test.js b/test/acceptance/multilayer-test.js
index 91868751..d291d86e 100644
--- a/test/acceptance/multilayer-test.js
+++ b/test/acceptance/multilayer-test.js
@@ -19,7 +19,7 @@ var windshaftFixtures = path.join(__dirname, '/../../node_modules/windshaft/test
 var IMAGE_EQUALS_TOLERANCE_PER_MIL = 20;
 var IMAGE_EQUALS_HIGHER_TOLERANCE_PER_MIL = 25;
 
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 var QueryTables = require('cartodb-query-tables').queryTables;
@@ -30,7 +30,7 @@ var QueryTables = require('cartodb-query-tables').queryTables;
         var server;
 
         before(function () {
-            server = new CartodbWindshaft(serverOptions);
+            server = createServer(serverOptions);
             server.setMaxListeners(0);
         });
 
@@ -851,7 +851,7 @@ var QueryTables = require('cartodb-query-tables').queryTables;
                 function doRestartServer (err/*, res */) {
                     assert.ifError(err);
                     // hack simulating restart...
-                    server = new CartodbWindshaft(serverOptions);
+                    server = createServer(serverOptions);
                     return null;
                 },
                 function doGet1 (err) {
@@ -1274,7 +1274,7 @@ var QueryTables = require('cartodb-query-tables').queryTables;
         it('cache control for layergroup default value', function (done) {
             global.environment.varnish.layergroupTtl = null;
 
-            var server = new CartodbWindshaft(serverOptions);
+            var server = createServer(serverOptions);
 
             assert.response(server, layergroupTtlRequest, layergroupTtlResponseExpectation,
                 function (res) {
@@ -1291,7 +1291,7 @@ var QueryTables = require('cartodb-query-tables').queryTables;
             var layergroupTtl = 300;
             global.environment.varnish.layergroupTtl = layergroupTtl;
 
-            var server = new CartodbWindshaft(serverOptions);
+            var server = createServer(serverOptions);
 
             assert.response(server, layergroupTtlRequest, layergroupTtlResponseExpectation,
                 function (res) {
diff --git a/test/acceptance/named-layers-test.js b/test/acceptance/named-layers-test.js
index 1ea33e31..edfc8067 100644
--- a/test/acceptance/named-layers-test.js
+++ b/test/acceptance/named-layers-test.js
@@ -3,7 +3,7 @@
 var testHelper = require('../support/test-helper');
 
 var assert = require('../support/assert');
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 var LayergroupToken = require('../../lib/models/layergroup-token');
@@ -17,7 +17,7 @@ describe('named_layers', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     // configure redis pool instance to use in tests
diff --git a/test/acceptance/named-layers-visibility-test.js b/test/acceptance/named-layers-visibility-test.js
index a9b0624c..51ad979e 100644
--- a/test/acceptance/named-layers-visibility-test.js
+++ b/test/acceptance/named-layers-visibility-test.js
@@ -4,7 +4,7 @@ var step = require('step');
 var testHelper = require('../support/test-helper');
 
 var assert = require('../support/assert');
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 var RedisPool = require('redis-mpool');
@@ -17,7 +17,7 @@ describe('layers visibility for previews', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     // configure redis pool instance to use in tests
diff --git a/test/acceptance/named-maps-authentication-test.js b/test/acceptance/named-maps-authentication-test.js
index cd1e20eb..f559bbbd 100644
--- a/test/acceptance/named-maps-authentication-test.js
+++ b/test/acceptance/named-maps-authentication-test.js
@@ -6,7 +6,7 @@ var querystring = require('querystring');
 
 var assert = require('../support/assert');
 const mapnik = require('@carto/mapnik');
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 var TemplateMaps = require('../../lib/backends/template-maps');
 var NamedMapsCacheEntry = require('../../lib/cache/model/named-maps-entry');
@@ -15,7 +15,7 @@ describe('named maps authentication', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     // configure redis pool instance to use in tests
diff --git a/test/acceptance/named-maps-cache-test.js b/test/acceptance/named-maps-cache-test.js
index 4c036858..712d859e 100644
--- a/test/acceptance/named-maps-cache-test.js
+++ b/test/acceptance/named-maps-cache-test.js
@@ -5,14 +5,14 @@ require('../support/test-helper');
 const helper = require('../support/test-helper');
 var assert = require('../support/assert');
 const mapnik = require('@carto/mapnik');
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 describe('named maps provider cache', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     var username = 'localhost';
diff --git a/test/acceptance/named-maps-static-view-test.js b/test/acceptance/named-maps-static-view-test.js
index 08d5ac82..8ffad2e9 100644
--- a/test/acceptance/named-maps-static-view-test.js
+++ b/test/acceptance/named-maps-static-view-test.js
@@ -6,7 +6,7 @@ var RedisPool = require('redis-mpool');
 
 var assert = require('../support/assert');
 const mapnik = require('@carto/mapnik');
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 var TemplateMaps = require('../../lib/backends/template-maps');
 
@@ -86,7 +86,7 @@ describe('named maps static view', function () {
         };
 
         // this could be removed once named maps are invalidated, otherwise you hits the cache
-        var server = new CartodbWindshaft(serverOptions);
+        var server = createServer(serverOptions);
 
         assert.response(server, requestOptions, expectedResponse, function (res, err) {
             testHelper.deleteRedisKeys({ 'user:localhost:mapviews:global': 5 }, function () {
@@ -323,7 +323,7 @@ describe('named maps static view', function () {
             };
 
             // this could be removed once named maps are invalidated, otherwise you hits the cache
-            var server = new CartodbWindshaft(serverOptions);
+            var server = createServer(serverOptions);
 
             assert.response(server, requestOptions, expectedResponse, function (res, err) {
                 assert.ifError(err);
diff --git a/test/acceptance/named-maps-stats-test.js b/test/acceptance/named-maps-stats-test.js
index c7a1ded7..bd6b474c 100644
--- a/test/acceptance/named-maps-stats-test.js
+++ b/test/acceptance/named-maps-stats-test.js
@@ -6,7 +6,7 @@ var querystring = require('querystring');
 
 var assert = require('../support/assert');
 const mapnik = require('@carto/mapnik');
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 var TemplateMaps = require('../../lib/backends/template-maps');
 var NamedMapsCacheEntry = require('../../lib/cache/model/named-maps-entry');
@@ -15,7 +15,7 @@ describe('named maps preview stats', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     var redisPool = new RedisPool(global.environment.redis);
diff --git a/test/acceptance/overviews-metadata-named-maps-test.js b/test/acceptance/overviews-metadata-named-maps-test.js
index 60712ec6..10dc2458 100644
--- a/test/acceptance/overviews-metadata-named-maps-test.js
+++ b/test/acceptance/overviews-metadata-named-maps-test.js
@@ -3,7 +3,7 @@
 var testHelper = require('../support/test-helper');
 
 var assert = require('../support/assert');
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 var LayergroupToken = require('../../lib/models/layergroup-token');
@@ -18,7 +18,7 @@ describe('overviews metadata for named maps', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     // configure redis pool instance to use in tests
diff --git a/test/acceptance/overviews-metadata-test.js b/test/acceptance/overviews-metadata-test.js
index d06b8cdf..828c34e3 100644
--- a/test/acceptance/overviews-metadata-test.js
+++ b/test/acceptance/overviews-metadata-test.js
@@ -3,7 +3,7 @@
 var testHelper = require('../support/test-helper');
 
 var assert = require('../support/assert');
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 var LayergroupToken = require('../../lib/models/layergroup-token');
@@ -18,7 +18,7 @@ describe('overviews metadata', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     // configure redis pool instance to use in tests
@@ -193,7 +193,7 @@ describe('overviews metadata with filters', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     // configure redis pool instance to use in tests
diff --git a/test/acceptance/regressions-test.js b/test/acceptance/regressions-test.js
index b777d729..a4c8672b 100644
--- a/test/acceptance/regressions-test.js
+++ b/test/acceptance/regressions-test.js
@@ -5,7 +5,7 @@ var assert = require('../support/assert');
 const helper = require('../support/test-helper');
 var TestClient = require('../support/test-client');
 const LayergroupToken = require('../../lib/models/layergroup-token');
-const CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 const serverOptions = require('../../lib/server-options');
 
 describe('regressions', function () {
@@ -44,7 +44,7 @@ describe('regressions', function () {
 
     // See: https://github.com/CartoDB/Windshaft-cartodb/pull/956
     it('"/user/localhost/api/v1/map" should create an anonymous map', function (done) {
-        const server = new CartodbWindshaft(serverOptions);
+        const server = createServer(serverOptions);
         const layergroup = {
             version: '1.7.0',
             layers: [
diff --git a/test/acceptance/server-test.js b/test/acceptance/server-test.js
index 7fb16e4d..245529aa 100644
--- a/test/acceptance/server-test.js
+++ b/test/acceptance/server-test.js
@@ -6,14 +6,14 @@ var assert = require('../support/assert');
 var querystring = require('querystring');
 var step = require('step');
 
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 describe('server', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
         server.setMaxListeners(0);
     });
 
@@ -45,7 +45,7 @@ describe('server old_api', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
         server.setMaxListeners(0);
     });
 
diff --git a/test/acceptance/templates-test.js b/test/acceptance/templates-test.js
index c7926fe3..fb4dca0b 100644
--- a/test/acceptance/templates-test.js
+++ b/test/acceptance/templates-test.js
@@ -21,7 +21,7 @@ var http = require('http');
 
 var helper = require('../support/test-helper');
 
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 
 var LayergroupToken = require('../../lib/models/layergroup-token');
@@ -30,7 +30,7 @@ describe('template_api', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
         server.setMaxListeners(0);
         // FIXME: we need a better way to reset cache while running tests
         server.layergroupAffectedTablesCache.cache.reset();
diff --git a/test/acceptance/turbo-carto/named-maps-test.js b/test/acceptance/turbo-carto/named-maps-test.js
index 5076b66f..67d40a54 100644
--- a/test/acceptance/turbo-carto/named-maps-test.js
+++ b/test/acceptance/turbo-carto/named-maps-test.js
@@ -4,7 +4,7 @@ var assert = require('../../support/assert');
 var step = require('step');
 var LayergroupToken = require('../../../lib/models/layergroup-token');
 var testHelper = require('../../support/test-helper');
-var CartodbWindshaft = require('../../../lib/server');
+const createServer = require('../../../lib/server');
 var serverOptions = require('../../../lib/server-options');
 const mapnik = require('@carto/mapnik');
 var IMAGE_TOLERANCE_PER_MIL = 10;
@@ -13,7 +13,7 @@ describe('turbo-carto for named maps', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     var keysToDelete;
diff --git a/test/acceptance/widgets/named-maps-test.js b/test/acceptance/widgets/named-maps-test.js
index b93f26eb..e91d71a4 100644
--- a/test/acceptance/widgets/named-maps-test.js
+++ b/test/acceptance/widgets/named-maps-test.js
@@ -8,7 +8,7 @@ var queue = require('queue-async');
 
 var helper = require('../../support/test-helper');
 
-var CartodbWindshaft = require('../../../lib/server');
+const createServer = require('../../../lib/server');
 var serverOptions = require('../../../lib/server-options');
 
 var LayergroupToken = require('../../../lib/models/layergroup-token');
@@ -17,7 +17,7 @@ describe('named-maps widgets', function () {
     var server;
 
     before(function () {
-        server = new CartodbWindshaft(serverOptions);
+        server = createServer(serverOptions);
     });
 
     var username = 'localhost';
diff --git a/test/support/test-client.js b/test/support/test-client.js
index 45fb198e..ffe71ef3 100644
--- a/test/support/test-client.js
+++ b/test/support/test-client.js
@@ -12,7 +12,7 @@ var LayergroupToken = require('../../lib/models/layergroup-token');
 var assert = require('./assert');
 var helper = require('./test-helper');
 
-var CartodbWindshaft = require('../../lib/server');
+const createServer = require('../../lib/server');
 var serverOptions = require('../../lib/server-options');
 serverOptions.analysis.batch.inlineExecution = true;
 
@@ -30,7 +30,7 @@ function TestClient (config, apiKey, extraHeaders = {}, overrideServerOptions =
     this.extraHeaders = extraHeaders;
     this.keysToDelete = {};
     this.serverOptions = Object.assign({}, serverOptions, overrideServerOptions);
-    this.server = new CartodbWindshaft(this.serverOptions);
+    this.server = createServer(this.serverOptions);
 }
 
 module.exports = TestClient;
@@ -1348,7 +1348,7 @@ TestClient.prototype.drain = function (callback) {
 module.exports.getStaticMap = function getStaticMap (templateName, params, callback) {
     var self = this;
 
-    self.server = new CartodbWindshaft(serverOptions);
+    self.server = createServer(serverOptions);
 
     if (!callback) {
         callback = params;
@@ -1378,7 +1378,7 @@ module.exports.getStaticMap = function getStaticMap (templateName, params, callb
     };
 
     // this could be removed once named maps are invalidated, otherwise you hits the cache
-    var server = new CartodbWindshaft(serverOptions);
+    var server = createServer(serverOptions);
 
     assert.response(server, requestOptions, expectedResponse, function (res, err) {
         helper.deleteRedisKeys({ 'user:localhost:mapviews:global': 5 }, function () {

From b60116410affe559fa9204395e09e3d64089faab Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 2 Jun 2020 12:31:18 +0200
Subject: [PATCH 05/44] Use req/res logger instead of the one bound to global
 object

---
 lib/api/map/anonymous-map-controller.js |  2 ++
 lib/api/middlewares/user.js             |  5 +--
 lib/backends/analysis.js                |  2 --
 lib/models/cdb-request.js               | 44 ++++++++++++-------------
 test/unit/cdb-request-test.js           | 13 ++++----
 5 files changed, 34 insertions(+), 32 deletions(-)

diff --git a/lib/api/map/anonymous-map-controller.js b/lib/api/map/anonymous-map-controller.js
index 85e9860a..7236935b 100644
--- a/lib/api/map/anonymous-map-controller.js
+++ b/lib/api/map/anonymous-map-controller.js
@@ -152,6 +152,7 @@ function prepareAdapterMapConfig (mapConfigAdapter) {
     return function prepareAdapterMapConfigMiddleware (req, res, next) {
         const requestMapConfig = req.body;
 
+        const { logger } = res.locals;
         const { user, api_key: apiKey } = res.locals;
         const { dbuser, dbname, dbpassword, dbhost, dbport } = res.locals;
         const params = Object.assign({ dbuser, dbname, dbpassword, dbhost, dbport }, req.query);
@@ -159,6 +160,7 @@ function prepareAdapterMapConfig (mapConfigAdapter) {
         const context = {
             analysisConfiguration: {
                 user,
+                logger,
                 db: {
                     host: dbhost,
                     port: dbport,
diff --git a/lib/api/middlewares/user.js b/lib/api/middlewares/user.js
index ce8c73bf..31e7f909 100644
--- a/lib/api/middlewares/user.js
+++ b/lib/api/middlewares/user.js
@@ -3,9 +3,10 @@
 const CdbRequest = require('../../models/cdb-request');
 
 module.exports = function user (metadataBackend) {
-    const cdbRequest = new CdbRequest();
-
     return function userMiddleware (req, res, next) {
+        const { logger } = res.locals;
+        const cdbRequest = new CdbRequest({ logger });
+
         res.locals.user = getUserNameFromRequest(req, cdbRequest);
 
         metadataBackend.getUserId(res.locals.user, (err, userId) => {
diff --git a/lib/backends/analysis.js b/lib/backends/analysis.js
index 2844a028..376e12bb 100644
--- a/lib/backends/analysis.js
+++ b/lib/backends/analysis.js
@@ -30,8 +30,6 @@ AnalysisBackend.prototype.create = function (analysisConfiguration, analysisDefi
     analysisConfiguration.batch.inlineExecution = this.batchConfig.inlineExecution;
     analysisConfiguration.batch.hostHeaderTemplate = this.batchConfig.hostHeaderTemplate;
 
-    analysisConfiguration.logger = global.logger;
-
     this.getAnalysesLimits(analysisConfiguration.user, function (err, limits) {
         if (err) {}
         analysisConfiguration.limits = limits || {};
diff --git a/lib/models/cdb-request.js b/lib/models/cdb-request.js
index 54b3db5c..a962b558 100644
--- a/lib/models/cdb-request.js
+++ b/lib/models/cdb-request.js
@@ -1,29 +1,29 @@
 'use strict';
 
-function CdbRequest () {
-    this.RE_USER_FROM_HOST = new RegExp(global.environment.user_from_host ||
-            '^([^\\.]+)\\.' // would extract "strk" from "strk.cartodb.com"
-    );
-}
-
-module.exports = CdbRequest;
-
-CdbRequest.prototype.userByReq = function (req) {
-    var host = req.headers.host || '';
-
-    if (req.params.user) {
-        return req.params.user;
+module.exports = class CdbRequest {
+    constructor ({ logger }) {
+        this.logger = logger;
+        // would extract "strk" from "strk.cartodb.com"
+        this.RE_USER_FROM_HOST = new RegExp(global.environment.user_from_host || '^([^\\.]+)\\.');
     }
 
-    var mat = host.match(this.RE_USER_FROM_HOST);
+    userByReq (req) {
+        const host = req.headers.host || '';
 
-    if (!mat) {
-        return global.logger.error(new Error(`Pattern '${this.RE_USER_FROM_HOST}' does not match hostname '${host}'`));
+        if (req.params.user) {
+            return req.params.user;
+        }
+
+        const mat = host.match(this.RE_USER_FROM_HOST);
+
+        if (!mat) {
+            return this.logger.error(new Error(`Pattern '${this.RE_USER_FROM_HOST}' does not match hostname '${host}'`));
+        }
+
+        if (mat.length !== 2) {
+            return this.logger.error(new Error(`Pattern '${this.RE_USER_FROM_HOST}' gave unexpected matches against '${host}': ${mat}`));
+        }
+
+        return mat[1];
     }
-
-    if (mat.length !== 2) {
-        return global.logger.error(new Error(`Pattern '${this.RE_USER_FROM_HOST}' gave unexpected matches against '${host}': ${mat}`));
-    }
-
-    return mat[1];
 };
diff --git a/test/unit/cdb-request-test.js b/test/unit/cdb-request-test.js
index 3e1880f7..9db38488 100644
--- a/test/unit/cdb-request-test.js
+++ b/test/unit/cdb-request-test.js
@@ -4,6 +4,7 @@ require('../support/test-helper');
 var assert = require('assert');
 
 var CdbRequest = require('../../lib/models/cdb-request');
+const { logger } = require('../../lib/server-options');
 
 describe('req2params', function () {
     function createRequest (host, userParam) {
@@ -22,7 +23,7 @@ describe('req2params', function () {
     }
 
     it('extracts name from host header', function () {
-        var cdbRequest = new CdbRequest();
+        var cdbRequest = new CdbRequest({ logger });
         var user = cdbRequest.userByReq(createRequest('localhost'));
 
         assert.strictEqual(user, 'localhost');
@@ -32,7 +33,7 @@ describe('req2params', function () {
         var userFromHostConfig = global.environment.user_from_host;
         global.environment.user_from_host = null;
 
-        var cdbRequest = new CdbRequest();
+        var cdbRequest = new CdbRequest({ logger });
         var user = cdbRequest.userByReq(createRequest('development.localhost.lan'));
 
         global.environment.user_from_host = userFromHostConfig;
@@ -41,7 +42,7 @@ describe('req2params', function () {
     });
 
     it('considers user param before headers', function () {
-        var cdbRequest = new CdbRequest();
+        var cdbRequest = new CdbRequest({ logger });
         var user = cdbRequest.userByReq(createRequest('localhost', 'development'));
 
         assert.strictEqual(user, 'development');
@@ -51,7 +52,7 @@ describe('req2params', function () {
         var userFromHostConfig = global.environment.user_from_host;
         global.environment.user_from_host = null;
 
-        var cdbRequest = new CdbRequest();
+        var cdbRequest = new CdbRequest({ logger });
         var user = cdbRequest.userByReq(createRequest('localhost'));
 
         global.environment.user_from_host = userFromHostConfig;
@@ -63,7 +64,7 @@ describe('req2params', function () {
         var userFromHostConfig = global.environment.user_from_host;
         global.environment.user_from_host = null;
 
-        var cdbRequest = new CdbRequest();
+        var cdbRequest = new CdbRequest({ logger });
         var user = cdbRequest.userByReq(createRequest(undefined));
 
         global.environment.user_from_host = userFromHostConfig;
@@ -75,7 +76,7 @@ describe('req2params', function () {
         var userFromHostConfig = global.environment.user_from_host;
         global.environment.user_from_host = null;
 
-        var cdbRequest = new CdbRequest();
+        var cdbRequest = new CdbRequest({ logger });
         var user = cdbRequest.userByReq(createRequest(null));
 
         global.environment.user_from_host = userFromHostConfig;

From b7b3392bdd6784896315d752f061feb39915e45b Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 2 Jun 2020 13:16:26 +0200
Subject: [PATCH 06/44] Be able to set log level from env variable LOG_LEVEL

---
 lib/utils/logger.js | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/lib/utils/logger.js b/lib/utils/logger.js
index 4d1340a7..33646049 100644
--- a/lib/utils/logger.js
+++ b/lib/utils/logger.js
@@ -5,11 +5,12 @@ const pino = require('pino');
 module.exports = class Logger {
     constructor () {
         const { LOG_LEVEL, NODE_ENV } = process.env;
+        const logLevelFromNodeEnv = NODE_ENV === 'test' ? 'fatal' : 'info';
         const options = {
             base: null, // Do not bind hostname, pid and friends by default
-            level: LOG_LEVEL || NODE_ENV === 'test' ? 'fatal' : 'info'
+            level: LOG_LEVEL || logLevelFromNodeEnv
         };
-        const dest = pino.destination({ sync: false });
+        const dest = pino.destination({ sync: false }); // stdout
 
         this._logger = pino(options, dest);
     }

From afeb91dc8605d96b1ab603ebef17c0c813863d33 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 2 Jun 2020 13:20:57 +0200
Subject: [PATCH 07/44] Bring back logger for windshaft

---
 lib/api/api-router.js | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/lib/api/api-router.js b/lib/api/api-router.js
index bee3ef90..62d318d9 100644
--- a/lib/api/api-router.js
+++ b/lib/api/api-router.js
@@ -86,7 +86,8 @@ module.exports = class ApiRouter {
         const { rendererCache, tileBackend, attributesBackend, previewBackend, mapBackend, mapStore } = windshaftFactory({
             rendererOptions: serverOptions,
             redisPool,
-            onTileErrorStrategy: getOnTileErrorStrategy({ enabled: environmentOptions.enabledFeatures.onTileErrorStrategy })
+            onTileErrorStrategy: getOnTileErrorStrategy({ enabled: environmentOptions.enabledFeatures.onTileErrorStrategy }),
+            logger: this.serverOptions.logger
         });
 
         const rendererStatsReporter = new RendererStatsReporter(rendererCache, serverOptions.renderCache.statsInterval);

From 7d8d05b865ab7a7efbc81c9aa4021f2b32c14928 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 2 Jun 2020 16:11:39 +0200
Subject: [PATCH 08/44] Log errors and do not send 'X-Tiler-Errors' header

---
 lib/api/middlewares/error-middleware.js  |  62 +--------
 test/acceptance/error-middleware-test.js |  44 ------
 test/unit/error-middleware-test.js       | 167 -----------------------
 3 files changed, 6 insertions(+), 267 deletions(-)
 delete mode 100644 test/acceptance/error-middleware-test.js

diff --git a/lib/api/middlewares/error-middleware.js b/lib/api/middlewares/error-middleware.js
index 05d1bd49..0822c144 100644
--- a/lib/api/middlewares/error-middleware.js
+++ b/lib/api/middlewares/error-middleware.js
@@ -1,10 +1,10 @@
 'use strict';
 
-const _ = require('underscore');
 const debug = require('debug')('windshaft:cartodb:error-middleware');
 
 module.exports = function errorMiddleware (/* options */) {
     return function error (err, req, res, next) {
+        const { logger } = res.locals;
         var allErrors = Array.isArray(err) ? err : [err];
 
         allErrors = populateLimitErrors(allErrors);
@@ -15,14 +15,14 @@ module.exports = function errorMiddleware (/* options */) {
 
         var statusCode = findStatusCode(err);
 
-        setErrorHeader(allErrors, statusCode, res);
-        debug('[%s ERROR] -- %d: %s, %s', label, statusCode, err, err.stack);
-
         // If a callback was requested, force status to 200
         if (req.query && req.query.callback) {
             statusCode = 200;
         }
 
+        allErrors.forEach((err) => debug('[%s ERROR] -- %d: %s, %s', label, statusCode, err, err.stack));
+        allErrors.forEach((err) => logger.error(err));
+
         var errorResponseBody = {
             errors: allErrors.map(errorMessage),
             errors_with_context: allErrors.map(errorMessageWithContext)
@@ -135,7 +135,7 @@ function statusFromErrorMessage (errMsg) {
 
 function errorMessage (err) {
     // See https://github.com/Vizzuality/Windshaft-cartodb/issues/68
-    var message = (_.isString(err) ? err : err.message) || 'Unknown error';
+    var message = (typeof err === 'string' ? err : err.message) || 'Unknown error';
 
     return stripConnectionInfo(message);
 }
@@ -165,7 +165,7 @@ function shouldBeExposed (prop) {
 
 function errorMessageWithContext (err) {
     // See https://github.com/Vizzuality/Windshaft-cartodb/issues/68
-    var message = (_.isString(err) ? err : err.message) || 'Unknown error';
+    var message = (typeof err === 'string' ? err : err.message) || 'Unknown error';
 
     var error = {
         type: err.type || 'unknown',
@@ -181,53 +181,3 @@ function errorMessageWithContext (err) {
 
     return error;
 }
-
-function setErrorHeader (errors, statusCode, res) {
-    const errorsCopy = errors.slice(0);
-    const mainError = errorsCopy.shift();
-
-    const errorsLog = {
-        mainError: {
-            statusCode: statusCode || 200,
-            message: mainError.message,
-            name: mainError.name,
-            label: mainError.label,
-            type: mainError.type,
-            subtype: mainError.subtype
-        }
-    };
-
-    errorsLog.moreErrors = errorsCopy.map(error => {
-        return {
-            message: error.message,
-            name: error.name,
-            label: error.label,
-            type: error.type,
-            subtype: error.subtype
-        };
-    });
-
-    res.set('X-Tiler-Errors', stringifyForLogs(errorsLog));
-}
-
-/**
- * Remove problematic nested characters
- * from object for logs RegEx
- *
- * @param {Object} object
- */
-function stringifyForLogs (object) {
-    Object.keys(object).map(key => {
-        if (typeof object[key] === 'string') {
-            object[key] = object[key].replace(/[^a-zA-Z0-9]/g, ' ');
-        } else if (typeof object[key] === 'object') {
-            stringifyForLogs(object[key]);
-        } else if (object[key] instanceof Array) {
-            for (const element of object[key]) {
-                stringifyForLogs(element);
-            }
-        }
-    });
-
-    return JSON.stringify(object);
-}
diff --git a/test/acceptance/error-middleware-test.js b/test/acceptance/error-middleware-test.js
deleted file mode 100644
index 936c957f..00000000
--- a/test/acceptance/error-middleware-test.js
+++ /dev/null
@@ -1,44 +0,0 @@
-'use strict';
-
-const assert = require('../support/assert');
-const TestClient = require('../support/test-client');
-
-describe('error middleware', function () {
-    it('should returns a errors header', function (done) {
-        const mapConfig = {
-            version: '1.6.0',
-            layers: [{
-                type: 'mapnik',
-                options: {}
-            }]
-        };
-
-        const errorHeader = {
-            mainError: {
-                statusCode: 400,
-                message: 'Missing cartocss for layer 0 options',
-                name: 'Error',
-                label: 'ANONYMOUS LAYERGROUP',
-                type: 'layer'
-            },
-            moreErrors: []
-        };
-
-        this.testClient = new TestClient(mapConfig, 1234);
-
-        const params = {
-            response: {
-                status: 400,
-                headers: {
-                    'Content-Type': 'application/json; charset=utf-8',
-                    'X-Tiler-Errors': JSON.stringify(errorHeader)
-                }
-            }
-        };
-
-        this.testClient.getLayergroup(params, (err) => {
-            assert.ifError(err);
-            done();
-        });
-    });
-});
diff --git a/test/unit/error-middleware-test.js b/test/unit/error-middleware-test.js
index b973d49a..8b845de5 100644
--- a/test/unit/error-middleware-test.js
+++ b/test/unit/error-middleware-test.js
@@ -20,171 +20,4 @@ describe('error-middleware', function () {
             'Error status code for multiline/PSQL does not match'
         );
     });
-
-    it('should return a header with errors', function (done) {
-        const error = new Error('error test');
-        error.label = 'test label';
-        error.type = 'test type';
-        error.subtype = 'test subtype';
-
-        const errors = [error, error];
-
-        const req = {};
-        const res = {
-            headers: {},
-            set (key, value) {
-                this.headers[key] = value;
-            },
-            statusCode: 0,
-            status (status) {
-                this.statusCode = status;
-            },
-            json () {},
-            send () {}
-        };
-
-        const errorHeader = {
-            mainError: {
-                statusCode: 400,
-                message: error.message,
-                name: error.name,
-                label: error.label,
-                type: error.type,
-                subtype: error.subtype
-            },
-            moreErrors: [{
-                message: error.message,
-                name: error.name,
-                label: error.label,
-                type: error.type,
-                subtype: error.subtype
-            }]
-        };
-
-        const errorFn = errorMiddleware();
-        errorFn(errors, req, res, (err) => {
-            if (err) {
-                return done(err);
-            }
-
-            assert.deepStrictEqual(res.headers, {
-                'X-Tiler-Errors': JSON.stringify(errorHeader)
-            });
-
-            return done();
-        });
-    });
-
-    it('JSONP should return a header with error status code', function (done) {
-        const error = new Error('error test');
-        error.label = 'test label';
-        error.type = 'test type';
-        error.subtype = 'test subtype';
-
-        const errors = [error, error];
-
-        const req = {
-            query: { callback: true }
-        };
-        const res = {
-            headers: {},
-            set (key, value) {
-                this.headers[key] = value;
-            },
-            statusCode: 0,
-            status (status) {
-                this.statusCode = status;
-            },
-            jsonp () {},
-            send () {}
-        };
-
-        const errorHeader = {
-            mainError: {
-                statusCode: 400,
-                message: error.message,
-                name: error.name,
-                label: error.label,
-                type: error.type,
-                subtype: error.subtype
-            },
-            moreErrors: [{
-                message: error.message,
-                name: error.name,
-                label: error.label,
-                type: error.type,
-                subtype: error.subtype
-            }]
-        };
-
-        const errorFn = errorMiddleware();
-        errorFn(errors, req, res, (err) => {
-            if (err) {
-                return done(err);
-            }
-
-            assert.deepStrictEqual(res.headers, {
-                'X-Tiler-Errors': JSON.stringify(errorHeader)
-            });
-
-            return done();
-        });
-    });
-
-    it('should escape chars that broke logs regex', function (done) {
-        const badString = 'error: ( ) = " \" \' * $ & |'; // eslint-disable-line no-useless-escape
-        const escapedString = 'error                     ';
-
-        const error = new Error(badString);
-        error.label = badString;
-        error.type = badString;
-        error.subtype = badString;
-
-        const errors = [error, error];
-
-        const req = {};
-        const res = {
-            headers: {},
-            set (key, value) {
-                this.headers[key] = value;
-            },
-            statusCode: 0,
-            status (status) {
-                this.statusCode = status;
-            },
-            json () {},
-            send () {}
-        };
-
-        const errorHeader = {
-            mainError: {
-                statusCode: 400,
-                message: escapedString,
-                name: error.name,
-                label: escapedString,
-                type: escapedString,
-                subtype: escapedString
-            },
-            moreErrors: [{
-                message: escapedString,
-                name: error.name,
-                label: escapedString,
-                type: escapedString,
-                subtype: escapedString
-            }]
-        };
-
-        const errorFn = errorMiddleware();
-        errorFn(errors, req, res, (err) => {
-            if (err) {
-                return done(err);
-            }
-
-            assert.deepStrictEqual(res.headers, {
-                'X-Tiler-Errors': JSON.stringify(errorHeader)
-            });
-
-            return done();
-        });
-    });
 });

From 29c6505252413edda9929c97d6c29c84acd85703 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 2 Jun 2020 17:09:06 +0200
Subject: [PATCH 09/44] Do not set header 'x-tiler-profiler' and log it instead

---
 lib/api/api-router.js                         |   4 +-
 lib/api/middlewares/metrics.js                |   9 +-
 lib/api/middlewares/{stats.js => profiler.js} |  11 +-
 lib/stats/profiler-proxy.js                   |   4 +
 package-lock.json                             |   5 -
 package.json                                  |   1 -
 test/acceptance/dataviews/overviews-test.js   |  24 +---
 .../overviews-metadata-named-maps-test.js     | 122 ------------------
 test/acceptance/overviews-metadata-test.js    |  77 -----------
 9 files changed, 17 insertions(+), 240 deletions(-)
 rename lib/api/middlewares/{stats.js => profiler.js} (73%)

diff --git a/lib/api/api-router.js b/lib/api/api-router.js
index 62d318d9..13a4fdd6 100644
--- a/lib/api/api-router.js
+++ b/lib/api/api-router.js
@@ -50,7 +50,7 @@ const initializeStatusCode = require('./middlewares/initialize-status-code');
 const initLogger = require('./middlewares/logger');
 const bodyParser = require('body-parser');
 const servedByHostHeader = require('./middlewares/served-by-host-header');
-const stats = require('./middlewares/stats');
+const profiler = require('./middlewares/profiler');
 const lzmaMiddleware = require('./middlewares/lzma');
 const cors = require('./middlewares/cors');
 const user = require('./middlewares/user');
@@ -206,7 +206,7 @@ module.exports = class ApiRouter {
             apiRouter.use(bodyParser.json());
             apiRouter.use(servedByHostHeader());
             apiRouter.use(clientHeader());
-            apiRouter.use(stats({
+            apiRouter.use(profiler({
                 enabled: this.serverOptions.useProfiler,
                 statsClient: global.statsClient
             }));
diff --git a/lib/api/middlewares/metrics.js b/lib/api/middlewares/metrics.js
index 60478557..dc69b373 100644
--- a/lib/api/middlewares/metrics.js
+++ b/lib/api/middlewares/metrics.js
@@ -53,7 +53,7 @@ function getEventData (req, res, tags) {
         template_hash: getTemplateHash({ res }),
         stat_tag: getStatTag({ res }),
         response_code: res.statusCode.toString(),
-        response_time: getResponseTime(res),
+        response_time: getResponseTime(req),
         source_domain: req.hostname,
         event_version: EVENT_VERSION
     }, tags.attributes, extra);
@@ -123,13 +123,12 @@ function getStatTag ({ res }) {
     }
 }
 
-// FIXME: 'X-Tiler-Profiler' might not be accurate enough
-function getResponseTime (res) {
-    const profiler = res.get('X-Tiler-Profiler');
+// FIXME: 'Profiler' might not be accurate enough
+function getResponseTime (req) {
     let stats;
 
     try {
-        stats = JSON.parse(profiler);
+        stats = req.profiler.toJSON();
     } catch (e) {
         return undefined;
     }
diff --git a/lib/api/middlewares/stats.js b/lib/api/middlewares/profiler.js
similarity index 73%
rename from lib/api/middlewares/stats.js
rename to lib/api/middlewares/profiler.js
index 9fe212ac..9ed3eb7b 100644
--- a/lib/api/middlewares/stats.js
+++ b/lib/api/middlewares/profiler.js
@@ -2,20 +2,21 @@
 
 const Profiler = require('../../stats/profiler-proxy');
 const debug = require('debug')('windshaft:cartodb:stats');
-const onHeaders = require('on-headers');
 
-module.exports = function stats (options) {
+module.exports = function profiler (options) {
     const { enabled = true, statsClient } = options;
 
-    return function statsMiddleware (req, res, next) {
+    return function profilerMiddleware (req, res, next) {
+        const { logger } = res.locals;
+
         req.profiler = new Profiler({
             statsd_client: statsClient,
             profile: enabled
         });
 
-        onHeaders(res, () => res.set('X-Tiler-Profiler', req.profiler.toJSONString()));
-
         res.on('finish', () => {
+            logger.info({ stats: req.profiler.toJSON() });
+
             try {
                 // May throw due to dns, see: http://github.com/CartoDB/Windshaft/issues/166
                 req.profiler.sendStats();
diff --git a/lib/stats/profiler-proxy.js b/lib/stats/profiler-proxy.js
index 9dad81f5..dc2de378 100644
--- a/lib/stats/profiler-proxy.js
+++ b/lib/stats/profiler-proxy.js
@@ -52,4 +52,8 @@ ProfilerProxy.prototype.toJSONString = function () {
     return this.profile ? this.profiler.toJSONString() : '{}';
 };
 
+ProfilerProxy.prototype.toJSON = function () {
+    return this.profile ? JSON.parse(this.profiler.toJSONString()) : {};
+};
+
 module.exports = ProfilerProxy;
diff --git a/package-lock.json b/package-lock.json
index 4eb1f3c8..fe1e59de 100644
--- a/package-lock.json
+++ b/package-lock.json
@@ -4920,11 +4920,6 @@
         "ee-first": "1.1.1"
       }
     },
-    "on-headers": {
-      "version": "1.0.1",
-      "resolved": "https://registry.npmjs.org/on-headers/-/on-headers-1.0.1.tgz",
-      "integrity": "sha1-ko9dD0cNSTQmUepnlLCFfBAGk/c="
-    },
     "once": {
       "version": "1.4.0",
       "resolved": "https://registry.npmjs.org/once/-/once-1.4.0.tgz",
diff --git a/package.json b/package.json
index 4e656ff0..af37467f 100644
--- a/package.json
+++ b/package.json
@@ -51,7 +51,6 @@
     "lru-cache": "4.1.3",
     "lzma": "2.3.2",
     "node-statsd": "0.1.1",
-    "on-headers": "1.0.1",
     "pino": "^6.3.1",
     "queue-async": "1.1.0",
     "redis-mpool": "^0.8.0",
diff --git a/test/acceptance/dataviews/overviews-test.js b/test/acceptance/dataviews/overviews-test.js
index f46226a8..722f486c 100644
--- a/test/acceptance/dataviews/overviews-test.js
+++ b/test/acceptance/dataviews/overviews-test.js
@@ -55,7 +55,6 @@ describe('dataviews using tables without overviews', function () {
                 return done(err);
             }
             assert.deepStrictEqual(formulaResult, { operation: 'count', result: 7313, nulls: 0, type: 'formula' });
-            assert(getUsesOverviewsFromHeaders(headers) === false); // Overviews logging
 
             testClient.drain(done);
         });
@@ -269,8 +268,6 @@ describe('dataviews using tables with overviews', function () {
                 nulls: 0,
                 type: 'formula'
             });
-            assert.ok(getUsesOverviewsFromHeaders(headers)); // Overviews logging
-            assert(getDataviewTypeFromHeaders(headers) === 'formula'); // Overviews logging
 
             testClient.drain(done);
         });
@@ -290,8 +287,6 @@ describe('dataviews using tables with overviews', function () {
                 infinities: 0,
                 nans: 0
             });
-            assert.ok(getUsesOverviewsFromHeaders(headers)); // Overviews logging
-            assert(getDataviewTypeFromHeaders(headers) === 'formula'); // Overviews logging
 
             testClient.drain(done);
         });
@@ -311,8 +306,6 @@ describe('dataviews using tables with overviews', function () {
                 infinities: 0,
                 nans: 0
             });
-            assert.ok(getUsesOverviewsFromHeaders(headers)); // Overviews logging
-            assert(getDataviewTypeFromHeaders(headers) === 'formula'); // Overviews logging
 
             testClient.drain(done);
         });
@@ -387,8 +380,6 @@ describe('dataviews using tables with overviews', function () {
             assert.ok(histogram);
             assert.strictEqual(histogram.type, 'histogram');
             assert.ok(Array.isArray(histogram.bins));
-            assert.ok(getUsesOverviewsFromHeaders(headers)); // Overviews logging
-            assert(getDataviewTypeFromHeaders(headers) === 'histogram'); // Overviews logging
 
             testClient.drain(done);
         });
@@ -480,7 +471,7 @@ describe('dataviews using tables with overviews', function () {
                         nans: 0,
                         type: 'formula'
                     });
-                    assert.ok(getUsesOverviewsFromHeaders(headers)); // Overviews logging
+
                     testClient.drain(done);
                 });
             });
@@ -499,7 +490,6 @@ describe('dataviews using tables with overviews', function () {
                         nans: 0,
                         type: 'formula'
                     });
-                    assert.ok(getUsesOverviewsFromHeaders(headers)); // Overviews logging
 
                     testClient.drain(done);
                 });
@@ -519,7 +509,6 @@ describe('dataviews using tables with overviews', function () {
                         nulls: 0,
                         type: 'formula'
                     });
-                    assert.ok(getUsesOverviewsFromHeaders(headers)); // Overviews logging
 
                     testClient.drain(done);
                 });
@@ -611,9 +600,6 @@ describe('dataviews using tables with overviews', function () {
                         type: 'aggregation'
                     });
 
-                    assert.ok(getUsesOverviewsFromHeaders(headers)); // Overviews logging
-                    assert(getDataviewTypeFromHeaders(headers) === 'aggregation'); // Overviews logging
-
                     testClient.drain(done);
                 });
             });
@@ -830,11 +816,3 @@ describe('dataviews using tables with overviews', function () {
         });
     });
 });
-
-function getUsesOverviewsFromHeaders (headers) {
-    return headers && headers['x-tiler-profiler'] && JSON.parse(headers['x-tiler-profiler']).usesOverviews;
-}
-
-function getDataviewTypeFromHeaders (headers) {
-    return headers && headers['x-tiler-profiler'] && JSON.parse(headers['x-tiler-profiler']).dataviewType;
-}
diff --git a/test/acceptance/overviews-metadata-named-maps-test.js b/test/acceptance/overviews-metadata-named-maps-test.js
index 10dc2458..be41488b 100644
--- a/test/acceptance/overviews-metadata-named-maps-test.js
+++ b/test/acceptance/overviews-metadata-named-maps-test.js
@@ -172,126 +172,4 @@ describe('overviews metadata for named maps', function () {
             }
         );
     });
-
-    describe('Overviews Flags', function () {
-        it('Overviews used', function (done) {
-            step(
-                function postTemplate () {
-                    var next = this;
-
-                    assert.response(server, {
-                        url: '/api/v1/map/named?api_key=1234',
-                        method: 'POST',
-                        headers: { host: 'localhost', 'Content-Type': 'application/json' },
-                        data: JSON.stringify(template)
-                    }, {}, function (res, err) {
-                        next(err, res);
-                    });
-                },
-                function instantiateTemplate (err) {
-                    assert.ifError(err);
-
-                    var next = this;
-                    assert.response(server, {
-                        url: '/api/v1/map/named/' + templateId,
-                        method: 'POST',
-                        headers: {
-                            host: 'localhost',
-                            'Content-Type': 'application/json'
-                        }
-                    }, {},
-                    function (res, err) {
-                        return next(err, res);
-                    });
-                },
-                function checkFlags (err, res) {
-                    assert.ifError(err);
-
-                    var next = this;
-
-                    var parsedBody = JSON.parse(res.body);
-
-                    keysToDelete['map_cfg|' + LayergroupToken.parse(parsedBody.layergroupid).token] = 0;
-                    keysToDelete['user:localhost:mapviews:global'] = 5;
-
-                    const headers = JSON.parse(res.headers['x-tiler-profiler']);
-
-                    assert.ok(headers.overviewsAddedToMapconfig);
-                    assert.strictEqual(headers.mapType, 'named');
-
-                    next();
-                },
-
-                function finish (err) {
-                    done(err);
-                }
-            );
-        });
-
-        it('Overviews NOT used', function (done) {
-            const nonOverviewsTemplateId = 'non-overviews-template';
-
-            var nonOverviewsTemplate = {
-                version: '0.0.1',
-                name: nonOverviewsTemplateId,
-                auth: { method: 'open' },
-                layergroup: {
-                    version: '1.0.0',
-                    layers: [nonOverviewsLayer]
-                }
-            };
-
-            step(
-                function postTemplate () {
-                    var next = this;
-
-                    assert.response(server, {
-                        url: '/api/v1/map/named?api_key=1234',
-                        method: 'POST',
-                        headers: { host: 'localhost', 'Content-Type': 'application/json' },
-                        data: JSON.stringify(nonOverviewsTemplate)
-                    }, {}, function (res, err) {
-                        next(err, res);
-                    });
-                },
-                function instantiateTemplate (err) {
-                    assert.ifError(err);
-
-                    var next = this;
-                    assert.response(server, {
-                        url: '/api/v1/map/named/' + nonOverviewsTemplateId,
-                        method: 'POST',
-                        headers: {
-                            host: 'localhost',
-                            'Content-Type': 'application/json'
-                        }
-                    }, {},
-                    function (res, err) {
-                        return next(err, res);
-                    });
-                },
-                function checkFlags (err, res) {
-                    assert.ifError(err);
-
-                    var next = this;
-
-                    var parsedBody = JSON.parse(res.body);
-
-                    keysToDelete['map_cfg|' + LayergroupToken.parse(parsedBody.layergroupid).token] = 0;
-                    keysToDelete['user:localhost:mapviews:global'] = 5;
-
-                    const headers = JSON.parse(res.headers['x-tiler-profiler']);
-
-                    assert.strictEqual(headers.overviewsAddedToMapconfig, false);
-                    assert.strictEqual(headers.mapType, 'named');
-
-                    next();
-                },
-
-                function finish (err) {
-                    done(err);
-                }
-            );
-        });
-    });
 });
diff --git a/test/acceptance/overviews-metadata-test.js b/test/acceptance/overviews-metadata-test.js
index 828c34e3..e2ca3be3 100644
--- a/test/acceptance/overviews-metadata-test.js
+++ b/test/acceptance/overviews-metadata-test.js
@@ -110,83 +110,6 @@ describe('overviews metadata', function () {
             }
         );
     });
-
-    describe('Overviews Flags', function () {
-        it('Overviews used', function (done) {
-            var layergroup = {
-                version: '1.0.0',
-                layers: [overviewsLayer, nonOverviewsLayer]
-            };
-
-            var layergroupUrl = '/api/v1/map';
-
-            var expectedToken;
-            step(
-                function doPost () {
-                    var next = this;
-                    assert.response(server, {
-                        url: layergroupUrl,
-                        method: 'POST',
-                        headers: { host: 'localhost', 'Content-Type': 'application/json' },
-                        data: JSON.stringify(layergroup)
-                    }, {}, function (res) {
-                        assert.strictEqual(res.statusCode, 200, res.body);
-
-                        const headers = JSON.parse(res.headers['x-tiler-profiler']);
-
-                        assert.ok(headers.overviewsAddedToMapconfig);
-                        assert.strictEqual(headers.mapType, 'anonymous');
-
-                        const parsedBody = JSON.parse(res.body);
-                        expectedToken = parsedBody.layergroupid;
-                        next();
-                    });
-                },
-                function finish (err) {
-                    keysToDelete['map_cfg|' + LayergroupToken.parse(expectedToken).token] = 0;
-                    keysToDelete['user:localhost:mapviews:global'] = 5;
-                    done(err);
-                }
-            );
-        });
-        it('Overviews NOT used', function (done) {
-            var layergroup = {
-                version: '1.0.0',
-                layers: [nonOverviewsLayer]
-            };
-
-            var layergroupUrl = '/api/v1/map';
-
-            var expectedToken;
-            step(
-                function doPost () {
-                    var next = this;
-                    assert.response(server, {
-                        url: layergroupUrl,
-                        method: 'POST',
-                        headers: { host: 'localhost', 'Content-Type': 'application/json' },
-                        data: JSON.stringify(layergroup)
-                    }, {}, function (res) {
-                        assert.strictEqual(res.statusCode, 200, res.body);
-
-                        const headers = JSON.parse(res.headers['x-tiler-profiler']);
-
-                        assert.strictEqual(headers.overviewsAddedToMapconfig, false);
-                        assert.strictEqual(headers.mapType, 'anonymous');
-
-                        const parsedBody = JSON.parse(res.body);
-                        expectedToken = parsedBody.layergroupid;
-                        next();
-                    });
-                },
-                function finish (err) {
-                    keysToDelete['map_cfg|' + LayergroupToken.parse(expectedToken).token] = 0;
-                    keysToDelete['user:localhost:mapviews:global'] = 5;
-                    done(err);
-                }
-            );
-        });
-    });
 });
 
 describe('overviews metadata with filters', function () {

From 1e89821d976070101115287201eba78eda10db97 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 3 Jun 2020 14:28:35 +0200
Subject: [PATCH 10/44] Use standard serializers for error, request, and
 response

---
 lib/api/middlewares/error-middleware.js | 5 +++--
 lib/api/middlewares/logger.js           | 4 ++--
 lib/utils/logger.js                     | 7 ++++++-
 3 files changed, 11 insertions(+), 5 deletions(-)

diff --git a/lib/api/middlewares/error-middleware.js b/lib/api/middlewares/error-middleware.js
index 0822c144..583b54f5 100644
--- a/lib/api/middlewares/error-middleware.js
+++ b/lib/api/middlewares/error-middleware.js
@@ -9,6 +9,7 @@ module.exports = function errorMiddleware (/* options */) {
 
         allErrors = populateLimitErrors(allErrors);
 
+        // TODO REMOVE THIS THREE LINES PLEASE
         const label = err.label || 'UNKNOWN';
         err = allErrors[0] || new Error(label);
         allErrors[0] = err;
@@ -20,8 +21,8 @@ module.exports = function errorMiddleware (/* options */) {
             statusCode = 200;
         }
 
-        allErrors.forEach((err) => debug('[%s ERROR] -- %d: %s, %s', label, statusCode, err, err.stack));
-        allErrors.forEach((err) => logger.error(err));
+        allErrors.forEach((err) => debug('[%s ERROR] -- %d: %s, %s', err.label || 'UNKNOWN', statusCode, err, err.stack));
+        logger.error({ errors: allErrors });
 
         var errorResponseBody = {
             errors: allErrors.map(errorMessage),
diff --git a/lib/api/middlewares/logger.js b/lib/api/middlewares/logger.js
index 93a02a03..09b92ef0 100644
--- a/lib/api/middlewares/logger.js
+++ b/lib/api/middlewares/logger.js
@@ -7,8 +7,8 @@ module.exports = function initLogger ({ logger }) {
         const id = req.get('X-Request-Id') || uuid.v4();
         res.locals.logger = logger.child({ id });
 
-        res.locals.logger.info(req);
-        res.on('finish', () => res.locals.logger.info(res));
+        res.locals.logger.info({ request: req });
+        res.on('finish', () => res.locals.logger.info({ response: res }));
 
         next();
     };
diff --git a/lib/utils/logger.js b/lib/utils/logger.js
index 33646049..d9c9b85c 100644
--- a/lib/utils/logger.js
+++ b/lib/utils/logger.js
@@ -8,7 +8,12 @@ module.exports = class Logger {
         const logLevelFromNodeEnv = NODE_ENV === 'test' ? 'fatal' : 'info';
         const options = {
             base: null, // Do not bind hostname, pid and friends by default
-            level: LOG_LEVEL || logLevelFromNodeEnv
+            level: LOG_LEVEL || logLevelFromNodeEnv,
+            serializers: {
+                request: pino.stdSerializers.req,
+                response: pino.stdSerializers.res,
+                errors: (errors) => errors.map((err) => pino.stdSerializers.err(err))
+            }
         };
         const dest = pino.destination({ sync: false }); // stdout
 

From 219d2c9044f80ef884cd563f05b4e8b43ccbb010 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 3 Jun 2020 15:10:31 +0200
Subject: [PATCH 11/44] Shortcuts for serializers

---
 lib/utils/logger.js | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/lib/utils/logger.js b/lib/utils/logger.js
index d9c9b85c..0a4b3df0 100644
--- a/lib/utils/logger.js
+++ b/lib/utils/logger.js
@@ -1,6 +1,7 @@
 'use strict';
 
 const pino = require('pino');
+const { req: requestSerializer, res: responseSerializer, err: errorSerializer } = pino.stdSerializers;
 
 module.exports = class Logger {
     constructor () {
@@ -10,9 +11,9 @@ module.exports = class Logger {
             base: null, // Do not bind hostname, pid and friends by default
             level: LOG_LEVEL || logLevelFromNodeEnv,
             serializers: {
-                request: pino.stdSerializers.req,
-                response: pino.stdSerializers.res,
-                errors: (errors) => errors.map((err) => pino.stdSerializers.err(err))
+                request: requestSerializer,
+                response: responseSerializer,
+                errors: (errors) => errors.map((err) => errorSerializer(err))
             }
         };
         const dest = pino.destination({ sync: false }); // stdout

From 107a97aa9eb705198f225c7966855722275db661 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 3 Jun 2020 15:11:08 +0200
Subject: [PATCH 12/44] Honor @oleurud's comment

---
 lib/api/api-router.js | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/lib/api/api-router.js b/lib/api/api-router.js
index 13a4fdd6..9491b506 100644
--- a/lib/api/api-router.js
+++ b/lib/api/api-router.js
@@ -235,10 +235,10 @@ function createTemplateMaps ({ redisPool, surrogateKeysCache, logger }) {
         const startTime = Date.now();
         surrogateKeysCache.invalidate(new NamedMapsCacheEntry(user, templateName), (err) => {
             if (err) {
-                return logger.error(err);
+                return logger.error(err, `Named map (${templateName}) invalidation failed, user: ${user}`);
             }
 
-            logger.info({ user, type: 'named_map_invalidation', elapsed: Date.now() - startTime });
+            logger.info({ user, type: 'named_map_invalidation', elapsed: Date.now() - startTime }, `Named map (${templateName}) invalidation success, user: ${user}`);
         });
     }
 

From c37e3f173d0a06aa0e0cff46d4b546569019d32f Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 3 Jun 2020 15:39:02 +0200
Subject: [PATCH 13/44] Handle error properly in user middleware, it will
 logged in error middleware

---
 lib/api/middlewares/user.js   | 11 +++++++----
 lib/models/cdb-request.js     | 11 +++--------
 test/unit/cdb-request-test.js | 33 +++++++++++++--------------------
 3 files changed, 23 insertions(+), 32 deletions(-)

diff --git a/lib/api/middlewares/user.js b/lib/api/middlewares/user.js
index 31e7f909..814b62e6 100644
--- a/lib/api/middlewares/user.js
+++ b/lib/api/middlewares/user.js
@@ -3,11 +3,14 @@
 const CdbRequest = require('../../models/cdb-request');
 
 module.exports = function user (metadataBackend) {
-    return function userMiddleware (req, res, next) {
-        const { logger } = res.locals;
-        const cdbRequest = new CdbRequest({ logger });
+    const cdbRequest = new CdbRequest();
 
-        res.locals.user = getUserNameFromRequest(req, cdbRequest);
+    return function userMiddleware (req, res, next) {
+        try {
+            res.locals.user = getUserNameFromRequest(req, cdbRequest);
+        } catch (err) {
+            return next(err);
+        }
 
         metadataBackend.getUserId(res.locals.user, (err, userId) => {
             if (err || !userId) {
diff --git a/lib/models/cdb-request.js b/lib/models/cdb-request.js
index a962b558..ca160649 100644
--- a/lib/models/cdb-request.js
+++ b/lib/models/cdb-request.js
@@ -1,8 +1,7 @@
 'use strict';
 
 module.exports = class CdbRequest {
-    constructor ({ logger }) {
-        this.logger = logger;
+    constructor () {
         // would extract "strk" from "strk.cartodb.com"
         this.RE_USER_FROM_HOST = new RegExp(global.environment.user_from_host || '^([^\\.]+)\\.');
     }
@@ -16,12 +15,8 @@ module.exports = class CdbRequest {
 
         const mat = host.match(this.RE_USER_FROM_HOST);
 
-        if (!mat) {
-            return this.logger.error(new Error(`Pattern '${this.RE_USER_FROM_HOST}' does not match hostname '${host}'`));
-        }
-
-        if (mat.length !== 2) {
-            return this.logger.error(new Error(`Pattern '${this.RE_USER_FROM_HOST}' gave unexpected matches against '${host}': ${mat}`));
+        if (!mat || mat.length !== 2) {
+            throw new Error(`No username found in hostname '${host}'`);
         }
 
         return mat[1];
diff --git a/test/unit/cdb-request-test.js b/test/unit/cdb-request-test.js
index 9db38488..93d1894a 100644
--- a/test/unit/cdb-request-test.js
+++ b/test/unit/cdb-request-test.js
@@ -4,9 +4,8 @@ require('../support/test-helper');
 var assert = require('assert');
 
 var CdbRequest = require('../../lib/models/cdb-request');
-const { logger } = require('../../lib/server-options');
 
-describe('req2params', function () {
+describe('username in host header (CdbRequest)', function () {
     function createRequest (host, userParam) {
         var req = {
             params: {},
@@ -23,7 +22,7 @@ describe('req2params', function () {
     }
 
     it('extracts name from host header', function () {
-        var cdbRequest = new CdbRequest({ logger });
+        var cdbRequest = new CdbRequest();
         var user = cdbRequest.userByReq(createRequest('localhost'));
 
         assert.strictEqual(user, 'localhost');
@@ -33,7 +32,7 @@ describe('req2params', function () {
         var userFromHostConfig = global.environment.user_from_host;
         global.environment.user_from_host = null;
 
-        var cdbRequest = new CdbRequest({ logger });
+        var cdbRequest = new CdbRequest();
         var user = cdbRequest.userByReq(createRequest('development.localhost.lan'));
 
         global.environment.user_from_host = userFromHostConfig;
@@ -42,45 +41,39 @@ describe('req2params', function () {
     });
 
     it('considers user param before headers', function () {
-        var cdbRequest = new CdbRequest({ logger });
+        var cdbRequest = new CdbRequest();
         var user = cdbRequest.userByReq(createRequest('localhost', 'development'));
 
         assert.strictEqual(user, 'development');
     });
 
-    it('returns undefined when it cannot extract username', function () {
+    it('returns throw when it cannot extract username', function () {
         var userFromHostConfig = global.environment.user_from_host;
         global.environment.user_from_host = null;
 
-        var cdbRequest = new CdbRequest({ logger });
-        var user = cdbRequest.userByReq(createRequest('localhost'));
+        var cdbRequest = new CdbRequest();
+        assert.throws(() => cdbRequest.userByReq(createRequest('localhost')));
 
         global.environment.user_from_host = userFromHostConfig;
-
-        assert.strictEqual(user, undefined);
     });
 
-    it('should not fail for undefined host header', function () {
+    it('should throw for undefined host header', function () {
         var userFromHostConfig = global.environment.user_from_host;
         global.environment.user_from_host = null;
 
-        var cdbRequest = new CdbRequest({ logger });
-        var user = cdbRequest.userByReq(createRequest(undefined));
+        var cdbRequest = new CdbRequest();
+        assert.throws(() => cdbRequest.userByReq(createRequest(undefined)));
 
         global.environment.user_from_host = userFromHostConfig;
-
-        assert.strictEqual(user, undefined);
     });
 
-    it('should not fail for null host header', function () {
+    it('should throw for null host header', function () {
         var userFromHostConfig = global.environment.user_from_host;
         global.environment.user_from_host = null;
 
-        var cdbRequest = new CdbRequest({ logger });
-        var user = cdbRequest.userByReq(createRequest(null));
+        var cdbRequest = new CdbRequest();
+        assert.throws(() => cdbRequest.userByReq(createRequest(null)));
 
         global.environment.user_from_host = userFromHostConfig;
-
-        assert.strictEqual(user, undefined);
     });
 });

From 0eadfe6ee9c0aceb9ea7fe3ca61a603ea29b3a5d Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 3 Jun 2020 15:51:36 +0200
Subject: [PATCH 14/44] Simpligy error middleware

---
 lib/api/middlewares/error-middleware.js | 31 +++++++------------------
 1 file changed, 8 insertions(+), 23 deletions(-)

diff --git a/lib/api/middlewares/error-middleware.js b/lib/api/middlewares/error-middleware.js
index 583b54f5..f4258383 100644
--- a/lib/api/middlewares/error-middleware.js
+++ b/lib/api/middlewares/error-middleware.js
@@ -1,35 +1,20 @@
 'use strict';
 
-const debug = require('debug')('windshaft:cartodb:error-middleware');
-
 module.exports = function errorMiddleware (/* options */) {
     return function error (err, req, res, next) {
         const { logger } = res.locals;
-        var allErrors = Array.isArray(err) ? err : [err];
+        const errors = populateLimitErrors(Array.isArray(err) ? err : [err]);
+        let statusCode = findStatusCode(errors[0]);
 
-        allErrors = populateLimitErrors(allErrors);
+        logger.error({ errors });
 
-        // TODO REMOVE THIS THREE LINES PLEASE
-        const label = err.label || 'UNKNOWN';
-        err = allErrors[0] || new Error(label);
-        allErrors[0] = err;
-
-        var statusCode = findStatusCode(err);
-
-        // If a callback was requested, force status to 200
-        if (req.query && req.query.callback) {
-            statusCode = 200;
-        }
-
-        allErrors.forEach((err) => debug('[%s ERROR] -- %d: %s, %s', err.label || 'UNKNOWN', statusCode, err, err.stack));
-        logger.error({ errors: allErrors });
-
-        var errorResponseBody = {
-            errors: allErrors.map(errorMessage),
-            errors_with_context: allErrors.map(errorMessageWithContext)
+        const errorResponseBody = {
+            errors: errors.map(errorMessage),
+            errors_with_context: errors.map(errorMessageWithContext)
         };
 
-        res.status(statusCode);
+        // If a callback was requested, force status to 200
+        res.status(req.query.callback ? 200 : statusCode);
 
         if (req.query && req.query.callback) {
             res.jsonp(errorResponseBody);

From 1dda183a31b41cf193fae7557f9d9193688e82de Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 3 Jun 2020 16:19:42 +0200
Subject: [PATCH 15/44] typo

---
 lib/api/middlewares/error-middleware.js | 3 +--
 1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/lib/api/middlewares/error-middleware.js b/lib/api/middlewares/error-middleware.js
index f4258383..645a8992 100644
--- a/lib/api/middlewares/error-middleware.js
+++ b/lib/api/middlewares/error-middleware.js
@@ -4,7 +4,6 @@ module.exports = function errorMiddleware (/* options */) {
     return function error (err, req, res, next) {
         const { logger } = res.locals;
         const errors = populateLimitErrors(Array.isArray(err) ? err : [err]);
-        let statusCode = findStatusCode(errors[0]);
 
         logger.error({ errors });
 
@@ -14,7 +13,7 @@ module.exports = function errorMiddleware (/* options */) {
         };
 
         // If a callback was requested, force status to 200
-        res.status(req.query.callback ? 200 : statusCode);
+        res.status(req.query.callback ? 200 : findStatusCode(errors[0]));
 
         if (req.query && req.query.callback) {
             res.jsonp(errorResponseBody);

From 210f5b01ec3fce48d5075fb9c100789de14b953d Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 3 Jun 2020 17:32:16 +0200
Subject: [PATCH 16/44] Make sure all errors use the serializer set for the
 logger

---
 lib/api/map/preview-template-controller.js      | 6 ++++--
 lib/api/middlewares/cache-channel-header.js     | 3 ++-
 lib/api/middlewares/cache-control-header.js     | 3 ++-
 lib/api/middlewares/error-middleware.js         | 2 +-
 lib/api/middlewares/increment-map-view-count.js | 3 ++-
 lib/api/middlewares/last-modified-header.js     | 3 ++-
 lib/api/middlewares/metrics.js                  | 2 ++
 lib/api/middlewares/surrogate-key-header.js     | 3 ++-
 lib/utils/logger.js                             | 2 +-
 test/acceptance/turbo-carto/regressions-test.js | 2 +-
 10 files changed, 19 insertions(+), 10 deletions(-)

diff --git a/lib/api/map/preview-template-controller.js b/lib/api/map/preview-template-controller.js
index 92d4380e..49ee18c7 100644
--- a/lib/api/map/preview-template-controller.js
+++ b/lib/api/map/preview-template-controller.js
@@ -342,7 +342,8 @@ function incrementMapViews ({ metadataBackend }) {
 
         mapConfigProvider.getMapConfig((err, mapConfig) => {
             if (err) {
-                logger.warn(err, `ERROR: failed to increment mapview count for user '${user}'`);
+                err.message = `Failed to increment mapview count for user '${user}'. ${err.message}`;
+                logger.warn({ error: err });
                 return next();
             }
 
@@ -354,7 +355,8 @@ function incrementMapViews ({ metadataBackend }) {
 
             metadataBackend.incMapviewCount(user, statTag, (err) => {
                 if (err) {
-                    logger.warn(err, `ERROR: failed to increment mapview count for user '${user}'`);
+                    err.message = `Failed to increment mapview count for user '${user}'. ${err.message}`;
+                    logger.warn({ error: err });
                 }
 
                 next();
diff --git a/lib/api/middlewares/cache-channel-header.js b/lib/api/middlewares/cache-channel-header.js
index 66486392..622aa053 100644
--- a/lib/api/middlewares/cache-channel-header.js
+++ b/lib/api/middlewares/cache-channel-header.js
@@ -10,7 +10,8 @@ module.exports = function setCacheChannelHeader () {
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                logger.warn(err, 'ERROR generating Cache Channel Header');
+                err.message = `Error generating Cache Channel Header. ${err.message}`;
+                logger.warn({ error: err });
                 return next();
             }
 
diff --git a/lib/api/middlewares/cache-control-header.js b/lib/api/middlewares/cache-control-header.js
index 18ec7728..5ae0d481 100644
--- a/lib/api/middlewares/cache-control-header.js
+++ b/lib/api/middlewares/cache-control-header.js
@@ -44,7 +44,8 @@ module.exports = function setCacheControlHeader ({
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                logger.warn(err, 'ERROR generating Cache Control Header');
+                err.message = `Error generating Cache Control Header. ${err.message}`;
+                logger.warn({ error: err });
                 return next();
             }
 
diff --git a/lib/api/middlewares/error-middleware.js b/lib/api/middlewares/error-middleware.js
index 645a8992..faca863f 100644
--- a/lib/api/middlewares/error-middleware.js
+++ b/lib/api/middlewares/error-middleware.js
@@ -5,7 +5,7 @@ module.exports = function errorMiddleware (/* options */) {
         const { logger } = res.locals;
         const errors = populateLimitErrors(Array.isArray(err) ? err : [err]);
 
-        logger.error({ errors });
+        logger.error({ error: errors });
 
         const errorResponseBody = {
             errors: errors.map(errorMessage),
diff --git a/lib/api/middlewares/increment-map-view-count.js b/lib/api/middlewares/increment-map-view-count.js
index 1b71e8e3..ea4fc285 100644
--- a/lib/api/middlewares/increment-map-view-count.js
+++ b/lib/api/middlewares/increment-map-view-count.js
@@ -14,7 +14,8 @@ module.exports = function incrementMapViewCount (metadataBackend) {
             req.profiler.done('incMapviewCount');
 
             if (err) {
-                logger.warn(err, `ERROR: failed to increment mapview count for user '${user}'`);
+                err.message = `Failed to increment mapview count for user '${user}'. ${err.message}`;
+                logger.warn({ error: err });
             }
 
             next();
diff --git a/lib/api/middlewares/last-modified-header.js b/lib/api/middlewares/last-modified-header.js
index b68d7c31..f2d41292 100644
--- a/lib/api/middlewares/last-modified-header.js
+++ b/lib/api/middlewares/last-modified-header.js
@@ -21,7 +21,8 @@ module.exports = function setLastModifiedHeader () {
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                logger.warn(err, 'ERROR generating Last Modified Header');
+                err.message = `Error generating Last Modified Header. ${err.message}`;
+                logger.warn({ error: err });
                 return next();
             }
 
diff --git a/lib/api/middlewares/metrics.js b/lib/api/middlewares/metrics.js
index dc69b373..6b7a9ff8 100644
--- a/lib/api/middlewares/metrics.js
+++ b/lib/api/middlewares/metrics.js
@@ -15,6 +15,8 @@ module.exports = function metrics ({ enabled, tags, metricsBackend }) {
     }
 
     return function metricsMiddleware (req, res, next) {
+        // FIXME: use parent logger as we don't want bind the error to the request
+        // but we still want to know if an error is thrown
         const { logger } = res.locals;
 
         res.on('finish', () => {
diff --git a/lib/api/middlewares/surrogate-key-header.js b/lib/api/middlewares/surrogate-key-header.js
index c1415038..c8fd550d 100644
--- a/lib/api/middlewares/surrogate-key-header.js
+++ b/lib/api/middlewares/surrogate-key-header.js
@@ -17,7 +17,8 @@ module.exports = function setSurrogateKeyHeader ({ surrogateKeysCache }) {
 
         mapConfigProvider.getAffectedTables((err, affectedTables) => {
             if (err) {
-                logger.warn(err, 'ERROR generating Surrogate Key Header');
+                err.message = `Erros generating Surrogate Key Header. ${err.message}`;
+                logger.warn({ error: err });
                 return next();
             }
 
diff --git a/lib/utils/logger.js b/lib/utils/logger.js
index 0a4b3df0..54beee2e 100644
--- a/lib/utils/logger.js
+++ b/lib/utils/logger.js
@@ -13,7 +13,7 @@ module.exports = class Logger {
             serializers: {
                 request: requestSerializer,
                 response: responseSerializer,
-                errors: (errors) => errors.map((err) => errorSerializer(err))
+                error: (error) => Array.isArray(error) ? error.map((err) => errorSerializer(err)) : [errorSerializer(error)]
             }
         };
         const dest = pino.destination({ sync: false }); // stdout
diff --git a/test/acceptance/turbo-carto/regressions-test.js b/test/acceptance/turbo-carto/regressions-test.js
index e36dc2e1..d0ba7d89 100644
--- a/test/acceptance/turbo-carto/regressions-test.js
+++ b/test/acceptance/turbo-carto/regressions-test.js
@@ -67,7 +67,7 @@ describe('turbo-carto regressions', function () {
         });
     });
 
-    it('should fail for private tables', function (done) {
+    it.only('should fail for private tables', function (done) {
         var cartocss = [
             '#private_table {',
             '  marker-placement: point;',

From d073f7e3dd8cb19d48233a3805e002d3d9fa26c5 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 3 Jun 2020 17:34:30 +0200
Subject: [PATCH 17/44] typo

---
 test/acceptance/turbo-carto/regressions-test.js | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/test/acceptance/turbo-carto/regressions-test.js b/test/acceptance/turbo-carto/regressions-test.js
index d0ba7d89..e36dc2e1 100644
--- a/test/acceptance/turbo-carto/regressions-test.js
+++ b/test/acceptance/turbo-carto/regressions-test.js
@@ -67,7 +67,7 @@ describe('turbo-carto regressions', function () {
         });
     });
 
-    it.only('should fail for private tables', function (done) {
+    it('should fail for private tables', function (done) {
         var cartocss = [
             '#private_table {',
             '  marker-placement: point;',

From 7b53b7c30a7a57f800d639273aaa87c85e294b2d Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 3 Jun 2020 19:51:56 +0200
Subject: [PATCH 18/44] Stop using profiling wrongly. Now it only saves custom
 events from backends (tile, map, attributes, etc..) and calculates the
 response time. Besides, removed tags to know whether overviews are being
 used.

---
 lib/api/map/anonymous-map-controller.js       | 11 +--------
 .../map/attributes-layergroup-controller.js   |  2 --
 ...lustered-features-layergroup-controller.js |  2 --
 lib/api/map/preview-layergroup-controller.js  |  2 --
 lib/api/map/preview-template-controller.js    |  5 ++--
 lib/api/map/tile-layergroup-controller.js     |  2 --
 lib/api/middlewares/authorize.js              |  2 --
 .../middlewares/check-json-content-type.js    |  2 --
 lib/api/middlewares/db-conn-setup.js          |  2 --
 .../middlewares/increment-map-view-count.js   |  2 --
 lib/api/middlewares/init-profiler.js          | 11 ---------
 lib/api/middlewares/lzma.js                   |  2 --
 lib/api/middlewares/map-error.js              |  1 -
 lib/api/middlewares/profiler.js               |  4 ++++
 lib/api/middlewares/send-response.js          |  2 --
 lib/api/template/admin-template-controller.js |  6 -----
 lib/api/template/named-template-controller.js |  8 -------
 lib/api/template/tile-template-controller.js  |  3 +--
 lib/backends/auth.js                          |  6 -----
 lib/models/dataview/base.js                   | 17 ++-----------
 lib/models/dataview/overviews/aggregation.js  |  2 +-
 lib/models/dataview/overviews/formula.js      |  2 +-
 lib/models/dataview/overviews/histogram.js    |  2 +-
 .../adapter/mapconfig-overviews-adapter.js    | 24 +++++++------------
 24 files changed, 21 insertions(+), 101 deletions(-)
 delete mode 100644 lib/api/middlewares/init-profiler.js

diff --git a/lib/api/map/anonymous-map-controller.js b/lib/api/map/anonymous-map-controller.js
index 7236935b..ad0f4324 100644
--- a/lib/api/map/anonymous-map-controller.js
+++ b/lib/api/map/anonymous-map-controller.js
@@ -7,7 +7,6 @@ const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
 const dbConnSetup = require('../middlewares/db-conn-setup');
 const authorize = require('../middlewares/authorize');
-const initProfiler = require('../middlewares/init-profiler');
 const checkJsonContentType = require('../middlewares/check-json-content-type');
 const incrementMapViewCount = require('../middlewares/increment-map-view-count');
 const augmentLayergroupData = require('../middlewares/augment-layergroup-data');
@@ -76,7 +75,6 @@ module.exports = class AnonymousMapController {
     }
 
     middlewares () {
-        const isTemplateInstantiation = false;
         const useTemplateHash = false;
         const includeQuery = true;
         const label = 'ANONYMOUS LAYERGROUP';
@@ -102,7 +100,6 @@ module.exports = class AnonymousMapController {
             dbConnSetup(this.pgConnection),
             rateLimit(this.userLimitsBackend, RATE_LIMIT_ENDPOINTS_GROUPS.ANONYMOUS),
             cleanUpQueryParams(['aggregation']),
-            initProfiler(isTemplateInstantiation),
             checkJsonContentType(),
             checkCreateLayergroup(),
             prepareAdapterMapConfig(this.mapConfigAdapter),
@@ -143,7 +140,6 @@ function checkCreateLayergroup () {
             }
         }
 
-        req.profiler.done('checkCreateLayergroup');
         return next();
     };
 }
@@ -179,12 +175,7 @@ function prepareAdapterMapConfig (mapConfigAdapter) {
             requestMapConfig,
             params,
             context,
-            (err, requestMapConfig, stats = { overviewsAddedToMapconfig: false }) => {
-                req.profiler.done('anonymous.getMapConfig');
-
-                stats.mapType = 'anonymous';
-                req.profiler.add(stats);
-
+            (err, requestMapConfig) => {
                 if (err) {
                     return next(err);
                 }
diff --git a/lib/api/map/attributes-layergroup-controller.js b/lib/api/map/attributes-layergroup-controller.js
index f734d3d2..ad0f1bc8 100644
--- a/lib/api/map/attributes-layergroup-controller.js
+++ b/lib/api/map/attributes-layergroup-controller.js
@@ -61,8 +61,6 @@ module.exports = class AttributesLayergroupController {
 
 function getFeatureAttributes (attributesBackend) {
     return function getFeatureAttributesMiddleware (req, res, next) {
-        req.profiler.start('windshaft.maplayer_attribute');
-
         const { mapConfigProvider } = res.locals;
         const { token } = res.locals;
         const { dbuser, dbname, dbpassword, dbhost, dbport } = res.locals;
diff --git a/lib/api/map/clustered-features-layergroup-controller.js b/lib/api/map/clustered-features-layergroup-controller.js
index 7b300ac7..611813c4 100644
--- a/lib/api/map/clustered-features-layergroup-controller.js
+++ b/lib/api/map/clustered-features-layergroup-controller.js
@@ -62,8 +62,6 @@ module.exports = class AggregatedFeaturesLayergroupController {
 
 function getClusteredFeatures (clusterBackend) {
     return function getFeatureAttributesMiddleware (req, res, next) {
-        req.profiler.start('windshaft.maplayer_cluster_features');
-
         const { mapConfigProvider } = res.locals;
         const { user, token } = res.locals;
         const { dbuser, dbname, dbpassword, dbhost, dbport } = res.locals;
diff --git a/lib/api/map/preview-layergroup-controller.js b/lib/api/map/preview-layergroup-controller.js
index 698d94ff..0d8edf9e 100644
--- a/lib/api/map/preview-layergroup-controller.js
+++ b/lib/api/map/preview-layergroup-controller.js
@@ -100,7 +100,6 @@ function getPreviewImageByCenter (previewBackend) {
         const options = { mapConfigProvider, format, width, height, zoom, center };
 
         previewBackend.getImage(options, (err, image, stats = {}) => {
-            req.profiler.done(`render-${format}`);
             req.profiler.add(stats);
 
             if (err) {
@@ -133,7 +132,6 @@ function getPreviewImageByBoundingBox (previewBackend) {
         const options = { mapConfigProvider, format, width, height, bbox };
 
         previewBackend.getImage(options, (err, image, stats = {}) => {
-            req.profiler.done(`render-${format}`);
             req.profiler.add(stats);
 
             if (err) {
diff --git a/lib/api/map/preview-template-controller.js b/lib/api/map/preview-template-controller.js
index 49ee18c7..287c0122 100644
--- a/lib/api/map/preview-template-controller.js
+++ b/lib/api/map/preview-template-controller.js
@@ -292,7 +292,7 @@ function getImage ({ previewBackend, label }) {
         if (zoom !== undefined && center) {
             const options = { mapConfigProvider, format, width, height, zoom, center };
 
-            return previewBackend.getImage(options, (err, image, stats) => {
+            return previewBackend.getImage(options, (err, image, stats = {}) => {
                 req.profiler.add(stats);
 
                 if (err) {
@@ -309,9 +309,8 @@ function getImage ({ previewBackend, label }) {
 
         const options = { mapConfigProvider, format, width, height, bbox };
 
-        previewBackend.getImage(options, (err, image, stats) => {
+        previewBackend.getImage(options, (err, image, stats = {}) => {
             req.profiler.add(stats);
-            req.profiler.done('render-' + format);
 
             if (err) {
                 err.label = label;
diff --git a/lib/api/map/tile-layergroup-controller.js b/lib/api/map/tile-layergroup-controller.js
index a067c2e6..5c5c468f 100644
--- a/lib/api/map/tile-layergroup-controller.js
+++ b/lib/api/map/tile-layergroup-controller.js
@@ -96,8 +96,6 @@ function getStatusCode (tile, format) {
 
 function getTile (tileBackend) {
     return function getTileMiddleware (req, res, next) {
-        req.profiler.start(`windshaft.${req.params.layer ? 'maplayer_tile' : 'map_tile'}`);
-
         const { mapConfigProvider } = res.locals;
         const { token } = res.locals;
         const { layer, z, x, y, format } = req.params;
diff --git a/lib/api/middlewares/authorize.js b/lib/api/middlewares/authorize.js
index 506f0b77..82f20a12 100644
--- a/lib/api/middlewares/authorize.js
+++ b/lib/api/middlewares/authorize.js
@@ -3,8 +3,6 @@
 module.exports = function authorize (authBackend) {
     return function authorizeMiddleware (req, res, next) {
         authBackend.authorize(req, res, (err, authorized) => {
-            req.profiler.done('authorize');
-
             if (err) {
                 return next(err);
             }
diff --git a/lib/api/middlewares/check-json-content-type.js b/lib/api/middlewares/check-json-content-type.js
index 57d7b5a8..e894809c 100644
--- a/lib/api/middlewares/check-json-content-type.js
+++ b/lib/api/middlewares/check-json-content-type.js
@@ -6,8 +6,6 @@ module.exports = function checkJsonContentType () {
             return next(new Error('POST data must be of type application/json'));
         }
 
-        req.profiler.done('checkJsonContentTypeMiddleware');
-
         next();
     };
 };
diff --git a/lib/api/middlewares/db-conn-setup.js b/lib/api/middlewares/db-conn-setup.js
index 7a7e76a8..a81e8ba0 100644
--- a/lib/api/middlewares/db-conn-setup.js
+++ b/lib/api/middlewares/db-conn-setup.js
@@ -7,8 +7,6 @@ module.exports = function dbConnSetup (pgConnection) {
         const { user } = res.locals;
 
         pgConnection.setDBConn(user, res.locals, (err) => {
-            req.profiler.done('dbConnSetup');
-
             if (err) {
                 if (err.message && err.message.indexOf('name not found') !== -1) {
                     err.http_status = 404;
diff --git a/lib/api/middlewares/increment-map-view-count.js b/lib/api/middlewares/increment-map-view-count.js
index ea4fc285..c226d1d6 100644
--- a/lib/api/middlewares/increment-map-view-count.js
+++ b/lib/api/middlewares/increment-map-view-count.js
@@ -11,8 +11,6 @@ module.exports = function incrementMapViewCount (metadataBackend) {
 
         // Error won't blow up, just be logged.
         metadataBackend.incMapviewCount(user, statTag, (err) => {
-            req.profiler.done('incMapviewCount');
-
             if (err) {
                 err.message = `Failed to increment mapview count for user '${user}'. ${err.message}`;
                 logger.warn({ error: err });
diff --git a/lib/api/middlewares/init-profiler.js b/lib/api/middlewares/init-profiler.js
deleted file mode 100644
index 86916822..00000000
--- a/lib/api/middlewares/init-profiler.js
+++ /dev/null
@@ -1,11 +0,0 @@
-'use strict';
-
-module.exports = function initProfiler (isTemplateInstantiation) {
-    const operation = isTemplateInstantiation ? 'instance_template' : 'createmap';
-
-    return function initProfilerMiddleware (req, res, next) {
-        req.profiler.start(`windshaft-cartodb.${operation}_${req.method.toLowerCase()}`);
-        req.profiler.done(`${operation}.initProfilerMiddleware`);
-        next();
-    };
-};
diff --git a/lib/api/middlewares/lzma.js b/lib/api/middlewares/lzma.js
index b47c3b28..7e8d8051 100644
--- a/lib/api/middlewares/lzma.js
+++ b/lib/api/middlewares/lzma.js
@@ -24,8 +24,6 @@ module.exports = function lzma () {
                 delete req.query.lzma;
                 Object.assign(req.query, JSON.parse(result));
 
-                req.profiler.done('lzma');
-
                 next();
             } catch (err) {
                 next(new Error('Error parsing lzma as JSON: ' + err));
diff --git a/lib/api/middlewares/map-error.js b/lib/api/middlewares/map-error.js
index fcc5ef2a..b3c915ee 100644
--- a/lib/api/middlewares/map-error.js
+++ b/lib/api/middlewares/map-error.js
@@ -4,7 +4,6 @@ module.exports = function mapError (options) {
     const { addContext = false, label = 'MAPS CONTROLLER' } = options;
 
     return function mapErrorMiddleware (err, req, res, next) {
-        req.profiler.done('error');
         const { mapConfig } = res.locals;
 
         if (addContext) {
diff --git a/lib/api/middlewares/profiler.js b/lib/api/middlewares/profiler.js
index 9ed3eb7b..2cf0736f 100644
--- a/lib/api/middlewares/profiler.js
+++ b/lib/api/middlewares/profiler.js
@@ -8,13 +8,17 @@ module.exports = function profiler (options) {
 
     return function profilerMiddleware (req, res, next) {
         const { logger } = res.locals;
+        const { id } = logger.bindings();
 
         req.profiler = new Profiler({
             statsd_client: statsClient,
             profile: enabled
         });
 
+        req.profiler.start(id);
+
         res.on('finish', () => {
+            req.profiler.done('response');
             logger.info({ stats: req.profiler.toJSON() });
 
             try {
diff --git a/lib/api/middlewares/send-response.js b/lib/api/middlewares/send-response.js
index f37457d6..d65d7597 100644
--- a/lib/api/middlewares/send-response.js
+++ b/lib/api/middlewares/send-response.js
@@ -2,8 +2,6 @@
 
 module.exports = function sendResponse () {
     return function sendResponseMiddleware (req, res, next) {
-        req.profiler.done('res');
-
         res.status(res.statusCode);
 
         if (Buffer.isBuffer(res.body)) {
diff --git a/lib/api/template/admin-template-controller.js b/lib/api/template/admin-template-controller.js
index 456f6bc0..1a9e90e2 100644
--- a/lib/api/template/admin-template-controller.js
+++ b/lib/api/template/admin-template-controller.js
@@ -166,8 +166,6 @@ function updateTemplate ({ templateMaps }) {
 
 function retrieveTemplate ({ templateMaps }) {
     return function retrieveTemplateMiddleware (req, res, next) {
-        req.profiler.start('windshaft-cartodb.get_template');
-
         const { user } = res.locals;
         const templateId = templateName(req.params.template_id);
 
@@ -195,8 +193,6 @@ function retrieveTemplate ({ templateMaps }) {
 
 function destroyTemplate ({ templateMaps }) {
     return function destroyTemplateMiddleware (req, res, next) {
-        req.profiler.start('windshaft-cartodb.delete_template');
-
         const { user } = res.locals;
         const templateId = templateName(req.params.template_id);
 
@@ -215,8 +211,6 @@ function destroyTemplate ({ templateMaps }) {
 
 function listTemplates ({ templateMaps }) {
     return function listTemplatesMiddleware (req, res, next) {
-        req.profiler.start('windshaft-cartodb.get_template_list');
-
         const { user } = res.locals;
 
         templateMaps.listTemplates(user, (err, templateIds) => {
diff --git a/lib/api/template/named-template-controller.js b/lib/api/template/named-template-controller.js
index 79b39d7c..41246d65 100644
--- a/lib/api/template/named-template-controller.js
+++ b/lib/api/template/named-template-controller.js
@@ -4,7 +4,6 @@ const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
 const dbConnSetup = require('../middlewares/db-conn-setup');
 const authorize = require('../middlewares/authorize');
-const initProfiler = require('../middlewares/init-profiler');
 const checkJsonContentType = require('../middlewares/check-json-content-type');
 const incrementMapViewCount = require('../middlewares/increment-map-view-count');
 const augmentLayergroupData = require('../middlewares/augment-layergroup-data');
@@ -74,7 +73,6 @@ module.exports = class NamedMapController {
     }
 
     middlewares () {
-        const isTemplateInstantiation = true;
         const useTemplateHash = true;
         const includeQuery = false;
         const label = 'NAMED MAP LAYERGROUP';
@@ -100,7 +98,6 @@ module.exports = class NamedMapController {
             dbConnSetup(this.pgConnection),
             rateLimit(this.userLimitsBackend, RATE_LIMIT_ENDPOINTS_GROUPS.NAMED),
             cleanUpQueryParams(['aggregation']),
-            initProfiler(isTemplateInstantiation),
             checkJsonContentType(),
             checkInstantiteLayergroup(),
             getTemplate(
@@ -150,8 +147,6 @@ function checkInstantiteLayergroup () {
             }
         }
 
-        req.profiler.done('checkInstantiteLayergroup');
-
         return next();
     };
 }
@@ -187,9 +182,6 @@ function getTemplate (
         );
 
         mapConfigProvider.getMapConfig((err, mapConfig, rendererParams, context, stats = {}) => {
-            req.profiler.done('named.getMapConfig');
-
-            stats.mapType = 'named';
             req.profiler.add(stats);
 
             if (err) {
diff --git a/lib/api/template/tile-template-controller.js b/lib/api/template/tile-template-controller.js
index 1112678e..bb2b0aa7 100644
--- a/lib/api/template/tile-template-controller.js
+++ b/lib/api/template/tile-template-controller.js
@@ -67,9 +67,8 @@ function getTile ({ tileBackend, label }) {
         const { layer, z, x, y, format } = req.params;
         const params = { layer, z, x, y, format };
 
-        tileBackend.getTile(mapConfigProvider, params, (err, tile, headers, stats) => {
+        tileBackend.getTile(mapConfigProvider, params, (err, tile, headers, stats = {}) => {
             req.profiler.add(stats);
-            req.profiler.done('render-' + format);
 
             if (err) {
                 err.label = label;
diff --git a/lib/backends/auth.js b/lib/backends/auth.js
index 2c9dd3ee..298b1d64 100644
--- a/lib/backends/auth.js
+++ b/lib/backends/auth.js
@@ -133,8 +133,6 @@ AuthBackend.prototype.authorize = function (req, res, callback) {
 
         if (isAuthorizedByApikey) {
             return this.pgConnection.setDBAuth(user, res.locals, 'regular', function (err) {
-                req.profiler.done('setDBAuth');
-
                 if (err) {
                     return callback(err);
                 }
@@ -150,8 +148,6 @@ AuthBackend.prototype.authorize = function (req, res, callback) {
 
             if (isAuthorizedBySigner) {
                 return this.pgConnection.setDBAuth(user, res.locals, 'master', function (err) {
-                    req.profiler.done('setDBAuth');
-
                     if (err) {
                         return callback(err);
                     }
@@ -163,8 +159,6 @@ AuthBackend.prototype.authorize = function (req, res, callback) {
             // if no signer name was given, use default api key
             if (!res.locals.signer) {
                 return this.pgConnection.setDBAuth(user, res.locals, 'default', function (err) {
-                    req.profiler.done('setDBAuth');
-
                     if (err) {
                         return callback(err);
                     }
diff --git a/lib/models/dataview/base.js b/lib/models/dataview/base.js
index 0813e3b1..18897635 100644
--- a/lib/models/dataview/base.js
+++ b/lib/models/dataview/base.js
@@ -23,7 +23,7 @@ function getPGTypeName (pgType) {
 
 module.exports = class BaseDataview {
     getResult (psql, override, callback) {
-        this.sql(psql, override, (err, query, flags = null) => {
+        this.sql(psql, override, (err, query) => {
             if (err) {
                 return callback(err);
             }
@@ -36,20 +36,7 @@ module.exports = class BaseDataview {
                 result = this.format(result, override);
                 result.type = this.getType();
 
-                // Overviews logging
-                const stats = {};
-
-                if (flags && flags.usesOverviews !== undefined) {
-                    stats.usesOverviews = flags.usesOverviews;
-                } else {
-                    stats.usesOverviews = false;
-                }
-
-                if (this.getType) {
-                    stats.dataviewType = this.getType();
-                }
-
-                return callback(null, result, stats);
+                return callback(null, result);
             }, true); // use read-only transaction
         });
     }
diff --git a/lib/models/dataview/overviews/aggregation.js b/lib/models/dataview/overviews/aggregation.js
index da988731..2ab6add2 100644
--- a/lib/models/dataview/overviews/aggregation.js
+++ b/lib/models/dataview/overviews/aggregation.js
@@ -213,7 +213,7 @@ Aggregation.prototype.sql = function (psql, override, callback) {
 
     debug(aggregationSql);
 
-    return callback(null, aggregationSql, { usesOverviews: true });
+    return callback(null, aggregationSql);
 };
 
 var aggregationFnQueryTpl = {
diff --git a/lib/models/dataview/overviews/formula.js b/lib/models/dataview/overviews/formula.js
index 35d52008..e860f8ec 100644
--- a/lib/models/dataview/overviews/formula.js
+++ b/lib/models/dataview/overviews/formula.js
@@ -76,5 +76,5 @@ Formula.prototype.sql = function (psql, override, callback) {
 
     debug(formulaSql);
 
-    return callback(null, formulaSql, { usesOverviews: true });
+    return callback(null, formulaSql);
 };
diff --git a/lib/models/dataview/overviews/histogram.js b/lib/models/dataview/overviews/histogram.js
index 4df5bd01..d10c1ae7 100644
--- a/lib/models/dataview/overviews/histogram.js
+++ b/lib/models/dataview/overviews/histogram.js
@@ -179,7 +179,7 @@ Histogram.prototype.sql = function (psql, override, callback) {
 
     var histogramSql = this._buildQuery(override);
 
-    return callback(null, histogramSql, { usesOverviews: true });
+    return callback(null, histogramSql);
 };
 
 Histogram.prototype._buildQuery = function (override) {
diff --git a/lib/models/mapconfig/adapter/mapconfig-overviews-adapter.js b/lib/models/mapconfig/adapter/mapconfig-overviews-adapter.js
index 3cb39a50..6473c162 100644
--- a/lib/models/mapconfig/adapter/mapconfig-overviews-adapter.js
+++ b/lib/models/mapconfig/adapter/mapconfig-overviews-adapter.js
@@ -25,58 +25,50 @@ MapConfigOverviewsAdapter.prototype.getMapConfig = function (user, requestMapCon
 
     layers.forEach(layer => augmentLayersQueue.defer(this._augmentLayer.bind(this), user, layer, analysesResults));
 
-    augmentLayersQueue.awaitAll(function layersAugmentQueueFinish (err, results) {
+    augmentLayersQueue.awaitAll(function layersAugmentQueueFinish (err, layers) {
         if (err) {
             return callback(err);
         }
 
-        const layers = results.map(result => result.layer);
-        const overviewsAddedToMapconfig = results.some(result => result.overviewsAddedToMapconfig);
-
         if (!layers || layers.length === 0) {
             return callback(new Error('Missing layers array from layergroup config'));
         }
 
         requestMapConfig.layers = layers;
 
-        const stats = { overviewsAddedToMapconfig };
-
-        return callback(null, requestMapConfig, stats);
+        return callback(null, requestMapConfig);
     });
 };
 
 MapConfigOverviewsAdapter.prototype._augmentLayer = function (user, layer, analysesResults, callback) {
-    let overviewsAddedToMapconfig = false;
     if (layer.type !== 'mapnik' && layer.type !== 'cartodb') {
-        return callback(null, { layer, overviewsAddedToMapconfig });
+        return callback(null, layer);
     }
 
     this.overviewsMetadataBackend.getOverviewsMetadata(user, layer.options.sql, (err, metadata) => {
         if (err) {
-            return callback(err, { layer, overviewsAddedToMapconfig });
+            return callback(err);
         }
 
         if (_.isEmpty(metadata)) {
-            return callback(null, { layer, overviewsAddedToMapconfig });
+            return callback(null, layer);
         }
 
         var filters = getFilters(analysesResults, layer);
 
-        overviewsAddedToMapconfig = true;
-
         if (!filters) {
             layer.options = Object.assign({}, layer.options, getQueryRewriteData(layer, analysesResults, {
                 overviews: metadata
             }));
 
-            return callback(null, { layer, overviewsAddedToMapconfig });
+            return callback(null, layer);
         }
 
         var unfilteredQuery = getUnfilteredQuery(analysesResults, layer);
 
         this.filterStatsBackend.getFilterStats(user, unfilteredQuery, filters, function (err, stats) {
             if (err) {
-                return callback(null, { layer, overviewsAddedToMapconfig });
+                return callback(null, layer);
             }
 
             layer.options = Object.assign({}, layer.options, getQueryRewriteData(layer, analysesResults, {
@@ -84,7 +76,7 @@ MapConfigOverviewsAdapter.prototype._augmentLayer = function (user, layer, analy
                 filter_stats: stats
             }));
 
-            return callback(null, { layer, overviewsAddedToMapconfig });
+            return callback(null, layer);
         });
     });
 };

From 6945cfc93c8974283a1c357610a5d1ec855d09e5 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Thu, 4 Jun 2020 12:10:15 +0200
Subject: [PATCH 19/44] Add TODO

---
 lib/api/middlewares/profiler.js | 1 +
 1 file changed, 1 insertion(+)

diff --git a/lib/api/middlewares/profiler.js b/lib/api/middlewares/profiler.js
index 2cf0736f..a3cb584f 100644
--- a/lib/api/middlewares/profiler.js
+++ b/lib/api/middlewares/profiler.js
@@ -10,6 +10,7 @@ module.exports = function profiler (options) {
         const { logger } = res.locals;
         const { id } = logger.bindings();
 
+        // TODO: stop using profiler and log stats instead of adding them to the profiler
         req.profiler = new Profiler({
             statsd_client: statsClient,
             profile: enabled

From adeffd20183ea87742fa54d7437645eb3e50b883 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Thu, 4 Jun 2020 17:45:15 +0200
Subject: [PATCH 20/44] Centralize common headers, this will help up to move
 biz metrics out of the process

---
 lib/api/map/preview-template-controller.js    |   6 +-
 lib/api/middlewares/error-middleware.js       |  28 ++--
 .../middlewares/increment-map-view-count.js   |   5 -
 lib/api/middlewares/send-response.js          |  28 ++--
 lib/api/middlewares/user.js                   |   2 +-
 lib/utils/common-headers.js                   | 127 ++++++++++++++++++
 6 files changed, 162 insertions(+), 34 deletions(-)
 create mode 100644 lib/utils/common-headers.js

diff --git a/lib/api/map/preview-template-controller.js b/lib/api/map/preview-template-controller.js
index 287c0122..dc960510 100644
--- a/lib/api/map/preview-template-controller.js
+++ b/lib/api/map/preview-template-controller.js
@@ -346,11 +346,9 @@ function incrementMapViews ({ metadataBackend }) {
                 return next();
             }
 
-            const statTag = mapConfig.obj().stat_tag;
+            res.locals.mapConfig = mapConfig;
 
-            if (statTag) {
-                res.set('Carto-Stat-Tag', `${statTag}`);
-            }
+            const statTag = mapConfig.obj().stat_tag;
 
             metadataBackend.incMapviewCount(user, statTag, (err) => {
                 if (err) {
diff --git a/lib/api/middlewares/error-middleware.js b/lib/api/middlewares/error-middleware.js
index faca863f..9994a754 100644
--- a/lib/api/middlewares/error-middleware.js
+++ b/lib/api/middlewares/error-middleware.js
@@ -1,5 +1,7 @@
 'use strict';
 
+const setCommonHeaders = require('../../utils/common-headers');
+
 module.exports = function errorMiddleware (/* options */) {
     return function error (err, req, res, next) {
         const { logger } = res.locals;
@@ -7,21 +9,23 @@ module.exports = function errorMiddleware (/* options */) {
 
         logger.error({ error: errors });
 
-        const errorResponseBody = {
-            errors: errors.map(errorMessage),
-            errors_with_context: errors.map(errorMessageWithContext)
-        };
+        setCommonHeaders(req, res, () => {
+            const errorResponseBody = {
+                errors: errors.map(errorMessage),
+                errors_with_context: errors.map(errorMessageWithContext)
+            };
 
-        // If a callback was requested, force status to 200
-        res.status(req.query.callback ? 200 : findStatusCode(errors[0]));
+            // If a callback was requested, force status to 200
+            res.status(req.query.callback ? 200 : findStatusCode(errors[0]));
 
-        if (req.query && req.query.callback) {
-            res.jsonp(errorResponseBody);
-        } else {
-            res.json(errorResponseBody);
-        }
+            if (req.query && req.query.callback) {
+                res.jsonp(errorResponseBody);
+            } else {
+                res.json(errorResponseBody);
+            }
 
-        return next();
+            return next();
+        });
     };
 };
 
diff --git a/lib/api/middlewares/increment-map-view-count.js b/lib/api/middlewares/increment-map-view-count.js
index c226d1d6..fb8bdacd 100644
--- a/lib/api/middlewares/increment-map-view-count.js
+++ b/lib/api/middlewares/increment-map-view-count.js
@@ -5,11 +5,6 @@ module.exports = function incrementMapViewCount (metadataBackend) {
         const { mapConfig, user, logger } = res.locals;
         const statTag = mapConfig.obj().stat_tag;
 
-        if (statTag) {
-            res.set('Carto-Stat-Tag', `${statTag}`);
-        }
-
-        // Error won't blow up, just be logged.
         metadataBackend.incMapviewCount(user, statTag, (err) => {
             if (err) {
                 err.message = `Failed to increment mapview count for user '${user}'. ${err.message}`;
diff --git a/lib/api/middlewares/send-response.js b/lib/api/middlewares/send-response.js
index d65d7597..f2328d6f 100644
--- a/lib/api/middlewares/send-response.js
+++ b/lib/api/middlewares/send-response.js
@@ -1,20 +1,24 @@
 'use strict';
 
+const setCommonHeaders = require('../../utils/common-headers');
+
 module.exports = function sendResponse () {
     return function sendResponseMiddleware (req, res, next) {
-        res.status(res.statusCode);
+        setCommonHeaders(req, res, () => {
+            res.status(res.statusCode);
 
-        if (Buffer.isBuffer(res.body)) {
-            res.send(res.body);
+            if (Buffer.isBuffer(res.body)) {
+                res.send(res.body);
+                return next();
+            }
+
+            if (req.query.callback) {
+                res.jsonp(res.body);
+                return next();
+            }
+
+            res.json(res.body);
             return next();
-        }
-
-        if (req.query.callback) {
-            res.jsonp(res.body);
-            return next();
-        }
-
-        res.json(res.body);
-        return next();
+        });
     };
 };
diff --git a/lib/api/middlewares/user.js b/lib/api/middlewares/user.js
index 814b62e6..bf508085 100644
--- a/lib/api/middlewares/user.js
+++ b/lib/api/middlewares/user.js
@@ -18,7 +18,7 @@ module.exports = function user (metadataBackend) {
             }
 
             res.locals.userId = userId;
-            res.set('Carto-User-Id', `${userId}`);
+
             return next();
         });
     };
diff --git a/lib/utils/common-headers.js b/lib/utils/common-headers.js
new file mode 100644
index 00000000..a0d20765
--- /dev/null
+++ b/lib/utils/common-headers.js
@@ -0,0 +1,127 @@
+'use strict';
+
+module.exports = function setCommonHeaders (req, res, callback) {
+    const { logger } = res.locals;
+
+    res.set('X-Request-Id', logger.bindings.id);
+
+    // TODO: x-layergroupid header??
+
+    const user = getUser({ res });
+
+    if (user) {
+        res.set('Carto-User', user);
+    }
+
+    const userId = getUserId({ res });
+
+    if (userId) {
+        res.set('Carto-User-Id', `${userId}`);
+    }
+
+    const mapId = getMapId({ res });
+
+    if (mapId) {
+        res.set('Carto-Map-Id', mapId);
+    }
+
+    const cacheBuster = getCacheBuster({ res });
+
+    if (cacheBuster) {
+        res.set('Carto-Cache-Buster', cacheBuster);
+    }
+
+    const templateHash = getTemplateHash({ res });
+
+    if (templateHash) {
+        res.set('Carto-Template-Hash', templateHash);
+    }
+
+    getStatTag({ res }, (err, statTag) => {
+        if (err) {
+            err.message = `Error generating Stat Tag header: ${err.message}`;
+            logger.warn({ error: err });
+        }
+
+        if (statTag) {
+            res.set('Carto-Stat-Tag', statTag);
+        }
+
+        callback();
+    });
+};
+
+function getUser ({ res }) {
+    if (res.locals.user) {
+        return res.locals.user;
+    }
+}
+
+function getUserId ({ res }) {
+    if (res.locals.userId) {
+        return res.locals.userId;
+    }
+}
+
+function getMapId ({ res }) {
+    if (res.locals.token) {
+        return res.locals.token;
+    }
+
+    if (res.locals.mapConfig) {
+        return res.locals.mapConfig.id();
+    }
+
+    if (res.locals.mapConfigProvider && res.locals.mapConfigProvider.mapConfig) {
+        return res.locals.mapConfigProvider.mapConfig.id();
+    }
+}
+
+function getCacheBuster ({ res }) {
+    if (res.locals.cache_buster !== undefined) {
+        return `${res.locals.cache_buster}`;
+    }
+
+    if (res.locals.mapConfigProvider) {
+        return `${res.locals.mapConfigProvider.getCacheBuster()}`;
+    }
+}
+
+function getTemplateHash ({ res }) {
+    const { logger } = res.locals;
+
+    if (res.locals.templateHash) {
+        return res.locals.templateHash;
+    }
+
+    if (res.locals.mapConfigProvider && typeof res.locals.mapConfigProvider.getTemplateHash === 'function') {
+        let templateHash;
+
+        try {
+            templateHash = res.locals.mapConfigProvider.getTemplateHash().substring(0, 8);
+        } catch (err) {
+            err.message = `Error generating Stat Tag header: ${err.message}`;
+            logger.warn({ error: err });
+        }
+
+        return templateHash;
+    }
+}
+
+function getStatTag ({ res }, callback) {
+    if (res.locals.mapConfig) {
+        return callback(null, res.locals.mapConfig.obj().stat_tag);
+    }
+
+    if (!res.locals.mapConfigProvider) {
+        return callback();
+    }
+
+    res.locals.mapConfigProvider.getMapConfig((err, mapConfig) => {
+        if (err) {
+            return callback(err);
+        }
+
+        return callback(null, mapConfig.obj().stat_tag);
+    });
+}

From 63bc8f75b93e530049ceeb4aa56ad2565dbd2359 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Thu, 4 Jun 2020 18:43:21 +0200
Subject: [PATCH 21/44] Typo

---
 lib/utils/common-headers.js | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/utils/common-headers.js b/lib/utils/common-headers.js
index a0d20765..5355d452 100644
--- a/lib/utils/common-headers.js
+++ b/lib/utils/common-headers.js
@@ -3,7 +3,7 @@
 module.exports = function setCommonHeaders (req, res, callback) {
     const { logger } = res.locals;
 
-    res.set('X-Request-Id', logger.bindings.id);
+    res.set('X-Request-Id', logger.bindings().id);
 
     // TODO: x-layergroupid header??
 

From 6f9f53dd03bf684829d49564b4754c033d9abd5a Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Thu, 4 Jun 2020 20:28:06 +0200
Subject: [PATCH 22/44] Be able to reduce the footprint in the final log file
 depending on the environment

---
 lib/utils/logger.js | 7 ++++++-
 package-lock.json   | 2 +-
 2 files changed, 7 insertions(+), 2 deletions(-)

diff --git a/lib/utils/logger.js b/lib/utils/logger.js
index 54beee2e..3acc1166 100644
--- a/lib/utils/logger.js
+++ b/lib/utils/logger.js
@@ -1,12 +1,17 @@
 'use strict';
 
 const pino = require('pino');
-const { req: requestSerializer, res: responseSerializer, err: errorSerializer } = pino.stdSerializers;
+const { req: requestSerializer, res: responseSerializer, err, wrapErrorSerializer } = pino.stdSerializers;
+const DEV_ENVS = ['test', 'development'];
 
 module.exports = class Logger {
     constructor () {
         const { LOG_LEVEL, NODE_ENV } = process.env;
         const logLevelFromNodeEnv = NODE_ENV === 'test' ? 'fatal' : 'info';
+        const errorSerializer = DEV_ENVS.includes(NODE_ENV) ? err : wrapErrorSerializer(err => {
+            err.stack = err.stack.split('\n').slice(0, 3).join('\n');
+            return err;
+        });
         const options = {
             base: null, // Do not bind hostname, pid and friends by default
             level: LOG_LEVEL || logLevelFromNodeEnv,
diff --git a/package-lock.json b/package-lock.json
index fe1e59de..580ad405 100644
--- a/package-lock.json
+++ b/package-lock.json
@@ -796,7 +796,7 @@
       "integrity": "sha1-MvxLn82vhF/N9+c7uXysImHwqwo="
     },
     "camshaft": {
-      "version": "github:cartodb/camshaft#8d8f62d3d98b4ac316d8444ac3f3f321c28040dc",
+      "version": "github:cartodb/camshaft#633d3b85869d894d52ac5c9970462f326d2f42cc",
       "from": "github:cartodb/camshaft#dgaubert/ch78389/camshaft-replace-logger-from-bunyan-to-pino",
       "requires": {
         "async": "^1.5.2",

From d28744a5e34789e1942402fdc671e5f02c4df7b8 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Fri, 5 Jun 2020 20:08:08 +0200
Subject: [PATCH 23/44] Be able to pass the logger to the analysis creation
 (camshaft) while instantiating a named map with analysis

---
 lib/api/template/named-template-controller.js       | 2 ++
 lib/models/mapconfig/provider/named-map-provider.js | 1 +
 2 files changed, 3 insertions(+)

diff --git a/lib/api/template/named-template-controller.js b/lib/api/template/named-template-controller.js
index 41246d65..a7d0b009 100644
--- a/lib/api/template/named-template-controller.js
+++ b/lib/api/template/named-template-controller.js
@@ -181,6 +181,8 @@ function getTemplate (
             params
         );
 
+        mapConfigProvider.logger = res.locals.logger;
+
         mapConfigProvider.getMapConfig((err, mapConfig, rendererParams, context, stats = {}) => {
             req.profiler.add(stats);
 
diff --git a/lib/models/mapconfig/provider/named-map-provider.js b/lib/models/mapconfig/provider/named-map-provider.js
index 63516853..371a9130 100644
--- a/lib/models/mapconfig/provider/named-map-provider.js
+++ b/lib/models/mapconfig/provider/named-map-provider.js
@@ -129,6 +129,7 @@ module.exports = class NamedMapMapConfigProvider extends BaseMapConfigProvider {
 
                 context.analysisConfiguration = {
                     user: this.user,
+                    logger: this.logger,
                     db: {
                         host: rendererParams.dbhost,
                         port: rendererParams.dbport,

From 02c8e28494c337d57a488e8b3d5d9cf4d0e743bd Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Fri, 5 Jun 2020 20:08:40 +0200
Subject: [PATCH 24/44] Finalize request's log

---
 lib/api/middlewares/logger.js | 1 +
 1 file changed, 1 insertion(+)

diff --git a/lib/api/middlewares/logger.js b/lib/api/middlewares/logger.js
index 09b92ef0..c081c8ea 100644
--- a/lib/api/middlewares/logger.js
+++ b/lib/api/middlewares/logger.js
@@ -9,6 +9,7 @@ module.exports = function initLogger ({ logger }) {
 
         res.locals.logger.info({ request: req });
         res.on('finish', () => res.locals.logger.info({ response: res }));
+        res.on('close', () => res.locals.logger.info({ end: true }));
 
         next();
     };

From 07b9decb034d533e39eac395160cc00bfa3ca329 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Fri, 5 Jun 2020 20:12:20 +0200
Subject: [PATCH 25/44] Add log-collector utlity, it will be moved to its onw
 repository. Attaching it here fro development purposes. Try it with the
 following command `LOG_LEVEL=info npm t | node ./log-collector.js`

---
 log-collector.js  | 71 +++++++++++++++++++++++++++++++++++++++++++++++
 package-lock.json | 19 +++++++++----
 package.json      |  2 ++
 3 files changed, 87 insertions(+), 5 deletions(-)
 create mode 100644 log-collector.js

diff --git a/log-collector.js b/log-collector.js
new file mode 100644
index 00000000..2b4c1f1c
--- /dev/null
+++ b/log-collector.js
@@ -0,0 +1,71 @@
+'use strict'
+
+const split = require('split2');
+const assingDeep = require('assign-deep');
+const logs = new Map();
+const { Transform } = require('readable-stream');
+
+const LEVELS = {
+    10: 'trace',
+    20: 'debug',
+    30: 'info',
+    40: 'warn',
+    50: 'error',
+    60: 'fatal'
+}
+
+function logTransport () {
+    return new Transform({
+        transform: function transform (chunk, enc, callback) {
+            let entry;
+
+            try {
+                entry = JSON.parse(chunk);
+            } catch (error) {
+                // this.push(chunk + '\n');
+                return callback();
+            }
+
+            const { id, end } = entry;
+
+            if (id === undefined) {
+                entry.level = LEVELS[entry.level];
+                this.push(`${JSON.stringify(entry)}\n`);
+                return callback();
+            }
+
+            if (end === true) {
+                const accEntry = logs.get(id);
+                accEntry.level = LEVELS[accEntry.level];
+                accEntry.time = entry.time;
+                this.push(`${JSON.stringify(accEntry)}\n`);
+                logs.delete(id);
+                return callback();
+            }
+
+            if (logs.has(id)) {
+                const accEntry = logs.get(id);
+
+                if (accEntry.level > entry.level) {
+                    delete entry.level
+                }
+
+                let error;
+                if (Object.prototype.hasOwnProperty.call(accEntry, 'error') && Object.prototype.hasOwnProperty.call(entry, 'error')) {
+                    logs.set(id, assingDeep({}, accEntry, entry, { error: accEntry.error.concat(entry.error) }));
+                } else {
+                    logs.set(id, assingDeep({}, accEntry, entry));
+                }
+            } else {
+                logs.set(id, entry);
+            }
+
+            callback();
+        }
+    })
+}
+
+process.stdin
+    .pipe(split())
+    .pipe(logTransport())
+    .pipe(process.stdout);
diff --git a/package-lock.json b/package-lock.json
index 580ad405..6737c08d 100644
--- a/package-lock.json
+++ b/package-lock.json
@@ -633,6 +633,19 @@
       "integrity": "sha512-jgsaNduz+ndvGyFt3uSuWqvy4lCnIJiovtouQN5JZHOKCS2QuhEdbcQHFhVksz2N2U9hXJo8odG7ETyWlEeuDw==",
       "dev": true
     },
+    "assign-deep": {
+      "version": "1.0.1",
+      "resolved": "https://registry.npmjs.org/assign-deep/-/assign-deep-1.0.1.tgz",
+      "integrity": "sha512-CSXAX79mibneEYfqLT5FEmkqR5WXF+xDRjgQQuVf6wSCXCYU8/vHttPidNar7wJ5BFmKAo8Wei0rCtzb+M/yeA==",
+      "requires": {
+        "assign-symbols": "^2.0.2"
+      }
+    },
+    "assign-symbols": {
+      "version": "2.0.2",
+      "resolved": "https://registry.npmjs.org/assign-symbols/-/assign-symbols-2.0.2.tgz",
+      "integrity": "sha512-9sBQUQZMKFKcO/C3Bo6Rx4CQany0R0UeVcefNGRRdW2vbmaMOhV1sbmlXcQLcD56juLXbSGTBm0GGuvmrAF8pA=="
+    },
     "astral-regex": {
       "version": "1.0.0",
       "resolved": "https://registry.npmjs.org/astral-regex/-/astral-regex-1.0.0.tgz",
@@ -5530,7 +5543,6 @@
       "version": "3.6.0",
       "resolved": "https://registry.npmjs.org/readable-stream/-/readable-stream-3.6.0.tgz",
       "integrity": "sha512-BViHy7LKeTz4oNnkcLJ+lVSL6vpiFeX6/d3oSH8zCW7UxP2onchk+vTGB143xuFjHS3deTgkKoXXymXqymiIdA==",
-      "dev": true,
       "requires": {
         "inherits": "^2.0.3",
         "string_decoder": "^1.1.1",
@@ -5970,7 +5982,6 @@
       "version": "3.1.1",
       "resolved": "https://registry.npmjs.org/split2/-/split2-3.1.1.tgz",
       "integrity": "sha512-emNzr1s7ruq4N+1993yht631/JH+jaj0NYBosuKmLcq+JkGQ9MmTw1RB1fGaTCzUuseRIClrlSLHRNYGwWQ58Q==",
-      "dev": true,
       "requires": {
         "readable-stream": "^3.0.0"
       }
@@ -6251,7 +6262,6 @@
       "version": "1.3.0",
       "resolved": "https://registry.npmjs.org/string_decoder/-/string_decoder-1.3.0.tgz",
       "integrity": "sha512-hkRX8U1WjJFd8LsDJ2yQ/wWWxaopEsABU1XfkM8A+j0+85JAGppt16cr1Whg6KIbb4okU6Mql6BOj+uup/wKeA==",
-      "dev": true,
       "requires": {
         "safe-buffer": "~5.2.0"
       },
@@ -6259,8 +6269,7 @@
         "safe-buffer": {
           "version": "5.2.1",
           "resolved": "https://registry.npmjs.org/safe-buffer/-/safe-buffer-5.2.1.tgz",
-          "integrity": "sha512-rp3So07KcdmmKbGvgaNxQSJr7bGVSVk5S9Eq1F+ppbRo70+YeaDxkw5Dd8NPN+GD6bjnYm2VuPuCXmpuYvmCXQ==",
-          "dev": true
+          "integrity": "sha512-rp3So07KcdmmKbGvgaNxQSJr7bGVSVk5S9Eq1F+ppbRo70+YeaDxkw5Dd8NPN+GD6bjnYm2VuPuCXmpuYvmCXQ=="
         }
       }
     },
diff --git a/package.json b/package.json
index af37467f..b0766b8f 100644
--- a/package.json
+++ b/package.json
@@ -36,6 +36,7 @@
   "dependencies": {
     "@carto/fqdn-sync": "0.2.2",
     "@google-cloud/pubsub": "1.5.0",
+    "assign-deep": "^1.0.1",
     "basic-auth": "2.0.0",
     "body-parser": "1.18.3",
     "camshaft": "github:cartodb/camshaft#dgaubert/ch78389/camshaft-replace-logger-from-bunyan-to-pino",
@@ -56,6 +57,7 @@
     "redis-mpool": "^0.8.0",
     "request": "2.87.0",
     "semver": "5.5.0",
+    "split2": "^3.1.1",
     "step-profiler": "0.3.0",
     "turbo-carto": "0.21.2",
     "underscore": "1.6.0",

From b115bca07e9644541de9bbc95cc230ca62b2f9f3 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Mon, 8 Jun 2020 16:29:22 +0200
Subject: [PATCH 26/44] Be able to tag requests with labels as easier way to
 provide business metrics

---
 lib/api/map/analyses-catalog-controller.js        |  2 ++
 lib/api/map/analysis-layergroup-controller.js     |  2 ++
 lib/api/map/anonymous-map-controller.js           |  2 ++
 lib/api/map/attributes-layergroup-controller.js   |  2 ++
 .../clustered-features-layergroup-controller.js   |  2 ++
 lib/api/map/dataview-layergroup-controller.js     |  2 ++
 lib/api/map/preview-layergroup-controller.js      |  2 ++
 lib/api/map/preview-template-controller.js        |  2 ++
 lib/api/map/tile-layergroup-controller.js         |  2 ++
 lib/api/middlewares/tag.js                        | 15 +++++++++++++++
 lib/api/template/admin-template-controller.js     |  2 ++
 lib/api/template/named-template-controller.js     |  2 ++
 lib/api/template/tile-template-controller.js      |  2 ++
 13 files changed, 39 insertions(+)
 create mode 100644 lib/api/middlewares/tag.js

diff --git a/lib/api/map/analyses-catalog-controller.js b/lib/api/map/analyses-catalog-controller.js
index e1a27641..917a9402 100644
--- a/lib/api/map/analyses-catalog-controller.js
+++ b/lib/api/map/analyses-catalog-controller.js
@@ -1,6 +1,7 @@
 'use strict';
 
 const PSQL = require('cartodb-psql');
+const tag = require('../middlewares/tag');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
 const authorize = require('../middlewares/authorize');
@@ -23,6 +24,7 @@ module.exports = class AnalysesController {
 
     middlewares () {
         return [
+            tag({ tags: ['analysis', 'catalog'] }),
             credentials(),
             authorize(this.authBackend),
             dbConnSetup(this.pgConnection),
diff --git a/lib/api/map/analysis-layergroup-controller.js b/lib/api/map/analysis-layergroup-controller.js
index 188292e5..9719a3d9 100644
--- a/lib/api/map/analysis-layergroup-controller.js
+++ b/lib/api/map/analysis-layergroup-controller.js
@@ -1,5 +1,6 @@
 'use strict';
 
+const tag = require('../middlewares/tag');
 const layergroupToken = require('../middlewares/layergroup-token');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
@@ -23,6 +24,7 @@ module.exports = class AnalysisLayergroupController {
 
     middlewares () {
         return [
+            tag({ tags: ['analysis', 'node'] }),
             layergroupToken(),
             credentials(),
             authorize(this.authBackend),
diff --git a/lib/api/map/anonymous-map-controller.js b/lib/api/map/anonymous-map-controller.js
index ad0f4324..dddc07b2 100644
--- a/lib/api/map/anonymous-map-controller.js
+++ b/lib/api/map/anonymous-map-controller.js
@@ -3,6 +3,7 @@
 const windshaft = require('windshaft');
 const MapConfig = windshaft.model.MapConfig;
 const Datasource = windshaft.model.Datasource;
+const tag = require('../middlewares/tag');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
 const dbConnSetup = require('../middlewares/db-conn-setup');
@@ -90,6 +91,7 @@ module.exports = class AnonymousMapController {
         };
 
         return [
+            tag({ tags: ['map', 'anonymous'] }),
             metrics({
                 enabled: this.config.pubSubMetrics.enabled,
                 metricsBackend: this.metricsBackend,
diff --git a/lib/api/map/attributes-layergroup-controller.js b/lib/api/map/attributes-layergroup-controller.js
index ad0f1bc8..56396d7b 100644
--- a/lib/api/map/attributes-layergroup-controller.js
+++ b/lib/api/map/attributes-layergroup-controller.js
@@ -1,5 +1,6 @@
 'use strict';
 
+const tag = require('../middlewares/tag');
 const layergroupToken = require('../middlewares/layergroup-token');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
@@ -38,6 +39,7 @@ module.exports = class AttributesLayergroupController {
 
     middlewares () {
         return [
+            tag({ tags: ['attributes'] }),
             layergroupToken(),
             credentials(),
             authorize(this.authBackend),
diff --git a/lib/api/map/clustered-features-layergroup-controller.js b/lib/api/map/clustered-features-layergroup-controller.js
index 611813c4..8bcb23b5 100644
--- a/lib/api/map/clustered-features-layergroup-controller.js
+++ b/lib/api/map/clustered-features-layergroup-controller.js
@@ -1,5 +1,6 @@
 'use strict';
 
+const tag = require('../middlewares/tag');
 const layergroupToken = require('../middlewares/layergroup-token');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
@@ -38,6 +39,7 @@ module.exports = class AggregatedFeaturesLayergroupController {
 
     middlewares () {
         return [
+            tag({ tags: ['cluster'] }),
             layergroupToken(),
             credentials(),
             authorize(this.authBackend),
diff --git a/lib/api/map/dataview-layergroup-controller.js b/lib/api/map/dataview-layergroup-controller.js
index 8f849565..ab004e4b 100644
--- a/lib/api/map/dataview-layergroup-controller.js
+++ b/lib/api/map/dataview-layergroup-controller.js
@@ -1,5 +1,6 @@
 'use strict';
 
+const tag = require('../middlewares/tag');
 const layergroupToken = require('../middlewares/layergroup-token');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
@@ -76,6 +77,7 @@ module.exports = class DataviewLayergroupController {
 
     middlewares ({ action, rateLimitGroup }) {
         return [
+            tag({ tags: ['dataview', action] }),
             layergroupToken(),
             credentials(),
             authorize(this.authBackend),
diff --git a/lib/api/map/preview-layergroup-controller.js b/lib/api/map/preview-layergroup-controller.js
index 0d8edf9e..a2177ee5 100644
--- a/lib/api/map/preview-layergroup-controller.js
+++ b/lib/api/map/preview-layergroup-controller.js
@@ -1,5 +1,6 @@
 'use strict';
 
+const tag = require('../middlewares/tag');
 const layergroupToken = require('../middlewares/layergroup-token');
 const coordinates = require('../middlewares/coordinates');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
@@ -61,6 +62,7 @@ module.exports = class PreviewLayergroupController {
         }
 
         return [
+            tag({ tags: ['static', 'tile'] }),
             layergroupToken(),
             validateZoom ? coordinates({ z: true, x: false, y: false }) : noop(),
             credentials(),
diff --git a/lib/api/map/preview-template-controller.js b/lib/api/map/preview-template-controller.js
index dc960510..2301e7d4 100644
--- a/lib/api/map/preview-template-controller.js
+++ b/lib/api/map/preview-template-controller.js
@@ -1,5 +1,6 @@
 'use strict';
 
+const tag = require('../middlewares/tag');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
 const dbConnSetup = require('../middlewares/db-conn-setup');
@@ -67,6 +68,7 @@ module.exports = class PreviewTemplateController {
         };
 
         return [
+            tag({ tags: ['named', 'static', 'tile'] }),
             metrics({
                 enabled: this.config.pubSubMetrics.enabled,
                 metricsBackend: this.metricsBackend,
diff --git a/lib/api/map/tile-layergroup-controller.js b/lib/api/map/tile-layergroup-controller.js
index 5c5c468f..9b6a8e6c 100644
--- a/lib/api/map/tile-layergroup-controller.js
+++ b/lib/api/map/tile-layergroup-controller.js
@@ -1,5 +1,6 @@
 'use strict';
 
+const tag = require('../middlewares/tag');
 const layergroupToken = require('../middlewares/layergroup-token');
 const coordinates = require('../middlewares/coordinates');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
@@ -59,6 +60,7 @@ module.exports = class TileLayergroupController {
 
     middlewares () {
         return [
+            tag({ tags: ['tile'] }),
             layergroupToken(),
             coordinates(),
             credentials(),
diff --git a/lib/api/middlewares/tag.js b/lib/api/middlewares/tag.js
new file mode 100644
index 00000000..de5404b1
--- /dev/null
+++ b/lib/api/middlewares/tag.js
@@ -0,0 +1,15 @@
+'use strict';
+
+module.exports = function tag ({ tags }) {
+    if (!Array.isArray(tags) || !tags.every((tag) => typeof tag === 'string')) {
+        throw new Error('Required "tags" option must be a valid Array: [string, string, ...]');
+    }
+
+    return function tagMiddleware (req, res, next) {
+        const { logger } = res.locals;
+        res.locals.tags = tags;
+        res.on('finish', () => logger.info({ tags: res.locals.tags }));
+
+        next();
+    };
+};
diff --git a/lib/api/template/admin-template-controller.js b/lib/api/template/admin-template-controller.js
index 1a9e90e2..6c01807c 100644
--- a/lib/api/template/admin-template-controller.js
+++ b/lib/api/template/admin-template-controller.js
@@ -1,6 +1,7 @@
 'use strict';
 
 const { templateName } = require('../../backends/template-maps');
+const tag = require('../middlewares/tag');
 const credentials = require('../middlewares/credentials');
 const rateLimit = require('../middlewares/rate-limit');
 const { RATE_LIMIT_ENDPOINTS_GROUPS } = rateLimit;
@@ -76,6 +77,7 @@ module.exports = class AdminTemplateController {
         }
 
         return [
+            tag({ tags: ['named', 'admin', action] }),
             credentials(),
             authorizedByAPIKey({ authBackend: this.authBackend, action, label }),
             rateLimit(this.userLimitsBackend, rateLimitGroup),
diff --git a/lib/api/template/named-template-controller.js b/lib/api/template/named-template-controller.js
index a7d0b009..2921748b 100644
--- a/lib/api/template/named-template-controller.js
+++ b/lib/api/template/named-template-controller.js
@@ -1,5 +1,6 @@
 'use strict';
 
+const tag = require('../middlewares/tag');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
 const dbConnSetup = require('../middlewares/db-conn-setup');
@@ -88,6 +89,7 @@ module.exports = class NamedMapController {
         };
 
         return [
+            tag({ tags: ['map', 'named'] }),
             metrics({
                 enabled: this.config.pubSubMetrics.enabled,
                 metricsBackend: this.metricsBackend,
diff --git a/lib/api/template/tile-template-controller.js b/lib/api/template/tile-template-controller.js
index bb2b0aa7..285eb0d0 100644
--- a/lib/api/template/tile-template-controller.js
+++ b/lib/api/template/tile-template-controller.js
@@ -1,5 +1,6 @@
 'use strict';
 
+const tag = require('../middlewares/tag');
 const coordinates = require('../middlewares/coordinates');
 const cleanUpQueryParams = require('../middlewares/clean-up-query-params');
 const credentials = require('../middlewares/credentials');
@@ -37,6 +38,7 @@ module.exports = class TileTemplateController {
 
     middlewares () {
         return [
+            tag({ tags: ['tile', 'named'] }),
             coordinates(),
             credentials(),
             authorize(this.authBackend),

From e206a1bca3f00a132156bd623d1fc49e12b1b1cf Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Mon, 8 Jun 2020 16:34:08 +0200
Subject: [PATCH 27/44] Check whether the log is a pino's log and skip them
 when they aren't

---
 log-collector.js | 20 ++++++++++++++++----
 1 file changed, 16 insertions(+), 4 deletions(-)

diff --git a/log-collector.js b/log-collector.js
index 2b4c1f1c..c079a7fc 100644
--- a/log-collector.js
+++ b/log-collector.js
@@ -2,8 +2,9 @@
 
 const split = require('split2');
 const assingDeep = require('assign-deep');
-const logs = new Map();
 const { Transform } = require('readable-stream');
+const DEV_ENVS = ['test', 'development'];
+const logs = new Map();
 
 const LEVELS = {
     10: 'trace',
@@ -21,8 +22,15 @@ function logTransport () {
 
             try {
                 entry = JSON.parse(chunk);
-            } catch (error) {
-                // this.push(chunk + '\n');
+                const { level, time } = entry;
+
+                if (level === undefined && time === undefined) {
+                    throw new Error('Entry log is not a valid');
+                }
+            } catch (e) {
+                if (DEV_ENVS.includes(process.env.NODE_ENV)) {
+                    this.push(chunk + '\n');
+                }
                 return callback();
             }
 
@@ -51,7 +59,7 @@ function logTransport () {
                 }
 
                 let error;
-                if (Object.prototype.hasOwnProperty.call(accEntry, 'error') && Object.prototype.hasOwnProperty.call(entry, 'error')) {
+                if (hasProperty(accEntry, 'error') && hasProperty(entry, 'error')) {
                     logs.set(id, assingDeep({}, accEntry, entry, { error: accEntry.error.concat(entry.error) }));
                 } else {
                     logs.set(id, assingDeep({}, accEntry, entry));
@@ -65,6 +73,10 @@ function logTransport () {
     })
 }
 
+function hasProperty(obj, prop) {
+    return Object.prototype.hasOwnProperty.call(obj, prop)
+}
+
 process.stdin
     .pipe(split())
     .pipe(logTransport())

From a5c83edef6ba4b88f07cbdc63065fa14597c75b5 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Mon, 8 Jun 2020 20:16:00 +0200
Subject: [PATCH 28/44] Introducing @carto/metro, the carto logs and metrics
 transport.

---
 lib/api/api-router.js                      |  15 +--
 metro/index.js                             |  11 ++
 log-collector.js => metro/log-collector.js |  11 +-
 metro/metrics-collector.js                 | 119 +++++++++++++++++++++
 package-lock.json                          |  21 ++++
 package.json                               |   1 +
 6 files changed, 163 insertions(+), 15 deletions(-)
 create mode 100644 metro/index.js
 rename log-collector.js => metro/log-collector.js (90%)
 create mode 100644 metro/metrics-collector.js

diff --git a/lib/api/api-router.js b/lib/api/api-router.js
index 9491b506..57881da7 100644
--- a/lib/api/api-router.js
+++ b/lib/api/api-router.js
@@ -199,20 +199,21 @@ module.exports = class ApiRouter {
             const apiRouter = router({ mergeParams: true });
             const { paths, middlewares = [] } = route;
 
-            middlewares.forEach(middleware => apiRouter.use(middleware()));
-
             apiRouter.use(initLogger({ logger: this.serverOptions.logger }));
-            apiRouter.use(initializeStatusCode());
-            apiRouter.use(bodyParser.json());
-            apiRouter.use(servedByHostHeader());
-            apiRouter.use(clientHeader());
             apiRouter.use(profiler({
                 enabled: this.serverOptions.useProfiler,
                 statsClient: global.statsClient
             }));
+            apiRouter.use(user(this.metadataBackend));
+
+            middlewares.forEach(middleware => apiRouter.use(middleware()));
+
+            apiRouter.use(initializeStatusCode());
+            apiRouter.use(bodyParser.json());
+            apiRouter.use(servedByHostHeader());
+            apiRouter.use(clientHeader());
             apiRouter.use(lzmaMiddleware());
             apiRouter.use(cors());
-            apiRouter.use(user(this.metadataBackend));
 
             this.templateRouter.route(apiRouter, route.template);
             this.mapRouter.route(apiRouter, route.map);
diff --git a/metro/index.js b/metro/index.js
new file mode 100644
index 00000000..972f628a
--- /dev/null
+++ b/metro/index.js
@@ -0,0 +1,11 @@
+'use strict';
+
+const split = require('split2');
+const logCollector = require('./log-collector');
+const metricsCollector = require('./metrics-collector');
+
+process.stdin
+    .pipe(split())
+    .pipe(logCollector())
+    .pipe(metricsCollector())
+    .pipe(process.stdout);
diff --git a/log-collector.js b/metro/log-collector.js
similarity index 90%
rename from log-collector.js
rename to metro/log-collector.js
index c079a7fc..5e4ef2f4 100644
--- a/log-collector.js
+++ b/metro/log-collector.js
@@ -2,7 +2,7 @@
 
 const split = require('split2');
 const assingDeep = require('assign-deep');
-const { Transform } = require('readable-stream');
+const { Transform } = require('stream');
 const DEV_ENVS = ['test', 'development'];
 const logs = new Map();
 
@@ -15,9 +15,9 @@ const LEVELS = {
     60: 'fatal'
 }
 
-function logTransport () {
+module.exports = function logCollector () {
     return new Transform({
-        transform: function transform (chunk, enc, callback) {
+        transform (chunk, enc, callback) {
             let entry;
 
             try {
@@ -76,8 +76,3 @@ function logTransport () {
 function hasProperty(obj, prop) {
     return Object.prototype.hasOwnProperty.call(obj, prop)
 }
-
-process.stdin
-    .pipe(split())
-    .pipe(logTransport())
-    .pipe(process.stdout);
diff --git a/metro/metrics-collector.js b/metro/metrics-collector.js
new file mode 100644
index 00000000..da5fd0a0
--- /dev/null
+++ b/metro/metrics-collector.js
@@ -0,0 +1,119 @@
+'use strict'
+
+const express = require('express');
+const { Counter, Histogram, register } = require('prom-client');
+const split = require('split2');
+const { Transform } = require('stream');
+const DEV_ENVS = ['test', 'development'];
+
+const requestCounter = new Counter({
+    name: 'maps_api_requests_total',
+    help: 'MAPS API requests total'
+});
+
+const requestOkCounter = new Counter({
+    name: 'maps_api_requests_ok_total',
+    help: 'MAPS API requests ok total'
+});
+
+const requestErrorCounter = new Counter({
+    name: 'maps_api_requests_errors_total',
+    help: 'MAPS API requests errors total'
+});
+
+const responseTimeHistogram = new Histogram({
+    name: 'maps_api_response_time_total',
+    help: 'MAPS API response time total'
+});
+
+const userRequestCounter = new Counter({
+    name: 'maps_api_requests',
+    help: 'MAPS API requests per user',
+    labelNames: ['user', 'http_code']
+});
+
+const userRequestOkCounter = new Counter({
+    name: 'maps_api_requests_ok',
+    help: 'MAPS API requests per user with success HTTP code',
+    labelNames: ['user', 'http_code']
+});
+
+const userRequestErrorCounter = new Counter({
+    name: 'maps_api_requests_errors',
+    help: 'MAPS API requests per user with error HTTP code',
+    labelNames: ['user', 'http_code']
+});
+
+const userResponseTimeHistogram = new Histogram({
+    name: 'maps_api_response_time',
+    help: 'MAPS API response time total',
+    labelNames: ['user']
+});
+
+module.exports = function updateMetrics () {
+    return new Transform({
+        transform (chunk, enc, callback) {
+            let entry;
+
+            try {
+                entry = JSON.parse(chunk);
+                const { level, time } = entry;
+
+                if (level === undefined && time === undefined) {
+                    throw new Error('Entry log is not valid');
+                }
+            } catch (e) {
+                if (DEV_ENVS.includes(process.env.NODE_ENV)) {
+                    this.push(chunk);
+                }
+                return callback();
+            }
+
+            const { request, response, stats } = entry;
+
+            if (request === undefined || response === undefined || stats === undefined) {
+                this.push(chunk + '\n');
+                return callback();
+            }
+
+            const { statusCode, headers } = response;
+            const { 'carto-user': user } = headers;
+
+            if (statusCode === undefined || headers === undefined || user === undefined) {
+                this.push(chunk + '\n');
+                return callback();
+            }
+
+            requestCounter.inc();
+            userRequestCounter.labels(user, `${statusCode}`).inc();
+
+            if (statusCode >= 200 && statusCode < 400) {
+                requestOkCounter.inc();
+                userRequestOkCounter.labels(user, `${statusCode}`).inc();
+            } else {
+                requestErrorCounter.inc();
+                userRequestErrorCounter.labels(user, `${statusCode}`).inc();
+            }
+
+            const { response: responseTime } = stats;
+
+            if (Number.isFinite(responseTime)) {
+                responseTimeHistogram.observe(responseTime);
+                userResponseTimeHistogram.labels(user).observe(responseTime);
+            }
+
+            this.push(chunk);
+            callback();
+        }
+    })
+}
+
+const port = process.env.PORT || 9144;
+const app = express();
+
+app.get('/metrics', (req, res) => {
+    res.set('Content-Type', register.contentType);
+    res.end(register.metrics());
+});
+
+app.listen(port);
diff --git a/package-lock.json b/package-lock.json
index 6737c08d..e14dbd48 100644
--- a/package-lock.json
+++ b/package-lock.json
@@ -719,6 +719,11 @@
       "integrity": "sha512-Phlt0plgpIIBOGTT/ehfFnbNlfsDEiqmzE2KRXoX1bLIlir4X/MR+zSyBEkL05ffWgnRSf/DXv+WrUAVr93/ow==",
       "dev": true
     },
+    "bintrees": {
+      "version": "1.0.1",
+      "resolved": "https://registry.npmjs.org/bintrees/-/bintrees-1.0.1.tgz",
+      "integrity": "sha1-DmVcm5wkNeqraL9AJyJtK1WjRSQ="
+    },
     "body-parser": {
       "version": "1.18.3",
       "resolved": "https://registry.npmjs.org/body-parser/-/body-parser-1.18.3.tgz",
@@ -5409,6 +5414,14 @@
       "integrity": "sha512-7PiHtLll5LdnKIMw100I+8xJXR5gW2QwWYkT6iJva0bXitZKa/XMrSbdmg3r2Xnaidz9Qumd0VPaMrZlF9V9sA==",
       "dev": true
     },
+    "prom-client": {
+      "version": "12.0.0",
+      "resolved": "https://registry.npmjs.org/prom-client/-/prom-client-12.0.0.tgz",
+      "integrity": "sha512-JbzzHnw0VDwCvoqf8y1WDtq4wSBAbthMB1pcVI/0lzdqHGJI3KBJDXle70XK+c7Iv93Gihqo0a5LlOn+g8+DrQ==",
+      "requires": {
+        "tdigest": "^0.1.1"
+      }
+    },
     "propagate": {
       "version": "1.0.0",
       "resolved": "https://registry.npmjs.org/propagate/-/propagate-1.0.0.tgz",
@@ -6398,6 +6411,14 @@
         }
       }
     },
+    "tdigest": {
+      "version": "0.1.1",
+      "resolved": "https://registry.npmjs.org/tdigest/-/tdigest-0.1.1.tgz",
+      "integrity": "sha1-Ljyyw56kSeVdHmzZEReszKRYgCE=",
+      "requires": {
+        "bintrees": "1.0.1"
+      }
+    },
     "test-exclude": {
       "version": "5.2.3",
       "resolved": "https://registry.npmjs.org/test-exclude/-/test-exclude-5.2.3.tgz",
diff --git a/package.json b/package.json
index b0766b8f..0cdeb510 100644
--- a/package.json
+++ b/package.json
@@ -53,6 +53,7 @@
     "lzma": "2.3.2",
     "node-statsd": "0.1.1",
     "pino": "^6.3.1",
+    "prom-client": "^12.0.0",
     "queue-async": "1.1.0",
     "redis-mpool": "^0.8.0",
     "request": "2.87.0",

From 9e14185990124254706ea5fe690d5bd8682bb948 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 9 Jun 2020 09:30:11 +0200
Subject: [PATCH 29/44] Rename

---
 metro/metrics-collector.js | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/metro/metrics-collector.js b/metro/metrics-collector.js
index da5fd0a0..dfd7699a 100644
--- a/metro/metrics-collector.js
+++ b/metro/metrics-collector.js
@@ -50,7 +50,7 @@ const userResponseTimeHistogram = new Histogram({
     labelNames: ['user']
 });
 
-module.exports = function updateMetrics () {
+module.exports = function metricsCollector () {
     return new Transform({
         transform (chunk, enc, callback) {
             let entry;

From 3583e064beede474c5897277b257146964da9549 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 9 Jun 2020 09:40:24 +0200
Subject: [PATCH 30/44] User native http server

---
 metro/metrics-collector.js | 15 +++++++--------
 1 file changed, 7 insertions(+), 8 deletions(-)

diff --git a/metro/metrics-collector.js b/metro/metrics-collector.js
index dfd7699a..50ef3cd5 100644
--- a/metro/metrics-collector.js
+++ b/metro/metrics-collector.js
@@ -1,6 +1,6 @@
 'use strict'
 
-const express = require('express');
+const http = require('http');
 const { Counter, Histogram, register } = require('prom-client');
 const split = require('split2');
 const { Transform } = require('stream');
@@ -109,11 +109,10 @@ module.exports = function metricsCollector () {
 }
 
 const port = process.env.PORT || 9144;
-const app = express();
 
-app.get('/metrics', (req, res) => {
-    res.set('Content-Type', register.contentType);
-    res.end(register.metrics());
-});
-
-app.listen(port);
+http
+    .createServer((req, res) => {
+        res.writeHead(200, { 'Content-Type': register.contentType });
+        res.end(register.metrics());
+    })
+    .listen(port);

From 6f9580bae26976903c000d4251b05773e43c39b1 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 9 Jun 2020 09:52:56 +0200
Subject: [PATCH 31/44] Allow the metro to exit if this is the only active
 server in the event loop system

---
 metro/metrics-collector.js | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/metro/metrics-collector.js b/metro/metrics-collector.js
index 50ef3cd5..bf488c17 100644
--- a/metro/metrics-collector.js
+++ b/metro/metrics-collector.js
@@ -115,4 +115,5 @@ http
         res.writeHead(200, { 'Content-Type': register.contentType });
         res.end(register.metrics());
     })
-    .listen(port);
+    .listen(port)
+    .unref();

From 7acbfc1e9bd44e21c2c5e0a1db0b0d354e5aaa83 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 9 Jun 2020 10:00:54 +0200
Subject: [PATCH 32/44] Typos

---
 metro/log-collector.js     | 2 +-
 metro/metrics-collector.js | 4 ++--
 2 files changed, 3 insertions(+), 3 deletions(-)

diff --git a/metro/log-collector.js b/metro/log-collector.js
index 5e4ef2f4..bbb3c7b5 100644
--- a/metro/log-collector.js
+++ b/metro/log-collector.js
@@ -25,7 +25,7 @@ module.exports = function logCollector () {
                 const { level, time } = entry;
 
                 if (level === undefined && time === undefined) {
-                    throw new Error('Entry log is not a valid');
+                    throw new Error('Entry log is not valid');
                 }
             } catch (e) {
                 if (DEV_ENVS.includes(process.env.NODE_ENV)) {
diff --git a/metro/metrics-collector.js b/metro/metrics-collector.js
index bf488c17..eb7a1112 100644
--- a/metro/metrics-collector.js
+++ b/metro/metrics-collector.js
@@ -72,7 +72,7 @@ module.exports = function metricsCollector () {
             const { request, response, stats } = entry;
 
             if (request === undefined || response === undefined || stats === undefined) {
-                this.push(chunk + '\n');
+                this.push(chunk);
                 return callback();
             }
 
@@ -80,7 +80,7 @@ module.exports = function metricsCollector () {
             const { 'carto-user': user } = headers;
 
             if (statusCode === undefined || headers === undefined || user === undefined) {
-                this.push(chunk + '\n');
+                this.push(chunk);
                 return callback();
             }
 

From 18525a60cdbf2a9b6a0af4d9624155e06e31cbfa Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Tue, 9 Jun 2020 16:35:08 +0200
Subject: [PATCH 33/44] Use 9145 as default port for metics

---
 metro/metrics-collector.js | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/metro/metrics-collector.js b/metro/metrics-collector.js
index eb7a1112..8343ebb6 100644
--- a/metro/metrics-collector.js
+++ b/metro/metrics-collector.js
@@ -108,7 +108,7 @@ module.exports = function metricsCollector () {
     })
 }
 
-const port = process.env.PORT || 9144;
+const port = process.env.PORT || 9145;
 
 http
     .createServer((req, res) => {

From e49ecda321867d446f0f2927fc72acc2947ec709 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Wed, 10 Jun 2020 17:21:35 +0200
Subject: [PATCH 34/44] Don't create a new metric for each request, use the
 same label to send to statsd

---
 lib/api/middlewares/profiler.js | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/lib/api/middlewares/profiler.js b/lib/api/middlewares/profiler.js
index a3cb584f..c505a77d 100644
--- a/lib/api/middlewares/profiler.js
+++ b/lib/api/middlewares/profiler.js
@@ -2,13 +2,13 @@
 
 const Profiler = require('../../stats/profiler-proxy');
 const debug = require('debug')('windshaft:cartodb:stats');
+const { name: prefix } = require('../../../package.json');
 
 module.exports = function profiler (options) {
     const { enabled = true, statsClient } = options;
 
     return function profilerMiddleware (req, res, next) {
         const { logger } = res.locals;
-        const { id } = logger.bindings();
 
         // TODO: stop using profiler and log stats instead of adding them to the profiler
         req.profiler = new Profiler({
@@ -16,7 +16,7 @@ module.exports = function profiler (options) {
             profile: enabled
         });
 
-        req.profiler.start(id);
+        req.profiler.start(prefix);
 
         res.on('finish', () => {
             req.profiler.done('response');

From f6c8796c8a158d6b04204af2cb55acb3beb42a09 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Thu, 11 Jun 2020 10:12:27 +0200
Subject: [PATCH 35/44] Do not duplicate timer

---
 lib/api/middlewares/profiler.js | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/lib/api/middlewares/profiler.js b/lib/api/middlewares/profiler.js
index c505a77d..9d2b573b 100644
--- a/lib/api/middlewares/profiler.js
+++ b/lib/api/middlewares/profiler.js
@@ -16,10 +16,10 @@ module.exports = function profiler (options) {
             profile: enabled
         });
 
-        req.profiler.start(prefix);
+        req.profiler.start([prefix, 'response'].join('.'));
 
         res.on('finish', () => {
-            req.profiler.done('response');
+            req.profiler.end();
             logger.info({ stats: req.profiler.toJSON() });
 
             try {

From bf250e592a1a3a22847014b61b422e559ae08b7f Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Thu, 11 Jun 2020 12:30:15 +0200
Subject: [PATCH 36/44] rename level => levelname to avoid type clashing in ES

---
 metro/log-collector.js | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/metro/log-collector.js b/metro/log-collector.js
index bbb3c7b5..4eda405d 100644
--- a/metro/log-collector.js
+++ b/metro/log-collector.js
@@ -44,7 +44,9 @@ module.exports = function logCollector () {
 
             if (end === true) {
                 const accEntry = logs.get(id);
-                accEntry.level = LEVELS[accEntry.level];
+                // rename level => levelname to avoid type clashing in ES
+                accEntry.levelname = LEVELS[accEntry.level];
+                delete accEntry.level;
                 accEntry.time = entry.time;
                 this.push(`${JSON.stringify(accEntry)}\n`);
                 logs.delete(id);

From 2444b4c0084d86610949b4d449112e4bbde7b6ed Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Thu, 11 Jun 2020 13:04:19 +0200
Subject: [PATCH 37/44] rename error => errors to avoid type clashing in ES

---
 metro/log-collector.js | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/metro/log-collector.js b/metro/log-collector.js
index 4eda405d..39e3df9c 100644
--- a/metro/log-collector.js
+++ b/metro/log-collector.js
@@ -47,6 +47,9 @@ module.exports = function logCollector () {
                 // rename level => levelname to avoid type clashing in ES
                 accEntry.levelname = LEVELS[accEntry.level];
                 delete accEntry.level;
+                accEntry.errors = accEntry.error;
+                delete accEntry.error;
+
                 accEntry.time = entry.time;
                 this.push(`${JSON.stringify(accEntry)}\n`);
                 logs.delete(id);

From 49735308defd22c1239792a536b6ecf2b6bdfffe Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Thu, 11 Jun 2020 18:15:44 +0200
Subject: [PATCH 38/44] Do not rename level and error fields

---
 metro/log-collector.js | 7 +------
 1 file changed, 1 insertion(+), 6 deletions(-)

diff --git a/metro/log-collector.js b/metro/log-collector.js
index 39e3df9c..bbb3c7b5 100644
--- a/metro/log-collector.js
+++ b/metro/log-collector.js
@@ -44,12 +44,7 @@ module.exports = function logCollector () {
 
             if (end === true) {
                 const accEntry = logs.get(id);
-                // rename level => levelname to avoid type clashing in ES
-                accEntry.levelname = LEVELS[accEntry.level];
-                delete accEntry.level;
-                accEntry.errors = accEntry.error;
-                delete accEntry.error;
-
+                accEntry.level = LEVELS[accEntry.level];
                 accEntry.time = entry.time;
                 this.push(`${JSON.stringify(accEntry)}\n`);
                 logs.delete(id);

From 578f543c019c1d62fbe1d30fb53e2e2b61b88c67 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Thu, 11 Jun 2020 18:21:13 +0200
Subject: [PATCH 39/44] log user

---
 lib/api/middlewares/user.js | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/lib/api/middlewares/user.js b/lib/api/middlewares/user.js
index bf508085..155d3347 100644
--- a/lib/api/middlewares/user.js
+++ b/lib/api/middlewares/user.js
@@ -6,8 +6,10 @@ module.exports = function user (metadataBackend) {
     const cdbRequest = new CdbRequest();
 
     return function userMiddleware (req, res, next) {
+        const { logger } = res.locals;
         try {
             res.locals.user = getUserNameFromRequest(req, cdbRequest);
+            logger.info({ user: res.locals.user });
         } catch (err) {
             return next(err);
         }

From a68618c336858b75c5dfcfd15b9936255bf74f9f Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Fri, 12 Jun 2020 10:12:32 +0200
Subject: [PATCH 40/44] Prepare init log to be kibana friendly

---
 app.js | 6 ++----
 1 file changed, 2 insertions(+), 4 deletions(-)

diff --git a/app.js b/app.js
index 84bc3e3b..8e231c54 100755
--- a/app.js
+++ b/app.js
@@ -78,13 +78,11 @@ const server = createServer(serverOptions);
 const backlog = global.environment.maxConnections || 128;
 
 const listener = server.listen(serverOptions.bind.port, serverOptions.bind.host, backlog);
-const version = require('./package').version;
+const { version, name } = require('./package');
 
 listener.on('listening', function () {
-    logger.info(`Using Node.js ${process.version}`);
-    logger.info(`Using configuration file ${configurationFile}`);
     const { address, port } = listener.address();
-    logger.info(`Windshaft tileserver ${version} started on ${address}:${port} PID=${process.pid} (${process.env.NODE_ENV})`);
+    logger.info({ 'Node.js': process.version, pid: process.pid, environment: process.env.NODE_ENV, [name]: version, address, port, config: configurationFile }, `${name} initialized successfully`);
 });
 
 function getCPUUsage (oldUsage) {

From 22086ba9141e84f22ab5e0be9dea7cdd90b0d23c Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Fri, 19 Jun 2020 10:18:06 +0200
Subject: [PATCH 41/44] Count requests even when the info is not complete

---
 metro/metrics-collector.js | 20 +++++++++++---------
 1 file changed, 11 insertions(+), 9 deletions(-)

diff --git a/metro/metrics-collector.js b/metro/metrics-collector.js
index 8343ebb6..e20377e8 100644
--- a/metro/metrics-collector.js
+++ b/metro/metrics-collector.js
@@ -79,20 +79,22 @@ module.exports = function metricsCollector () {
             const { statusCode, headers } = response;
             const { 'carto-user': user } = headers;
 
-            if (statusCode === undefined || headers === undefined || user === undefined) {
-                this.push(chunk);
-                return callback();
-            }
-
             requestCounter.inc();
-            userRequestCounter.labels(user, `${statusCode}`).inc();
+
+            if (statusCode !== undefined && user !== undefined) {
+                userRequestCounter.labels(user, `${statusCode}`).inc();
+            }
 
             if (statusCode >= 200 && statusCode < 400) {
                 requestOkCounter.inc();
-                userRequestOkCounter.labels(user, `${statusCode}`).inc();
-            } else {
+                if (user !== undefined) {
+                   userRequestOkCounter.labels(user, `${statusCode}`).inc();
+                }
+            } else if (statusCode >= 400) {
                 requestErrorCounter.inc();
-                userRequestErrorCounter.labels(user, `${statusCode}`).inc();
+                if (user !== undefined) {
+                    userRequestErrorCounter.labels(user, `${statusCode}`).inc();
+                }
             }
 
             const { response: responseTime } = stats;

From 6cddec562a7fdc2a74d000b319f581d7e32a9b3f Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Fri, 19 Jun 2020 11:42:46 +0200
Subject: [PATCH 42/44] Profiler don't log times if there is no one task done
 at least

---
 lib/api/middlewares/profiler.js | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/lib/api/middlewares/profiler.js b/lib/api/middlewares/profiler.js
index 9d2b573b..f4af21d7 100644
--- a/lib/api/middlewares/profiler.js
+++ b/lib/api/middlewares/profiler.js
@@ -16,9 +16,10 @@ module.exports = function profiler (options) {
             profile: enabled
         });
 
-        req.profiler.start([prefix, 'response'].join('.'));
+        req.profiler.start(prefix);
 
         res.on('finish', () => {
+            req.profiler.done('response');
             req.profiler.end();
             logger.info({ stats: req.profiler.toJSON() });
 

From 43a603922d1deeb2c84fdfa364ce3b8266c0d5b0 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Mon, 22 Jun 2020 12:24:06 +0200
Subject: [PATCH 43/44] Update NEWS

---
 NEWS.md | 16 +++++++++++++++-
 1 file changed, 15 insertions(+), 1 deletion(-)

diff --git a/NEWS.md b/NEWS.md
index 54a883ff..dc732cba 100644
--- a/NEWS.md
+++ b/NEWS.md
@@ -1,8 +1,22 @@
 # Changelog
 
-## 9.0.1
+## 10.0.0
 Released 2020-mm-dd
 
+Breaking changes:
+- Log system revamp:
+  - Logs to stdout, disabled while testing
+  - Upgrade `camshaft` to version [`0.x.0`](https://github.com/CartoDB/camshaft/releases/tag/0.x.0)
+  - Use header `X-Request-Id`, or create a new `uuid` when no present, to identyfy log entries
+  - Be able to set log level from env variable `LOG_LEVEL`, useful while testing: `LOG_LEVEL=info npm test`; even more human-readable: `LOG_LEVEL=info npm t | ./node_modules/.bin/pino-pretty`
+  - Stop responding with `X-Tiler-Errors` header. Now errors are properly logged and will end up in ELK as usual.
+  - Stop responding with `X-Tiler-Profiler` header. Now profiling stats are properly logged and will end up in ELK as usual.
+  - Be able to reduce the footprint in the final log file depending on the environment
+  - Be able to pass the logger to the analysis creation (camshaft) while instantiating a named map with analysis.
+  - Be able to tag requests with labels as an easier way to provide business metrics
+  - Metro: Add log-collector utility (`metro`), it will be moved to its own repository. Attaching it here fro development purposes. Try it with the following command `LOG_LEVEL=info npm t | node metro`
+  - Metro: Creates `metrics-collector.js` a stream to update Prometheus' counters and histograms and exposes them via Express' app (`:9145/metrics`). Use the ones defined in `grok_exporter`
+
 Bug Fixes:
 - While instantiating a map, set the `cache buster` equal to `0` when there are no affected tables in the MapConfig. Thus `layergroupid` has the same structure always:
   - `${map_id}:${cache_buster}` for anonymous map

From 360b98254b46669b769b7b5d8b9e06950b6ed906 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Daniel=20Garc=C3=ADa=20Aubert?=
 <danielgarciaaubert@gmail.com>
Date: Mon, 22 Jun 2020 17:01:29 +0200
Subject: [PATCH 44/44] Upgrade camshaft to version 0.66.0

---
 NEWS.md           | 2 +-
 package-lock.json | 5 +++--
 package.json      | 2 +-
 3 files changed, 5 insertions(+), 4 deletions(-)

diff --git a/NEWS.md b/NEWS.md
index dc732cba..5a31df25 100644
--- a/NEWS.md
+++ b/NEWS.md
@@ -6,7 +6,7 @@ Released 2020-mm-dd
 Breaking changes:
 - Log system revamp:
   - Logs to stdout, disabled while testing
-  - Upgrade `camshaft` to version [`0.x.0`](https://github.com/CartoDB/camshaft/releases/tag/0.x.0)
+  - Upgrade `camshaft` to version [`0.66.0`](https://github.com/CartoDB/camshaft/releases/tag/0.66.0)
   - Use header `X-Request-Id`, or create a new `uuid` when no present, to identyfy log entries
   - Be able to set log level from env variable `LOG_LEVEL`, useful while testing: `LOG_LEVEL=info npm test`; even more human-readable: `LOG_LEVEL=info npm t | ./node_modules/.bin/pino-pretty`
   - Stop responding with `X-Tiler-Errors` header. Now errors are properly logged and will end up in ELK as usual.
diff --git a/package-lock.json b/package-lock.json
index e14dbd48..bfc05c7e 100644
--- a/package-lock.json
+++ b/package-lock.json
@@ -814,8 +814,9 @@
       "integrity": "sha1-MvxLn82vhF/N9+c7uXysImHwqwo="
     },
     "camshaft": {
-      "version": "github:cartodb/camshaft#633d3b85869d894d52ac5c9970462f326d2f42cc",
-      "from": "github:cartodb/camshaft#dgaubert/ch78389/camshaft-replace-logger-from-bunyan-to-pino",
+      "version": "0.66.0",
+      "resolved": "https://registry.npmjs.org/camshaft/-/camshaft-0.66.0.tgz",
+      "integrity": "sha512-25WFuUEiPD9Tw0XWSno/m7qJ7QqaEy9t/WbcXt+j+zMTOxvQ4RqpvCAhmUEbLgTLRyTCTvY8nqPtu4PaVJuIyw==",
       "requires": {
         "async": "^1.5.2",
         "cartodb-psql": "0.14.0",
diff --git a/package.json b/package.json
index 0cdeb510..dbe54e23 100644
--- a/package.json
+++ b/package.json
@@ -39,7 +39,7 @@
     "assign-deep": "^1.0.1",
     "basic-auth": "2.0.0",
     "body-parser": "1.18.3",
-    "camshaft": "github:cartodb/camshaft#dgaubert/ch78389/camshaft-replace-logger-from-bunyan-to-pino",
+    "camshaft": "^0.66.0",
     "cartodb-psql": "0.14.0",
     "cartodb-query-tables": "^0.7.0",
     "cartodb-redis": "^3.0.0",