Merge pull request #90 from kidroca/kidroca/md-print-format

`Onxy.printMetrics` MD, CSV and JSON formats

README.md

@@ -62,28 +62,36 @@ This will return an object containing `totalTime`, `averageTime` and `summaries`
 
 If you wish to reset the metrics and start over use `Onyx.resetMetrics()`
 
-Finally, there's a `Onyx.printMetrics()` method which prints human friendly statistics information on the dev console
-You can use this method during debugging e.g. add an `Onyx.printMetrics()` line somewhere in code or call it
-through the dev console. 
+Finally, there's a `Onyx.printMetrics()` method which prints human statistics information on the dev console
+You can use this method during debugging. For example add an `Onyx.printMetrics()` line somewhere in code or call it
+through the dev console. It supports 3 popular formats *MD* - human friendly markdown, *CSV* and *JSON*
+The default is MD if you want to print another format call `Onyx.printMetrics({ format: 'csv' })` or 
+`Onyx.printMetrics({ format: 'json' })`
 
 Sample output of `Onyx.printMetrics()`
 
 ```
-Onyx Benchmark
-  Total: 135.9min
-  Average: 45.3min
-
-Onyx:get
-  total: 51.5min
-  max: 6.20sec
-  min: 26.650ms
-  avg: 4.24sec 
-  calls: 728
-
-Onyx:getAllKeys
-  total: 84.3min
-  max: 6.20sec
-  min: 8.210ms
-  avg: 3.78sec 
-  calls: 1336
+### Onyx Benchmark
+  - Total: 1.5min
+  - Last call finished at: 12.55sec
+
+|     method      | total time spent |    max    |   min    |    avg    | time last call completed | calls made |
+|-----------------|-----------------:|----------:|---------:|----------:|-------------------------:|-----------:|
+| Onyx:getAllKeys |           1.2min |   2.16sec |  0.159ms | 782.230ms |                 12.55sec |         90 |
+| Onyx:merge      |          4.73sec |   2.00sec | 74.412ms | 591.642ms |                 10.24sec |          8 |
+| Onyx:set        |          3.90sec | 846.760ms | 43.663ms | 433.056ms |                  7.47sec |          9 |
+| Onyx:get        |          8.87sec |   2.00sec |  0.063ms |  61.998ms |                 10.24sec |        143 |
+
+
+|                           Onyx:set                            |
+|---------------------------------------------------------------|
+| start time | end time  | duration  |           args           |
+|-----------:|----------:|----------:|--------------------------|
+|  291.042ms | 553.079ms | 262.037ms | session, [object Object] |
+|  293.719ms | 553.316ms | 259.597ms | account, [object Object] |
+|  294.541ms | 553.651ms | 259.109ms | network, [object Object] |
+|  365.378ms | 554.246ms | 188.867ms | iou, [object Object]     |
+|    1.08sec |   2.20sec |   1.12sec | network, [object Object] |
+|    1.08sec |   2.20sec |   1.12sec | iou, [object Object]     |
+|    1.17sec |   2.20sec |   1.03sec | currentURL, /            |
 ```

lib/MDTable.js

