Allocate just one `ClosureTable` entry per self-send by ggreif · Pull Request #2663 · caffeinelabs/motoko

ggreif · 2021-07-16T12:32:32Z

This PR cleans up the ClosureTable entries in the last-resort cleanup callback. Since potentially all call and reply state changes of a canister can be rolled back by carefully engineering the traps, the initiator of a message send must only allocate exactly one slot in the closure table. Formerly self-sends would leak a slot when the receiver trapped and the reject callback too. See #2663 (comment).

Motivation: fixes #2640

undortunatrely I still see ``` trace: Warning: `stdenv.lib` is deprecated and will be removed in the next release. Please use `lib` instead. For more information see NixOS/nixpkgs#108938 ```

... but I don't see the `ping! ...` log line :-(

dfinity-ci · 2021-07-16T12:34:28Z

This PR does not affect the produced WebAssembly code.

but I cannot see yet how oneshot is involved

still no closures lost by oneshot

These are copies from `run-drun/ok/count-callbacks.*`, but strangely running `accept` won't refresh them!?

Fun thing is that these appear for other tests than the one _designed to trigger_ it. The plot thickens...

must be a Motoko test from an inner directory

this triggers for ``` make -C test/run-drun commit-on-await.only make -C test/run-drun await-without-yield.only ``` but strangely not for ``` make -C test/run-drun oneshot-callbacks.only ``` It remains to be investigated why this is the case. Also I see `ping` being rejected (or at least the reject callback being called) for one-shot sends.

this is the current trace: oneshot-callbacks: [tc] [comp] [comp-ref] [valid] [valid-ref] [ic-ref-run] --- oneshot-callbacks.ic-ref-run (expected) +++ oneshot-callbacks.ic-ref-run (actual) @@ -4,19 +4,67 @@ ← replied: () → update go() debug.print: go 0: 0 +debug.print: remember_closure: 0 +debug.print: remember_closure: 1 debug.print: ping! 2 +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT debug.print: go 1: 1 +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: remember_closure: 1 +debug.print: remember_closure: 0 debug.print: ping! 2 -← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.26-14.38" +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: go 2: 1 +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT +debug.print: IN REJECT callback +← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.98-14.110" → update go() debug.print: go 0: 1 +debug.print: remember_closure: 0 +debug.print: remember_closure: 2 debug.print: ping! 3 +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT debug.print: go 1: 2 +debug.print: recall_closure: 2 +debug.print: recall_closure: 2 OUT +debug.print: remember_closure: 2 +debug.print: remember_closure: 0 debug.print: ping! 3 -← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.26-14.38" +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 2 +debug.print: recall_closure: 2 OUT +debug.print: go 2: 2 +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT +debug.print: IN REJECT callback +← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.98-14.110" → update go() debug.print: go 0: 2 +debug.print: remember_closure: 0 +debug.print: remember_closure: 3 debug.print: ping! 4 +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT debug.print: go 1: 3 +debug.print: recall_closure: 3 +debug.print: recall_closure: 3 OUT +debug.print: remember_closure: 3 +debug.print: remember_closure: 0 debug.print: ping! 4 -← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.26-14.38" +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 3 +debug.print: recall_closure: 3 OUT +debug.print: go 2: 3 +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT +debug.print: IN REJECT callback +← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.98-14.110" Some tests failed: oneshot-callbacks.mo I *think* I understand this by now :-)

…leak This doesn't handle the case yet where the reject traps, but the testcase doesn't implement that just yet. Here comes the evidence trace: ``` oneshot-callbacks: [tc] [comp] [comp-ref] [valid] [valid-ref] [ic-ref-run] --- oneshot-callbacks.ic-ref-run (expected) +++ oneshot-callbacks.ic-ref-run (actual) @@ -4,19 +4,73 @@ ← replied: () → update go() debug.print: go 0: 0 +debug.print: remember_closure: 0 +debug.print: remember_closure: 1 debug.print: ping! 2 +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT debug.print: go 1: 1 +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: remember_closure: 1 +debug.print: remember_closure: 0 debug.print: ping! 2 -← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.26-14.38" +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: go 2: 1 +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: IN SELF REJECT callback +← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.98-14.110" → update go() -debug.print: go 0: 1 -debug.print: ping! 3 -debug.print: go 1: 2 -debug.print: ping! 3 -← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.26-14.38" +debug.print: go 0: 0 +debug.print: remember_closure: 1 +debug.print: remember_closure: 0 +debug.print: ping! 2 +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: go 1: 1 +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT +debug.print: remember_closure: 0 +debug.print: remember_closure: 1 +debug.print: ping! 2 +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT +debug.print: go 2: 1 +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT +debug.print: IN SELF REJECT callback +← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.98-14.110" → update go() -debug.print: go 0: 2 -debug.print: ping! 4 -debug.print: go 1: 3 -debug.print: ping! 4 -← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.26-14.38" +debug.print: go 0: 0 +debug.print: remember_closure: 0 +debug.print: remember_closure: 1 +debug.print: ping! 2 +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT +debug.print: go 1: 1 +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: remember_closure: 1 +debug.print: remember_closure: 0 +debug.print: ping! 2 +debug.print: RECALLING, but this may trap and gets undone +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: go 2: 1 +debug.print: recall_closure: 0 +debug.print: recall_closure: 0 OUT +debug.print: recall_closure: 1 +debug.print: recall_closure: 1 OUT +debug.print: IN SELF REJECT callback +← rejected (RC_CANISTER_REJECT): canister trapped: EvalTrapError region:0xXXX-0xXXX "canister trapped explicitly: assertion failed at oneshot-callbacks.mo:14.98-14.110" Some tests failed: oneshot-callbacks.mo ```

