diff --git a/browserid/app.js b/browserid/app.js index e31733579e0c44a46d02f9eb75f51e68a44ad8cd..4a3ecdaf9db7a4b091252cfb8c4d8e24a7e42ab7 100644 --- a/browserid/app.js +++ b/browserid/app.js @@ -54,7 +54,10 @@ secrets = require('./lib/secrets.js'), db = require('./lib/db.js'), configuration = require('../libs/configuration.js'), substitution = require('../libs/substitute.js'); -metrics = require("../libs/metrics.js"); +metrics = require("../libs/metrics.js"), +logger = require("../libs/logging.js").logger; + +logger.info("browserid server starting up"); // open the databse db.open(configuration.get('database')); @@ -147,7 +150,7 @@ function router(app) { }); app.get('/code_update', function(req, resp, next) { - console.log("code updated. shutting down."); + logger.warn("code updated. shutting down."); process.exit(); }); }; @@ -155,6 +158,16 @@ function router(app) { exports.varDir = VAR_DIR; exports.setup = function(server) { + // request to logger, dev formatted which omits personal data in the requests + server.use(express.logger({ + format: 'dev', + stream: { + write: function(x) { + logger.info(typeof x === 'string' ? x.trim() : x); + } + } + })); + // over SSL? var overSSL = (configuration.get('scheme') == 'https'); @@ -183,7 +196,7 @@ exports.setup = function(server) { try { cookieSessionMiddleware(req, resp, next); } catch(e) { - console.log("invalid cookie found: ignoring"); + logger.info("invalid cookie found: ignoring"); delete req.cookies[COOKIE_KEY]; cookieSessionMiddleware(req, resp, next); } diff --git a/browserid/lib/db.js b/browserid/lib/db.js index 7baab9a6e27577257ee7b21dfa05e69c05098698..9dada634a7cac8b1587e357b09fdac81d9336104 100644 --- a/browserid/lib/db.js +++ b/browserid/lib/db.js @@ -33,6 +33,8 @@ * * ***** END LICENSE BLOCK ***** */ +var logger = require('../../libs/logging.js').logger; + var driver; var ready = false; @@ -60,7 +62,7 @@ exports.open = function(cfg, cb) { if (error) { if (cb) cb(error); else { - console.log("ERROR:" + error); + logger.error(error); process.exit(1); } } else { diff --git a/browserid/lib/email.js b/browserid/lib/email.js index ffd06e13e919e1629aeb2e9d745ebb9184391914..726a4493f65574818886e9d9e8b02e5797827e3a 100644 --- a/browserid/lib/email.js +++ b/browserid/lib/email.js @@ -39,7 +39,8 @@ emailer = require('nodemailer'), fs = require('fs'), path = require('path'), mustache = require('mustache'), -config = require('../../libs/configuration.js'); +config = require('../../libs/configuration.js'), +logger = require('../../libs/logging.js').logger; const template = fs.readFileSync(path.join(__dirname, "prove_template.txt")).toString(); @@ -76,8 +77,8 @@ exports.sendVerificationEmail = function(email, site, secret) { body: mustache.to_html(template, { email: email, link: url, site: site }) }, function(err, success){ if(!success) { - console.log("error sending email: ", err); - console.log("verification URL: ", url); + logger.error("error sending email: " + err); + logger.error("verification URL: " + url); } }); }; diff --git a/browserid/lib/wsapi.js b/browserid/lib/wsapi.js index 9f69e0d2c5eccb3a3d9fed0a742cb7d5f88f0d1f..fe5033c6fd068f05ce05e51e0b179900e3bdbdce 100644 --- a/browserid/lib/wsapi.js +++ b/browserid/lib/wsapi.js @@ -43,7 +43,8 @@ db = require('./db.js'), url = require('url'), httputils = require('./httputils.js'); email = require('./email.js'), -bcrypt = require('bcrypt'); +bcrypt = require('bcrypt'), +logger = require('../../libs/logging.js').logger; function checkParams(params) { return function(req, resp, next) { @@ -61,7 +62,7 @@ function checkParams(params) { } }); } catch(e) { - console.log("error : " + e.toString()); + logger.error(e.toString()); return httputils.badRequest(resp, "missing '" + e + "' argument"); } next(); @@ -225,7 +226,7 @@ function setup(app) { db.removeEmail(req.session.authenticatedUser, email, function(error) { if (error) { - console.log("error removing email " + email); + logger.error("error removing email " + email); httputils.badRequest(resp, error.toString()); } else { resp.json(true); @@ -235,7 +236,7 @@ function setup(app) { app.post('/wsapi/account_cancel', checkAuthed, function(req, resp) { db.cancelAccount(req.session.authenticatedUser, function(error) { if (error) { - console.log("error cancelling account : " + error.toString()); + logger.error("error cancelling account : " + error.toString()); httputils.badRequest(resp, error.toString()); } else { resp.json(true); @@ -278,7 +279,7 @@ function setup(app) { app.get('/wsapi/prove_email_ownership', checkParams(["token"]), function(req, resp) { db.gotVerificationSecret(req.query.token, function(e) { if (e) { - console.log("error completing the verification: " + e); + logger.error("error completing the verification: " + e); resp.json(false); } else { resp.json(true); diff --git a/browserid/run.js b/browserid/run.js index e83192d2fdf67955d34cf8ddd0d03f0f9c01df39..b486602f039e52a7f6695c3c403fa3e746475d32 100755 --- a/browserid/run.js +++ b/browserid/run.js @@ -37,7 +37,8 @@ var path = require("path"), fs = require("fs"), -express = require("express"); +express = require("express"), +logger = require("../libs/logging.js").logger; const amMain = (process.argv[1] === __filename); diff --git a/libs/configuration.js b/libs/configuration.js index 84c179bb576e54c249c39986e2094b456db9cbef..33fa1b66fc60dc819a8a9df123004074509cd851 100644 --- a/libs/configuration.js +++ b/libs/configuration.js @@ -141,3 +141,7 @@ if (process.argv[1] == path.join(__dirname, "..", "browserid", "run.js")) { g_config['process_type'] = 'ephemeral'; } +// log the process_type +setTimeout(function() { + require("./logging.js").logger.info("process type is " + g_config["process_type"]); +}, 0); diff --git a/libs/logging.js b/libs/logging.js new file mode 100644 index 0000000000000000000000000000000000000000..68250d4b044f8dc556122bd6c6cc3ad4215d8aa8 --- /dev/null +++ b/libs/logging.js @@ -0,0 +1,78 @@ +/* ***** BEGIN LICENSE BLOCK ***** + * Version: MPL 1.1/GPL 2.0/LGPL 2.1 + * + * The contents of this file are subject to the Mozilla Public License Version + * 1.1 (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * http://www.mozilla.org/MPL/ + * + * Software distributed under the License is distributed on an "AS IS" basis, + * WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License + * for the specific language governing rights and limitations under the + * License. + * + * The Original Code is Mozilla BrowserID. + * + * The Initial Developer of the Original Code is Mozilla. + * Portions created by the Initial Developer are Copyright (C) 2011 + * the Initial Developer. All Rights Reserved. + * + * Contributor(s): + * Lloyd Hilaiel <lloyd@hilaiel.com> + * + * Alternatively, the contents of this file may be used under the terms of + * either the GNU General Public License Version 2 or later (the "GPL"), or + * the GNU Lesser General Public License Version 2.1 or later (the "LGPL"), + * in which case the provisions of the GPL or the LGPL are applicable instead + * of those above. If you wish to allow use of your version of this file only + * under the terms of either the GPL or the LGPL, and not to allow others to + * use your version of this file under the terms of the MPL, indicate your + * decision by deleting the provisions above and replace them with the notice + * and other provisions required by the GPL or the LGPL. If you do not delete + * the provisions above, a recipient may use your version of this file under + * the terms of any one of the MPL, the GPL or the LGPL. + * + * ***** END LICENSE BLOCK ***** */ + +/* + * A very thin wrapper around winston for general server logging. + * Exports a winston Logger instance in exports.logger with several functions + * corresponding to different log levels. use it like this: + * + * const logger = require('../libs/logging.js').logger; + * logger.debug("you can probably ignore this. just for debugging."); + * logger.info("something happened, here's info about it!"); + * logger.warn("this isn't good. it's not a fatal error, but needs attention"); + * logger.error("this isn't good at all. I will probably crash soon."); + */ + +const +winston = require("winston"), +configuration = require("./configuration"), +path = require('path'), +fs = require('fs'); + +// go through the configuration and determine log location +var log_path = configuration.get('log_path'); + +// simple inline function for creation of dirs +function mkdir_p(p) { + if (!path.existsSync(p)) { + mkdir_p(path.dirname(p)); + fs.mkdirSync(p, "0755"); + } +} + +mkdir_p(log_path); + +var filename = path.join(log_path, configuration.get('process_type') + ".log"); + +exports.logger = new (winston.Logger)({ + transports: [new (winston.transports.File)({ + filename: filename, + colorize: true + })] +}); + +exports.logger.emitErrs = false; + diff --git a/run.js b/run.js index d710da851074ff0fb3c2d308f8889e182520fe81..3290f0705c320e982d1bf7467926e87874298080 100755 --- a/run.js +++ b/run.js @@ -43,25 +43,19 @@ var sys = require("sys"), path = require("path"), fs = require("fs"), express = require("express"), -substitution = require('./libs/substitute.js'), -configuration = require('./libs/configuration.js'); +substitution = require('./libs/substitute.js'); + +// when running under the harness, let's also output log messages to the terminal +require('./libs/logging.js').logger.on('log', function(transport, level, msg, meta) { + console.log(level + ":", msg); +}); + +var configuration = require('./libs/configuration.js'); var PRIMARY_HOST = "127.0.0.1"; var boundServers = [ ]; -// -// this is the test harness, don't send emails, dump them to stdout -// -var nodemailer = require('nodemailer'); -nodemailer.EmailMessage.prototype.send = function(callback) { - this.prepareVariables(); - var headers = this.generateHeaders(), - body = this.generateBody(); - console.log(headers); - console.log(body); -}; - var subs = undefined; function substitutionMiddleware(req, resp, next) { if (!subs) { @@ -97,8 +91,6 @@ function substitutionMiddleware(req, resp, next) { function createServer(obj) { var app = express.createServer(); - app.use(express.logger()); - // this file is a *test* harness, to make it go, we'll insert a little // handler that substitutes output, changing production URLs to // developement URLs. @@ -180,3 +172,4 @@ dirs.forEach(function(dirObj) { boundServers.push(so); console.log(" " + dirObj.name + ": " + formatLink(so.server)); }); + diff --git a/verifier/.gitignore b/verifier/.gitignore deleted file mode 100644 index c4c53c804943031be0c755915d85c53e73beca7b..0000000000000000000000000000000000000000 --- a/verifier/.gitignore +++ /dev/null @@ -1 +0,0 @@ -/var diff --git a/verifier/app.js b/verifier/app.js index e2afb4fb2c7da528f182cae8eab00790c357c8e3..ee39f29aa4059496fb9d6a59cd780ee1fa66d5ff 100644 --- a/verifier/app.js +++ b/verifier/app.js @@ -40,7 +40,10 @@ const path = require('path'), idassertion = require('./lib/idassertion.js'), jwt = require('./lib/jwt.js'), express = require('express'); - metrics = require('../libs/metrics.js'); + metrics = require('../libs/metrics.js'), + logger = require('../libs/logging.js').logger; + +logger.info("verifier server starting up"); // create the var directory if it doesn't exist var VAR_DIR = path.join(__dirname, "var"); @@ -95,7 +98,8 @@ function doVerify(req, resp, next) { } ); } catch (e) { - console.log(e.stack); + // XXX: is this really a warning, or is it just informational + logger.warn(e.stack); metrics.report('verify', { result: 'failure', rp: audience @@ -107,13 +111,24 @@ function doVerify(req, resp, next) { exports.varDir = VAR_DIR; exports.setup = function(app) { + // request to logger, dev formatted which omits personal data in the requests + + app.use(express.logger({ + format: 'dev', + stream: { + write: function(x) { + logger.info(typeof x === 'string' ? x.trim() : x); + } + } + })); + app.use(express.bodyParser()); // code_update is an internal api that causes the node server to // shut down. This should never be externally accessible and // is used during the dead simple deployment procedure. app.get("/code_update", function (req, resp) { - console.log("code updated. shutting down."); + logger.warn("code updated. shutting down."); process.exit(); }); diff --git a/verifier/run.js b/verifier/run.js index 1ab4c936e1273f6f92016975af1f1283eff166ce..3c93845cef5995e116f6cf0e3937f0c835f124f3 100755 --- a/verifier/run.js +++ b/verifier/run.js @@ -45,9 +45,7 @@ var PRIMARY_PORT = 62800; var handler = require("./app.js"); -var app = express.createServer().use(express.logger({ - stream: fs.createWriteStream(path.join(handler.varDir, "server.log")) -})); +var app = express.createServer(); // let the specific server interact directly with the express server to register their middleware if (handler.setup) handler.setup(app);