@@ -0,0 +1,69 @@
+import AsciTable from 'ascii-table';
+
+class MDTable extends AsciTable {
+    /**
+     * Create a CSV string from the table data
+     * @returns {string}
+     */
+    toCSV() {
+        return [this.getTitle(), this.getHeading(), ...this.getRows()].join('\n');
+    }
+
+    /**
+     * Create a JSON string from the table data
+     * @returns {string}
+     */
+    toJSON() {
+        return JSON.stringify(super.toJSON());
+    }
+
+    /**
+     * Create a MD string from the table data
+     * @returns {string}
+     */
+    toString() {
+        // Ignore modifying the first |---| for titled tables
+        let idx = this.getTitle() ? -2 : -1;
+        const ascii = super.toString()
+            .replace(/-\|/g, () => {
+                /* we replace "----|" with "---:|" to align the data to the right in MD */
+                idx++;
+
+                if (idx < 0 || this.leftAlignedCols.includes(idx)) {
+                    return '-|';
+                }
+
+                return ':|';
+            });
+
+        // strip the top and the bottom row (----) to make an MD table
+        const md = ascii.split('\n').slice(1, -1).join('\n');
+        return md;
+    }
+}
+
+/**
+ * Table Factory helper
+ * @param {Object} options
+ * @param {string} [options.title] - optional title center above the table
+ * @param {string[]} options.heading - table column names
+ * @param {number[]} [options.leftAlignedCols=[]] - indexes of columns that should be left aligned
+ * Pass the columns that are non numeric here - the rest will be aligned to the right
+ * @param {Array} [options.rows] The table can be initialized with row. Rows can also be added by `addRow`
+ * @returns {MDTable}
+ */
+MDTable.factory = ({
+    title, heading, leftAlignedCols = [], rows = []
+}) => {
+    const table = new MDTable({title, heading, rows});
+    table.leftAlignedCols = leftAlignedCols;
+
+    /* By default we want everything aligned to the right as most values are numbers
+         * we just override the columns that are not right aligned */
+    heading.forEach((name, idx) => table.setAlign(idx, AsciTable.RIGHT));
+    leftAlignedCols.forEach(idx => table.setAlign(idx, AsciTable.LEFT));
+
+    return table;
+};
+
+export default MDTable;

lib/decorateWithMetrics.js

@@ -1,4 +1,5 @@
 import _ from 'underscore';
