Fix QueueCache bugs and enable engine caching

QueueCache was disabled in 2015, so every request was rebuilding engines
from scratch. This fixes bugs and enables it.

- Replace Promise.delay() (Bluebird, no longer installed) with native
  setTimeout
- Set working flag on resolved engine instead of on the Promise object,
  which left the mutex broken and theoretically allowed concurrent
  requests for the same style to corrupt each other's results
- Add 5s timeout on busy-wait retry loop, replacing the stuck cache
  entry with a fresh engine so subsequent requests aren't penalized
- Fix inverted LRU eviction sort (was evicting hottest items)
- Set engineCacheSize to 20

Author: dstillman

config/default.json

@@ -5,7 +5,7 @@
     "cslPath" : "./csl",
     "renamedStylesPath": "./csl/renamed-styles.json",
     "cslDependentPath": "./csl/dependent",
-    "engineCacheSize" : 40,
+    "engineCacheSize" : 20,
     "timings": false,
     "debug": true,
     "userAgent": "Zotero Citation Server (https://github.com/zotero/citeproc-js-server)"

lib/citeServer.js

@@ -116,8 +116,7 @@ var requestCount = 0;
 // Instantiate resource managers
 let cslLoader = new styles.CslLoader(config);
 let localeManager = new locales.LocaleManager(config.localesPath);
-//let engineCache = new enginecaching.QueueCache(config);
-let engineCache = new enginecaching.NoncacheEngineCache(config);
+let engineCache = new enginecaching.QueueCache(config);
 engineCache.localeManager = localeManager;
 engineCache.cslLoader = cslLoader;
 

lib/engineCaching.js

@@ -34,6 +34,12 @@ let citeproc = require('./citeprocnode');
 let path = require('path');
 let jsonWalker = require("./json_walker.js");
 
+function delay(ms) {
+	return new Promise(function(resolve) {
+		setTimeout(resolve, ms);
+	});
+}
+
 exports.NoncacheEngineCache = function(config){
     if(config){
         this.config = config;
@@ -106,7 +112,7 @@ exports.QueueCache.prototype.config = {
  * @param  {[type]} locale   [description]
  * @return {[type]}          [description]
  */
-exports.QueueCache.prototype.getEngine = function(styleUrlObj, locale) {
+exports.QueueCache.prototype.getEngine = function(styleUrlObj, locale, _retryStart) {
     let engineCache = this;
     log.info("engine requested with locale:", locale);
     //try to get a cached engine
@@ -121,15 +127,21 @@ exports.QueueCache.prototype.getEngine = function(styleUrlObj, locale) {
         log.info("No cached engine found");
         let newEngine = engineCache.buildNewEngine(styleUrlObj, locale);
         engineCache.cachedEngines[cacheEngineString] = newEngine;
-        newEngine.working = true;
         return newEngine;
     } else {
         log.info("cached engine found");
         return engineCache.cachedEngines[cacheEngineString].then(function(citeprocEngine){
             if(citeprocEngine instanceof citeproc.CiteprocEngine){
                 if(citeprocEngine.working){
-                    return Promise.delay(10).then(function(){
-                        return engineCache.getEngine(styleUrlObj, locale);
+                    let retryStart = _retryStart || Date.now();
+                    if(Date.now() - retryStart > 5000){
+                        log.warn("Timed out waiting for engine -- replacing stuck cache entry:", cacheEngineString);
+                        let newEngine = engineCache.buildNewEngine(styleUrlObj, locale);
+                        engineCache.cachedEngines[cacheEngineString] = newEngine;
+                        return newEngine;
+                    }
+                    return delay(10).then(function(){
+                        return engineCache.getEngine(styleUrlObj, locale, retryStart);
                     });
                 }
                 log.info("returning existing citeproc instance from QueueCache.getEngine");
@@ -187,8 +199,9 @@ exports.QueueCache.prototype.buildNewEngine = function(styleUrlObj, locale){
             cslObject = jsonWalker.JsonWalker.walkStyleToObj(cslDoc).obj;
             cslDoc.defaultView.close();
         }
-        
+
         let citeprocEngine = new citeproc.CiteprocEngine({}, cslObject, locale, engineCache.localeManager, null);
+        citeprocEngine.working = true;
         return citeprocEngine;
     });
 };
@@ -222,9 +235,9 @@ exports.QueueCache.prototype.clean = function(){
             gcCacheArray.push(i);
         }
 
-        //sort by last used
+        //sort by last used (oldest first so we evict the coldest)
         gcCacheArray.sort(function(a, b){
-            return engineCache.lastUsed[b] - engineCache.lastUsed[a];
+            return (engineCache.lastUsed[a] || 0) - (engineCache.lastUsed[b] || 0);
         });
 
         //evict a third of the cache