Improving cache logs (#821)

nshiab · Feb 27, 2025 · ff1422a · ff1422a
1 parent 93ce230
commit ff1422a
Show file tree

Hide file tree

Showing 3 changed files with 50 additions and 40 deletions.
diff --git a/src/class/SimpleDB.ts b/src/class/SimpleDB.ts
@@ -51,6 +51,8 @@ export default class SimpleDB extends SimpleWebDB {
   cacheVerbose: boolean;
   /** Amount of time saved by using the cache. */
   cacheTimeSaved: number;
+  /** Amount of time spent writing the cache. */
+  cacheTimeWriting: number;
 
   constructor(
     options: {
@@ -66,6 +68,7 @@ export default class SimpleDB extends SimpleWebDB {
     this.tables = [];
     this.cacheVerbose = options.cacheVerbose ?? false;
     this.cacheTimeSaved = 0;
+    this.cacheTimeWriting = 0;
     this.runQuery = runQuery;
     if (this.cacheVerbose) {
       this.durationStart = Date.now();
@@ -189,23 +192,26 @@ export default class SimpleDB extends SimpleWebDB {
     }
     cleanCache(this);
     if (typeof this.durationStart === "number") {
+      let string = prettyDuration(this.durationStart, {
+        prefix: "\nSimpleDB - Done in ",
+      });
+
       if (this.cacheTimeSaved > 0) {
-        prettyDuration(this.durationStart, {
-          log: true,
-          prefix: "\nSimpleDB - Done in ",
-          suffix: ` / You saved ${
-            prettyDuration(0, {
-              end: this.cacheTimeSaved,
-            })
-          } by using the cache\n`,
-        });
-      } else {
-        prettyDuration(this.durationStart, {
-          log: true,
-          prefix: "\nSimpleDB - Done in ",
-          suffix: "\n",
-        });
+        string += ` / ${
+          prettyDuration(0, {
+            end: this.cacheTimeSaved,
+          })
+        } saved by using the cache`;
       }
+      if (this.cacheTimeWriting > 0) {
+        string += ` / ${
+          prettyDuration(0, {
+            end: this.cacheTimeWriting,
+          })
+        } spent writing the cache`;
+      }
+
+      console.log(`${string}\n`);
     }
 
     return await this;

diff --git a/src/helpers/cleanCache.ts b/src/helpers/cleanCache.ts
@@ -6,15 +6,10 @@ export default function cleanCache(sdb: SimpleDB) {
     const cacheSources = JSON.parse(
       readFileSync(".sda-cache/sources.json", "utf-8"),
     );
-    let first = true;
     for (const cacheId of Object.keys(cacheSources)) {
       if (!sdb.cacheSourcesUsed.includes(cacheId)) {
-        if (first) {
-          console.log("");
-          first = false;
-        }
         if (cacheSources[cacheId].file !== null) {
-          sdb.cacheVerbose &&
+          sdb.debug &&
             console.log(
               `Removing unused file from cache: ${cacheSources[cacheId].file}`,
             );
@@ -23,7 +18,6 @@ export default function cleanCache(sdb: SimpleDB) {
         delete cacheSources[cacheId];
       }
     }
-    console.log("");
     writeFileSync(".sda-cache/sources.json", JSON.stringify(cacheSources));
   }
 }
diff --git a/src/methods/cache.ts b/src/methods/cache.ts
@@ -64,7 +64,7 @@ export default async function cache(
   ) {
     (table.debug || options.verbose) &&
       console.log(
-        `Found ${cache.file} in cache.\nttl of ${
+        `Found in cache.\nttl of ${
           prettyDuration(0, { end: options.ttl * 1000 })
         } has expired. The creation date is ${
           formatDate(
@@ -85,7 +85,7 @@ export default async function cache(
     );
   } else {
     (table.debug || options.verbose) &&
-      console.log(`Found ${cache.file} in cache.`);
+      console.log(`Found in cache.`);
     if (typeof options.ttl === "number") {
       const ttlLimit = new Date(cache.creation + options.ttl * 1000);
       (table.debug || options.verbose) &&
@@ -115,11 +115,9 @@ export default async function cache(
         console.log(
           `Data loaded in ${
             prettyDuration(start, { end })
-          }. Running the computations took ${
+          }. Running computations previously took ${
             prettyDuration(0, { end: cache.duration })
-          } last time. You saved ${
-            prettyDuration(duration, { end: cache.duration })
-          }.\n`,
+          }. You saved ${prettyDuration(duration, { end: cache.duration })}.\n`,
         );
         table.sdb.cacheTimeSaved += cache.duration - duration;
       }
@@ -136,11 +134,9 @@ export default async function cache(
         console.log(
           `Data loaded in ${
             prettyDuration(start, { end })
-          }. Running the computations took ${
+          }. Running computations previously took ${
             prettyDuration(0, { end: cache.duration })
-          } last time. You saved ${
-            prettyDuration(duration, { end: cache.duration })
-          }.\n`,
+          }. You saved ${prettyDuration(duration, { end: cache.duration })}.\n`,
         );
         table.sdb.cacheTimeSaved += cache.duration - duration;
       }
@@ -160,6 +156,10 @@ async function runAndWrite(
   await run();
   const end = Date.now();
   const duration = end - start;
+  table.sdb.cacheVerbose &&
+    console.log(
+      `Computations done in ${prettyDuration(start, { end })}.`,
+    );
   table.debug && console.log("\ncache() after run()");
   if (!(await table.sdb.hasTable(table.name))) {
     console.log(`No data in table ${table.name}. Nothing stored in cache.`);
@@ -178,25 +178,39 @@ async function runAndWrite(
       table.debug &&
         console.log(`\nThe table has geometries. Using writeGeoData.`);
       const file = `${cachePath}/${id}.geoparquet`;
+      const writeStart = Date.now();
       await table.writeGeoData(file);
       cacheSources[id] = {
         creation: Date.now(),
         duration,
         file,
         geo: true,
       };
-      if (table.sdb.cacheSourcesUsed.indexOf(id) < 0) {
-        table.sdb.cacheSourcesUsed.push(id);
-      }
+      const writeEnd = Date.now();
       table.sdb.cacheVerbose &&
         console.log(
-          `Duration: ${prettyDuration(start, { end })}. Wrote ${file}.\n`,
+          `Wrote in cache in ${
+            prettyDuration(writeStart, { end: writeEnd })
+          }.\n`,
         );
+      table.sdb.cacheTimeWriting += writeEnd - writeStart;
+      if (table.sdb.cacheSourcesUsed.indexOf(id) < 0) {
+        table.sdb.cacheSourcesUsed.push(id);
+      }
     } else {
       table.debug &&
         console.log(`\nNo geometries in the table. Using writeData.`);
       const file = `${cachePath}/${id}.parquet`;
+      const writeStart = Date.now();
       await table.writeData(file);
+      const writeEnd = Date.now();
+      table.sdb.cacheVerbose &&
+        console.log(
+          `Wrote in cache in ${
+            prettyDuration(writeStart, { end: writeEnd })
+          }.\n`,
+        );
+      table.sdb.cacheTimeWriting += writeEnd - writeStart;
       cacheSources[id] = {
         creation: Date.now(),
         duration,
@@ -206,10 +220,6 @@ async function runAndWrite(
       if (table.sdb.cacheSourcesUsed.indexOf(id) < 0) {
         table.sdb.cacheSourcesUsed.push(id);
       }
-      table.sdb.cacheVerbose &&
-        console.log(
-          `Duration: ${prettyDuration(start, { end })}. Wrote ${file}.\n`,
-        );
     }
   }