Do not bind logger to global object, now it's a part of serverOptions

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 = argv._[0] || process.env.NODE_ENV || global.environment.environment;
-process.env.NODE_ENV = 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}`);
+    logger.info(`Using Node.js ${process.version}`);
-    global.logger.info(`Using configuration file ${configurationFile}`);
+    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) => {
+const exitProcess = logger.finish((err, finalLogger, listener, signal, killTimeout) => {
-    scheduleForcedExit(killTimeout, logger);
+    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);
 

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 });
         });
     }
 

lib/api/middlewares/logger.js

@@ -2,13 +2,13 @@
 
 const uuid = require('uuid');
 
-module.exports = function logger () {
+module.exports = function initLogger ({ logger }) {
-    return function loggerMiddleware (req, res, next) {
+    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.locals.logger.info(req);
-        res.on('finish', () => logger.info(res));
+        res.on('finish', () => res.locals.logger.info(res));
 
         next();
     };

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()
 };

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);
+    }
+};

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;

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 = {

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,