feat(SwingSet): track the meter usage in deliverResults[2]

This works for local vats, and should also work for xsnap.  The
results are surfaced in the slog as well as Prometheus.

packages/SwingSet/src/kernel/slogger.js

@@ -22,7 +22,7 @@ function makeCallbackRegistry(callbacks) {
       const cb = callbacks[method];
       if (!cb) {
         // No registered callback, just use the implementation directly.
-        console.error('no registered callback for', method);
+        // console.error('no registered callback for', method);
         return impl;
       }
 
@@ -143,9 +143,9 @@ export function makeSlogger(slogCallbacks, writeObj) {
       syscallNum = 0;
 
       // dr: deliveryResult
-      function finish(dr, stats) {
+      function finish(dr) {
         assertOldState(DELIVERY, 'delivery-finish called twice?');
-        write({ type: 'deliver-result', ...when, dr, stats });
+        write({ type: 'deliver-result', ...when, dr });
         state = IDLE;
       }
       return harden(finish);

packages/SwingSet/src/kernel/vatManager/deliver.js

@@ -1,6 +1,7 @@
 import { assert, details as X } from '@agoric/assert';
 import { insistMessage } from '../../message';
 
+const METER_TYPE = 'tame-metering-1';
 export function makeDeliver(tools, dispatch) {
   const {
     meterRecord,
@@ -51,16 +52,16 @@ export function makeDeliver(tools, dispatch) {
     await runAndWait(() => dispatch[dispatchOp](...dispatchArgs), errmsg);
     stopGlobalMeter();
 
-    let status = ['ok'];
+    let status = ['ok', null, null];
     // refill this vat's meter, if any, accumulating its usage for stats
     if (meterRecord) {
       // note that refill() won't actually refill an exhausted meter
-      const used = meterRecord.refill();
+      status[2] = { ...meterRecord.refill(), meterType: METER_TYPE };
       const exhaustionError = meterRecord.isExhausted();
       if (exhaustionError) {
-        status = ['error', exhaustionError.message];
+        status = ['error', exhaustionError.message, status[2]];
       } else {
-        updateStats(used);
+        updateStats(status[2]);
       }
     }
 

packages/SwingSet/src/kernel/vatManager/manager-subprocess-xsnap.js

@@ -169,7 +169,15 @@ export function makeXsSubprocessFactory({
       const result = await issueTagged(['deliver', ...delivery]);
       parentLog(vatID, `deliverDone`, result.reply[0], result.reply.length);
       transcriptManager.finishDispatch();
-      return result.reply;
+
+      // Attach the crank stats to the deliver result.
+      /** @type {Tagged} */
+      const deliverResult = [
+        result.reply[0], // 'ok' or 'error'
+        result.reply[1] || null, // problem or null
+        result.crankStats || null, // meter usage statistics or null
+      ];
+      return harden(deliverResult);
     }
 
     async function replayTranscript() {

packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js

@@ -109,7 +109,7 @@ function abbreviateReplacer(_, arg) {
 function runAndWait(f, errmsg) {
   Promise.resolve()
     .then(f)
-    .then(undefined, err => {
+    .catch(err => {
       workerLog(`doProcess: ${errmsg}:`, err.message);
     });
   return waitUntilQuiescent();

packages/cosmic-swingset/lib/launch-chain.js

@@ -14,7 +14,7 @@ import {
   loadBasedir,
   loadSwingsetConfigFile,
 } from '@agoric/swingset-vat';
-import { assert, details as X } from '@agoric/assert';
+import { assert, details as X, quote } from '@agoric/assert';
 import makeStore from '@agoric/store';
 import { getBestSwingStore } from './check-lmdb';
 import { exportKernelStats } from './kernel-stats';
@@ -139,9 +139,23 @@ export async function launch(
       description: 'Vat delivery time (ms)',
     }),
   );
+  nameToBaseMetric.init(
+    'swingset_meter_usage',
+    metricMeter.createValueRecorder('swingset_meter_usage', {
+      description: 'Vat meter usage',
+    }),
+  );
   const vatToMetrics = makeStore();
 
-  const getVatMetric = (vatID, name) => {
+  /**
+   * This function reuses or creates per-vat named metrics.
+   *
+   * @param {string} vatID id of the vat to label the metric with
+   * @param {string} name name of the base metric
+   * @param {Record<string, string>} [labels] the metric statistic
+   * @returns {any} the labelled metric
+   */
+  const getVatMetric = (vatID, name, labels = {}) => {
     let nameToMetric;
     if (vatToMetrics.has(vatID)) {
       nameToMetric = vatToMetrics.get(vatID);
@@ -150,12 +164,15 @@ export async function launch(
       vatToMetrics.init(vatID, nameToMetric);
     }
     let metric;
-    if (nameToMetric.has(name)) {
-      metric = nameToMetric.get(name);
+    const labeledName = `${name}:${quote(labels)}`;
+    if (nameToMetric.has(labeledName)) {
+      metric = nameToMetric.get(labeledName);
     } else {
       // Bind the base metric to the vatID label.
-      metric = nameToBaseMetric.get(name).bind({ ...METRIC_LABELS, vatID });
-      nameToMetric.init(name, metric);
+      metric = nameToBaseMetric
+        .get(name)
+        .bind({ ...METRIC_LABELS, vatID, ...labels });
+      nameToMetric.init(labeledName, metric);
     }
     return metric;
   };
@@ -171,8 +188,24 @@ export async function launch(
       });
     },
     delivery(_method, [vatID], finisher) {
-      return wrapDeltaMS(finisher, (deltaMS, [_dr, _stats]) => {
-        // console.info(vatID, 'delivery.finish', stats);
+      return wrapDeltaMS(finisher, (deltaMS, [[_status, _problem, used]]) => {
+        if (used) {
+          // Add to aggregated metering stats.
+          const labels = {};
+          if (used.meterType) {
+            labels.meterType = used.meterType;
+          }
+          for (const [key, value] of Object.entries(used)) {
+            if (key === 'meterType') {
+              // eslint-disable-next-line no-continue
+              continue;
+            }
+            getVatMetric(vatID, `swingset_meter_usage`, {
+              ...labels,
+              stat: key,
+            }).record(value || 0);
+          }
+        }
         getVatMetric(vatID, 'swingset_vat_delivery').record(deltaMS);
       });
     },