winston out, intel in

bin/browserid

@@ -23,7 +23,7 @@ const forward = require('../lib/http_forward.js');
 const heartbeat = require('../lib/heartbeat.js');
 const httputils = require('../lib/httputils.js');
 const i18n_check = require('../lib/i18n_client_check');
-const logger = require('../lib/logging/logging.js').logger;
+const logger = require('../lib/logging/logging.js').getLogger('bid.bin.browserid');
 const primary = require('../lib/primary');
 const proxySecure = require('../lib/proxy-secure');
 const shutdown = require('../lib/shutdown');

bin/dbwriter

@@ -21,7 +21,7 @@ const assets = require('../lib/static_resources').all;
 const db = require('../lib/db.js');
 const config = require('../lib/configuration.js');
 const heartbeat = require('../lib/heartbeat.js');
-const logger = require('../lib/logging/logging.js').logger;
+const logger = require('../lib/logging/logging.js').getLogger('bid.bin.dbwriter');
 const primary = require('../lib/primary');
 const proxySecure = require('../lib/proxy-secure');
 const shutdown = require('../lib/shutdown');

bin/keysigner

@@ -15,7 +15,7 @@ _ = require('underscore'),
 config = require('../lib/configuration.js'),
 httputils = require('../lib/httputils.js'),
 validate = require('../lib/validate.js'),
-logger = require('../lib/logging/logging.js').logger,
+logger = require('../lib/logging/logging.js').getLogger('bid.bin.keysigner'),
 heartbeat = require('../lib/heartbeat'),
 shutdown = require('../lib/shutdown'),
 computecluster = require('compute-cluster'),

bin/load_gen

@@ -11,7 +11,7 @@
 require('../lib/baseExceptions').addExceptionHandler();
 var wsapi_client = require('../lib/wsapi_client');
 
-const winston = require('winston');
+const intel = require('intel');
 
 // option processing with optimist
 var argv = require('optimist')
@@ -219,7 +219,7 @@ function poll() {
           } else {
             completed[act][1]++;
           }
-          winston.error('('+act+') ' + err.toString());
+          intel.error('('+act+') ' + err.toString());
         } else {
           completed[act][0]++;
         }

bin/router

@@ -19,7 +19,7 @@ const addP3PHeader = require('../lib/p3p.js');
 const config = require('../lib/configuration.js');
 const forward = require('../lib/http_forward').forward;
 const heartbeat = require('../lib/heartbeat.js');
-const logger = require('../lib/logging/logging.js').logger;
+const logger = require('../lib/logging/logging.js').getLogger('bid.bin.router');
 const metrics = require('../lib/logging/middleware/metrics.js');
 const proxySecure = require('../lib/proxy-secure');
 const shutdown = require('../lib/shutdown.js');

bin/static

@@ -27,7 +27,7 @@ const db = require('../lib/db.js');
 const heartbeat = require('../lib/heartbeat.js');
 const httputils = require('../lib/httputils.js');
 const i18n_check = require('../lib/i18n_client_check');
-const logger = require('../lib/logging/logging.js').logger;
+const logger = require('../lib/logging/logging.js').getLogger('bid.bin.static');
 const proxySecure = require('../lib/proxy-secure');
 const shutdown = require('../lib/shutdown.js');
 const statsd = require("../lib/logging/middleware/statsd");

bin/verifier

@@ -15,7 +15,7 @@ fs = require('fs'),
 express = require('express'),
 computecluster = require('compute-cluster'),
 heartbeat = require('../lib/heartbeat'),
-logger = require('../lib/logging/logging').logger,
+logger = require('../lib/logging/logging').getLogger('bid.bin'),
 config = require('../lib/configuration'),
 shutdown = require('../lib/shutdown'),
 booleanQuery = require('../lib/boolean-query'),

config/local.json

@@ -10,6 +10,13 @@
   "database": {
     "driver": "json"
   },
+  "logging": {
+    "loggers": {
+      "bid": {
+        "level": "VERBOSE"
+      }
+    }
+  },
   "express_log_format": "dev_bid",
   "email_to_console": true,
   "env": "local",

config/production.json

@@ -17,6 +17,13 @@
   "statsd": {
     "enabled": true
   },
+  "logging": {
+    "loggers": {
+      "bid": {
+        "level": "INFO"
+      }
+    }
+  },
   "kpi": {
     "backend_sample_rate": 0.0
   },

lib/bcrypt.js

@@ -5,7 +5,7 @@
 const
 path = require('path'),
 computecluster = require('compute-cluster'),
-logger = require('../lib/logging/logging.js').logger,
+logger = require('../lib/logging/logging.js').getLogger('bid.bcrypt'),
 bcrypt = require('bcrypt'),
 config = require('./configuration.js');
 

lib/browserid/fake_verification.js

@@ -12,7 +12,7 @@ const
 configuration = require('../configuration.js'),
 url = require('url'),
 db = require('../db.js'),
