Replayable Actions Trace (V0 → V1)

High level goals

The former raw actions trace generation was very artisanal. Let's formalize that process and upgrade it to record more things and make it ready for future use cases
- Record anywhere in blockchain (don't just crash before Edo)
- Record as many operations as possible (although, supporting everything in the replayable actions trace is not necessary)
- Don't spread the recording logic in the middle of the lib_context logic, isolate and functorise it
- Upstream the feature to tezos/tezos
Start replays from existing stores (don't just start at genesis)
- This implies being able to replay operations using Context.tree objects
- This implies being able to replay fold and patch_context (recursive replay logic)
Produce precise Tezos transaction per second (TPS) stats
Include the repo closing step in the statistics. It is important for the short benchmark to count the latest merge.

Planning

Main steps (ordered):

[X] In lib_context, being able to produce a raw actions trace v0 from a running tezos node when an env variable is set
- [X] refactoring of existing code
[X] In irmin-bench, manage_actions.exe to-replayable: Convert a raw actions trace v0 into a replayable actions trace v1
- [X] be able to fetch the block details from tzstats.com
[x] In irmin-bench, update the code that replays replayable actions trace
- [X] import the necessary code from lib_context
[x] In irmin-bench, upgrade the stat trace
- [x] definition from V0 to V1
- [x] collection
[x] In irmin-bench, upgrade the stat trace summary
- [x] definition
- [x] manage_stats.exe summarise: Convert a stat trace v1 into a stat trace summary
[X] In irmin-bench, upgrade the stat trace summary observers
- [x] manage_stats.exe pp

Upstreaming

[ ] Split and move the code between irmin, tezos and somewhere else.
[ ] MR the refactoring + recording of both traces
[ ] MR the replay
[ ] PR the removal of stuff from irmin

Extra steps

[X] Launch a raw actions trace v0 collection from Edo and keep the process alive for as long as possible
- On July 19th 2021: 220_566 blocks, 208_377 trees, 170_105_031 contexts, 220_552 unique commit hashes. 897_981_317 lib_context events, first/last block levels are 1_343_487/1_564_030
[x] As soon as possible, run a stat-less replay from edo, to see how long it takes
[x] Rebase on schema
[ ] Generate a Florence store/rep-trace pair
[ ] Generate an end-to-end raw/rep-stats trace
[ ] Rerun all the monthly and release benchmarks
[ ] Re-upload the replayable traces on data.tarides and on comanche

Extra optional steps

[X] manage_actions.exe summarise: Read a raw actions trace and print JSON statistics about its content (needed to get insights on which operations should be supported in replayable actions trace v1
[X] manage_actions.exe list: Convert a raw actions trace to human readable text. (needed for corrupted store debugging)

WIP Branches

tezos/tezos diffs: https://github.com/tarides/tezos/pull/15
irmin diffs: https://github.com/mirage/irmin/compare/master...Ngoguey42:new-replay-traces

Files and Commands Workflow

            (tezos-node) ------> {not yet implemented} ---------\
                  |                                             |
                  v                                             |
          [raw actions trace] -> (manage_actions.exe summarise) |
                  |                            |                |
                  |                            v                |
                  |                 [raw_actions_summary.json]  |
                  |                            |                |
                  |                            v                |
                  |                   (pandas / matplotlib)     |
                  v                                             |
  (manage_actions.exe to-replayable)                            |
                  |                                             |
                  v                                             |
       [replayable actions trace]                               |
                  |                                             |
                  v                                             v
             (tree.exe) -----------------------------> [stat trace]
                                                            |
                                                            v
                                               (manage_stats.exe summarise)
                                                            |
                                                            v
                                                  [stat_summary.json]
                                                            |
                                                            v
                                     (pandas / matplotlib / manage_stats.exe pp)

bpm = blocks per minute tps = transactions per second tx = transaction

bpm decay during replay

For the first time, I've executed a replay from edo up to now (level 1_343_487 to ~1_567_400). (I haven't reimplemented the stat trace yet, only the total runtime is available).

Replaying edo took 5h25, at a rate of 378 bpm and 296 tps.

Replaying flo took 11h45, at a rate of 143 bpm and ~217 tps.

There are 2 reasons for that bpm decay:

There are 2x more tx per block in flo than edo
Index's merge having a poor complexity given the size of the index/data file, replaying on a shallow irmin store is a huge performance improvement. I.e:
- Replaying flo from a snapshot would be quicker than 143 bpm
- Replaying flo from an archive store would be slower 143 bpm

In the future, when benchmarking, we will have to choose between replaying from snapshots or from archives.

bpm decay during bootstrap

That same problem can be observed on a bootstraping tezos node when looking at the length of the blocks that got stuck on index merge

The 2 following graphics show the evolution of the block length for 2 bootstrapping tezos nodes. The first one started from genesis and the second one started from a snashot, a few blocks before Edo.

At the beginning of florence, the blocks stuck on merges last ~2.5 min in the first one vs ~40 sec in the second one.

While the average block length is ~0.5 sec in both graphics, it starts to decay from Delphi in the first one. The reason is because the length of the commits blocked on merge start to dominate the over the length of the non-bocked ones.

long

short

Misc

Some stats per protocol extracted from tzstats.com

op_count              15,866,555.00
op_count_tx            1,873,210.00
op_count_contract          6,466.00
blocks                   655,361.00
op_count_tx / block            2.86
Name: genesis, dtype: float64

op_count              5,884,601.00
op_count_tx           1,197,242.00
op_count_contract       607,631.00
blocks                  196,608.00
op_count_tx / block           6.09
Name: babylon, dtype: float64

op_count              12,509,277.00
op_count_tx            4,236,021.00
op_count_contract        907,658.00
blocks                   360,448.00
op_count_tx / block           11.75
Name: carthage, dtype: float64

op_count              5,360,581.00
op_count_tx           2,404,503.00
op_count_contract       442,364.00
blocks                  131,072.00
op_count_tx / block          18.34
Name: dephi, dtype: float64

op_count              8,597,058.00
op_count_tx           5,775,811.00
op_count_contract     2,695,300.00
blocks                  122,878.00
op_count_tx / block          47.00
Name: edo, dtype: float64

op_count              10,602,467.00
op_count_tx            8,519,477.00
op_count_contract      5,047,644.00
blocks                    93,633.00
op_count_tx / block           90.99
Name: florence (so far), dtype: float64

Misc

For reference, the replay rate when starting from genesis is 10k bpm, and the progress rate of mainnet is 1 bpm.

mirage / irmin