+import MDTable from './MDTable';
 
 /**
  * Each key is a method name and the value is an array of calls metadata
@@ -8,8 +9,9 @@ let stats = {};
 
 /* For some reason `performance.now()` does not start from `0` but a very large offset
 * like `508,080,000` see: https://github.com/facebook/react-native/issues/30069
-* Capturing an offset allows us to record start/ends times relative to app launch time */
-const APP_LAUNCH_TIME = performance.now();
+* Capturing an offset allows us to record start/ends times relative to app launch time
+* It also allows us to compare start/end times relative to the last resetMetrics */
+let PERFORMANCE_OFFSET = performance.now();
 
 /**
  * Wraps a function with metrics capturing logic
@@ -25,7 +27,7 @@ function decorateWithMetrics(func, alias = func.name) {
     stats[alias] = [];
 
     function decorated(...args) {
-        const startTime = performance.now() - APP_LAUNCH_TIME;
+        const startTime = performance.now() - PERFORMANCE_OFFSET;
 
         const originalPromise = func.apply(this, args);
 
@@ -35,7 +37,7 @@ function decorateWithMetrics(func, alias = func.name) {
         * */
         originalPromise
             .finally(() => {
-                const endTime = performance.now() - APP_LAUNCH_TIME;
+                const endTime = performance.now() - PERFORMANCE_OFFSET;
 
                 if (!_.has(stats, alias)) {
                     stats[alias] = [];
@@ -136,62 +138,91 @@ function toDuration(millis, raw = false) {
  * max, min, average, total time for each method
  * and a table of individual calls
  *
- * @param {boolean} [raw=false] setting this to true will print raw instead of human friendly times
+ * @param {Object} [options]
+ * @param {boolean} [options.raw=false] - setting this to true will print raw instead of human friendly times
  * Useful when you copy the printed table to excel and let excel do the number formatting
+ * @param {'console'|'csv'|'json'|'string'} [options.format=console] The output format of this function
+ * `string` is useful when __DEV__ is set to `false` as writing to the console is disabled, but the result of this
+ * method would still get printed as output
+ * @returns {string|undefined}
  */
-function printMetrics(raw = false) {
-    const {totalTime, summaries, lastCompleteCall = {endTime: -1}} = getMetrics();
+function printMetrics({raw = false, format = 'console'} = {}) {
+    const {totalTime, summaries, lastCompleteCall} = getMetrics();
 
-    const prettyData = _.chain(summaries)
+    const tableSummary = MDTable.factory({
+        heading: ['method', 'total time spent', 'max', 'min', 'avg', 'time last call completed', 'calls made'],
+        leftAlignedCols: [0],
+    });
+
+    const methodCallTables = _.chain(summaries)
         .filter(method => method.avg > 0)
         .sortBy('avg')
         .reverse()
-        .map(({
-            calls, methodName, lastCall, ...summary
-        }) => {
-            const prettyTimes = _.chain(summary)
-                .map((value, key) => ([key, toDuration(value, raw)]))
-                .object()
-                .value();
-
-            const prettyCalls = calls.map(call => ({
-                startTime: toDuration(call.startTime, raw),
-                endTime: toDuration(call.endTime, raw),
-                duration: toDuration(call.duration, raw),
-                args: JSON.stringify(call.args)
-            }));
-
-            return {
+        .map(({methodName, calls, ...methodStats}) => {
+            tableSummary.addRow(
                 methodName,
-                ...prettyTimes,
-                'time last call completed': toDuration(lastCall.endTime, raw),
-                calls: calls.length,
-                prettyCalls,
-            };
+                toDuration(methodStats.total, raw),
+                toDuration(methodStats.max, raw),
+                toDuration(methodStats.min, raw),
+                toDuration(methodStats.avg, raw),
+                toDuration(methodStats.lastCall.endTime, raw),
+                calls.length,
+            );
+
+            const callsTable = MDTable.factory({
+                title: methodName,
+                heading: ['start time', 'end time', 'duration', 'args'],
+                leftAlignedCols: [3],
+                rows: calls.map(call => ([
+                    toDuration(call.startTime, raw),
+                    toDuration(call.endTime, raw),
+                    toDuration(call.duration, raw),
+                    call.args.map(String).join(', ').slice(0, 60), // Restrict cell width to 60 chars max
+                ]))
+            });
+
+            return callsTable;
         })
         .value();
 
-    /* eslint-disable no-console */
-    console.group('Onyx Benchmark');
-    console.info('  Total: ', toDuration(totalTime, raw));
-    console.info('  Last call finished at: ', toDuration(lastCompleteCall.endTime, raw));
+    if (/csv|json|string/i.test(format)) {
+        const allTables = [tableSummary, ...methodCallTables];
+
+        return allTables.map((table) => {
+            switch (format.toLowerCase()) {
+                case 'csv':
+                    return table.toCSV();
+                case 'json':
+                    return table.toJSON();
+                default:
+                    return table.toString();
+            }
+        }).join('\n\n');
+    }
 
-    console.table(prettyData.map(({prettyCalls, ...summary}) => summary));
+    const mainOutput = [
+        '### Onyx Benchmark',
+        `  - Total: ${toDuration(totalTime, raw)}`,
+        `  - Last call finished at: ${lastCompleteCall ? toDuration(lastCompleteCall.endTime, raw) : 'N/A'}`,
+        '',
+        tableSummary.toString()
+    ];
 
-    prettyData.forEach((method) => {
-        console.groupCollapsed(`[${method.methodName}] individual calls: `);
-        console.table(method.prettyCalls);
+    /* eslint-disable no-console */
+    console.info(mainOutput.join('\n'));
+    methodCallTables.forEach((table) => {
+        console.groupCollapsed(table.getTitle());
+        console.info(table.toString());
         console.groupEnd();
     });
-
-    console.groupEnd();
     /* eslint-enable */
 }
 
 /**
  * Clears all collected metrics.
  */
 function resetMetrics() {
+    PERFORMANCE_OFFSET = performance.now();
     stats = {};
 }
 

package.json

@@ -12,6 +12,7 @@
     "test": "jest"
   },
   "dependencies": {
+    "ascii-table": "0.0.9",
     "expensify-common": "git+https://github.com/Expensify/expensify-common.git#2e5cff552cf132da90a3fb9756e6b4fb6ae7b40c",
     "lodash": "4.17.21",
     "underscore": "^1.13.1"