Print detailed fee statement for gov proposal simulation

vineethk commented 4 days ago

Description

When simulating gov. proposals, it is often useful to see detailed fee statement instead of just the total gas used. This PR prints that information.

Here is a sample output of a gov. proposal simulation after this PR:

Executing governance scripts...
    0-gas-schedule.move
        Fee statement: FeeStatement {
            total_charge_gas_units: 229,
            execution_gas_units: 39,
            io_gas_units: 57,
            storage_fee_octas: 13360,
            storage_fee_refund_octas: 0,
        }
        Success
    1-move-stdlib.move
        Fee statement: FeeStatement {
            total_charge_gas_units: 1161,
            execution_gas_units: 77,
            io_gas_units: 105,
            storage_fee_octas: 97880,
            storage_fee_refund_octas: 0,
        }
        Success
    2-aptos-stdlib.move
        Fee statement: FeeStatement {
            total_charge_gas_units: 1670,
            execution_gas_units: 1498,
            io_gas_units: 123,
            storage_fee_octas: 4960,
            storage_fee_refund_octas: 0,
        }
        Success
    3-aptos-framework.move
        Fee statement: FeeStatement {
            total_charge_gas_units: 4401,
            execution_gas_units: 3860,
            io_gas_units: 163,
            storage_fee_octas: 37800,
            storage_fee_refund_octas: 0,
        }
        Success
    4-aptos-token.move
        Fee statement: FeeStatement {
            total_charge_gas_units: 144,
            execution_gas_units: 68,
            io_gas_units: 76,
            storage_fee_octas: 0,
            storage_fee_refund_octas: 0,
        }
        Success
    5-aptos-token-objects.move
        Fee statement: FeeStatement {
            total_charge_gas_units: 151,
            execution_gas_units: 74,
            io_gas_units: 77,
            storage_fee_octas: 0,
            storage_fee_refund_octas: 0,
        }
        Success
All scripts succeeded!
All proposals succeeded!

How Has This Been Tested?

Manually ran the scripts with a couple of options. The output of one of them is posted above.

Type of Change

[x] Refactoring

Which Components or Systems Does This Change Impact?

[x] Governance proposal simulation

trunk-io[bot] commented 4 days ago

⏱️ 2h 19m total CI duration on this PR