instead, perpetuate the argument directly

ggreif · 2021-07-22T14:50:17Z

We have several problems currently.
a) non-self-send async methods may invoke a reply/reject continuation that traps. The index allocated in the ClosureTable and what it points to will never be deallocated.
b) Explicit self-sends allocate ClosureTable index (for the future) that is supposed to be removed on the other side of the call. If that traps, the sender-side becomes the owner of the future's slot. Then the reject callback gets invoked and can (additionally) pop it. The trouble starts when the reject callback also traps. Then the cleanup callback will be invoked and must clean up two slots. But the problem is that if the reply callback trapped it only needs to clean-up one slot. Alas, the cleanup callback has no information whatsoever what happened.

For a) the solution is easy, pop the one slot in the cleanup callback.
For b) we have to consolidate the two slots to one (pointing to a 3-element array) in which the other side can peek to fetch the future. This reduces the problem to a), for which we have a solution.

crusso · 2021-07-22T16:11:32Z

To avoid serializing/deserializing the result of the future, if wonder if it would make sense to transfer it in a fourth slot of that array?

ggreif · 2021-07-22T17:34:41Z

To avoid serializing/deserializing the result of the future, if wonder if it would make sense to transfer it it in a fourth slot of that array?

Yep, I was thinking overwriting the third position of the array (i.e. the future) since that is not needed any more. But sending the payload back in heap changes the semantics a bit, so I'd only do that for single, small results.

Update: this is #2679 now.

this means _the other side_ never owns a table slot and must simply peek into the array to fetch the future's closure cleanup becomes the same as a foreign send's

review feedback

test/run-drun/oneshot-callbacks.mo

and implement `ic_call` and `ic_self_call` in terms of it

crusso

LGTM.

