fix(objectionary#368): added utility function for elapsed time tracking

src/commands/assemble.js

@@ -25,6 +25,7 @@
 const rel = require('relative');
 const path = require('path');
 const {mvnw, flags} = require('../mvnw');
+const {elapsed} = require('../elapsed');
 
 /**
  * Command to assemble .XMIR files.
@@ -33,8 +34,10 @@ const {mvnw, flags} = require('../mvnw');
  */
 module.exports = function(opts) {
   const target = path.resolve(opts.target);
-  return mvnw(['eo:assemble'].concat(flags(opts)), opts.target, opts.batch).then((r) => {
-    console.info('EO program assembled in %s', rel(target));
-    return r;
+  return elapsed((tracked) => {
+    return mvnw(['eo:assemble'].concat(flags(opts)), opts.target, opts.batch).then((r) => {
+      tracked.print('EO program assembled in %s', rel(target));
+      return r;
+    });
   });
-};
+};

src/commands/java/compile.js

@@ -33,6 +33,10 @@ const path = require('path');
  */
 module.exports = function(opts) {
   const target = path.resolve(opts.target);
+  /**
+   * @todo #368
+   * It is necessary to use 'elapsed' in all logging cases that require output of elapsed time
+   */
   return mvnw(['compiler:compile'].concat(flags(opts)), opts.target, opts.batch).then((r) => {
     console.info('Java .class files compiled into %s', rel(target));
     return r;

src/elapsed.js

@@ -0,0 +1,69 @@
+/*
+ * The MIT License (MIT)
+ *
+ * Copyright (c) 2022-2024 Objectionary.com
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included
+ * in all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NON-INFRINGEMENT. IN NO EVENT SHALL THE
+ * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
+ * SOFTWARE.
+ */
+
+/**
+ * @todo #368
+ * Consider if this method belong is in the right place.
+ * It might belong in a utility module.
+ * For now, it remains here.
+ *
+ * Also, review whether the test file for this method is located appropriately.
+ * It’s unclear if its current location is the best fit.
+ */
+
+/**
+ * A utility function to measure the elapsed time of a task and provide
+ * detailed timing information.
+ *
+ * This function wraps a given task (callback function) and provides it with
+ * a `tracked` object that includes a `print` method. The `print` method can
+ * be used within the task to log messages along with the elapsed time
+ * since the task started execution. The elapsed time is formatted in milliseconds,
+ * seconds, or minutes, based on the duration.
+ *
+ * @param {Function} task - A callback function to be measured. The function
+ *                          is invoked with a `tracked` object as an argument.
+ * @return {*} Result of the wrapped callback function. The result of the
+ *             `task` callback will be returned unchanged.
+ */
+module.exports.elapsed = function elapsed(task) {
+    const startTime = Date.now();
+    const tracked = {
+        print: (message) => {
+            const duration = Date.now() - startTime;
+            let extended;
+            if (duration < 1000) {
+                extended = `${duration}ms`;
+            } else if (duration < 60 * 1000) {
+                extended = `${Math.ceil(duration / 1000)}s`;
+            } else {
+                extended = `${Math.ceil(duration / 3600000)}min`;
+            }
+            let msg = `${message} in ${extended}`;
+            console.info(msg);
+            return msg;
+        }
+    }
+    return task(tracked);
+}

test/test_elapsed.js

@@ -0,0 +1,76 @@
+/*
+ * The MIT License (MIT)
+ *
+ * Copyright (c) 2022-2024 Objectionary.com
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included
+ * in all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NON-INFRINGEMENT. IN NO EVENT SHALL THE
+ * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
+ * SOFTWARE.
+ */
+
+const {elapsed} = require('../src/elapsed')
+const assert = require("assert");
+
+describe('elapsed', function(){
+    const snooze = ms => new Promise(resolve => setTimeout(resolve, ms));
+    it('measures time correctly', async () => {
+        return elapsed(async (tracked) => {
+            await snooze(300);
+            return tracked.print("task");
+        }).then(
+            (actual)=> assert(
+                /task in 30\d+ms/.test(actual),
+                `Expected "${actual}" to match /task in 30\\d+ms/`
+            )
+        )
+    });
+
+    it('measures short time correctly', async () => {
+        return elapsed(async (tracked) => {
+            await snooze(10);
+            return tracked.print("short task");
+        }).then(
+            (actual) => assert(
+                /short task in 1\d+ms/.test(actual),
+                `Expected "${actual}" to match /short task in 1\\d+ms/`
+            )
+        );
+    });
+
+    it('measures long time correctly', async () => {
+        return elapsed(async (tracked) => {
+            await snooze(1200);
+            return tracked.print("long task");
+        }).then(
+            (actual) => assert(
+                /long task in 2s/.test(actual),
+                `Expected "${actual}" to match /long task in 2s/`
+            )
+        );
+    });
+
+    it('handles errors in task correctly', async () => {
+        try {
+            await elapsed(async (tracked) => {
+                throw new Error("task error");
+            });
+            assert.fail("Expected an error to be thrown");
+        } catch (error) {
+            assert.equal(error.message, "task error");
+        }
+    });
+})