merge #101, fixes #99

README.md

@@ -8,7 +8,7 @@ Inspired by [Gravatar](https://gravatar.com) (hence the name) and [Minotar](http
 
 Image manipulation is done by [lwip](https://github.com/EyalAr/lwip). 3D renders are created with [node-canvas](https://github.com/Automattic/node-canvas), based on math by [confuser](https://github.com/confuser/serverless-mc-skin-viewer).
 
-![jomo's avatar](https://crafatar.com/avatars/ae795aa86327408e92ab25c8a59f3ba1?size=128) ![Jake0oo0's avatar](https://crafatar.com/avatars/2d5aa9cdaeb049189930461fc9b91cc5?size=128) ![Notch's avatar](https://crafatar.com/avatars/069a79f444e94726a5befca90e38aaf5?size=128) ![sk89q's avatar](https://crafatar.com/avatars/0ea8eca3dbf647cc9d1ac64551ca975c?size=128) ![md_5's avatar](https://crafatar.com/avatars/af74a02d19cb445bb07f6866a861f783?size=128) 
+![jomo's avatar](https://crafatar.com/avatars/ae795aa86327408e92ab25c8a59f3ba1?size=128) ![Jake_0's avatar](https://crafatar.com/avatars/2d5aa9cdaeb049189930461fc9b91cc5?size=128) ![Notch's avatar](https://crafatar.com/avatars/069a79f444e94726a5befca90e38aaf5?size=128) ![sk89q's avatar](https://crafatar.com/avatars/0ea8eca3dbf647cc9d1ac64551ca975c?size=128) ![md_5's avatar](https://crafatar.com/avatars/af74a02d19cb445bb07f6866a861f783?size=128) 
 ## Usage / Documentation
 
 Please [visit the website](https://crafatar.com) for details.
@@ -45,3 +45,19 @@ Please [visit the website](https://crafatar.com) for details.
 * Start `redis-server`
 * `npm start`
 * Access [http://localhost:3000](http://localhost:3000)
+
+
+## Tests
+```shell
+npm test
+```
+
+If you want to debug failing tests, you can set the env
+```shell
+VERBOSE_TEST=true
+```
+
+To debug caching, it can be helpful to monitor redis commands while tests are running:
+```shell
+redis-cli monitor
+```

modules/cache.js

@@ -92,11 +92,14 @@ exp.info = function(callback) {
   });
 };
 
-// sets the timestamp for +userId+ and its face file's date to now
+// sets the timestamp for +userId+ and its face file's (+hash+) date to the current time
+// if +temp+ is true, the timestamp is set so that the record will be outdated after 60 seconds
+// these 60 seconds match the duration of Mojang's rate limit ban
 // +callback+ contains error
-exp.update_timestamp = function(rid, userId, hash, callback) {
+exp.update_timestamp = function(rid, userId, hash, temp, callback) {
   logging.log(rid + "cache: updating timestamp");
-  var time = new Date().getTime();
+  sub = temp ? (config.local_cache_time - 60) : 0;
+  var time = new Date().getTime() - sub;
   // store userId in lower case if not null
   userId = userId && userId.toLowerCase();
   redis.hmset(userId, "t", time, function(err) {
@@ -105,20 +108,31 @@ exp.update_timestamp = function(rid, userId, hash, callback) {
   update_file_date(rid, hash);
 };
 
-// create the key +userId+, store +skin_hash+ hash, +cape_hash+ hash and time
+// create the key +userId+, store +skin_hash+, +cape_hash+ and time
+// if either +skin_hash+ or +cape_hash+ are undefined, they will not be stored
+// 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 hash");
-  logging.log(rid + "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 || ".";
-  cape_hash = cape_hash || ".";
+  skin_hash = (skin_hash === null ? "" : skin_hash);
+  cape_hash = (cape_hash === null ? "" : cape_hash);
   // store userId in lower case if not null
   userId = userId && userId.toLowerCase();
-  redis.hmset(userId, "s", skin_hash, "c", cape_hash, "t", time, function(err){
-    callback(err);
-  });
+  if (skin_hash === undefined) {
+    redis.hmset(userId, "c", cape_hash, "t", time, function(err){
+      callback(err);
+    });
+  } else if (cape_hash === undefined) {
+    redis.hmset(userId, "s", skin_hash, "t", time, function(err){
+      callback(err);
+    });
+  } else {
+    redis.hmset(userId, "s", skin_hash, "c", cape_hash, "t", time, function(err){
+      callback(err);
+    });
+  }
 };
 
 // removes the hash for +userId+ from the cache
@@ -129,7 +143,8 @@ exp.remove_hash = function(rid, userId) {
 
 // get a details object for +userId+
 // {skin: "0123456789abcdef", cape: "gs1gds1g5d1g5ds1", time: 1414881524512}
-// null when userId unkown
+// +callback+ contains error, details
+// details is null when userId not cached
 exp.get_details = function(userId, callback) {
   // get userId in lower case if not null
   userId = userId && userId.toLowerCase();
@@ -137,8 +152,8 @@ exp.get_details = function(userId, callback) {
     var details = null;
     if (data) {
       details = {
-        skin: (data.s === "." ? null : data.s),
-        cape: (data.c === "." ? null : data.c),
+        skin: data.s === "" ? null : data.s,
+        cape: data.c === "" ? null : data.c,
         time: Number(data.t)
       };
     }
@@ -147,4 +162,4 @@ exp.get_details = function(userId, callback) {
 };
 
 connect_redis();
-module.exports = exp;
+module.exports = exp;

modules/helpers.js

@@ -16,11 +16,11 @@ function get_hash(url) {
 }
 
 function store_skin(rid, userId, profile, details, callback) {
-  networking.get_skin_url(rid, userId, profile, function(url) {
-    if (url) {
+  networking.get_skin_url(rid, userId, profile, function(err, url) {
+    if (!err && url) {
       var skin_hash = get_hash(url);
       if (details && details.skin === skin_hash) {
-        cache.update_timestamp(rid, userId, skin_hash, function(err) {
+        cache.update_timestamp(rid, userId, skin_hash, false, function(err) {
           callback(err, skin_hash);
         });
       } else {
@@ -41,9 +41,9 @@ function store_skin(rid, userId, profile, details, callback) {
                     logging.error(rid + err2.stack);
                     callback(err2, null);
                   } else {
-                    logging.log(rid + "face extracted");
+                    logging.debug(rid + "face extracted");
                     skins.extract_helm(rid, facepath, img, helmpath, function(err3) {
-                      logging.log(rid + "helm extracted");
+                      logging.debug(rid + "helm extracted");
                       logging.debug(rid + helmpath);
                       callback(err3, skin_hash);
                     });
@@ -55,17 +55,17 @@ function store_skin(rid, userId, profile, details, callback) {
         });
       }
     } else {
-      callback(null, null);
+      callback(err, null);
     }
   });
 }
 
 function store_cape(rid, userId, profile, details, callback) {
-  networking.get_cape_url(rid, userId, profile, function(url) {
-    if (url) {
+  networking.get_cape_url(rid, userId, profile, function(err, url) {
+    if (!err && url) {
       var cape_hash = get_hash(url);
       if (details && details.cape === cape_hash) {
-        cache.update_timestamp(rid, userId, cape_hash, function(err) {
+        cache.update_timestamp(rid, userId, cape_hash, false, function(err) {
           callback(err, cape_hash);
         });
       } else {
@@ -82,7 +82,7 @@ function store_cape(rid, userId, profile, details, callback) {
                 callback(err, null);
               } else {
                 skins.save_image(img, capepath, function(err) {
-                  logging.log(rid + "cape saved");
+                  logging.debug(rid + "cape saved");
                   callback(err, cape_hash);
                 });
               }
@@ -91,7 +91,7 @@ function store_cape(rid, userId, profile, details, callback) {
         });
       }
     } else {
-      callback(null, null);
+      callback(err, null);
     }
   });
 }
@@ -155,20 +155,30 @@ function store_images(rid, userId, details, type, callback) {
             callback_for(userId, "cape", cache_err, null);
           });
         } else {
-          // an error occured, not caching
+          // an error occured, not caching. we can try in 60 seconds
           callback_for(userId, type, err, null);
         }
       } else {
-        // no error and we have a profile or it's not a uuid
+        // no error and we have a profile (if it's a uuid)
         store_skin(rid, userId, profile, details, function(err, skin_hash) {
-          cache.save_hash(rid, userId, skin_hash, null, function(cache_err) {
-            callback_for(userId, "skin", (err || cache_err), skin_hash);
-            store_cape(rid, userId, profile, details, function(err, cape_hash) {
-              cache.save_hash(rid, userId, skin_hash, cape_hash, function(cache_err) {
-                callback_for(userId, "cape", (err || cache_err), cape_hash);
-              });
+          if (err && !skin_hash) {
+            // an error occured, not caching. we can try in 60 seconds
+            callback_for(userId, "skin", err, null);
+          } else {
+            cache.save_hash(rid, userId, skin_hash, null, function(cache_err) {
+              callback_for(userId, "skin", (err || cache_err), skin_hash);
             });
-          });
+          }
+        });
+        store_cape(rid, userId, profile, details, function(err, cape_hash) {
+          if (err && !cape_hash) {
+            // an error occured, not caching. we can try in 60 seconds
+            callback_for(userId, "cape", (err || cache_err), cape_hash);
+          } else {
+            cache.save_hash(rid, userId, undefined, cape_hash, function(cache_err) {
+              callback_for(userId, "cape", (err || cache_err), cape_hash);
+            });
+          }
         });
       }
     });
@@ -186,7 +196,7 @@ exp.id_valid = function(userId) {
   return valid_user_id.test(userId);
 };
 
-// decides whether to get an image from disk or to download it
+// decides whether to get a +type+ image for +userId+ from disk or to download it
 // callback contains error, status, hash
 // the status gives information about how the image was received
 //  -1: "error"
@@ -196,11 +206,11 @@ exp.id_valid = function(userId) {
 //   3: "checked" - profile re-downloaded (was too old), but it has either not changed or has no skin
 exp.get_image_hash = function(rid, userId, type, callback) {
   cache.get_details(userId, function(err, details) {
-    var cached_hash = details !== null ? (type === "skin" ? details.skin : details.cape) : null;
+    var cached_hash = (details !== null) ? (type === "skin" ? details.skin : details.cape) : null;
     if (err) {
       callback(err, -1, null);
     } else {
-      if (details && details.time + config.local_cache_time * 1000 >= new Date().getTime()) {
+      if (details && details[type] !== undefined && details.time + config.local_cache_time * 1000 >= new Date().getTime()) {
         // use cached image
         logging.log(rid + "userId cached & recently updated");
         callback(null, (cached_hash ? 1 : 0), cached_hash);
@@ -215,7 +225,9 @@ exp.get_image_hash = function(rid, userId, type, callback) {
           if (err) {
             // we might have a cached hash although an error occured
             // (e.g. Mojang servers not reachable, using outdated hash)
-            callback(err, -1, details && cached_hash);
+            cache.update_timestamp(rid, userId, cached_hash, true, function(err2) {
+              callback(err2 || err, -1, details && cached_hash);
+            });
           } else {
             var status = details && (cached_hash === new_hash) ? 3 : 2;
             logging.debug(rid + "cached hash: " + (details && cached_hash));
@@ -261,7 +273,6 @@ exp.get_avatar = function(rid, userId, helm, size, callback) {
 // handles requests for +userId+ skins
 // callback contains error, skin hash, image buffer
 exp.get_skin = function(rid, userId, callback) {
-  logging.log(rid + "skin request");
   exp.get_image_hash(rid, userId, "skin", function(err, status, skin_hash) {
     var skinpath = __dirname + "/../" + config.skins_dir + skin_hash + ".png";
     fs.exists(skinpath, function(exists) {
@@ -312,7 +323,7 @@ exp.get_render = function(rid, userId, scale, helm, body, callback) {
           } else {
             fs.writeFile(renderpath, img, "binary", function(err) {
               if (err) {
-                logging.log(rid + err.stack);
+                logging.error(rid + err.stack);
               }
               callback(null, 2, skin_hash, img);
             });
@@ -326,7 +337,6 @@ exp.get_render = function(rid, userId, scale, helm, body, callback) {
 // handles requests for +userId+ capes
 // callback contains error, cape hash, image buffer
 exp.get_cape = function(rid, userId, callback) {
-  logging.log(rid + "cape request");
   exp.get_image_hash(rid, userId, "cape", function(err, status, cape_hash) {
     if (!cape_hash) {
       callback(err, null, null);

modules/networking.js

@@ -56,15 +56,16 @@ exp.get_from_options = function(rid, url, options, callback) {
     // log url + code + description
     var code = response && response.statusCode;
     if (!error) {
-     var logfunc = code && code < 405 ? logging.log : logging.warn;
-     logfunc(rid + url + " " + code + " " + http_code[code]);
-   }
+      var logfunc = code && code < 405 ? logging.log : logging.warn;
+      logfunc(rid + url + " " + code + " " + http_code[code]);
+    }
 
     // 200 or 301 depending on content type
     if (!error && (code === 200 || code === 301)) {
       // response received successfully
       callback(body, response, null);
     } else if (error) {
+      logging.error(error);
       callback(body || null, response, error);
     } else if (code === 404 || code === 204) {
       // page does not exist
@@ -128,16 +129,16 @@ exp.get_profile = function(rid, uuid, callback) {
 // get the skin URL for +userId+
 // +profile+ is used if +userId+ is a uuid
 exp.get_skin_url = function(rid, userId, profile, callback) {
-  get_url(rid, userId, profile, 0, function(url) {
-    callback(url);
+  get_url(rid, userId, profile, 0, function(err, url) {
+    callback(err, url);
   });
 };
 
 // get the cape URL for +userId+
 // +profile+ is used if +userId+ is a uuid
 exp.get_cape_url = function(rid, userId, profile, callback) {
-  get_url(rid, userId, profile, 1, function(url) {
-    callback(url);
+  get_url(rid, userId, profile, 1, function(err, url) {
+    callback(err, url);
   });
 };
 
@@ -145,11 +146,11 @@ function get_url(rid, userId, profile, type, callback) {
   if (userId.length <= 16) {
     //username
     exp.get_username_url(rid, userId, type, function(err, url) {
-      callback(url || null);
+      callback(err, url || null);
     });
   } else {
     exp.get_uuid_url(profile, type, function(url) {
-      callback(url || null);
+      callback(null, url || null);
     });
   }
 }
@@ -164,7 +165,7 @@ exp.save_texture = function(rid, tex_hash, outpath, callback) {
       } else {
         fs.writeFile(outpath, img, "binary", function(err) {
           if (err) {
-            logging.log(rid + "error: " + err.stack);
+            logging.error(rid + "error: " + err.stack);
           }
           callback(err, response, img);
         });

modules/renders.js

@@ -150,19 +150,16 @@ exp.draw_model = function(rid, img, scale, helm, body, callback) {
     //Scale it
     scale_image(skin_ctx.getImageData(0,0,64,original_height), skin_ctx, 0, 0, scale);
     if (body) {
-      logging.log(rid + "drawing body");
       exp.draw_body(rid, skin_canvas, model_ctx, scale);
     }
-    logging.log(rid + "drawing head");
     exp.draw_head(skin_canvas, model_ctx, scale);
     if (helm) {
-      logging.log(rid + "drawing helmet");
       exp.draw_helmet(skin_canvas, model_ctx, scale);
     }
 
     model_canvas.toBuffer(function(err, buf){
       if (err) {
-        logging.log(rid + "error creating buffer: " + err);
+        logging.error(rid + "error creating buffer: " + err);
       }
       callback(err, buf);
     });

modules/skins.js

@@ -53,7 +53,7 @@ exp.extract_helm = function(rid, facefile, buffer, outname, callback) {
                           callback(err);
                         });
                       } else {
-                        logging.log(rid + "helm image is the same as face image, not storing!");
+                        logging.log(rid + "helm img == face img, not storing!");
                         callback(null);
                       }
                     });

public/stylesheets/style.css

@@ -231,8 +231,8 @@ img.preload {
 .avatar.jomo {background-image: url("/avatars/ae795aa86327408e92ab25c8a59f3ba1?size=64")}
 .avatar.jomo:hover {background-image: url("/avatars/ae795aa86327408e92ab25c8a59f3ba1?size=64&helm")}
 
-.avatar.jake0oo0 {background-image: url("/avatars/2d5aa9cdaeb049189930461fc9b91cc5?size=64")}
-.avatar.jake0oo0:hover {background-image: url("/avatars/2d5aa9cdaeb049189930461fc9b91cc5?size=64&helm")}
+.avatar.jake_0 {background-image: url("/avatars/2d5aa9cdaeb049189930461fc9b91cc5?size=64")}
+.avatar.jake_0:hover {background-image: url("/avatars/2d5aa9cdaeb049189930461fc9b91cc5?size=64&helm")}
 
 .avatar.sk89q {background-image: url("/avatars/0ea8eca3dbf647cc9d1ac64551ca975c?size=64")}
 .avatar.sk89q:hover {background-image: url("/avatars/0ea8eca3dbf647cc9d1ac64551ca975c?size=64&helm")}

routes/renders.js

@@ -118,7 +118,7 @@ module.exports = function(req, res) {
         // we render the default skins, but not custom images
         renders.draw_model(rid, buf, scale, helm, body, function(err, def_img) {
           if (err) {
-            logging.log(rid + "error while rendering default image: " + err);
+            logging.error(rid + "error while rendering default image: " + err);
           }
           sendimage(rid, http_status, img_status, def_img);
         });

test/test.js

@@ -15,7 +15,9 @@ var request = require("request");
 config.http_timeout *= 3;
 
 // no spam
-logging.log = function() {};
+if (process.env.VERBOSE_TEST !== "true") {
+  logging.log = function() {};
+}
 
 var uuids = fs.readFileSync("test/uuids.txt").toString().split(/\r?\n/);
 var names = fs.readFileSync("test/usernames.txt").toString().split(/\r?\n/);
@@ -166,7 +168,7 @@ describe("Crafatar", function() {
     });
     it("should ignore file updates on invalid files", function(done) {
       assert.doesNotThrow(function() {
-        cache.update_timestamp(rid, "0123456789abcdef0123456789abcdef", "invalid-file.png", function(err) {
+        cache.update_timestamp(rid, "0123456789abcdef0123456789abcdef", "invalid-file.png", false, function(err) {
           done();
         });
       });
@@ -211,7 +213,7 @@ describe("Crafatar", function() {
 
     it("should return a 422 (invalid size)", function(done) {
       var size = config.max_size + 1;
-      request.get("http://localhost:3000/avatars/Jake0oo0?size=" + size, function(error, res, body) {
+      request.get("http://localhost:3000/avatars/Jake_0?size=" + size, function(error, res, body) {
         assert.equal(422, res.statusCode);
         done();
       });
@@ -219,7 +221,7 @@ describe("Crafatar", function() {
 
     it("should return a 422 (invalid scale)", function(done) {
       var scale = config.max_scale + 1;
-      request.get("http://localhost:3000/renders/head/Jake0oo0?scale=" + scale, function(error, res, body) {
+      request.get("http://localhost:3000/renders/head/Jake_0?scale=" + scale, function(error, res, body) {
         assert.equal(422, res.statusCode);
         done();
       });
@@ -227,14 +229,14 @@ describe("Crafatar", function() {
 
     // no default images for capes, should 404
     it("should return a 404 (no cape)", function(done) {
-      request.get("http://localhost:3000/capes/Jake0oo0", function(error, res, body) {
+      request.get("http://localhost:3000/capes/Jake_0", function(error, res, body) {
         assert.equal(404, res.statusCode);
         done();
       });
     });
 
     it("should return a 422 (invalid render type)", function(done) {
-      request.get("http://localhost:3000/renders/side/Jake0oo0", function(error, res, body) {
+      request.get("http://localhost:3000/renders/side/Jake_0", function(error, res, body) {
         assert.equal(422, res.statusCode);
         done();
       });
@@ -246,7 +248,7 @@ describe("Crafatar", function() {
       var location = locations[l];
       (function(location) {
         it("should return a 200 (valid input " + location + ")", function(done) {
-          request.get("http://localhost:3000/" + location + "/Jake0oo0", function(error, res, body) {
+          request.get("http://localhost:3000/" + location + "/Jake_0", function(error, res, body) {
             assert.equal(200, res.statusCode);
             done();
           });
@@ -310,7 +312,7 @@ describe("Crafatar", function() {
       });
     });
     it("should not fail (username, 64x64 skin)", function(done) {
-      helpers.get_render(rid, "Jake0oo0", 6, true, true, function(err, hash, img) {
+      helpers.get_render(rid, "Jake_0", 6, true, true, function(err, hash, img) {
         assert.strictEqual(err, null);
         done();
       });
@@ -334,7 +336,7 @@ describe("Crafatar", function() {
       });
     });
     it("should not be found", function(done) {
-      helpers.get_cape(rid, "Jake0oo0", function(err, hash, img) {
+      helpers.get_cape(rid, "Jake_0", function(err, hash, img) {
         assert.strictEqual(img, null);
         done();
       });
@@ -343,7 +345,7 @@ describe("Crafatar", function() {
 
   describe("Networking: Skin", function() {
     it("should not fail", function(done) {
-      helpers.get_cape(rid, "Jake0oo0", function(err, hash, img) {
+      helpers.get_cape(rid, "Jake_0", function(err, hash, img) {
         assert.strictEqual(err, null);
         done();
       });
@@ -352,7 +354,7 @@ describe("Crafatar", function() {
       before(function() {
         cache.get_redis().flushall();
       });
-      helpers.get_cape(rid, "Jake0oo0", function(err, hash, img) {
+      helpers.get_cape(rid, "Jake_0", function(err, hash, img) {
         assert.strictEqual(err, null);
         done();
       });

views/index.jade

@@ -7,7 +7,7 @@ block content
         p A blazing fast API for Minecraft faces!
         .avatar-wrapper
           .avatar.jomo(title="jomo's avatar")
-          .avatar.jake0oo0(title="jake0oo0's avatar")
+          .avatar.jake_0(title="jake_0's avatar")
           .avatar.sk89q(title="sk89q's avatar")
           .avatar.md_5(title="md_5's avatar")
           .avatar.notch(title="notch's avatar")