Skip to content

feat(exec): dump intermediate cache blocks from FVM exec in StateReplay #12822

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

Draft
wants to merge 8 commits into
base: master
Choose a base branch
from

Conversation

rvagg
Copy link
Member

@rvagg rvagg commented Jan 11, 2025

As with filecoin-project/filecoin-ffi#512, I may bail on some or all of this, it's a little bit janky (but it is for debugging!). But the ExecutionEvent::Log thing probably needs to stay, so that may become a new PR.

@rvagg
Copy link
Member Author

rvagg commented Jan 11, 2025

Added an inspection of the block_link(X) log lines so that it loads the blocks from the blockstore and tries to determine what they are (using code started in #12809).

With my node running with LOTUS_REPLAY_DUMP_CACHED_BLOCKS=yes I can now do:

$ lotus-shed msg --show-message=false --exec-trace bafy2bzacecctmt55nihbteknhzm35rksjwy2nemfwbpoybhhroed6uqz7j6qg

...

Cached blocks written to /tmp/bafy2bzacecctmt55nihbteknhzm35rksjwy2nemfwbpoybhhroed6uqz7j6qg.car
Message (f02973061) block writes:
┌────────────────────────────────────────────────────────────────┬─────────────────────────────────────────────────┬───────┬────────┬───────────────┬────────┐
│ CID                                                            │ Known Type                                      │  Size │     S% │ Estimated Gas │     G% │ 
├────────────────────────────────────────────────────────────────┼─────────────────────────────────────────────────┼───────┼────────┼───────────────┼────────┤
│ bafy2bzacedgfawwsrzqo2rpaxxhx5h47qatr72luon5x6muay2jnxfwoizzme │ AMTNode[miner16.SectorOnChainInfo]              │  3170 │  22.95 │      11093800 │  19.72 │ 
│ bafy2bzacebl66k65cm4ddx5fqqdrlc5hqwhqdk3o5rw7tvi65dkhgpfxiitzs │ AMTNode                                         │  1170 │   8.47 │       4413800 │   7.85 │ 
│ bafy2bzacebhevd6hl7zl7od7l5iyxmtq5xjd6wgfv7ppyjh2mqmwjcyivosla │ AMTNode                                         │   524 │   3.79 │       2256160 │   4.01 │ 
│ bafy2bzacecount4it23nrrsv6ylm57nhhanuvjyuhcjjtxk4wwmz5eqfgxh62 │ AMTRoot{5}                                      │   188 │   1.36 │       1133920 │   2.02 │ 
│ bafy2bzaceby2rerem5uqp2rectcburcwdxsyvsqnp6k7aglh6r56i4utklrlq │ HAMTNode{5}[miner16.SectorPreCommitOnChainInfo] │  4734 │  34.28 │      16317560 │  29.01 │ 
│ bafy2bzacea3jqfyj6azdv3nlicglzdkgy3c5umayykhzvbuukjvr4omrmlxfy │ AMTNode[miner16.ExpirationSet]                  │    76 │   0.55 │        759840 │   1.35 │ 
│ bafy2bzacebsi57btbhapznr3yd2iwitfsxr4x2x7aizxqtcfzn4xg5zfslf6q │ AMTNode                                         │    49 │   0.35 │        669660 │   1.19 │ 
│ bafy2bzacea6hwnno52mf6vvm7e2jvwsjsi3ffiadxycd7m6hlmqlv7vb5vsre │ AMTNode                                         │    49 │   0.35 │        669660 │   1.19 │ 
│ bafy2bzacecphc3jd7ku7qkrr5pdjyoq3kfvmthw7p4zcqbigqoir3fcml5vnu │ AMTNode                                         │   221 │   1.60 │       1244140 │   2.21 │ 
│ bafy2bzacebqbprezf7xig6jkpgu2gezd5lnw6pztkezj7wl7oe4srymwpdfm4 │ AMTNode                                         │    92 │   0.67 │        813280 │   1.45 │ 
│ bafy2bzaceaiypfyb6uyp2vgudyoyjruhkj2cb2ifzthqbflngfkmsugthsibs │ AMTRoot{4}                                      │    53 │   0.38 │        683020 │   1.21 │ 
│ bafy2bzacebrgugydjb3mppmev5tzrwlqr5mvujuo7hicwpwybui5kortlgolk │ AMTRoot{3}[miner16.Partition]                   │   327 │   2.37 │       1598180 │   2.84 │ 
│ bafy2bzacedzsurbz5ahvgvdadc7vegqrw5acpvwaxss5mvukphjvtqk7hf7iu │ AMTNode[Bytes]                                  │    10 │   0.07 │        539400 │   0.96 │ 
│ bafy2bzacecv7bexiciv4az2lpdjwahgw4z7jzzqqehiqjy4nyydkzqt7tmhx2 │ AMTNode                                         │    51 │   0.37 │        676340 │   1.20 │ 
│ bafy2bzacearbtg5axyjsxgv6aada3tinvd74woxfjudmfjfnkdndx4opp4hni │ AMTNode                                         │   266 │   1.93 │       1394440 │   2.48 │ 
│ bafy2bzacecgzfhzd3fywkydt65w736vtacj7hlcxmjczepjpilwxkc3w22h3w │ AMTNode                                         │    94 │   0.68 │        819960 │   1.46 │ 
│ bafy2bzacebq3dodn5glb6eq63idsfrvnc4qy64zr3crl5naw6nzmrf6wzvrbq │ AMTRoot{5}                                      │    55 │   0.40 │        689700 │   1.23 │ 
│ bafy2bzaceb2dlcjahn3krpl4boinjvznvmcqbioebexeoxaii5fgttzolesa2 │ miner16.Deadline                                │   270 │   1.95 │       1407800 │   2.50 │ 
│ bafy2bzaceaetyuhjg3ihkxzqnfeznhbe5d5jyyuvlryix6v7dvfanxsybybbu │ miner16.Deadlines                               │  2067 │  14.97 │       7409780 │  13.17 │ 
│ bafy2bzaceahrlskr6pffxyeqq2fvr5k5ixnmvr52ydtmb4k2b2t3bnjkxck2s │ miner16.State                                   │   345 │   2.50 │       1658300 │   2.95 │ 
│ Total                                                          │                                                 │ 13811 │ 100.00 │      56248740 │ 100.00 │ 
└────────────────────────────────────────────────────────────────┴─────────────────────────────────────────────────┴───────┴────────┴───────────────┴────────┘
Subcall (f02973061➜f06) block writes:
┌────────────────────────────────────────────────────────────────┬────────────────────────────────────┬───────┬────────┬───────────────┬────────┐
│ CID                                                            │ Known Type                         │  Size │     S% │ Estimated Gas │     G% │ 
├────────────────────────────────────────────────────────────────┼────────────────────────────────────┼───────┼────────┼───────────────┼────────┤
│ bafy2bzacectjpdejaohejkkxtxh67plbsrzmv5vhpnoj643adfela4vdxnirc │ HAMTNode{5}[verifreg16.Allocation] │  3685 │  19.58 │      12813900 │  18.73 │ 
│ bafy2bzacebm5zgsuqu44jr3amhj3n2jdb76f7njwf3lttpci2i7x3yh2mvog6 │ HAMTNode{5}                        │  1384 │   7.36 │       5128560 │   7.50 │ 
│ bafy2bzaceboucp34puzcqhs27zdifpncd3laryrgd2u77txal5z76qrcblmno │ HAMTNode{5}[Cid]                   │  1291 │   6.86 │       4817940 │   7.04 │ 
│ bafy2bzacecfizqyfy37rycglpdggy74avtp75whixdvi4op3k2lfjdryoyyzw │ HAMTNode{5}                        │  1384 │   7.36 │       5128560 │   7.50 │ 
│ bafy2bzaceavywkq5lbo4nlyjzhdearsaecfhuhlqk65lkmqvtdxe32cjafl46 │ HAMTNode{5}[verifreg16.Claim]      │   370 │   1.97 │       1741800 │   2.55 │ 
│ bafy2bzaceazexng6eskrptvstgwwtedxfpjqhuq7dtcnrbc5mbxs5tdwmorhk │ HAMTNode{5}[verifreg16.Claim]      │  4364 │  23.19 │      15081760 │  22.05 │ 
│ bafy2bzacedufzfsr424t5nwipjyjoofcxngv4rombmfikkm53hclfqu3wznfk │ HAMTNode{5}                        │  1384 │   7.36 │       5128560 │   7.50 │ 
│ bafy2bzaceb35a7sxhxbol3sihhxez6zvwgthasclzvwvbt2nwnmfhpl23lgvc │ HAMTNode{5}                        │  1384 │   7.36 │       5128560 │   7.50 │ 
│ bafy2bzacebecag7xkpywbvsfvogtfqqy5xffedqldaiskjony2hieqtsr4vzw │ HAMTNode{5}[Cid]                   │  2005 │  10.66 │       7202700 │  10.53 │ 
│ bafy2bzacedlitsotsx7f5vibj7ga4sdojt7akb6cjz3m5mrzsh6k6y77x6p6m │ HAMTNode{5}                        │  1384 │   7.36 │       5128560 │   7.50 │ 
│ bafy2bzacecpitgynd42bysazulqt2qzwhaqybv372ilfa2zsbgrqpridjbmvu │ verifreg16.State                   │   181 │   0.96 │       1110540 │   1.62 │ 
│ Total                                                          │                                    │ 18816 │ 100.00 │      68411440 │ 100.00 │ 
└────────────────────────────────────────────────────────────────┴────────────────────────────────────┴───────┴────────┴───────────────┴────────┘
Subcall (f02973061➜f06➜f07) block writes:
┌────────────────────────────────────────────────────────────────┬────────────────────┬──────┬────────┬───────────────┬────────┐
│ CID                                                            │ Known Type         │ Size │     S% │ Estimated Gas │     G% │ 
├────────────────────────────────────────────────────────────────┼────────────────────┼──────┼────────┼───────────────┼────────┤
│ bafy2bzaceaglbojv6vttuqcnv2jt7hu47dzvyvudsa44jxe7w5ghozrk4q6we │ HAMTNode{5}[Bytes] │ 1244 │  45.45 │       4660960 │  43.73 │ 
│ bafy2bzaceanjczap6kw4lo4fmqjov33zkeoavp46p7b27i7j3osstihilnsss │ HAMTNode{5}        │ 1384 │  50.57 │       5128560 │  48.11 │ 
│ bafy2bzacecuhy2p3we4rboffuks6vzmtxettqrlwlktvocg4qerqkaj4xmv5w │ datacap16.State    │  109 │   3.98 │        870060 │   8.16 │ 
│ Total                                                          │                    │ 2737 │ 100.00 │      10659580 │ 100.00 │ 
└────────────────────────────────────────────────────────────────┴────────────────────┴──────┴────────┴───────────────┴────────┘
Subcall (f02973061➜f04) block writes:
┌────────────────────────────────────────────────────────────────┬───────────────┬──────┬────────┬───────────────┬────────┐
│ CID                                                            │ Known Type    │ Size │     S% │ Estimated Gas │     G% │ 
├────────────────────────────────────────────────────────────────┼───────────────┼──────┼────────┼───────────────┼────────┤
│ bafy2bzaceae4zfgr3bolptpqcu76arhi3bhwllawe3dx5gm265xw3d6267ets │ power16.State │  253 │ 100.00 │       1351020 │ 100.00 │ 
│ Total                                                          │               │  253 │ 100.00 │       1351020 │ 100.00 │ 
└────────────────────────────────────────────────────────────────┴───────────────┴──────┴────────┴───────────────┴────────┘
Subcall (f02973061➜f05) block writes:
┌────────────────────────────────────────────────────────────────┬─────────────────────────────┬───────┬────────┬───────────────┬────────┐
│ CID                                                            │ Known Type                  │  Size │     S% │ Estimated Gas │     G% │ 
├────────────────────────────────────────────────────────────────┼─────────────────────────────┼───────┼────────┼───────────────┼────────┤
│ bafy2bzacebu6um5sp7wupdmcnrhqzdacnvdsz2ywyn2jfnjezitrkgelwmbhq │ AMTNode[market16.DealState] │   116 │   0.76 │        893440 │   1.52 │ 
│ bafy2bzacedhixrjyiyvh4zfdp3lapjjv4imssu5v3xoik3gubvrz2jgagmffq │ AMTNode                     │  2464 │  16.09 │       8735760 │  14.87 │ 
│ bafy2bzacebbg6teglvzbs7gzvsjodt4wsgwcnmtxido2bfyf533pgxz4jqzdy │ AMTNode                     │   356 │   2.32 │       1695040 │   2.89 │ 
│ bafy2bzacebvgukqvfsozsbjjklp3dpdy2uxmvz3j2vwtncc3l65xnudo4e3g2 │ AMTNode                     │   528 │   3.45 │       2269520 │   3.86 │ 
│ bafy2bzacebtgtdyycwdnskxk5c3vvz2sgvegd5xlgpbvchi62hed6isrfzulc │ AMTRoot{6}                  │   278 │   1.82 │       1434520 │   2.44 │ 
│ bafy2bzacec25g65e34iqa2sspo2btyz67r46luuefdul4av4dosbbpaab5iyc │ HAMTNode{5}[[Int]]          │   112 │   0.73 │        880080 │   1.50 │ 
│ bafy2bzacecdh6flwqht3i5wipvbszqom5mraaksosq6hoxoynuy4pitcszij4 │ HAMTNode{5}[[Int]]          │   998 │   6.52 │       3839320 │   6.54 │ 
│ bafy2bzaceasmv3n4zo5ojos7bwxbsoquevew3am36vm6rwcms6snmixpna3u6 │ HAMTNode{5}                 │  1384 │   9.04 │       5128560 │   8.73 │ 
│ bafy2bzacec7poqczyekoftlcnytt2lb5wbyhb423hrabdzkt5n7s4igehj3eo │ HAMTNode{5}                 │  1384 │   9.04 │       5128560 │   8.73 │ 
│ bafy2bzacedzaxptnqyzm4bo5qbzgizymfq775nbkohmfibelqg7t66sbqcema │ HAMTNode{5}[Cid]            │  2096 │  13.69 │       7506640 │  12.78 │ 
│ bafy2bzacealmoxeo26nwmemsodftavcqwgdug26m7g6r3jxu3lqskfwf3yvfs │ HAMTNode{5}                 │  1384 │   9.04 │       5128560 │   8.73 │ 
│ bafy2bzaceaipwzc3tc65h3uppttgsdgixcsrho4zpcqv357mobdmuny4udyic │ HAMTNode{5}[Int]            │  1067 │   6.97 │       4069780 │   6.93 │ 
│ bafy2bzaceawvufbenwqcpokbm72lb3535dbl5u2rtvgkis2cl2frerq6bio62 │ HAMTNode{5}                 │  1384 │   9.04 │       5128560 │   8.73 │ 
│ bafy2bzaceb547jze4ucxdn33w263h5cjhgiksl5bqla6xkq45wuianqsk5dbk │ HAMTNode{5}                 │  1384 │   9.04 │       5128560 │   8.73 │ 
│ bafy2bzacebehh4jax3txj63qp52mftfmtxxwadshxofz6de6znericrpwjdmo │ market16.State              │   379 │   2.47 │       1771860 │   3.02 │ 
│ Total                                                          │                             │ 15314 │ 100.00 │      58738760 │ 100.00 │ 
└────────────────────────────────────────────────────────────────┴─────────────────────────────┴───────┴────────┴───────────────┴────────┘

@ZenGround0
Copy link
Contributor

This is beautiful

@rvagg rvagg force-pushed the rvagg/state-replay-dump-cache branch from 0f4fc44 to 6c98b11 Compare March 28, 2025 08:31
rvagg added 7 commits April 3, 2025 18:12
* Plumb through dump_cache from fvm4 to access intermediate blocks:
  - filecoin-project/filecoin-ffi#512
  - filecoin-project/ref-fvm#2101
* Enable cache dumping in StateReplay with LOTUS_REPLAY_DUMP_CACHED_BLOCKS
* Add optional "Blocks" field InvocResult
* Handle ExecutionEvent::Log's and add "Logs" field to ExecutionTrace
* Dump intermediate cache blocks to CAR in /tmp when they appear while using
  `lotus-shed msg --exec-trace`.
@rvagg rvagg force-pushed the rvagg/state-replay-dump-cache branch from 6c98b11 to 1fbd28e Compare April 3, 2025 07:12
@rvagg
Copy link
Member Author

rvagg commented Apr 3, 2025

This is back on the menu again! With filecoin-project/ref-fvm#2101 and filecoin-project/ref-fvm#2113 merged, filecoin-project/filecoin-ffi#512 is now depending on ref-fvm master and it all works!

  • flush_all_blocks / FlushAllBlocks goes through to the fvm and if set to true will put all blocks, not just final state-root-connected blocks into the provided blockstore.
  • The fvm will now record ipld operations on the execution trace, these are reads and writes with CIDs and byte lengths; this is useful for gas accounting but helps match blocks with where they were involved in a message's execution
  • I've pivoted this PR to use StateCall to do its work and extended it so that it now takes either its original two arguments (msg, tipset) or takes a map that can have "message", "tipsetKey" and "includeBlocks". It makes it slightly awkward in Go to call but I've introduced a helper to make it a bit easier. It's backward compatible from an RPC perspective but breaking in Go.
  • When you StateCall and includeBlocks, it will track which blocks are written during message execution and then attach them to the InvocResult, you get CID:Data pairs. It will also turn on FlushAllBlocks and you'll get the new IpldOps array on all the execution traces.
  • lotus-shed msg has had the heaviest work in this PR. I've done some major refactoring to make it a bit more ergonomic while introducing new options:
NAME:
   lotus-shed message - Inspect a message, either on chain (by CID) or attempt to decode raw bytes (hex, base64, json)

USAGE:
   lotus-shed message [command options] Message in any form

OPTIONS:
   --show-message          Print the message details (default: true)
   --message-format value  Format of the message (hex, base64, json) (default: "json")
   --exec-trace            Print the execution trace (default: false)
   --show-receipt          Print the message receipt (default: true)
   --gas-stats             Print a summary of gas charges (default: false)
   --block-analysis        Perform and print an analysis of the blocks written during message execution (default: false)
   --help, -h              show help

It's now much less noisy when you run it with default args, just json output of the pieces it can give you. But --gas-stats gives you the nice summary tables, and --block-analysis will do the block guessing that I showed above. You can turn things off so you just get one of these things too so it can be nice and focused.

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

Successfully merging this pull request may close these issues.

2 participants