From 13360430d95b7943a48e10856fb262ba165db633 Mon Sep 17 00:00:00 2001 From: jomo Date: Sun, 15 Mar 2015 01:57:19 +0100 Subject: [PATCH] join logs using `,` instead of `+ " " +` --- bin/www.js | 2 +- lib/cache.js | 10 +++++----- lib/cleaner.js | 4 ++-- lib/helpers.js | 42 +++++++++++++++++++++--------------------- lib/logging.js | 2 +- lib/networking.js | 10 +++++----- lib/renders.js | 10 +++++----- lib/skins.js | 4 ++-- routes/avatars.js | 16 ++++++++-------- routes/capes.js | 14 +++++++------- routes/renders.js | 22 +++++++++++----------- routes/skins.js | 14 +++++++------- server.js | 6 +++--- 13 files changed, 78 insertions(+), 78 deletions(-) diff --git a/bin/www.js b/bin/www.js index 69b1a77..3caaa26 100644 --- a/bin/www.js +++ b/bin/www.js @@ -5,7 +5,7 @@ var cluster = require("cluster"); if (cluster.isMaster) { var cores = config.clusters || require("os").cpus().length; - logging.log("Starting " + cores + " workers"); + logging.log("Starting", cores + " workers"); for (var i = 0; i < cores; i++) { cluster.fork(); } diff --git a/lib/cache.js b/lib/cache.js index cda3848..b796c3b 100644 --- a/lib/cache.js +++ b/lib/cache.js @@ -45,11 +45,11 @@ function update_file_date(rid, skin_hash) { var date = new Date(); fs.utimes(path, date, date, function(err){ if (err) { - logging.error(rid + "Error: " + err.stack); + logging.error(rid, "Error:", err.stack); } }); } else { - logging.error(rid + "tried to update " + path + " date, but it does not exist"); + logging.error(rid, "tried to update", path + " date, but it does not exist"); } }); } @@ -97,7 +97,7 @@ exp.info = function(callback) { // these 60 seconds match the duration of Mojang's rate limit ban // callback: error exp.update_timestamp = function(rid, userId, hash, temp, callback) { - logging.log(rid + "cache: updating timestamp"); + logging.log(rid, "cache: updating timestamp"); sub = temp ? (config.local_cache_time - 60) : 0; var time = new Date().getTime() - sub; // store userId in lower case if not null @@ -113,7 +113,7 @@ exp.update_timestamp = function(rid, userId, hash, temp, callback) { // this feature can be used to write both cape and skin at separate times // +callback+ contans error exp.save_hash = function(rid, userId, skin_hash, cape_hash, callback) { - logging.log(rid + "cache: saving skin:" + skin_hash + " cape:" + cape_hash); + logging.log(rid, "cache: saving skin:" + skin_hash + " cape:" + cape_hash); var time = new Date().getTime(); // store shorter null byte instead of "null" skin_hash = (skin_hash === null ? "" : skin_hash); @@ -137,7 +137,7 @@ exp.save_hash = function(rid, userId, skin_hash, cape_hash, callback) { // removes the hash for +userId+ from the cache exp.remove_hash = function(rid, userId) { - logging.log(rid + "cache: deleting hash"); + logging.log(rid, "cache: deleting hash"); redis.del(userId.toLowerCase(), "h", "t"); }; diff --git a/lib/cleaner.js b/lib/cleaner.js index f8e190e..117daf1 100644 --- a/lib/cleaner.js +++ b/lib/cleaner.js @@ -18,7 +18,7 @@ function should_clean_redis(callback) { //logging.debug(info.toString()); logging.debug("used mem:" + info.used_memory); var used = parseInt(info.used_memory) / 1024; - logging.log("RedisCleaner: " + used + "KB used"); + logging.log("RedisCleaner:", used + "KB used"); callback(err, used >= config.cleaning_redis_limit); } catch(e) { callback(e, false); @@ -40,7 +40,7 @@ function should_clean_disk(callback) { callback(err, false); } else { var available = response[0].available; - logging.log("DiskCleaner: " + available + "KB available"); + logging.log("DiskCleaner:", available + "KB available"); callback(err, available < config.cleaning_disk_limit); } }); diff --git a/lib/helpers.js b/lib/helpers.js index 67f3ed5..118d06d 100644 --- a/lib/helpers.js +++ b/lib/helpers.js @@ -28,12 +28,12 @@ function store_skin(rid, userId, profile, cache_details, callback) { callback(err, skin_hash); }); } else { - logging.log(rid + "new skin hash: " + skin_hash); + logging.log(rid, "new skin hash:", skin_hash); var facepath = __dirname + "/../" + config.faces_dir + skin_hash + ".png"; var helmpath = __dirname + "/../" + config.helms_dir + skin_hash + ".png"; fs.exists(facepath, function(exists) { if (exists) { - logging.log(rid + "skin already exists, not downloading"); + logging.log(rid, "skin already exists, not downloading"); callback(null, skin_hash); } else { networking.get_from(rid, url, function(img, response, err1) { @@ -42,13 +42,13 @@ function store_skin(rid, userId, profile, cache_details, callback) { } else { skins.extract_face(img, facepath, function(err2) { if (err2) { - logging.error(rid + err2.stack); + logging.error(rid, err2.stack); callback(err2, null); } else { - logging.debug(rid + "face extracted"); + logging.debug(rid, "face extracted"); skins.extract_helm(rid, facepath, img, helmpath, function(err3) { - logging.debug(rid + "helm extracted"); - logging.debug(rid + helmpath); + logging.debug(rid, "helm extracted"); + logging.debug(rid, helmpath); callback(err3, skin_hash); }); } @@ -77,20 +77,20 @@ function store_cape(rid, userId, profile, cache_details, callback) { callback(err, cape_hash); }); } else { - logging.log(rid + "new cape hash: " + cape_hash); + logging.log(rid, "new cape hash:", cape_hash); var capepath = __dirname + "/../" + config.capes_dir + cape_hash + ".png"; fs.exists(capepath, function(exists) { if (exists) { - logging.log(rid + "cape already exists, not downloading"); + logging.log(rid, "cape already exists, not downloading"); callback(null, cape_hash); } else { networking.get_from(rid, url, function(img, response, err) { if (err || !img) { - logging.error(rid + err.stack); + logging.error(rid, err.stack); callback(err, null); } else { skins.save_image(img, capepath, function(err) { - logging.debug(rid + "cape saved"); + logging.debug(rid, "cape saved"); callback(err, cape_hash); }); } @@ -116,7 +116,7 @@ function callback_for(userId, type, err, hash) { req_count++; if (req_count !== 1) { // otherwise this would show up on single/first requests, too - logging.debug(current.rid + "queued " + type + " request continued"); + logging.debug(current.rid, "queued", type + " request continued"); } currently_running.splice(i, 1); // remove from array current.callback(err, hash); @@ -124,7 +124,7 @@ function callback_for(userId, type, err, hash) { } } if (req_count > 1) { - logging.debug(req_count + " simultaneous requests for " + userId); + logging.debug(req_count + " simultaneous requests for", userId); } } @@ -194,7 +194,7 @@ function store_images(rid, userId, cache_details, type, callback) { } }); } else { - logging.log(rid + "ID already being processed, adding to queue"); + logging.log(rid, "ID already being processed, adding to queue"); currently_running.push(new_hash); } } @@ -223,14 +223,14 @@ exp.get_image_hash = function(rid, userId, type, callback) { } else { if (cache_details && cache_details[type] !== undefined && cache_details.time + config.local_cache_time * 1000 >= new Date().getTime()) { // use cached image - logging.log(rid + "userId cached & recently updated"); + logging.log(rid, "userId cached & recently updated"); callback(null, (cached_hash ? 1 : 0), cached_hash); } else { // download image if (cache_details) { - logging.log(rid + "userId cached, but too old"); + logging.log(rid, "userId cached, but too old"); } else { - logging.log(rid + "userId not cached"); + logging.log(rid, "userId not cached"); } store_images(rid, userId, cache_details, type, function(err, new_hash) { if (err) { @@ -241,8 +241,8 @@ exp.get_image_hash = function(rid, userId, type, callback) { }); } else { var status = cache_details && (cached_hash === new_hash) ? 3 : 2; - logging.debug(rid + "cached hash: " + (cache_details && cached_hash)); - logging.log(rid + "new hash: " + new_hash); + logging.debug(rid, "cached hash:", (cache_details && cached_hash)); + logging.log(rid, "new hash:", new_hash); callback(null, status, new_hash); } }); @@ -288,7 +288,7 @@ exp.get_skin = function(rid, userId, callback) { var skinpath = __dirname + "/../" + config.skins_dir + skin_hash + ".png"; fs.exists(skinpath, function(exists) { if (exists) { - logging.log(rid + "skin already exists, not downloading"); + logging.log(rid, "skin already exists, not downloading"); skins.open_skin(rid, skinpath, function(err, img) { callback(err, skin_hash, img); }); @@ -337,7 +337,7 @@ exp.get_render = function(rid, userId, scale, helm, body, callback) { } else { fs.writeFile(renderpath, img, "binary", function(err) { if (err) { - logging.error(rid + err.stack); + logging.error(rid, err.stack); } callback(null, 2, skin_hash, img); }); @@ -359,7 +359,7 @@ exp.get_cape = function(rid, userId, callback) { var capepath = __dirname + "/../" + config.capes_dir + cape_hash + ".png"; fs.exists(capepath, function(exists) { if (exists) { - logging.log(rid + "cape already exists, not downloading"); + logging.log(rid, "cape already exists, not downloading"); skins.open_skin(rid, capepath, function(err, img) { callback(err, cape_hash, img); }); diff --git a/lib/logging.js b/lib/logging.js index f49fc9b..2c9ec56 100644 --- a/lib/logging.js +++ b/lib/logging.js @@ -21,7 +21,7 @@ function log(level, args, logger) { var clid = (cluster.worker && cluster.worker.id || "M"); var lines = join_args(args).split("\n"); for (var i = 0, l = lines.length; i < l; i++) { - logger(time + clid + " " + level + ": " + lines[i]); + logger(time + clid, level + ":", lines[i]); } } diff --git a/lib/networking.js b/lib/networking.js index 9aacb9b..1e87c1d 100644 --- a/lib/networking.js +++ b/lib/networking.js @@ -62,7 +62,7 @@ exp.get_from_options = function(rid, url, options, callback) { logging.error(url, error); } else { var logfunc = code && code < 405 ? logging.log : logging.warn; - logfunc(rid + url + " " + code + " " + http_code[code]); + logfunc(rid, url, code, http_code[code]); } // 200 or 301 depending on content type @@ -79,8 +79,8 @@ exp.get_from_options = function(rid, url, options, callback) { // cause error so the image will not be cached callback(body || null, response, (error || "TooManyRequests")); } else { - logging.error(rid + " Unknown reply:"); - logging.error(rid + JSON.stringify(response)); + logging.error(rid, " Unknown reply:"); + logging.error(rid, JSON.stringify(response)); callback(body || null, response, error); } }); @@ -169,12 +169,12 @@ exp.save_texture = function(rid, tex_hash, outpath, callback) { var textureurl = textures_url + tex_hash; exp.get_from(rid, textureurl, function(img, response, err) { if (err) { - logging.error(rid + "error while downloading texture"); + logging.error(rid, "error while downloading texture"); callback(err, response, null); } else { fs.writeFile(outpath, img, "binary", function(err) { if (err) { - logging.error(rid + "error: " + err.stack); + logging.error(rid, "error:", err.stack); } callback(err, response, img); }); diff --git a/lib/renders.js b/lib/renders.js index d518110..45b1044 100644 --- a/lib/renders.js +++ b/lib/renders.js @@ -43,7 +43,7 @@ exp.draw_head = function(skin_canvas, model_ctx, scale) { // parts are labeled as if drawn from the skin's POV exp.draw_body = function(rid, skin_canvas, model_ctx, scale) { if (skin_canvas.height === 32 * scale) { - logging.debug(rid + "uses old skin format"); + logging.debug(rid, "uses old skin format"); //Left Leg //Left Leg - Front model_ctx.setTransform(1,-0.5,0,1.2,0,0); @@ -84,7 +84,7 @@ exp.draw_body = function(rid, skin_canvas, model_ctx, scale) { model_ctx.scale(-1,1); model_ctx.drawImage(skin_canvas, 44*scale, 16*scale, 4*scale, 4*scale, -16*scale, 16*scale, 4*scale, 4*scale); } else { - logging.debug(rid + "uses new skin format"); + logging.debug(rid, "uses new skin format"); //Left Leg //Left Leg - Front model_ctx.setTransform(1,-0.5,0,1.2,0,0); @@ -133,7 +133,7 @@ exp.draw_model = function(rid, img, scale, helm, body, callback) { var image = new Image(); image.onerror = function(err) { - logging.error(rid + "render error: " + err.stack); + logging.error(rid, "render error:", err.stack); callback(err, null); }; @@ -159,7 +159,7 @@ exp.draw_model = function(rid, img, scale, helm, body, callback) { model_canvas.toBuffer(function(err, buf){ if (err) { - logging.error(rid + "error creating buffer: " + err); + logging.error(rid, "error creating buffer:", err); } callback(err, buf); }); @@ -173,7 +173,7 @@ exp.draw_model = function(rid, img, scale, helm, body, callback) { exp.open_render = function(rid, renderpath, callback) { fs.readFile(renderpath, function (err, buf) { if (err) { - logging.error(rid + "error while opening skin file: " + err); + logging.error(rid, "error while opening skin file:", err); } callback(err, buf); }); diff --git a/lib/skins.js b/lib/skins.js index da9a85d..a7dcf38 100644 --- a/lib/skins.js +++ b/lib/skins.js @@ -53,7 +53,7 @@ exp.extract_helm = function(rid, facefile, buffer, outname, callback) { callback(err); }); } else { - logging.log(rid + "helm img == face img, not storing!"); + logging.log(rid, "helm img == face img, not storing!"); callback(null); } }); @@ -109,7 +109,7 @@ exp.default_skin = function(uuid) { exp.open_skin = function(rid, skinpath, callback) { fs.readFile(skinpath, function(err, buf) { if (err) { - logging.error(rid + "error while opening skin file: " + err); + logging.error(rid, "error while opening skin file:", err); callback(err, null); } else { callback(null, buf); diff --git a/routes/avatars.js b/routes/avatars.js index ce492b4..16d6b4e 100644 --- a/routes/avatars.js +++ b/routes/avatars.js @@ -43,14 +43,14 @@ module.exports = function(req, res) { // strip dashes userId = userId.replace(/-/g, ""); - logging.log(rid + "userid: " + userId); + logging.log(rid, "userid:", userId); try { helpers.get_avatar(rid, userId, helm, size, function(err, status, image, hash) { - logging.log(rid + "storage type: " + human_status[status]); + logging.log(rid, "storage type:", human_status[status]); if (err) { - logging.error(rid + err); + logging.error(rid, err); if (err.code === "ENOENT") { // no such file cache.remove_hash(rid, userId); @@ -65,21 +65,21 @@ module.exports = function(req, res) { } else if (err) { http_status = 503; } - logging.debug(rid + "etag: " + req.headers["if-none-match"]); - logging.debug(rid + "matches: " + matches); + logging.debug(rid, "etag:", req.headers["if-none-match"]); + logging.debug(rid, "matches:", matches); sendimage(rid, http_status, status, image); } else { handle_default(rid, 404, status, userId); } }); } catch(e) { - logging.error(rid + "error: " + e.stack); + logging.error(rid, "error:", e.stack); handle_default(rid, 500, -1, userId); } function handle_default(rid, http_status, img_status, userId) { if (def && def !== "steve" && def !== "alex") { - logging.log(rid + "status: 301"); + logging.log(rid, "status: 301"); res.writeHead(301, { "Cache-Control": "max-age=" + config.browser_cache_time + ", public", "Response-Time": new Date() - start, @@ -98,7 +98,7 @@ module.exports = function(req, res) { } function sendimage(rid, http_status, img_status, image) { - logging.log(rid + "status: " + http_status); + logging.log(rid, "status:", http_status); res.writeHead(http_status, { "Content-Type": "image/png", "Cache-Control": "max-age=" + config.browser_cache_time + ", public", diff --git a/routes/capes.js b/routes/capes.js index 3f2f0f8..94008fd 100644 --- a/routes/capes.js +++ b/routes/capes.js @@ -29,13 +29,13 @@ module.exports = function(req, res) { // strip dashes userId = userId.replace(/-/g, ""); - logging.log(rid + "userid: " + userId); + logging.log(rid, "userid:", userId); try { helpers.get_cape(rid, userId, function(err, status, image, hash) { - logging.log(rid + "storage type: " + human_status[status]); + logging.log(rid, "storage type:", human_status[status]); if (err) { - logging.error(rid + err); + logging.error(rid, err); if (err.code === "ENOENT") { // no such file cache.remove_hash(rid, userId); @@ -50,9 +50,9 @@ module.exports = function(req, res) { } else if (err) { http_status = 503; } - logging.debug(rid + "etag: " + req.headers["if-none-match"]); - logging.debug(rid + "matches: " + matches); - logging.log(rid + "status: " + http_status); + logging.debug(rid, "etag:", req.headers["if-none-match"]); + logging.debug(rid, "matches:", matches); + logging.log(rid, "status:", http_status); sendimage(rid, http_status, status, image); } else { res.writeHead(404, { @@ -63,7 +63,7 @@ module.exports = function(req, res) { } }); } catch(e) { - logging.error(rid + "error:" + e.stack); + logging.error(rid, "error:" + e.stack); res.writeHead(500, { "Content-Type": "text/plain", "Response-Time": new Date() - start diff --git a/routes/renders.js b/routes/renders.js index 3d0d1ee..51b1ade 100644 --- a/routes/renders.js +++ b/routes/renders.js @@ -59,13 +59,13 @@ module.exports = function(req, res) { // strip dashes userId = userId.replace(/-/g, ""); - logging.log(rid + "userId: " + userId); + logging.log(rid, "userId:", userId); try { helpers.get_render(rid, userId, scale, helm, body, function(err, status, hash, image) { - logging.log(rid + "storage type: " + human_status[status]); + logging.log(rid, "storage type:", human_status[status]); if (err) { - logging.error(rid + err); + logging.error(rid, err); if (err.code === "ENOENT") { // no such file cache.remove_hash(rid, userId); @@ -80,16 +80,16 @@ module.exports = function(req, res) { } else if (err) { http_status = 503; } - logging.debug(rid + "etag: " + req.headers["if-none-match"]); - logging.debug(rid + "matches: " + matches); + logging.debug(rid, "etag:", req.headers["if-none-match"]); + logging.debug(rid, "matches:", matches); sendimage(rid, http_status, status, image); } else { - logging.log(rid + "image not found, using default."); + logging.log(rid, "image not found, using default."); handle_default(rid, 404, status, userId); } }); } catch(e) { - logging.error(rid + "error: " + e.stack); + logging.error(rid, "error:", e.stack); handle_default(rid, 500, -1, userId); } @@ -98,7 +98,7 @@ module.exports = function(req, res) { // custom images will not be function handle_default(rid, http_status, img_status, userId) { if (def && def !== "steve" && def !== "alex") { - logging.log(rid + "status: 301"); + logging.log(rid, "status: 301"); res.writeHead(301, { "Cache-Control": "max-age=" + config.browser_cache_time + ", public", "Response-Time": new Date() - start, @@ -113,12 +113,12 @@ module.exports = function(req, res) { fs.readFile("public/images/" + def + "_skin.png", function (err, buf) { if (err) { // errored while loading the default image, continuing with null image - logging.error(rid + "error loading default render image: " + err); + logging.error(rid, "error loading default render image:", err); } // we render the default skins, but not custom images renders.draw_model(rid, buf, scale, helm, body, function(err, def_img) { if (err) { - logging.error(rid + "error while rendering default image: " + err); + logging.error(rid, "error while rendering default image:", err); } sendimage(rid, http_status, img_status, def_img); }); @@ -127,7 +127,7 @@ module.exports = function(req, res) { } function sendimage(rid, http_status, img_status, image) { - logging.log(rid + "status: " + http_status); + logging.log(rid, "status:", http_status); res.writeHead(http_status, { "Content-Type": "image/png", "Cache-Control": "max-age=" + config.browser_cache_time + ", public", diff --git a/routes/skins.js b/routes/skins.js index f2b65b5..3a8da64 100644 --- a/routes/skins.js +++ b/routes/skins.js @@ -23,12 +23,12 @@ module.exports = function(req, res) { // strip dashes userId = userId.replace(/-/g, ""); - logging.log(rid + "userid: " + userId); + logging.log(rid, "userid:", userId); try { helpers.get_skin(rid, userId, function(err, hash, image) { if (err) { - logging.error(rid + err); + logging.error(rid, err); } etag = hash && hash.substr(0, 32) || "none"; var matches = req.headers["if-none-match"] === '"' + etag + '"'; @@ -39,21 +39,21 @@ module.exports = function(req, res) { } else if (err) { http_status = 503; } - logging.debug(rid + "etag: " + req.headers["if-none-match"]); - logging.debug(rid + "matches: " + matches); + logging.debug(rid, "etag:", req.headers["if-none-match"]); + logging.debug(rid, "matches:", matches); sendimage(rid, http_status, image); } else { handle_default(rid, 404, userId); } }); } catch(e) { - logging.error(rid + "error: " + e.stack); + logging.error(rid, "error:", e.stack); handle_default(rid, 500, userId); } function handle_default(rid, http_status, userId) { if (def && def !== "steve" && def !== "alex") { - logging.log(rid + "status: 301"); + logging.log(rid, "status: 301"); res.writeHead(301, { "Cache-Control": "max-age=" + config.browser_cache_time + ", public", "Response-Time": new Date() - start, @@ -74,7 +74,7 @@ module.exports = function(req, res) { } function sendimage(rid, http_status, image) { - logging.log(rid + "status: " + http_status); + logging.log(rid, "status:", http_status); res.writeHead(http_status, { "Content-Type": "image/png", "Cache-Control": "max-age=" + config.browser_cache_time + ", public", diff --git a/server.js b/server.js index 34934a7..9737f1a 100644 --- a/server.js +++ b/server.js @@ -45,10 +45,10 @@ function requestHandler(req, res) { request.url.path_list = path_list; // generate 12 character random string - request.id = Math.random().toString(36).substring(2,14) + " "; + request.id = Math.random().toString(36).substring(2,14); var local_path = request.url.path_list[1]; - logging.log(request.id + request.method + " " + request.url.href); + logging.log(request.id + request.method, request.url.href); if (request.method === "GET" || request.method === "HEAD") { try { switch (local_path) { @@ -72,7 +72,7 @@ function requestHandler(req, res) { } } catch(e) { var error = JSON.stringify(req.headers) + "\n" + e.stack; - logging.error(request.id + "Error: " + error); + logging.error(request.id + "Error:", error); res.writeHead(500, { "Content-Type": "text/plain" });