Merge pull request #1172 from CartoDB/dgaubert/ch78384/maps-api-replace-log4js-logger-by-pino-bis-bis

Stop using profiler wrongly

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 }) => {
+            (err, requestMapConfig) => {
-                req.profiler.done('anonymous.getMapConfig');
-
-                stats.mapType = 'anonymous';
-                req.profiler.add(stats);
-
                 if (err) {
                     return next(err);
                 }

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;

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;

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

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;

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;

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

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

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;

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

lib/api/middlewares/init-profiler.js

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

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

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

lib/api/middlewares/profiler.js

@@ -8,13 +8,18 @@ module.exports = function profiler (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({
             statsd_client: statsClient,
             profile: enabled
         });
 
+        req.profiler.start(id);
+
         res.on('finish', () => {
+            req.profiler.done('response');
             logger.info({ stats: req.profiler.toJSON() });
 
             try {

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

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

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

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;

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

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
+                return callback(null, result);
-                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);
             }, true); // use read-only transaction
         });
     }

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

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

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

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);
-
-        return callback(null, requestMapConfig, stats);
     });
 };
 
 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);
         });
     });
 };