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

Error in vault task #30

Closed
mhofman opened this issue Sep 17, 2021 · 12 comments
Closed

Error in vault task #30

mhofman opened this issue Sep 17, 2021 · 12 comments
Assignees

Comments

@mhofman
Copy link
Member

mhofman commented Sep 17, 2021

When running a vault loadgen task, some I believe Zoe originating error crops up. amm tasks run fine, both before and after, so it's probably not a metering issue.

This is happening on Agoric/agoric-sdk@d48e6a7

stage-0: loadgen: starting vault [2], active=1 at Fri Sep 17 2021 15:52:25 GMT+0000 (Coordinated Universal Time)
stage-0: loadgen: {"time":1631893945.062216,"type":"start","task":"vault","seq":2}
stage-0: chain: 3:52PM INF Timed out dur=4983.352474 height=104 module=consensus round=0 step=1
stage-0: chain: 3:52PM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"27395A3254D69585CADD077807FB4AB434E540DB4FB11D91F362C0F3EB3C2A50","parts":{"hash":"84DA044272E0F53236CD978EDA9386E73351F71B46FD35C6AF586C5291D29536","total":1}},"height":104,"pol_round":-1,"round":0,"signature":"v/rQCGnevDnz5KCoKWX3eEy99QL4kYrgdU82EJLoL8n3U4nYLiX5K4Y0S1GEHnYk0nAJDDYeBRm3+I43xqQsAQ==","timestamp":"2021-09-17T15:52:25.346451704Z"}
stage-0: chain: 3:52PM INF received complete proposal block hash=27395A3254D69585CADD077807FB4AB434E540DB4FB11D91F362C0F3EB3C2A50 height=104 module=consensus
stage-0: chain: 3:52PM INF finalizing commit of block hash=27395A3254D69585CADD077807FB4AB434E540DB4FB11D91F362C0F3EB3C2A50 height=104 module=consensus num_txs=0 root=79391116436782A9A2FBBAF43C2081DF2BC894CCC7148255EB472CBFC0154BCE
stage-0: chain: 2021-09-17T15:52:25.365Z block-manager: block 104 begin
stage-0: monitor-chain: slog event cosmic-swingset-begin-block delay 7 ms
stage-0: monitor-chain: begin-block 104
stage-0: monitor-chain: slog event cosmic-swingset-end-block-start delay 3 ms
stage-0: monitor-chain: slog event cosmic-swingset-end-block-finish delay 2 ms
stage-0: monitor-chain: end-block 104 linesInBlock= 0
stage-0: chain: 3:52PM INF executed block height=104 module=state num_invalid_txs=0 num_valid_txs=0
stage-0: chain: 2021-09-17T15:52:25.377Z block-manager: block 104 commit
stage-0: chain: 3:52PM INF commit synced commit=436F6D6D697449447B5B31332036203235332031343120373720313036203633203130352035392032313720313034203132382032323720323230203433203131352031333720323337203231342038392031303220313032203139362037332031333820313937203430203136382031303420313230203131382037375D3A36387D
stage-0: chain: 3:52PM INF committed state app_hash=0D06FD8D4D6A3F693BD96880E3DC2B7389EDD6596666C4498AC528A86878764D height=104 module=state num_txs=0
stage-0: chain: 3:52PM INF indexed block height=104 module=txindex
stage-0: client: 2021-09-17T15:52:26.205Z chain-cosmos-sdk: gas estimate: 49085
stage-0: chain: 3:52PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
stage-0: chain: 3:52PM INF No addresses to dial. Falling back to seeds module=pex
stage-0: chain: 3:52PM INF Timed out dur=4973.735312 height=105 module=consensus round=0 step=1
stage-0: chain: 3:52PM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"6AE5AC1FD7C296054DFCC6406785D7B6F79772790A4F088FEF4606364172875B","parts":{"hash":"1EFF82FAF50DDE6FDC78BFD23A8D375B5C9FE6DB7D09329CCF5D4C1574AF8672","total":1}},"height":105,"pol_round":-1,"round":0,"signature":"DpdHClVSogqZvAvc9SJ+U4lEoq2v8Pl373/whsdioU0D3C/OIyiEM3MkoH1/ZRR+DRjIbQMvYnO6cUP2tQT0Dw==","timestamp":"2021-09-17T15:52:30.372301607Z"}
stage-0: chain: 3:52PM INF received complete proposal block hash=6AE5AC1FD7C296054DFCC6406785D7B6F79772790A4F088FEF4606364172875B height=105 module=consensus
stage-0: chain: 3:52PM INF finalizing commit of block hash=6AE5AC1FD7C296054DFCC6406785D7B6F79772790A4F088FEF4606364172875B height=105 module=consensus num_txs=1 root=0D06FD8D4D6A3F693BD96880E3DC2B7389EDD6596666C4498AC528A86878764D
stage-0: chain: 2021-09-17T15:52:30.388Z block-manager: block 105 begin
stage-0: monitor-chain: slog event cosmic-swingset-begin-block delay 3 ms
stage-0: monitor-chain: begin-block 105
stage-0: monitor-chain: slog event cosmic-swingset-end-block-start delay 2 ms
stage-0: chain: 3:52PM INF burned tokens from module account amount=135955ubld from=vbank module=x/bank
stage-0: chain: Logging sent error stack (Error#4)
stage-0: chain: Error#4: Withdrawal of [object Object] failed because the purse only contained [object Object]
stage-0: chain: Error: Withdrawal of (an object) failed because the purse only contained (an object)
stage-0: chain:  at makeError (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:3527)
stage-0: chain:  at fail (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:3655)
stage-0: chain:  at baseAssert (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:3673)
stage-0: chain:  at withdraw (/bundled-source/.../packages/ERTP/src/paymentLedger.js:296)
stage-0: chain:  at (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:123)
stage-0: chain:  at win (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:583)
stage-0: chain:  at ()
stage-0: chain: 
stage-0: chain: Error#4 ERROR_NOTE: Thrown from: (Error#5) : 833 . 0
stage-0: chain: Error#4 ERROR_NOTE: Rejection from: (Error#6) : 829 . 0
stage-0: chain: Error#4 ERROR_NOTE: Sent as error:liveSlots:v10#70002
stage-0: chain: Error#5: Event: 832.1
stage-0: chain: Error: Event: 832.1
stage-0: chain:  at construct ()
stage-0: chain:  at Error (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:8983)
stage-0: chain:  at trackTurns (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:107)
stage-0: chain:  at handle (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:571)
stage-0: chain:  at (/bundled-source/.../packages/eventual-send/src/E.js:38)
stage-0: chain:  at transferFeeToCreator (/bundled-source/.../packages/zoe/src/zoeService/startInstance.js:167)
stage-0: chain:  at transferFeeToCreator ()
stage-0: chain:  at offer (/bundled-source/.../packages/zoe/src/zoeService/offer/offer.js:66)
stage-0: chain:  at ()
stage-0: chain:  at ()
stage-0: chain: 
stage-0: chain: Error#6: Event: 828.1
stage-0: chain: Error: Event: 828.1
stage-0: chain:  at construct ()
stage-0: chain:  at Error (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:8983)
stage-0: chain:  at trackTurns (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:107)
stage-0: chain:  at handle (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:571)
stage-0: chain:  at deliver (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:7414)
stage-0: chain:  at dispatchToUserspace (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:7697)
stage-0: chain:  at runWithoutMetering (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:8074)
stage-0: chain:  at ()
stage-0: chain: 
stage-0: monitor-chain: slog event cosmic-swingset-end-block-finish delay 1 ms
stage-0: monitor-chain: end-block 105 linesInBlock= 1300
stage-0: chain: 3:52PM INF executed block height=105 module=state num_invalid_txs=0 num_valid_txs=1
stage-0: chain: 2021-09-17T15:52:30.804Z block-manager: block 105 commit
stage-0: chain: 3:52PM INF commit synced commit=436F6D6D697449447B5B3933203338203137342032352037203230302031393720323234203539203737203138362031383520323336203234342031353120343120313539203131332036203431203136322032333420393620313337203533203233332036352031343720323230203939203132352037375D3A36397D
stage-0: chain: 3:52PM INF committed state app_hash=5D26AE1907C8C5E03B4DBAB9ECF497299F710629A2EA608935E94193DC637D4D height=105 module=state num_txs=1
stage-0: chain: 3:52PM INF indexed block height=105 module=txindex
stage-0: client: Logging sent error stack (RemoteError(error:liveSlots:v10#70002)#4)
stage-0: client: RemoteError(error:liveSlots:v10#70002)#4: Withdrawal of (an object) failed because the purse only contained (an object)
stage-0: client: Error: Withdrawal of (an object) failed because the purse only contained (an object)
stage-0: client:  at construct ()
stage-0: client:  at Error (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:8983)
stage-0: client:  at makeError (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:3527)
stage-0: client:  at fullRevive (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:4624)
stage-0: client:  at unserialize (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:4714)
stage-0: client:  at notifyOnePromise (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:7493)
stage-0: client:  at notify (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:7506)
stage-0: client:  at dispatchToUserspace (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:7702)
stage-0: client:  at runWithoutMetering (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:8074)
stage-0: client:  at ()
stage-0: client: 
stage-0: client: RemoteError(error:liveSlots:v10#70002)#4 ERROR_NOTE: Rejection from: (Error#5) : 58 . 0
stage-0: client: RemoteError(error:liveSlots:v10#70002)#4 ERROR_NOTE: Rejection from: (Error#6) : 55 . 3
stage-0: client: RemoteError(error:liveSlots:v10#70002)#4 ERROR_NOTE: Sent as error:liveSlots:v12#70002
stage-0: client: Error#5: Event: 55.3
stage-0: client: Error: Event: 55.3
stage-0: client:  at construct ()
stage-0: client:  at Error (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:8983)
stage-0: client:  at trackTurns (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:107)
stage-0: client:  at handle (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:571)
stage-0: client:  at (/bundled-source/.../agoric-sdk/packages/eventual-send/src/E.js:38)
stage-0: client:  at openVault (/bundled-source/.../testnet-load-generator/loadgen/agent-create-vault.js:70)
stage-0: client:  at openVault ()
stage-0: client:  at doVaultCycle (/bundled-source/.../testnet-load-generator/loadgen/agent-create-vault.js:112)
stage-0: client:  at doVaultCycle ()
stage-0: client:  at (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:123)
stage-0: client:  at win (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:583)
stage-0: client:  at ()
stage-0: client: 
stage-0: client: Error#5 ERROR_NOTE: Caused by: (Error#6)
stage-0: client: Error#6: Event: 54.1
stage-0: client: Error: Event: 54.1
stage-0: client:  at construct ()
stage-0: client:  at Error (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:8983)
stage-0: client:  at trackTurns (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:107)
stage-0: client:  at handle (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/lockdown-subprocess-xsnap.js:571)
stage-0: client:  at deliver (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:7414)
stage-0: client:  at dispatchToUserspace (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:7697)
stage-0: client:  at runWithoutMetering (/workspaces/agoric/agoric-sdk/packages/SwingSet/src/kernel/vatManager/supervisor-subprocess-xsnap.js:8074)
stage-0: client:  at ()
stage-0: client: 
stage-0: loadgen: CapTP bundle exception: (RemoteError(error:captp:http://127.0.0.1#20002)#4)
stage-0: loadgen: RemoteError(error:captp:http://127.0.0.1#20002)#4: Withdrawal of (an object) failed because the purse only contained (an object)
stage-0: loadgen: 
stage-0: loadgen:   at fullRevive (packages/marshal/src/marshal.js:368:34)
stage-0: loadgen:   at unserialize (packages/marshal/src/marshal.js:458:19)
stage-0: loadgen:   at CTP_RETURN (packages/captp/src/captp.js:504:16)
stage-0: loadgen:   at dispatch (packages/captp/src/captp.js:568:9)
stage-0: loadgen:   at WebSocket.<anonymous> (packages/agoric-cli/lib/deploy.js:117:13)
stage-0: loadgen:   at WebSocket.emit (events.js:315:20)
stage-0: loadgen:   at WebSocket.EventEmitter.emit (domain.js:467:12)
stage-0: loadgen:   at Receiver.emit (events.js:315:20)
stage-0: loadgen:   at Receiver.EventEmitter.emit (domain.js:467:12)
stage-0: loadgen:   at Socket.emit (events.js:315:20)
stage-0: loadgen:   at Socket.EventEmitter.emit (domain.js:467:12)
stage-0: loadgen: 
stage-0: loadgen: RemoteError(error:captp:http://127.0.0.1#20002)#4 ERROR_NOTE: Rejection from: (Error#5) : 17 . 0
stage-0: loadgen: Nested error under RemoteError(error:captp:http://127.0.0.1#20002)#4
stage-0: loadgen:   Error#5: Event: 16.1
stage-0: loadgen:   
stage-0: loadgen:     at Object.vaultCycle [as cycle] (/workspaces/agoric/testnet-load-generator/loadgen/task-create-vault.js:33:59)
stage-0: loadgen:     at maybeStartOneCycle (/workspaces/agoric/testnet-load-generator/loadgen/loop.js:79:6)
stage-0: loadgen:     at Timeout.bump [as _onTimeout] (/workspaces/agoric/testnet-load-generator/loadgen/loop.js:149:7)
stage-0: loadgen:   
stage-0: loadgen: [vault] failed: (RemoteError(error:captp:http://127.0.0.1#20002)#4)
stage-0: loadgen: {"time":1631893950.9799988,"type":"finish","task":"vault","seq":2,"success":false}
stage-0: loadgen:  vault.active now 0
stage-0: loadgen: {"time":1631893950.98006,"type":"status","status":{"amm":{"active":0,"succeeded":2,"failed":0,"next":2},"vault":{"active":0,"succeeded":1,"failed":2,"next":3}}}
stage-0: loadgen: not starting vault, 0 active reached dynamic limit 0
@dckc
Copy link
Member

dckc commented Sep 17, 2021

The uncensored form of the amounts is obscure on XS relative to node because our xsnap console shim just uses toString rather than something more like inspect.

Error#4: Withdrawal of [object Object] failed because the purse only contained [object Object]

cc @kriskowal

@katelynsills
Copy link
Contributor

The uncensored form of the amounts is obscure on XS relative to node because our xsnap console shim just uses toString rather than something more like inspect.

Oo, this sounds like it needs an issue of its own.

@katelynsills
Copy link
Contributor

@mhofman Can you confirm that the bld purse has BLD in it and has enough to match bldToLock?

Based on the error, it's this line erroring:

const payment = harden({ Collateral: E(bldPurse).withdraw(bldToLock) });

@mhofman
Copy link
Member Author

mhofman commented Sep 17, 2021

Admittedly I don't fully understand what the vault task does, but my cursory reading is that it should?

  // put 1% into the vault
  const bldToLock = AmountMath.make(bldBrand, bldBalance.value / BigInt(100));

@katelynsills
Copy link
Contributor

What's the environment in which this code is being run? Can you do a console log of the current amount of the purse?

@mhofman
Copy link
Member Author

mhofman commented Sep 17, 2021

I switched the local solo to --verbose mode and printed the bldPurse balance before starting the vault operation. I also extracted the relevant blocks from the slog. https://gist.github.com/mhofman/5f54f68d63bce102e03553938051ba93

index 9c038d8..5162475 100644
--- a/loadgen/agent-create-vault.js
+++ b/loadgen/agent-create-vault.js
@@ -57,6 +57,10 @@ export default async function startAgent([key, home]) {
   // (we close over 'bldToLock')
   async function openVault() {
     console.error('create-vault: openVault');
+    const currentBldBalance = await E(bldPurse).getCurrentAmount();
+    console.error(
+      `create-vault: openVault: start balance: ${disp(currentBldBalance)} BLD`,
+    );
     const openInvitationP = E(treasuryPublicFacet).makeLoanInvitation();
     const proposal = harden({
       give: {

@katelynsills
Copy link
Contributor

Ok, thanks! Can you give me instructions for reproducing?

@mhofman
Copy link
Member Author

mhofman commented Sep 20, 2021

With a agoric-sdk built and agoric cli in PATH:

./runner/bin/loadgen-runner --stages=1 --no-stage.0.save-storage --stage.0.duration=10 --stage.0.loadgen

@katelynsills
Copy link
Contributor

Also, looking at the log again, it looks like the error goes through startInstance.js:167, which is the fee purse being charged for an offer. Are you sure the fee purse has enough RUN in it?

@katelynsills
Copy link
Contributor

This doesn't look like a bug in the Zoe or ERTP packages (or at least, we haven't found anything that would indicate that), so I need to reassign this back. I'm happy to give advice and discuss the debugging though.

@katelynsills katelynsills assigned mhofman and unassigned katelynsills Sep 21, 2021
@mhofman
Copy link
Member Author

mhofman commented Sep 21, 2021

I do believe this used to work as expected, but it's possible the way a local solo is provisioned isn't compatible with the metering fees needed to run the loadgen tasks. I'll try to figure out when this broke.

@mhofman
Copy link
Member Author

mhofman commented Feb 7, 2022

There has been other similar non fatal errors (e.g. Agoric/agoric-sdk#4114). I'm not sure if this one has occurred since then. Will close and open an issue to detect regressions in the loadgen.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants