Make a vast majority of logs debug, make it so that essential info is in one line

lib/helpers.js

@@ -29,13 +29,13 @@ function store_skin(rid, userId, profile, cache_details, callback) {
           callback(cache_err, skin_hash);
         });
       } else {
-        logging.log(rid, "new skin hash:", skin_hash);
+        logging.debug(rid, "new skin hash:", skin_hash);
         var facepath = path.join(__dirname, "..", config.directories.faces, skin_hash + ".png");
         var helmpath = path.join(__dirname, "..", config.directories.helms, skin_hash + ".png");
         var skinpath = path.join(__dirname, "..", config.directories.skins, skin_hash + ".png");
         fs.exists(facepath, function(exists) {
           if (exists) {
-            logging.log(rid, "skin already exists, not downloading");
+            logging.debug(rid, "skin already exists, not downloading");
             callback(null, skin_hash);
           } else {
             networking.get_from(rid, url, function(img, response, err1) {
@@ -86,11 +86,11 @@ function store_cape(rid, userId, profile, cache_details, callback) {
           callback(cache_err, cape_hash);
         });
       } else {
-        logging.log(rid, "new cape hash:", cape_hash);
+        logging.debug(rid, "new cape hash:", cape_hash);
         var capepath = path.join(__dirname, "..", config.directories.capes, cape_hash + ".png");
         fs.exists(capepath, function(exists) {
           if (exists) {
-            logging.log(rid, "cape already exists, not downloading");
+            logging.debug(rid, "cape already exists, not downloading");
             callback(null, cape_hash);
           } else {
             networking.get_from(rid, url, function(img, response, net_err) {
@@ -225,14 +225,14 @@ exp.get_image_hash = function(rid, userId, type, callback) {
     } else {
       if (cache_details && cache_details[type] !== undefined && cache_details.time + config.caching.local * 1000 >= Date.now()) {
         // use cached image
-        logging.log(rid, "userId cached & recently updated");
+        logging.debug(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.debug(rid, "userId cached, but too old");
         } else {
-          logging.log(rid, "userId not cached");
+          logging.debug(rid, "userId not cached");
         }
         store_images(rid, userId, cache_details, type, function(store_err, new_hash) {
           if (store_err) {
@@ -244,7 +244,7 @@ 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, "new hash:", new_hash);
             callback(null, status, new_hash);
           }
         });
@@ -291,7 +291,7 @@ exp.get_skin = function(rid, userId, callback) {
       var skinpath = path.join(__dirname, "..", config.directories.skins, skin_hash + ".png");
       fs.exists(skinpath, function(exists) {
         if (exists) {
-          logging.log(rid, "skin already exists, not downloading");
+          logging.debug(rid, "skin already exists, not downloading");
           skins.open_skin(rid, skinpath, function(skin_err, img) {
             callback(skin_err || err, skin_hash, status, img);
           });
@@ -365,7 +365,7 @@ exp.get_cape = function(rid, userId, callback) {
     var capepath = path.join(__dirname, "..", config.directories.capes, cape_hash + ".png");
     fs.exists(capepath, function(exists) {
       if (exists) {
-        logging.log(rid, "cape already exists, not downloading");
+        logging.debug(rid, "cape already exists, not downloading");
         skins.open_skin(rid, capepath, function(skin_err, img) {
           callback(skin_err || err, cape_hash, status, img);
         });

lib/networking.js

@@ -76,7 +76,7 @@ exp.get_from_options = function(rid, url, options, callback) {
     if (error) {
       logging.error(rid, url, error);
     } else {
-      var logfunc = code && code < 405 ? logging.log : logging.warn;
+      var logfunc = code && code < 405 ? logging.debug : logging.warn;
       logfunc(rid, url, code, http_code[code]);
     }
 

lib/response.js

@@ -29,7 +29,7 @@ module.exports = function(request, response, result) {
   });
 
   response.on("finish", function() {
-    logging.log(request.id, response.statusCode, headers["Response-Time"] + "ms", "(" + (human_status[result.status] || "-") + ")");
+    logging.log(request.method, request.url.href, request.id, response.statusCode, headers["Response-Time"] + "ms", "(" + (human_status[result.status] || "-") + ")");
   });
 
   response.on("error", function(err) {

lib/routes/renders.js

@@ -112,7 +112,7 @@ module.exports = function(req, callback) {
           err: err
         });
       } else {
-        logging.log(rid, "image not found, using default.");
+        logging.debug(rid, "image not found, using default.");
         handle_default(rid, scale, helm, body, status, userId, scale, def, req, err, callback);
       }
     });

lib/server.js

@@ -65,7 +65,7 @@ function requestHandler(req, res) {
   req.start = Date.now();
 
   var local_path = req.url.path_list[0];
-  logging.log(req.id, req.method, req.url.href);
+  logging.debug(req.id, req.method, req.url.href);
 
   toobusy.maxLag(200);
   if (toobusy() && !process.env.TRAVIS) {
@@ -73,7 +73,7 @@ function requestHandler(req, res) {
       "Content-Type": "text/plain"
     });
     res.end("Server is over capacity :/");
-    logging.log(req.id, 503, Date.now() - req.start + "ms", "(error)");
+    logging.warn("Too busy:", req.id, 503, Date.now() - req.start + "ms", "(error)");
     return;
   }
 

lib/skins.js

@@ -51,7 +51,7 @@ exp.extract_helm = function(rid, facefile, buffer, outname, callback) {
                     callback(img_err);
                   } else {
                     if (!skin_img.__trans) {
-                      logging.log(rid, "Skin is not transparent, skipping helm!");
+                      logging.debug(rid, "Skin is not transparent, skipping helm!");
                       callback(null);
                     } else {
                       face_helm_img.toBuffer("png", {compression: "none"}, function(buf_err2, face_helm_buffer) {
@@ -63,7 +63,7 @@ exp.extract_helm = function(rid, facefile, buffer, outname, callback) {
                               callback(write_err);
                             });
                           } else {
-                            logging.log(rid, "helm img == face img, not storing!");
+                            logging.debug(rid, "helm img == face img, not storing!");
                             callback(null);
                           }
                         }