-logger = require('../logging/logging.js').logger,
+logger = require('../logging/logging.js').getLogger('bid.fake_verification'),
 wsapi = require('../wsapi');
 
 logger.warn("HEAR YE: Fake verfication enabled, aceess via /wsapi/fake_verification?email=foo@bar.com");

lib/configuration.js

@@ -221,6 +221,73 @@ var conf = module.exports = convict({
       env: 'CEF_SYSLOG_PORT'
     }
   },
+  logging: {
+    formatters: {
+      doc: 'Formatters for intel loggers.',
+      format: Object,
+      env: 'LOG_FORMATTERS',
+      default: {
+        "dev": {
+          "format": "%(levelname)s %(name)s: %(message)s",
+          "colorize": true
+        },
+        "file": "%O",
+        "metrics": {
+          "class": "./logging/formatters/metrics",
+          "format": "%O"
+        }
+      }
+    },
+    filters: {
+      doc: 'Filters log messages to handlers and loggers.',
+      format: Object,
+      default: {
+        "metrics": {
+          "class": "./logging/filters/metrics"
+        }
+      }
+    },
+    handlers: {
+      doc: 'Handlers deliver log messages to different destinations.',
+      format: Object,
+      default: {
+        "null": {
+          "class": "intel/handlers/null"
+        },
+        "console": {
+          "class": "intel/handlers/console",
+          "formatter": "dev"
+        },
+        "file": {
+          "class": "intel/handlers/file",
+          "formatter": "file"
+        },
+        "statsd": {
+          "class": "./logging/handlers/statsd"
+        },
+        "metrics": {
+          "class": "intel/handlers/file",
+          "formatter": "metrics",
+          "filters": ["metrics"]
+        },
+        "kpiggybank": {
+          "class": "./logging/handlers/kpi",
+          "filters": ["metrics"]
+        }
+      }
+    },
+    loggers: {
+      default: {
+        "bid": {
+          "level": "DEBUG",
+          "handlers": ["file", "statsd", "metrics", "kpiggybank"],
+          "propagate": false,
+          "handleExceptions": true,
+          "exitOnError": false
+        }
+      }
+    }
+  },
   kpi: {
     backend_sample_rate: {
       doc: "Float between 0 and 1 inclusive, for the % of user flows that should send back KPI JSON blobs. Example: 0.5 would be 50% traffic.",
@@ -571,6 +638,6 @@ module.exports.performSubstitution = function(app) {
 
 // log the process_type
 process.nextTick(function() {
-  var logging = require("./logging/logging.js").logger;
+  var logging = require("./logging/logging.js").getLogger('bid.config');
   logging.info("process type is " + conf.get("process_type"));
 });

lib/db.js

@@ -2,7 +2,7 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
-var logger = require('./logging/logging.js').logger;
+var logger = require('./logging/logging.js').getLogger('bid.db');
 const config = require('./configuration.js');
 
 var driver;

lib/db/dbutils.js

@@ -3,7 +3,7 @@
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 const
-logger = require('../logging/logging.js').logger,
+logger = require('../logging/logging.js').getLogger('bid.db.utils'),
 primary = require('../primary.js');
 
 // Callback has the signature `function (type) {}`

lib/db/json.js

@@ -13,7 +13,7 @@ path = require('path'),
 fs = require('fs'),
 secrets = require('../secrets.js'),
 jsel = require('JSONSelect'),
-logger = require('../logging/logging.js').logger,
+logger = require('../logging/logging.js').getLogger('bid.db.json'),
 configuration = require('../configuration.js'),
 primary = require('../primary.js'),
 temp = require('temp');

lib/db/mysql.js

@@ -34,7 +34,7 @@ const
 conf = require('../configuration.js'),
 dbutils = require('./dbutils.js'),
 mysql = require('./mysql_wrapper.js'),
-logger = require('../logging/logging.js').logger,
+logger = require('../logging/logging.js').getLogger('bid.db.mysql'),
 primary = require('../primary.js'),
 secrets = require('../secrets.js');
 

lib/db/mysql_wrapper.js

@@ -9,7 +9,7 @@
 
 const
 mysql = require('mysql'),
-logger = require('../logging/logging.js').logger,
+logger = require('../logging/logging.js').getLogger('bid.db.mysql.wrapper'),
 config = require('../configuration.js');
 
 exports.createClient = function(options) {

lib/email.js

@@ -7,7 +7,7 @@ const fs = require('fs');
 const path = require('path');
 const ejs = require('ejs');
 const config = require('./configuration.js');
-const logger = require('./logging/logging.js').logger;
+const logger = require('./logging/logging.js').getLogger('bid.email');
 const url = require('url');
 const cachify = require('connect-cachify').cachify;
 const underscore = require('underscore');

lib/generate_code_version.js

@@ -7,7 +7,7 @@ const
 fs = require('fs'),
 path = require('path'),
 mkdirp = require('mkdirp'),
-logger = require('../lib/logging/logging').logger,
+logger = require('../lib/logging/logging').getLogger('bid.generate_version'),
 version = require('../lib/version.js');
 
 const BUILD_DIR_PATH = path.join(__dirname, "..", "resources", "static", "build");
@@ -24,7 +24,7 @@ const CODE_VERSION_JS_PATH = path.join(BUILD_DIR_PATH, "code_version.js");
  * 1) get the new version
  * 2) open code_version.js and read the already written version.
  * 3) if the new version is different than the already written version, update.
- *
+ *')
  * A new code_version.js file is only written if the versions are different.
  * A needless update causes a re-compilation of all JS resources for all
  * enabled locales.

lib/heartbeat.js

@@ -4,7 +4,7 @@
 
 const
 urlparse = require('urlparse'),
-logger = require('./logging/logging.js').logger,
+logger = require('./logging/logging.js').getLogger('bid.middleware.heartbeat'),
 url = require('url');
 
 // the path that heartbeats live at

lib/http_forward.js

@@ -6,7 +6,7 @@ const
 url = require('url'),
 http = require('http'),
 https = require('https'),
-logger = require('./logging/logging.js').logger,
+logger = require('./logging/logging.js').getLogger('bid.http_forward'),
 querystring = require('querystring');
 
 var global_forward_timeout;

lib/i18n_client_check.js

@@ -18,7 +18,7 @@
 var config = require('./configuration.js'),
     fs = require('fs'),
     i18n = require('i18n-abide'),
-    logger = require('./logging/logging.js').logger,
+    logger = require('./logging/logging.js').getLogger('bid.i18n'),
     path = require('path'),
     util = require('util');
 

lib/keysigner/ca.js

@@ -7,7 +7,7 @@
 var jwcrypto = require('jwcrypto'),
     cert = jwcrypto.cert,
     secrets = require('../secrets.js'),
-    logger = require('../logging/logging.js').logger;
+    logger = require('../logging/logging.js').getLogger('bid.keysigner.ca');
 
 // load up the right algorithms
 require("jwcrypto/lib/algs/rs");

lib/kpi_data.js

@@ -11,7 +11,7 @@ const querystring = require('querystring');
 const und = require('underscore');
 const urlparse = require('urlparse');
 const config = require('./configuration');
-const logger = require('./logging/logging').logger;
+const logger = require('./logging/logging').getLogger('bid.kpi');
 const TEN_MIN_IN_MS = 10 * 60 * 1000;
 
 // http and https are vars to override for testing.
@@ -55,7 +55,6 @@ function onResponse(cb, res) {
                       + res.statusCode);
     return cb(null, false);
   }
