From 98df4ecf619e5a400c49e4430a318c180bbb820c Mon Sep 17 00:00:00 2001 From: Ian Bicking Date: Tue, 23 May 2017 13:49:32 -0500 Subject: [PATCH] Fix #2177, change console.* server messages to use mozlog (#2858) --- server/src/jobs.js | 2 +- server/src/pages/leave-screenshots/server.js | 3 +- server/src/pages/metrics/server.js | 7 ++-- server/src/pages/shotindex/server.js | 3 +- server/src/responses.js | 3 +- server/src/server.js | 35 ++++++++++---------- server/src/servershot.js | 4 +-- 7 files changed, 31 insertions(+), 26 deletions(-) diff --git a/server/src/jobs.js b/server/src/jobs.js index a5dd472f8b..f8d3fc0e46 100644 --- a/server/src/jobs.js +++ b/server/src/jobs.js @@ -9,7 +9,7 @@ let checkDeletedInterval = config.checkDeletedInterval * 1000; exports.start = function() { if (config.disableControllerTasks) { - console.info("Note: not performing periodic tasks in this server"); + mozlog.info("no-periodic-tasks", {msg: "Note: not performing periodic tasks in this server"}); return; } diff --git a/server/src/pages/leave-screenshots/server.js b/server/src/pages/leave-screenshots/server.js index 75dd8dd7f6..8cf071413e 100644 --- a/server/src/pages/leave-screenshots/server.js +++ b/server/src/pages/leave-screenshots/server.js @@ -2,6 +2,7 @@ const express = require("express"); const csrf = require('csurf'); const reactrender = require("../../reactrender"); const { Shot } = require("../../servershot"); +const mozlog = require("mozlog")("leave-screenshots"); const csrfProtection = csrf({cookie: true}); let app = express(); @@ -24,7 +25,7 @@ app.post("/leave", csrfProtection, function(req, res) { Shot.deleteEverythingForDevice(req.backend, req.deviceId).then(() => { res.redirect("/leave-screenshots/?complete"); }).catch((e) => { - console.error("An error occurred trying to delete:", e); + mozlog.error("delete-account-error", {msg: "An error occurred trying to delete account", error: e}); res.status(500).send("An error occurred"); }); }); diff --git a/server/src/pages/metrics/server.js b/server/src/pages/metrics/server.js index 6267043dd2..85b13fe014 100644 --- a/server/src/pages/metrics/server.js +++ b/server/src/pages/metrics/server.js @@ -3,6 +3,7 @@ const reactrender = require("../../reactrender"); const { checkLastStoreQueriesTime, storeQueries } = require("./model"); const config = require("../../config").getProperties(); const { captureRavenException } = require("../../ravenclient"); +const mozlog = require("mozlog")("metrics"); let app = exports.app = express(); @@ -20,11 +21,11 @@ function safeStoreQueries() { checkLastStoreQueriesTime().then((time) => { if ((!time) || Date.now() - time.getTime() > config.refreshMetricsTime * 1000) { return storeQueries().then(() => { - console.info("Updated metrics"); + mozlog.info("updated-metrics", {msg: "Updated metrics"}); }); } }).catch((error) => { - console.error("Error running metrics queries:", error); + mozlog.error("metrics-update-error", {msg: "Error running metrics queries", error}); captureRavenException(error); }); } @@ -37,7 +38,7 @@ if (config.refreshMetricsTime && !config.disableControllerTasks) { } setInterval(safeStoreQueries, interval); } else { - console.info("Not running periodic metrics updating"); + mozlog.info("no-periodic-metrics", {msg: "Not running periodic metrics updating"}); } if (!config.disableControllerTasks) { diff --git a/server/src/pages/shotindex/server.js b/server/src/pages/shotindex/server.js index f82741dbdf..a4e8f739ed 100644 --- a/server/src/pages/shotindex/server.js +++ b/server/src/pages/shotindex/server.js @@ -2,6 +2,7 @@ const express = require("express"); const csrf = require("csurf"); const reactrender = require("../../reactrender"); const { Shot } = require("../../servershot"); +const mozlog = require("mozlog")("shotindex"); let app = express(); @@ -20,7 +21,7 @@ app.get("/", csrf({cookie: true}), function(req, res) { getShots.then(_render) .catch((err) => { res.type("txt").status(500).send("Error rendering page: " + err); - console.error("Error rendering page:", err); + mozlog.error("error-rendering", {msg: "Error rendering page", error: err}); }); function _render(shots) { diff --git a/server/src/responses.js b/server/src/responses.js index 06e9bdb49b..079bc1963e 100644 --- a/server/src/responses.js +++ b/server/src/responses.js @@ -1,5 +1,6 @@ const config = require("./config").getProperties(); const { captureRavenException } = require("./ravenclient"); +const mozlog = require("mozlog")("server"); exports.simpleResponse = function(res, message, status) { status = status || 200; @@ -27,6 +28,6 @@ exports.errorResponse = function(res, message, err) { } else { res.send("Server error"); } - console.error(`Error: ${message}`, err + "", err); + mozlog.error("generic-error-response", {msg: message, error: err}); captureRavenException(err); }; diff --git a/server/src/server.js b/server/src/server.js index c1351f403f..bc463ddc01 100644 --- a/server/src/server.js +++ b/server/src/server.js @@ -42,6 +42,7 @@ console.info = logFactory("info"); console.warn = logFactory("warn"); console.error = logFactory("error"); +const mozlog = require("mozlog")("server"); const path = require('path'); const { readFileSync, existsSync } = require('fs'); const Cookies = require("cookies"); @@ -101,17 +102,17 @@ if (config.useS3) { // Test a PUT to s3 because configuring this requires using the aws web interface // If the permissions are not set up correctly, then we want to know that asap var s3bucket = new AWS.S3({params: {Bucket: config.s3BucketName}}); - console.info(new Date(), `creating ${config.s3BucketName}`); + mozlog.info("creating-s3-bucket", {msg: `creating ${config.s3BucketName}`, bucketName: config.s3BucketName}); // createBucket is a horribly named api; it creates a local object to access // an existing bucket s3bucket.createBucket(function() { var params = {Key: 'test', Body: 'Hello!'}; - s3bucket.upload(params, function(err, data) { - if (err) { - console.warn("Error uploading data during test: ", err); + s3bucket.upload(params, function(error, data) { + if (error) { + mozlog.warn("test-upload-error", {msg: "Error uploading data during test", error, bucketName: config.s3BucketName}); } else { - console.info(`Successfully uploaded data to ${config.s3BucketName}/test`); + mozlog.info("test-upload-success", {msg: `Successfully uploaded data to ${config.s3BucketName}/test`, bucketName: config.s3BucketName}) } }); }); @@ -126,16 +127,16 @@ function initDatabase() { }, (e) => { hadError = true; - console.error("Error forcing database version:", forceDbVersion, e); + mozlog.error("database-version-update-error", {msg: "Error forcing database version:", dbVersion: forceDbVersion, error: e}); }).then(() => { - console.info("Exiting after downgrade"); + mozlog.info("database-version-update-exit", {msg: "Exiting after downgrade"}); process.exit(hadError ? 2 : 0); }); return; } let promise; if (config.disableControllerTasks) { - console.info("Note: this server will not perform database initialization"); + mozlog.info("database-version-update-skipped", {msg: "Note: this server will not perform database initialization"}); promise = dbschema.createKeygrip(); } else { promise = dbschema.createTables().then(() => { @@ -145,7 +146,7 @@ function initDatabase() { }); } promise.catch((e) => { - console.error("Error initializing database:", e, e.stack); + mozlog.error("database-version-update-error", {msg: "Error initializing database:", error: e, stack: e.stack}); captureRavenException(e); // Give Raven/etc a chance to work before exit: setTimeout(() => { @@ -424,7 +425,7 @@ app.post("/error", function(req, res) { applicationVersion: bodyObj.version, exceptionDescription: desc }).send(); - console.info("Error received:", desc); + mozlog.info("remote-error", {msg: "Error received:", description: desc}); simpleResponse(res, "OK", 200); }); @@ -510,7 +511,7 @@ app.get("/redirect", function(req, res) { res.status(200); let redirectUrl = req.query.to; if (!validUrl.isUri(redirectUrl)) { - console_mozlog.warn("redirect-bad-url", {msg: "Redirect attempted to invalid URL", url: redirectUrl}); + mozlog.warn("redirect-bad-url", {msg: "Redirect attempted to invalid URL", url: redirectUrl}); sendRavenMessage(req, "Redirect attempted to invalid URL", {extra: {redirectUrl}}); simpleResponse(res, "Bad Request", 400); return; @@ -529,7 +530,7 @@ window.location = ${redirectUrlJs}; `; res.send(output); } else { - console_mozlog.warn("no-redirect-to", {"msg": "Bad Request, no ?to parameter"}); + mozlog.warn("no-redirect-to", {"msg": "Bad Request, no ?to parameter"}); sendRavenMessage(req, "Bad request, no ?to parameter"); simpleResponse(res, "Bad Request", 400); } @@ -539,7 +540,7 @@ app.post("/api/register", function(req, res) { let vars = req.body; let canUpdate = vars.deviceId === req.deviceId; if (!vars.deviceId) { - console.error("Bad register request:", JSON.stringify(vars, null, " ")); + mozlog.error("bad-api-register", {msg: "Bad register request", vars: JSON.stringify(vars, null, " ")}); sendRavenMessage(req, "Attempted to register without deviceId"); simpleResponse(res, "Bad request, no deviceId", 400); return; @@ -646,7 +647,7 @@ app.put("/data/:id/:domain", function(req, res) { let slowResponse = config.testing.slowResponse; let failSometimes = config.testing.failSometimes; if (failSometimes && Math.floor(Math.random() * failSometimes)) { - console.info("Artificially making request fail"); + console.log("Artificially making request fail"); // eslint-disable-line no-console res.status(500); res.end(); return; @@ -657,7 +658,7 @@ app.put("/data/:id/:domain", function(req, res) { } let shotId = `${req.params.id}/${req.params.domain}`; if (!req.deviceId) { - console.warn("Attempted to PUT without logging in", req.url); + mozlog.warn("put-without-auth", {msg: "Attempted to PUT without logging in", url: req.url}); sendRavenMessage(req, "Attempt PUT without authentication"); simpleResponse(res, "Not logged in", 401); return; @@ -1110,9 +1111,9 @@ linker.init().then(() => { scheme = "http"; } server.listen(config.port); - console.info(`server listening on ${scheme}://localhost:${config.port}/`); + mozlog.info("server-started", {msg: `server listening on ${scheme}://localhost:${config.port}/`}); }).catch((err) => { - console.error("Error getting git revision:", err, err.stack); + mozlog.error("git-revision-error", {msg: "Error getting git revision", error: err, stack: err.stack}); }); require("./jobs").start(); diff --git a/server/src/servershot.js b/server/src/servershot.js index ae6b2cb51b..d77656be18 100644 --- a/server/src/servershot.js +++ b/server/src/servershot.js @@ -339,10 +339,10 @@ class ServerClip extends AbstractShot.prototype.Clip { let match = (/^data:([^;]*);base64,/).exec(url); if (!match) { if (!url) { - console.warn("Submitted with empty clip URL"); + mozlog.warn("empty-clip-url", {msg: "Submitted with empty clip URL"}); throw new Error("Empty clip URL"); } else { - console.warn("Submitted with bad clip URL:", url.substr(0, 10) + "..."); + mozlog.warn("bad-clip-url", {msg: "Submitted with bad clip URL", urlPrefix: url.substr(0, 10) + "..."}); throw new Error("Bad clip URL"); } }