| Slowest 15 Jobs | Cumulative Duration | Recent Runs | |---|---|---| | [rust-move-tests](https://github.com/aptos-labs/aptos-core/actions/runs/11977274427/job/33394792738) | 14m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977274427/job/33394792738) | | [execution-performance / test-target-determinator](https://github.com/aptos-labs/aptos-core/actions/runs/11977518532/job/33395574294) | 13m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11964837759/job/33357836548) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977274473/job/33394790590) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977518532/job/33395574294) | | [test-target-determinator](https://github.com/aptos-labs/aptos-core/actions/runs/11977518446/job/33395593535) | 13m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11964837856/job/33357843324) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977274542/job/33394798633) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977518446/job/33395593535) | | [rust-move-tests](https://github.com/aptos-labs/aptos-core/actions/runs/11963563026/job/33354226527) | 12m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11963563026/job/33354226527) | | [rust-move-tests](https://github.com/aptos-labs/aptos-core/actions/runs/11977518513/job/33395574288) | 12m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977518513/job/33395574288) | | [rust-move-tests](https://github.com/aptos-labs/aptos-core/actions/runs/11964837746/job/33357837476) | 12m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11964837746/job/33357837476) | | [check](https://github.com/aptos-labs/aptos-core/actions/runs/11977518503/job/33395574055) | 11m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11964837730/job/33357836462) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977274437/job/33394790389) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977518503/job/33395574055) | | [check-dynamic-deps](https://github.com/aptos-labs/aptos-core/actions/runs/11977518508/job/33395573461) | 9m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11964837729/job/33357836041) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977183451/job/33394503684) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977274443/job/33394789637) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977271436/job/33394780090) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977518508/job/33395573461) (+2 more) | | [rust-cargo-deny](https://github.com/aptos-labs/aptos-core/actions/runs/11977518505/job/33395599797) | 9m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11963563034/job/33354236831) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11964837737/job/33357845495) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977183445/job/33394517362) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977274445/job/33394839968) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977518505/job/33395599797) | | [rust-move-tests](https://github.com/aptos-labs/aptos-core/actions/runs/11977183433/job/33394504387) | 5m | [⬜](https://github.com/aptos-labs/aptos-core/actions/runs/11977183433/job/33394504387) | | [fetch-last-released-docker-image-tag](https://github.com/aptos-labs/aptos-core/actions/runs/11977518446/job/33395593864) | 5m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11964837856/job/33357843688) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977274542/job/33394798382) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977518446/job/33395593864) | | [rust-doc-tests](https://github.com/aptos-labs/aptos-core/actions/runs/11977518505/job/33395586211) | 5m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977518505/job/33395586211) | | [rust-doc-tests](https://github.com/aptos-labs/aptos-core/actions/runs/11977274445/job/33394827519) | 5m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977274445/job/33394827519) | | [rust-doc-tests](https://github.com/aptos-labs/aptos-core/actions/runs/11964837737/job/33357839447) | 4m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11964837737/job/33357839447) | | [semgrep/ci](https://github.com/aptos-labs/aptos-core/actions/runs/11977518509/job/33395573576) | 3m | [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11964837749/job/33357836063) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977183430/job/33394503562) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977271485/job/33394780362) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977274426/job/33394789353) [🟩](https://github.com/aptos-labs/aptos-core/actions/runs/11977518509/job/33395573576) (+2 more) |

🚨 1 job on the last run was significantly faster/slower than expected

Job	Duration	vs 7d avg	Delta
execution-performance / single-node-performance	10s	17m

_{settings ⋅ feedback ⋅ docs ⋅ learn more about trunk.io}

vineethk commented 4 days ago

#15363 👈 (View in Graphite)
main

This stack of pull requests is managed by Graphite. Learn more about stacking.

vineethk commented 4 days ago

Wondering if it's still clearer to keep the indentation but I guess it's more of a personal preference.

When printing the fee statement, keeping the indentation might have required custom implementations (instead of the format!("{:#?}")) to add the leading padding - did not seem worth the complication.

In the future we should probably introduce some sort of structural logging and make that the standard practice.

Agree.

vgao1996 commented 4 days ago

@vineethk agreed on the downsides. Although for this particular case I've found it easier to just add the indents at the string level.

github-actions[bot] commented 4 days ago

Forge is running suite `compat` on `a734d235af377347196f25d90291df51a23915b5` ==> `dea0710e195a105e1f4974a24c083c2a42059384`

github-actions[bot] commented 4 days ago

Forge is running suite `framework_upgrade` on `a734d235af377347196f25d90291df51a23915b5` ==> `dea0710e195a105e1f4974a24c083c2a42059384`

github-actions[bot] commented 4 days ago

Forge is running suite `realistic_env_max_load` on `dea0710e195a105e1f4974a24c083c2a42059384`

vineethk commented 4 days ago

@vineethk agreed on the downsides. Although for this particular case I've found it easier to just add the indents at the string level.

Can you add indent padding to each line of a struct debug display (note that {:#?} prints each field on a new line)?

vgao1996 commented 4 days ago

@vineethk yeah, I did this already in the code a few lines below

                    format!("{:#?}", txn_status)
                        .lines()
                        .map(|line| format!("        {}", line))
                        .collect::<Vec<_>>()
.join("\n")

Far from being efficient, but it works

github-actions[bot] commented 4 days ago

:white_check_mark: Forge suite `realistic_env_max_load` success on `dea0710e195a105e1f4974a24c083c2a42059384`

two traffics test: inner traffic : committed: 14468.49 txn/s, latency: 2748.73 ms, (p50: 2700 ms, p70: 2700, p90: 2900 ms, p99: 3000 ms), latency samples: 5501640
two traffics test : committed: 100.03 txn/s, latency: 1481.94 ms, (p50: 1400 ms, p70: 1400, p90: 1500 ms, p99: 8600 ms), latency samples: 1840
Latency breakdown for phase 0: ["MempoolToBlockCreation: max: 2.009, avg: 1.550", "ConsensusProposalToOrdered: max: 0.328, avg: 0.293", "ConsensusOrderedToCommit: max: 0.374, avg: 0.362", "ConsensusProposalToCommit: max: 0.665, avg: 0.656"]
Max non-epoch-change gap was: 0 rounds at version 0 (avg 0.00) [limit 4], 0.72s no progress at version 2065284 (avg 0.20s) [limit 15].
Max epoch-change gap was: 0 rounds at version 0 (avg 0.00) [limit 4], 8.60s no progress at version 2065282 (avg 7.50s) [limit 15].
Test Ok

github-actions[bot] commented 4 days ago

:white_check_mark: Forge suite `compat` success on `a734d235af377347196f25d90291df51a23915b5` ==> `dea0710e195a105e1f4974a24c083c2a42059384`

Compatibility test results for a734d235af377347196f25d90291df51a23915b5 ==> dea0710e195a105e1f4974a24c083c2a42059384 (PR)
1. Check liveness of validators at old version: a734d235af377347196f25d90291df51a23915b5
compatibility::simple-validator-upgrade::liveness-check : committed: 12697.54 txn/s, latency: 2689.99 ms, (p50: 1700 ms, p70: 1900, p90: 3300 ms, p99: 25400 ms), latency samples: 477520
2. Upgrading first Validator to new version: dea0710e195a105e1f4974a24c083c2a42059384
compatibility::simple-validator-upgrade::single-validator-upgrading : committed: 7461.84 txn/s, latency: 3849.22 ms, (p50: 4200 ms, p70: 4500, p90: 4700 ms, p99: 4700 ms), latency samples: 141640
compatibility::simple-validator-upgrade::single-validator-upgrade : committed: 6947.05 txn/s, latency: 4628.40 ms, (p50: 4600 ms, p70: 4700, p90: 6700 ms, p99: 6900 ms), latency samples: 231500
3. Upgrading rest of first batch to new version: dea0710e195a105e1f4974a24c083c2a42059384
compatibility::simple-validator-upgrade::half-validator-upgrading : committed: 5348.60 txn/s, latency: 5219.18 ms, (p50: 6000 ms, p70: 6100, p90: 6200 ms, p99: 6400 ms), latency samples: 111520
compatibility::simple-validator-upgrade::half-validator-upgrade : committed: 5726.00 txn/s, latency: 5636.91 ms, (p50: 6000 ms, p70: 6200, p90: 7700 ms, p99: 8000 ms), latency samples: 201280
4. upgrading second batch to new version: dea0710e195a105e1f4974a24c083c2a42059384
compatibility::simple-validator-upgrade::rest-validator-upgrading : committed: 11114.30 txn/s, latency: 2438.58 ms, (p50: 2400 ms, p70: 2700, p90: 3900 ms, p99: 4100 ms), latency samples: 188100
compatibility::simple-validator-upgrade::rest-validator-upgrade : committed: 11178.98 txn/s, latency: 2776.76 ms, (p50: 2400 ms, p70: 2700, p90: 5600 ms, p99: 7200 ms), latency samples: 360820
5. check swarm health
Compatibility test for a734d235af377347196f25d90291df51a23915b5 ==> dea0710e195a105e1f4974a24c083c2a42059384 passed
Test Ok

github-actions[bot] commented 4 days ago

:white_check_mark: Forge suite `framework_upgrade` success on `a734d235af377347196f25d90291df51a23915b5` ==> `dea0710e195a105e1f4974a24c083c2a42059384`

Compatibility test results for a734d235af377347196f25d90291df51a23915b5 ==> dea0710e195a105e1f4974a24c083c2a42059384 (PR)
Upgrade the nodes to version: dea0710e195a105e1f4974a24c083c2a42059384
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1405.40 txn/s, submitted: 1408.06 txn/s, failed submission: 2.66 txn/s, expired: 2.66 txn/s, latency: 2110.15 ms, (p50: 1800 ms, p70: 2100, p90: 3900 ms, p99: 5100 ms), latency samples: 127000
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1380.38 txn/s, submitted: 1383.73 txn/s, failed submission: 3.35 txn/s, expired: 3.35 txn/s, latency: 2209.26 ms, (p50: 2100 ms, p70: 2400, p90: 3500 ms, p99: 4800 ms), latency samples: 123720
5. check swarm health
Compatibility test for a734d235af377347196f25d90291df51a23915b5 ==> dea0710e195a105e1f4974a24c083c2a42059384 passed
Upgrade the remaining nodes to version: dea0710e195a105e1f4974a24c083c2a42059384
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1401.16 txn/s, submitted: 1404.30 txn/s, failed submission: 2.92 txn/s, expired: 3.14 txn/s, latency: 2219.39 ms, (p50: 2100 ms, p70: 2400, p90: 3500 ms, p99: 4600 ms), latency samples: 124561
Test Ok

vineethk commented 3 days ago

@vgao1996

Far from being efficient, but it works

Fair enough. I looked at things like println!("{:>8}!", "m") etc to see if there was someway to add padding more declaratively, but did not find anything. I have adopted your solution, especially because we already do this.

I've reverted the changes that removed padding elsewhere.