-
   logger.info('interaction data successfully posted to KPI Backend');
   cb(null, true);
 }

lib/load_gen/activities/add_email.js

@@ -8,7 +8,7 @@
 const
 wcli = require("../../wsapi_client.js"),
 userdb = require("../user_db.js"),
-winston = require('winston'),
+intel = require('intel'),
 common = require('../common.js');
 
 exports.startFunc = function(cfg, cb) {
@@ -27,7 +27,7 @@ exports.startFunc = function(cfg, cb) {
   var user = userdb.getExistingUser();
 
   if (!user) {
-    winston.warn("can't achieve desired concurrency!  not enough users!");
+    intel.warn("can't achieve desired concurrency!  not enough users!");
     return cb("not enough users");
   }
 

lib/load_gen/activities/change_pass.js

@@ -9,15 +9,15 @@
 const
 wcli = require("../../wsapi_client.js"),
 userdb = require("../user_db.js"),
-winston = require('winston'),
+intel = require('intel'),
 crypto = require('../crypto'),
 common = require('../common');
 
 exports.startFunc = function(cfg, cb) {
   var user = userdb.getExistingUser();
 
   if (!user) {
-    winston.warn("can't achieve desired concurrency!  not enough users!");
+    intel.warn("can't achieve desired concurrency!  not enough users!");
     return cb("not enough users");
   }
 

lib/load_gen/activities/reauth.js

@@ -9,7 +9,7 @@
 const
 common = require("../common.js"),
 userdb = require("../user_db.js"),
-winston = require('winston'),
+intel = require('intel'),
 wcli = require('../../wsapi_client.js');
 
 exports.startFunc = function(cfg, cb) {
@@ -28,7 +28,7 @@ exports.startFunc = function(cfg, cb) {
   var user = userdb.getExistingUser();
 
   if (!user) {
-    winston.warn("can't achieve desired concurrency!  not enough users!");
+    intel.warn("can't achieve desired concurrency!  not enough users!");
     return cb("concurrency error");
   }
 

lib/load_gen/activities/reset_pass.js

@@ -8,15 +8,15 @@
 const
 wcli = require("../../wsapi_client.js"),
 userdb = require("../user_db.js"),
-winston = require('winston'),
+intel = require('intel'),
 common = require('../common');
 
 exports.startFunc = function(cfg, cb) {
 
   var origUser = userdb.getExistingUser();
 
   if (!origUser) {
-    winston.warn("can't achieve desired concurrency!  not enough users!");
+    intel.warn("can't achieve desired concurrency!  not enough users!");
     return cb("not enough users");
   }