dev: measure cache rate and fix an edge-case

Author: KernelDeimos

src/backend/src/services/file-cache/FileCacheService.js

@@ -20,6 +20,8 @@
 const { AdvancedBase } = require("@heyputer/putility");
 const { FileTracker } = require("./FileTracker");
 const { pausing_tee } = require("../../util/streamutil");
+const putility = require("@heyputer/putility");
+const { EWMA } = require("../../util/opmath");
 
 /**
  * FileCacheService
@@ -71,6 +73,11 @@ class FileCacheService extends AdvancedBase {
         this.precache = new Map();
         this.uid_to_tracker = new Map();
 
+        this.cache_hit_rate = new EWMA({
+            initial: 0.5,
+            alpha: 0.2,
+        });
+
         this.init();
 
         this._register_commands(services.get('commands'));
@@ -139,7 +146,12 @@ class FileCacheService extends AdvancedBase {
     * @param {string} uid - The unique identifier of the file.
     * @returns {string} The full path where the file is stored on disk.
     */
-    async try_get (fsNode, opt_log) {
+    async try_get(fsNode, opt_log) {
+        const result = await this.try_get_(fsNode, opt_log);
+        this.cache_hit_rate.put(result ? 1 : 0);
+        return result;
+    }
+    async try_get_ (fsNode, opt_log) {
         const tracker = this.uid_to_tracker.get(await fsNode.get('uid'));
 
         if ( ! tracker ) {
@@ -153,6 +165,27 @@ class FileCacheService extends AdvancedBase {
 
         tracker.touch();
 
+        // If the file is in pending, that means it's currenty being read
+        // for cache entry, so we wait for it to be ready.
+        if ( tracker.phase === FileTracker.PHASE_PENDING ) {
+            Promise.race([
+                tracker.p_ready,
+                new Promise(resolve => setTimeout(resolve, 2000))
+            ]);
+        }
+
+        // If the file is still in pending it means we waited too long;
+        // it's possible that reading the file failed is is delayed.
+        if ( tracker.phase === FileTracker.PHASE_PENDING ) {
+            return this._get_path(await fsNode.get('uid'));
+        }
+
+        // Since we waited for the file to be ready, it's not impossible
+        // that it was evicted in the meantime; just very unlikely.
+        if ( tracker.phase === FileTracker.PHASE_GONE ) {
+            return null;
+        }
+
         if ( tracker.phase === FileTracker.PHASE_PRECACHE ) {
             if ( opt_log ) opt_log.info('obtained from precache');
             return this.precache.get(await fsNode.get('uid'));
@@ -218,6 +251,7 @@ class FileCacheService extends AdvancedBase {
         // Add file tracker
         const tracker = new FileTracker({ key, size });
         this.uid_to_tracker.set(key, tracker);
+        tracker.p_ready = new putility.libs.promise.TeePromise();
         tracker.touch();
 
 
@@ -236,6 +270,7 @@ class FileCacheService extends AdvancedBase {
             await this._precache_make_room(size);
             this.precache.set(key, data);
             tracker.phase = FileTracker.PHASE_PRECACHE;
+            tracker.p_ready.resolve();
         })()
 
         return { cached: true, stream: replace_stream };
@@ -395,6 +430,12 @@ class FileCacheService extends AdvancedBase {
 
                     log.log(JSON.stringify(status, null, 2));
                 }
+            },
+            {
+                id: 'hitrate',
+                handler: async (args, log) => {
+                    log.log(this.cache_hit_rate.get());
+                }
             }
         ]);
     }