Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

xs-worker doesn't tolerate BigInts in console.log() #2936

Closed
warner opened this issue Apr 22, 2021 · 9 comments · Fixed by #2967
Closed

xs-worker doesn't tolerate BigInts in console.log() #2936

warner opened this issue Apr 22, 2021 · 9 comments · Fixed by #2967
Assignees
Labels
bug Something isn't working SwingSet package: SwingSet

Comments

@warner
Copy link
Member

warner commented Apr 22, 2021

Describe the bug

In trying to get the XS worker usable for all vats, one problem I ran into was a vat that did console.log() of a BigInt. The xsnap supervisor is currently sending the log arguments to the supervisor with the same JSON.stringify it uses for all other messages (namely syscalls). This fails (somewhat opaquely) when vat code logs something that can't be serialized this way.

For the local worker, the vat's console.log is routed to two places:

function makeVatConsole(kind, vatID) {
const origConsole = makeConsole(`${debugPrefix}SwingSet:${kind}:${vatID}`);
if (kind === 'ls') {
// LiveSlots is not recorded to kernelSlog.
// The slog captures 1: what a vat is told to do, and
// 2: what a vat says about its activities
return origConsole;
}
return kernelSlog.vatConsole(vatID, origConsole);
}

The first is makeConsole(), which returns an instance of anylogger. The second is the kernelSlot.vatConsole, which wraps the log arguments and ultimately puts them into a serialized JSON object written to the slog file. That serialization special-cases any BigInts:

function writeSlogObject(obj) {
// TODO sqlite
if (slogF) {
const timeMS = performance.timeOrigin + performance.now();
const time = timeMS / 1000;
slogF.write(
JSON.stringify({ time, ...obj }, (_, arg) =>
typeof arg === 'bigint' ? Number(arg) : arg,
),
);
slogF.write('\n');
}
}

For the XS worker, we need to handle this somehow. It's probably sufficient, for now, to just special-case BigInt (i.e. not use a full marshal, and accept the loss of fidelity for debug logs).

That probably means changing this code:

https://github.com/Agoric/agoric-sdk/blob/master/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js#L166-L168

to pre-transform args, like:

port.send(['console', level, tag, ...(JSON.parse(JSON.stringify(args, (_, val) => { if (typeof(val) === 'bigint') { return Number(val); } return val; })))]);

In the long run, we need to nail down what exactly we're willing to tolerate in console.log calls, what precisely is the set of values that might appear in deliveries and syscalls, and make sure all our manager-worker communication pathways can support that full set. Our deliveries and syscalls are fairly conservative, and were designed to be JSON serializable, so it's really console.log that's the outlier.

Testing

We should add a console.log(0n) to our test vat (in test/workers/vat-target.js) to exercise this.

@warner warner added bug Something isn't working SwingSet package: SwingSet labels Apr 22, 2021
@warner warner self-assigned this Apr 22, 2021
@dckc
Copy link
Member

dckc commented Apr 22, 2021

... In the long run, we need to nail down what exactly we're willing to tolerate in console.log calls. ...

Shall I open an issue?

Or was that more of a rhetorical "need" in the sense of "would ideally"?

@warner
Copy link
Member Author

warner commented Apr 22, 2021

Shall I open an issue?

done

@erights
Copy link
Member

erights commented Apr 22, 2021

On what to change it to, try replacing

... JSON.stringify(stuff) ...

with something like

const { quote: q } = assert;
... `${q(stuff)} ...

It was designed for purposes like this --- strings useful for human diagnostics. Anything semantically closer to JSON.stringify will drop too much information on the floor.

@erights
Copy link
Member

erights commented Apr 22, 2021

The algorithm it uses to stringify is at https://github.com/endojs/endo/blob/a7222d745ddc831167996ffaf30ccd7e036fe726/packages/ses/src/error/stringify-utils.js#L22 . Like your suggestion above, it calls JSON.stringify with a replacer. But a much more informative replacer.

warner added a commit that referenced this issue Apr 23, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 23, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 23, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 23, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 23, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 23, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 24, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 24, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 24, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 24, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
warner added a commit that referenced this issue Apr 24, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
@warner
Copy link
Member Author

warner commented Apr 26, 2021

It would be nice to retain whatever structure we can, so I wouldn't want to entirely flatten/stringify the arguments.

@erights this is a case where the serializer (the XS worker child process) wants to deliver full-fidelity information to the unserializer (the kernel process): both sides are as privileged as we get. Is there a way to use details here that enables full data retention?

@dckc I'm going to hand this one to you. The patch I started with is f55e733 (which includes a test). Please see if you can adapt @erights 's approach to it.

@warner warner assigned dckc and unassigned warner Apr 26, 2021
@warner warner added this to the Testnet: Staking Dynamics milestone Apr 26, 2021
@erights
Copy link
Member

erights commented Apr 26, 2021

I don't understand. The full fidelity approach is marshal. But this is about logging. What role does any kind of unserialization have in logging?

@dckc
Copy link
Member

dckc commented Apr 26, 2021

The code is trying to pass the individual console.log args from one process to another without lumping them all together... though f55e733 lumps them together and parses them back out only to lump them back together for transport, after which they get parsed apart again.

dckc pushed a commit that referenced this issue Apr 26, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
dckc pushed a commit that referenced this issue Apr 26, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
@warner
Copy link
Member Author

warner commented Apr 26, 2021

Oh, I should mention that we must not harden the console.log arguments.. that would be awfully surprising for developers (especially when they're debugging something and add temporary logging of intermediate results, like a list that is still being mutated). Which means we can't just use marshal to deliver the arguments from worker process to kernel process, as simple and elegant as that would be.

@erights
Copy link
Member

erights commented Apr 26, 2021

You can certainly use ${q(stuff)} on each argument separately. But this just preserves the separateness of the arguments. Beyond that, I still don't understand. What are you unserializing them to? What are you trying preserve of the original meaning? For what purpose?

dckc pushed a commit that referenced this issue Apr 27, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
dckc added a commit that referenced this issue Apr 27, 2021
* fix(swingset): supervisor-xs: tolerate console.log(BigInt)

We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936

* chore(xs-worker): use assert.q replacer to handle bigint etc.

* test(swingset): console.log doesn't harden args

Co-authored-by: Brian Warner <warner@lothar.com>
dckc pushed a commit that referenced this issue May 13, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
dckc pushed a commit that referenced this issue May 17, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
dckc pushed a commit that referenced this issue May 18, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
dckc pushed a commit that referenced this issue May 19, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
dckc pushed a commit that referenced this issue Jun 14, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
dckc pushed a commit that referenced this issue Jun 14, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
dckc pushed a commit that referenced this issue Jun 15, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
dckc pushed a commit that referenced this issue Jun 15, 2021
We serialize console.log arguments (to send over the pipe to the kernel
process) with JSON.stringify, which doesn't tolerate BigInt. Use a simple
replacer to turn them into Numbers first; we can tolerate the loss of
fidelity for console.log.

closes #2936
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working SwingSet package: SwingSet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants