feat(SwingSet): Echo kernel console output to the slog

[gibson042]

Fixes #10776

Description

After a lot of refactoring, makes the relatively simple change of endowing the compartment in which the kernel runs with a console whose methods are augmented to write slog entries. Best reviewed by commit.

Security Considerations

Security posture should not be affected.

Scaling Considerations

The slog will gain new entries, but kernel logging tends to be reasonably small AFAIK.

Documentation Considerations

Anything consuming slogfiles (such as for telemetry reporting) should be prepared to encounter entries with type "console" and source "kernel".

Testing Considerations

Manual confirmation per #10776:

slog excerpts

{"type":"terminate","vatID":"v12","shouldReject":false,"info":{"body":"#\"payment retrieved\"","slots":[]},"time":1738358161.052329,"monotime":71.14055863702298}
{"type":"console","source":"kernel","args":["kernel terminating vat v12 (failure=false)"],"time":1738358161.052675,"monotime":71.14090518701076}
{"type":"crank-finish","crankNum":407,"crankhash":"38659f7b8b9b1628e74ca7fdd0fef9d8a4706ddf6cd78e8698aae891c558ffb2","activityhash":"b5bb680d4f6641fa9256fb68672d1fd0644462930576b0b08f4f8ba6ed80dcd9","time":1738358161.059831,"monotime":71.14806092399358}
{"type":"crank-start","crankType":"routing","crankNum":408,"message":{"type":"send","target":"ko107","msg":{"methargs":{"body":"#[\"exitAllSeats\",[\"payment retrieved\"]]","slots":[]},"result":"kp140"}},"time":1738358161.06028,"monotime":71.14851041698456}
{"type":"crank-finish","crankNum":408,"crankhash":"994c78a3c5c6cecd51f656cf7202b7ee7e1d594e0c8bf5440b0b5d3d2ddffeb3","activityhash":"12eabf17b96cd47b11554750cc910e01110fbb33e40ba7fa8d63f0d120946ecf","time":1738358161.060456,"monotime":71.1486860319972}
{"type":"crank-start","crankType":"routing","crankNum":409,"message":{"type":"notify","vatID":"v1","kpid":"kp139"},"time":1738358161.060624,"monotime":71.14885371297598}

{"type":"crank-finish","crankNum":5051,"crankhash":"c541bb4757bf6a14f5f889d1d1d1864a4aa0c4cc69f64463c10c6827b6a1d7aa","activityhash":"dc641db0486240e2a15f86f88ee8caa9440803b4f818f9b262f4204d763f6594","time":1738358367.758784,"monotime":277.8470162190199}
{"type":"crank-start","crankType":"delivery","crankNum":5052,"message":{"type":"send","target":"ko349","msg":{"methargs":{"body":"#[\"update\",[\"osmosis-1_shido__9008-1\",{\"client_id\":\"07-tendermint-3198\",\"counterparty\":{\"client_id\":\"07-tendermint-0\",\"connection_id\":\"connection-0\"},\"id\":\"connection-2654\",\"state\":3,\"transferChannel\":{\"channelId\":\"channel-73755\",\"counterPartyChannelId\":\"channel-0\",\"counterPartyPortId\":\"transfer\",\"ordering\":0,\"portId\":\"transfer\",\"state\":3,\"version\":\"ics20-1\"}}]]","slots":[]},"result":"kp1257"}},"time":1738358367.7592,"monotime":277.8474297670126}
{"type":"clist","crankNum":5052,"mode":"import","vatID":"v6","kobj":"kp1257","vobj":"p-394","time":1738358367.759473,"monotime":277.84770355999467}
{"type":"deliver","crankNum":5052,"vatID":"v6","deliveryNum":599,"replay":false,"kd":["message","ko349",{"methargs":{"body":"#[\"update\",[\"osmosis-1_shido__9008-1\",{\"client_id\":\"07-tendermint-3198\",\"counterparty\":{\"client_id\":\"07-tendermint-0\",\"connection_id\":\"connection-0\"},\"id\":\"connection-2654\",\"state\":3,\"transferChannel\":{\"channelId\":\"channel-73755\",\"counterPartyChannelId\":\"channel-0\",\"counterPartyPortId\":\"transfer\",\"ordering\":0,\"portId\":\"transfer\",\"state\":3,\"version\":\"ics20-1\"}}]]","slots":[]},"result":"kp1257"}],"vd":["message","o+d10/10:0",{"methargs":{"body":"#[\"update\",[\"osmosis-1_shido__9008-1\",{\"client_id\":\"07-tendermint-3198\",\"counterparty\":{\"client_id\":\"07-tendermint-0\",\"connection_id\":\"connection-0\"},\"id\":\"connection-2654\",\"state\":3,\"transferChannel\":{\"channelId\":\"channel-73755\",\"counterPartyChannelId\":\"channel-0\",\"counterPartyPortId\":\"transfer\",\"ordering\":0,\"portId\":\"transfer\",\"state\":3,\"version\":\"ics20-1\"}}]]","slots":[]},"result":"p-394"}],"time":1738358367.759596,"monotime":277.8478261709809}
{"type":"console","source":"kernel","args":["error in kernel.deliver:",{"name":"ExitSignal","code":"SIGINT"}],"time":1738358367.780067,"monotime":277.86829756200314}

Upgrade Considerations

This tweaks some typing in packages/swingset-liveslots/src/liveslots.js and adds some utilities to package "internal", but everything else is kernel code that is not subject to and does not affect consensus.

Release verification should look for slog entries like the above (type "console" and source "kernel").

[cloudflare-workers-and-pages]

Deploying agoric-sdk with    Cloudflare Pages

Latest commit:	8cfe644
Status:	✅  Deploy successful!
Preview URL:	https://b46807e8.agoric-sdk.pages.dev
Branch Preview URL:	https://gh-10776-kernel-console-slog.agoric-sdk.pages.dev

View logs

[gibson042]

I'm considering reducing this even further:

  const unusedWrapperMsg = 'Unused makeSlogger slogCallbacks method names';
  const wrappedMethods = addSlogCallbacks(slogCallbacks, unusedWrapperMsg, {
    provideVatSlogger,
    vatConsole: (vatID, ...args) =>
      provideVatSlogger(vatID).vatSlog.vatConsole(...args),
    ),
    startup: (vatID, ...args) =>
      provideVatSlogger(vatID).vatSlog.startup(...args),
    ),
    …
  });
  return harden({ ...wrappedMethods, write: safeWrite });

[gibson042]

Would it be worth indicating that each SlogWrapper method can return a finisher, even though that information would be subsumed in many places?

Suggested change

	/** @typedef {Partial<Record<Exclude<keyof KernelSlog, 'write'>, (methodName: string, args: unknown[], finisher: AnyFinisher) => unknown>>} SlogWrappers */
	/** @typedef {Partial<Record<Exclude<keyof KernelSlog, 'write'>, (methodName: string, args: unknown[], finisher: AnyFinisher) => (AnyFinisher | unknown)>>} SlogWrappers */

[gibson042]

I can't find any use of this method: https://github.com/search?q=repo%3AAgoric%2Fagoric-sdk%20replayVatTranscript&type=code

[gibson042]

It's weird that we map source "ls" to "liveslots" in the slog but not in console output. For that matter, it's weird that we use an abbreviation just to reverse it anyway.