(Good you refactored the ic_(self)_call too - wasn't actually asking for that ;->)

src/codegen/compile.ml

crusso

LGTM.

(Good you refactored the ic_(self)_call too - wasn't actually asking for that ;->)

(One formatting change only)

review feedback

This is a wholesale rename, in the spirit of #2663 (comment)

nomeata · 2021-08-09T10:55:29Z

Thanks for this! I had quite some trouble figuring out what’s happening based on the patch only, but the comment in #2663 (comment) helped. Maybe worth expanding the code comments a bit, so that future readers (who don’t have the benefit of the PR discussion) can make sense of it? Probably one comprehensive GHC-style code node that explains how async self-calls works would be useful.

ggreif added 3 commits July 13, 2021 14:57

a bit of nix gardening

643a4d6

undortunatrely I still see ``` trace: Warning: `stdenv.lib` is deprecated and will be removed in the next release. Please use `lib` instead. For more information see NixOS/nixpkgs#108938 ```

simplify nix/xargo.nix

8bec1ca

first draft of a oneshot_ping testcase

8967dc1

... but I don't see the `ping! ...` log line :-(

ggreif added 16 commits July 16, 2021 16:19

reproduce the callback table growth

2d1e626

but I cannot see yet how oneshot is involved

smething more interesting

c2dc791

still no closures lost by oneshot

add the ok/ files

b700116

These are copies from `run-drun/ok/count-callbacks.*`, but strangely running `accept` won't refresh them!?

patch this based on the raw log

a59ebd0

this too

e94aa7a

use compile_exp_vanilla where possible

0ef6f23

Merge remote-tracking branch 'origin/master' into gabor/cleanup

da004b9

install cleanup_callback to be called when either reply or reject traps

aa03c04

Fun thing is that these appear for other tests than the one _designed to trigger_ it. The plot thickens...

add makefile helper to only run a single test

6504a1e

must be a Motoko test from an inner directory

fix

06394cb

exercise the reject path

aee0943

beef-up the testcase

97315b4

WIP: don't serialise at all when self-sending

804964d

instead, perpetuate the argument directly

ggreif added 4 commits July 23, 2021 13:05

WIP: transition to a single closure table index scheme

dfc02fa

this means _the other side_ never owns a table slot and must simply peek into the array to fetch the future's closure cleanup becomes the same as a foreign send's

clean up and fmt

dfc3f87

another cleanup

6368748

more cleanup

70444fe

ggreif force-pushed the gabor/cleanup branch from 03fe1e4 to 70444fe Compare July 23, 2021 19:30

ggreif added 2 commits July 23, 2021 21:41

fmt

7a555a5

undo the butcher job I inflicted on poor @reject_callback

f9bca48

ggreif added 7 commits July 29, 2021 10:24

Merge branch 'master' into gabor/cleanup

93342e2

add a recursive invocation test with futures

cdf94f6

review feedback

make the test more interesting

0fb93b4

update test output

3d6323b

WIP: factor out stash_closures

40a6d15

break out stash_closures_pushing_callbacks

9adabc1

WIP: partial application, less of a cool trick

8b8660b

crusso reviewed Jul 29, 2021

View reviewed changes

test/run-drun/oneshot-callbacks.mo Show resolved Hide resolved

ggreif added 7 commits July 29, 2021 12:05

WIP: break out message_reject_callback

1b17d1d

clean up

3c1fee0

WIP: sync

8f48924

move stuff back into closures_to_reply_reject_callbacks

251207f

tidy up the comments

cf91635

WIP: factor out ic_call_threaded

27ab45a

and implement `ic_call` and `ic_self_call` in terms of it

tweak the comments and clean up

34a2c7a

ggreif requested a review from crusso July 29, 2021 11:11

crusso reviewed Jul 29, 2021

View reviewed changes

src/codegen/compile.ml Outdated Show resolved Hide resolved

crusso approved these changes Jul 29, 2021

View reviewed changes

reindent

dacf7cc

review feedback

ggreif added the automerge-squash When ready, merge (using squash) label Jul 29, 2021

Merge branch 'master' into gabor/cleanup

418dced

mergify bot merged commit 7c95059 into master Jul 29, 2021

mergify bot deleted the gabor/cleanup branch July 29, 2021 12:28

mergify bot removed the automerge-squash When ready, merge (using squash) label Jul 29, 2021

ggreif mentioned this pull request Jul 29, 2021

Rename: closure*table -> continuation*table #2690

Merged

mergify bot pushed a commit that referenced this pull request Jul 30, 2021

Rename: closure*table -> continuation*table (#2690)

6dfd0ae

This is a wholesale rename, in the spirit of #2663 (comment)

ggreif mentioned this pull request Jul 30, 2021

build: niv motoko: update bd98d37a -> 44f7f18b dfinity/sdk#1778

Merged

nomeata mentioned this pull request Nov 26, 2021

Trap in callback makes canister unupgradeable #2937

Closed

ggreif mentioned this pull request Dec 10, 2021

Use an invalid table index as the callback for one-way functions #2942

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Comments

Allocate just one `ClosureTable` entry per self-send#2663

Allocate just one `ClosureTable` entry per self-send#2663
mergify[bot] merged 65 commits intomasterfrom
gabor/cleanup

ggreif commented Jul 16, 2021 •

edited

Loading

Uh oh!

dfinity-ci commented Jul 16, 2021

Uh oh!

ggreif commented Jul 22, 2021 •

edited

Loading

Uh oh!

crusso commented Jul 22, 2021 •

edited by ggreif

Loading

Uh oh!

ggreif commented Jul 22, 2021 •

edited

Loading

Uh oh!

Uh oh!

crusso left a comment

Uh oh!

Uh oh!

crusso left a comment

Uh oh!

nomeata commented Aug 9, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

Comments

Conversation

ggreif commented Jul 16, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

dfinity-ci commented Jul 16, 2021

Uh oh!

ggreif commented Jul 22, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

crusso commented Jul 22, 2021 • edited by ggreif Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ggreif commented Jul 22, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

crusso left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

crusso left a comment

Choose a reason for hiding this comment

Uh oh!

nomeata commented Aug 9, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

ggreif commented Jul 16, 2021 •

edited

Loading

ggreif commented Jul 22, 2021 •

edited

Loading

crusso commented Jul 22, 2021 •

edited by ggreif

Loading

ggreif commented Jul 22, 2021 •

edited

Loading