Agoric / agoric-sdk

monorepo for the Agoric Javascript smart contract platform
Apache License 2.0
326 stars 205 forks source link

increase `snapshotInitial` to accommodate new initialize-worker event #7548

Closed warner closed 1 year ago

warner commented 1 year ago

What is the Problem Being Solved?

All vats start with a startVat delivery (which evaluates the source bundle and runs buildRootObject, doing a lot of work that we'd like to avoid re-doing upon replay). ZCF/contract vats then do a start or startInstance delivery, which fetches and evaluates the contract bundle (also a lot of work), and does a bunch of setup.

Previously, we set the default value of snapshotInitial to 2, with the intention that we'd write a heap snapshot just after the startInstance. This seems like a good point to capture: we don't know how many more deliveries will be made soon (and thus we don't know when our next opportunity to create a snapshot will be), but we know that we've just done a lot of work that we'd like to avoid re-doing.

PR #7484 added an initialize-worker pseudo-event to the transcript, which counts against this snapshotInitial counter. So now we're probably writing a snapshot just after the startVat, but before the startInstance, which is not ideal.

Description of the Design

Increase snapshotInitial to 3.

Swingset has a built-in default for this, but it can be overridden by config.snapshotInitial. I forget if cosmic-swingset/src/launch-chain.js overrides or relies on the default.

It would probably be appropriate to increase both.

Security Considerations

none

Scaling Considerations

probably a net improvement, assuming that it's likely for the node to be restarted within the first 2000-ish deliveries (whatever snapshotInterval is, which tells us when the second snapshot gets written)

Test Plan

some tests might need to be updated, but snapshotInitial is simple enough that I'm not worried about adding more test coverage

warner commented 1 year ago

Using test-vaults-performance.js as a guide, vat v49 (probably the vaults contract? one of the vaults contracts? it receives messages when the test opens a vault) receives the following deliveries during the chain initialization phase, before we do any openVault calls:

$ cat start.slog |jq -c 'select(.vatID=="v49" and .type=="deliver")'|cut -c-150
{"type":"deliver","crankNum":4795,"vatID":"v49","deliveryNum":1,"replay":false,"kd":["startVat",{"body":"#{\"contractBundleCap\":\"$0.Alleged: device
{"type":"deliver","crankNum":4809,"vatID":"v49","deliveryNum":4,"replay":false,"kd":["message","ko725",{"methargs":{"body":"#[\"startZcf\",[\"$0.Alleg
{"type":"deliver","crankNum":4817,"vatID":"v49","deliveryNum":5,"replay":false,"kd":["notify",[["kp1290",{"state":"fulfilled","data":{"body":"#\"$0.Al
{"type":"deliver","crankNum":4825,"vatID":"v49","deliveryNum":6,"replay":false,"kd":["notify",[["kp1292",{"state":"fulfilled","data":{"body":"#{\"asse
{"type":"deliver","crankNum":4867,"vatID":"v49","deliveryNum":7,"replay":false,"kd":["notify",[["kp1294",{"state":"fulfilled","data":{"body":"#\"$0.Al
{"type":"deliver","crankNum":4868,"vatID":"v49","deliveryNum":8,"replay":false,"kd":["notify",[["kp1295",{"state":"fulfilled","data":{"body":"#\"$0.Al
{"type":"deliver","crankNum":4871,"vatID":"v49","deliveryNum":9,"replay":false,"kd":["notify",[["kp1297",{"state":"fulfilled","data":{"body":"#{\"desc
{"type":"deliver","crankNum":4872,"vatID":"v49","deliveryNum":10,"replay":false,"kd":["notify",[["kp1298",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":4875,"vatID":"v49","deliveryNum":11,"replay":false,"kd":["notify",[["kp1300",{"state":"fulfilled","data":{"body":"#{\"des
{"type":"deliver","crankNum":4876,"vatID":"v49","deliveryNum":12,"replay":false,"kd":["notify",[["kp1301",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":4877,"vatID":"v49","deliveryNum":13,"replay":false,"kd":["notify",[["kp1302",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":4878,"vatID":"v49","deliveryNum":14,"replay":false,"kd":["notify",[["kp1303",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":4880,"vatID":"v49","deliveryNum":15,"replay":false,"kd":["notify",[["kp1304",{"state":"fulfilled","data":{"body":"#{\"liv
{"type":"deliver","crankNum":4881,"vatID":"v49","deliveryNum":16,"replay":false,"kd":["notify",[["kp1305",{"state":"fulfilled","data":{"body":"#{\"Auc
{"type":"deliver","crankNum":4892,"vatID":"v49","deliveryNum":17,"replay":false,"kd":["notify",[["kp1296",{"state":"fulfilled","data":{"body":"#{\"bra
{"type":"deliver","crankNum":4893,"vatID":"v49","deliveryNum":18,"replay":false,"kd":["notify",[["kp1299",{"state":"fulfilled","data":{"body":"#{\"bra
{"type":"deliver","crankNum":4905,"vatID":"v49","deliveryNum":19,"replay":false,"kd":["message","ko734",{"methargs":{"body":"#[\"getLimitedCreatorFace
{"type":"deliver","crankNum":4907,"vatID":"v49","deliveryNum":20,"replay":false,"kd":["message","ko734",{"methargs":{"body":"#[\"getParamMgrRetriever\
{"type":"deliver","crankNum":4918,"vatID":"v49","deliveryNum":21,"replay":false,"kd":["notify",[["kp1307",{"state":"fulfilled","data":{"body":"#\"publ
{"type":"deliver","crankNum":4919,"vatID":"v49","deliveryNum":22,"replay":false,"kd":["notify",[["kp1308",{"state":"fulfilled","data":{"body":"#\"+359
{"type":"deliver","crankNum":4920,"vatID":"v49","deliveryNum":23,"replay":false,"kd":["notify",[["kp1309",{"state":"fulfilled","data":{"body":"#\"+360
{"type":"deliver","crankNum":4921,"vatID":"v49","deliveryNum":24,"replay":false,"kd":["notify",[["kp1310",{"state":"fulfilled","data":{"body":"#\"+360
{"type":"deliver","crankNum":4924,"vatID":"v49","deliveryNum":25,"replay":false,"kd":["message","ko746",{"methargs":{"body":"#[\"get\",[{\"key\":\"gov
{"type":"deliver","crankNum":4931,"vatID":"v49","deliveryNum":26,"replay":false,"kd":["notify",[["kp1316",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":4933,"vatID":"v49","deliveryNum":27,"replay":false,"kd":["notify",[["kp1318",{"state":"fulfilled","data":{"body":"#{\"bod
{"type":"deliver","crankNum":4936,"vatID":"v49","deliveryNum":28,"replay":false,"kd":["message","ko749",{"methargs":{"body":"#[\"getInternalParamValue
{"type":"deliver","crankNum":4949,"vatID":"v49","deliveryNum":29,"replay":false,"kd":["notify",[["kp1317",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":4950,"vatID":"v49","deliveryNum":30,"replay":false,"kd":["notify",[["kp1322",{"state":"fulfilled","data":{"body":"#\"#und
{"type":"deliver","crankNum":4973,"vatID":"v49","deliveryNum":31,"replay":false,"kd":["message","ko734",{"methargs":{"body":"#[\"getParamMgrRetriever\
{"type":"deliver","crankNum":4975,"vatID":"v49","deliveryNum":32,"replay":false,"kd":["message","ko734",{"methargs":{"body":"#[\"getGovernedApis\",[]]
{"type":"deliver","crankNum":4977,"vatID":"v49","deliveryNum":33,"replay":false,"kd":["message","ko734",{"methargs":{"body":"#[\"getGovernedApiNames\"
{"type":"deliver","crankNum":5015,"vatID":"v49","deliveryNum":34,"replay":false,"kd":["message","ko745",{"methargs":{"body":"#[\"addVaultType\",[\"$0.
{"type":"deliver","crankNum":5018,"vatID":"v49","deliveryNum":35,"replay":false,"kd":["message","ko745",{"methargs":{"body":"#[\"makeCollectFeesInvita
{"type":"deliver","crankNum":5041,"vatID":"v49","deliveryNum":36,"replay":false,"kd":["notify",[["kp1343",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":5065,"vatID":"v49","deliveryNum":37,"replay":false,"kd":["message","ko735",{"methargs":{"body":"#[\"handleOffer\",[\"$0.A
{"type":"deliver","crankNum":5075,"vatID":"v49","deliveryNum":38,"replay":false,"kd":["notify",[["kp1342",{"state":"fulfilled","data":{"body":"#{\"ass
{"type":"deliver","crankNum":5089,"vatID":"v49","deliveryNum":39,"replay":false,"kd":["notify",[["kp1353",{"state":"fulfilled","data":{"body":"#\"#und
{"type":"deliver","crankNum":5090,"vatID":"v49","deliveryNum":40,"replay":false,"kd":["notify",[["kp1354",{"state":"fulfilled","data":{"body":"#\"#und
{"type":"deliver","crankNum":5097,"vatID":"v49","deliveryNum":41,"replay":false,"kd":["notify",[["kp1355",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":5119,"vatID":"v49","deliveryNum":42,"replay":false,"kd":["notify",[["kp1359",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":5120,"vatID":"v49","deliveryNum":43,"replay":false,"kd":["notify",[["kp1360",{"state":"fulfilled","data":{"body":"#\"+0\"
{"type":"deliver","crankNum":5122,"vatID":"v49","deliveryNum":44,"replay":false,"kd":["notify",[["kp1361",{"state":"fulfilled","data":{"body":"#{\"bod
{"type":"deliver","crankNum":5137,"vatID":"v49","deliveryNum":45,"replay":false,"kd":["notify",[["kp1364",{"state":"fulfilled","data":{"body":"#\"IbcA
{"type":"deliver","crankNum":5139,"vatID":"v49","deliveryNum":46,"replay":false,"kd":["notify",[["kp1365",{"state":"fulfilled","data":{"body":"#\"#und
{"type":"deliver","crankNum":5147,"vatID":"v49","deliveryNum":47,"replay":false,"kd":["notify",[["kp1368",{"state":"fulfilled","data":{"body":"#{\"ass
{"type":"deliver","crankNum":5186,"vatID":"v49","deliveryNum":48,"replay":false,"kd":["notify",[["kp1370",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":5189,"vatID":"v49","deliveryNum":49,"replay":false,"kd":["notify",[["kp1371",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":5196,"vatID":"v49","deliveryNum":50,"replay":false,"kd":["notify",[["kp1373",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":5197,"vatID":"v49","deliveryNum":51,"replay":false,"kd":["notify",[["kp1374",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":5198,"vatID":"v49","deliveryNum":52,"replay":false,"kd":["notify",[["kp1375",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":5199,"vatID":"v49","deliveryNum":53,"replay":false,"kd":["notify",[["kp1376",{"state":"fulfilled","data":{"body":"#{\"bod
{"type":"deliver","crankNum":5201,"vatID":"v49","deliveryNum":54,"replay":false,"kd":["notify",[["kp1377",{"state":"fulfilled","data":{"body":"#{\"bod
{"type":"deliver","crankNum":5205,"vatID":"v49","deliveryNum":55,"replay":false,"kd":["notify",[["kp1378",{"state":"fulfilled","data":{"body":"#\"publ
{"type":"deliver","crankNum":5208,"vatID":"v49","deliveryNum":56,"replay":false,"kd":["notify",[["kp1381",{"state":"fulfilled","data":{"body":"#{\"upd
{"type":"deliver","crankNum":5236,"vatID":"v49","deliveryNum":57,"replay":false,"kd":["notify",[["kp1385",{"state":"fulfilled","data":{"body":"#{\"bod
{"type":"deliver","crankNum":5238,"vatID":"v49","deliveryNum":58,"replay":false,"kd":["notify",[["kp1386",{"state":"fulfilled","data":{"body":"#\"publ
{"type":"deliver","crankNum":5240,"vatID":"v49","deliveryNum":59,"replay":false,"kd":["notify",[["kp1372",{"state":"fulfilled","data":{"body":"#\"$0.A
{"type":"deliver","crankNum":5247,"vatID":"v49","deliveryNum":60,"replay":false,"kd":["notify",[["kp1389",{"state":"fulfilled","data":{"body":"#\"#und
{"type":"deliver","crankNum":5248,"vatID":"v49","deliveryNum":61,"replay":false,"kd":["notify",[["kp1390",{"state":"fulfilled","data":{"body":"#\"#und
{"type":"deliver","crankNum":5255,"vatID":"v49","deliveryNum":62,"replay":false,"kd":["notify",[["kp1393",{"state":"fulfilled","data":{"body":"#{\"bod
{"type":"deliver","crankNum":5259,"vatID":"v49","deliveryNum":63,"replay":false,"kd":["notify",[["kp1379",{"state":"fulfilled","data":{"body":"#{\"upd
{"type":"deliver","crankNum":5262,"vatID":"v49","deliveryNum":64,"replay":false,"kd":["notify",[["kp1380",{"state":"fulfilled","data":{"body":"#{\"upd
{"type":"deliver","crankNum":5275,"vatID":"v49","deliveryNum":65,"replay":false,"kd":["notify",[["kp1399",{"state":"fulfilled","data":{"body":"#\"#und
{"type":"deliver","crankNum":5288,"vatID":"v49","deliveryNum":66,"replay":false,"kd":["notify",[["kp1401",{"state":"fulfilled","data":{"body":"#\"#und
{"type":"deliver","crankNum":5289,"vatID":"v49","deliveryNum":67,"replay":false,"kd":["notify",[["kp1402",{"state":"fulfilled","data":{"body":"#{\"bod
{"type":"deliver","crankNum":5303,"vatID":"v49","deliveryNum":68,"replay":false,"kd":["notify",[["kp1408",{"state":"fulfilled","data":{"body":"#\"#und

Looking at the transcript, we see a snapshot is created after the very first one (the startVat):

$ sqlite3 swingstore/swingstore.sqlite 'select * from transcriptItems where vatID="v49" and position < 10'|cut -c-150
v49|0|{"d":["initialize-worker",{"source":{"bundleID":"b1-77835e0a7b8963a808bf20344e52eaa7c069f2a3857198de5b3f7382a69cf97d0d487618c8fcfbc78ce2bafb94c5
v49|1|{"d":["startVat",{"body":"#{\"contractBundleCap\":\"$0.Alleged: device node\",\"invitationIssuer\":\"$1.Alleged: Zoe Invitation issuer\",\"zoeSe
v49|2|{"d":["save-snapshot"],"sc":[],"r":{"status":"ok","snapshotID":"13839174c0faaa8d9be6fc3df14bed79d1b0c829957e9bef182485095a58c92b"}}|0
v49|3|{"d":["load-snapshot",{"snapshotID":"13839174c0faaa8d9be6fc3df14bed79d1b0c829957e9bef182485095a58c92b"}],"sc":[],"r":{"status":"ok"}}|0
v49|4|{"d":["message","o+0",{"methargs":{"body":"#[\"startZcf\",[\"$0.Alleged: zoeInstanceAdmin\",{\"installation\":\"$1.Alleged: BundleIDInstallation
v49|5|{"d":["notify",[["p+5",false,{"body":"#\"$0.Alleged: ZoeMint\"","slots":["o-73"]}]]],"sc":[{"s":["vatstoreGet","vom.o+d20/1"],"r":["ok","{}"]},{
v49|6|{"d":["notify",[["p+6",false,{"body":"#{\"assetKind\":\"nat\",\"brand\":\"$0.Alleged: IST brand\",\"displayInfo\":{\"assetKind\":\"nat\",\"decim
v49|7|{"d":["notify",[["p+7",false,{"body":"#\"$0.Alleged: ChainStorageNode\"","slots":["o-75"]}]]],"sc":[],"r":{"status":"ok","metering":{"computrons
v49|8|{"d":["notify",[["p+8",false,{"body":"#\"$0.Alleged: Zoe Invitation issuer\"","slots":["o-50"]}]]],"sc":[],"r":{"status":"ok","metering":{"compu
v49|9|{"d":["notify",[["p+10",false,{"body":"#{\"description\":\"questionPoser\",\"handle\":\"$0.Alleged: InvitationHandle\",\"installation\":\"$1.All

and the next snapshot is written about 200 deliveries later:

$ sqlite3 -box swingstore/swingstore.sqlite 'select vatID,startPos,endPos,isCurrent,incarnation from transcriptSpans where vatID="v49"'
┌───────┬──────────┬────────┬───────────┬─────────────┐
│ vatID │ startPos │ endPos │ isCurrent │ incarnation │
├───────┼──────────┼────────┼───────────┼─────────────┤
│ v49   │ 0        │ 3      │           │ 0           │
│ v49   │ 3        │ 203    │           │ 0           │
│ v49   │ 203      │ 269    │ 1         │ 0           │
└───────┴──────────┴────────┴───────────┴─────────────┘

For reference, each openVault operation causes 18 deliveries to v49: three messages (getCollateralManager, makeVaultInvitation, handleOffer), plus 15 notifys with the results of outbound messages.

warner commented 1 year ago

Computron counts for those 65 deliveries are:

cat out.slog |jq -c 'select(.vatID=="v49" and .type=="deliver-result" and .deliveryNum < 66) |[.deliveryNum, .dr[2].compute]'
deliveryNum computrons
0 (initialize-worker)
1 124438210
2 (save-snapshot)
3 (load-snapshot)
4 717781
5 52890
6 2061494
7 10054
8 10148
9 10184
10 10148
11 10184
12 10556
13 10556
14 66234
15 10084
16 79628
17 14037
18 625880
19 41475
20 46077
21 15461
22 10049
23 10049
24 10049
25 27068
26 10148
27 25681
28 18254
29 10054
30 10101
31 37252
32 45489
33 45889
34 309780
35 89328
36 16828
37 1281119
38 276131
39 10049
40 10049
41 261454
42 10054
43 27429
44 25646
45 24788
46 10101
47 1731582
48 11114
49 145761
50 11020
51 11522
52 11522
53 26426
54 26426
55 16427
56 185434
57 26431
58 16427
59 11208
60 94354
61 61365
62 26426
63 63748
64 31731
65 139559
66 85321
67 26625
68 11067

where the significant ones (and the time they happened to take in my test run) were:

deliveryNum computrons seconds what
1 124.0 M 0.946 startVat
4 0.718 M 0.032 startZcf
6 2.0 M 0.062 response to getIssuerRecord
18 0.626 M 0.008 response to getAmountOf
37 1.3 M 0.041 handleOffer
47 1.7 M 0.055 response to getDisplayInfo

So in terms of computrons captured by the snapshot, capturing the first real delivery (startVat, in deliveryNum 1) is probably enough. It would be nice if we could capture through the fourth real delivery (response to getIssuerRecord, in deliveryNum 6), because that has another 2M computrons, but the actual time saved from the future replay is pretty small.