op-node: log mgasps across event based block processing lifecycle

[bitwiseguy]

Overview

In order to provide more visibility into the block processing performance of op-node + its execution client, this pr attempts to add logs to surface data for plotting mgasps (Mgas per second) for every block.

This is similar to the log written by op-geth here, however this pr attempts to provide a more holistic view of mgasps by logging duration of the entire block processing lifecycle instead of just the engineApi.NewPayload portion of block processing. The entire lifecycle consists of the following sequential engineApi calls:

1. engineApi.ForkchoiceUpdate (with block attributes)
2. engineApi.GetPayload
3. engineApi.NewPayload
4. engineApi.ForkchoiceUpdate

Event state machine

• BuildStartEvent
  • EngDeriver.onBuildStart
    • engine.startPayload
      • engine.ForkchoiceUpdate(attrs)
    • emit ForkchoiceUpdateEvent
    • emit BuildStartedEvent
• BuildStartedEvent
  • EngDeriver.onBuildStarted (basically a no-op)
    • emit BuildSealEvent
• BuildSealEvent
  • EngDeriver.onBuildSeal
    • engine.GetPayload
    • log Built new l2 block
      • seal_time (covers GetPayload)
      • build_time (covers ForkchoiceUpdate + GetPayload)
    • emit BuildSealedEvent
• BuildSealedEvent
  • EngDeriver.onBuildSealed (basically a no-op)
    • emit PayloadProcessEvent
• PayloadProcessEvent
  • EngDeriver.onPayloadProcess
    • engineFork.NewPayload
    • emit PayloadSuccessEvent
• PayloadSuccessEvent
  • EngDeriver.onPayloadSuccess
    • log Inserted block
      • build_time (ForkchoiceUpdate + GetPayload)
      • import_time (NewPayload)
      • total_time
      • mgasps
    • emit TryUpdateEngineEvent

Open questions

1. Why do I not see any of these logs emitted by op-node? Does that event handler only get triggered by a certain sync type (execution-layer versus consensus-layer)?

   Answer: For block processing of P2P blocks as verifier, there is still an older payload processing function, that does not use those events. It’s attached to the engine-controller. I am keen to remove that and to make it consistent with the sequencing / block replication codepath.

2. Should we include TryUpdateEngineEvent processing time in total_time value?

Metadata

Closes https://github.com/ethereum-optimism/platforms-team/issues/446

[codecov[bot]]

Codecov Report

All modified and coverable lines are covered by tests :white_check_mark:

Project coverage is 66.77%. Comparing base (72e67e5) to head (d7906bb).

Additional details and impacted files

```diff @@ Coverage Diff @@ ## develop #12907 +/- ## =========================================== - Coverage 68.78% 66.77% -2.02% =========================================== Files 56 56 Lines 4665 4665 =========================================== - Hits 3209 3115 -94 - Misses 1274 1378 +104 + Partials 182 172 -10 ``` | [Flag](https://app.codecov.io/gh/ethereum-optimism/optimism/pull/12907/flags?src=pr&el=flags&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=ethereum-optimism) | Coverage Δ | | |---|---|---| | [cannon-go-tests-32](https://app.codecov.io/gh/ethereum-optimism/optimism/pull/12907/flags?src=pr&el=flag&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=ethereum-optimism) | `61.81% <ø> (-2.02%)` | :arrow_down: | | [cannon-go-tests-64](https://app.codecov.io/gh/ethereum-optimism/optimism/pull/12907/flags?src=pr&el=flag&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=ethereum-optimism) | `56.38% <ø> (-1.66%)` | :arrow_down: | Flags with carried forward coverage won't be shown. [Click here](https://docs.codecov.io/docs/carryforward-flags?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=ethereum-optimism#carryforward-flags-in-the-pull-request-comment) to find out more. [see 8 files with indirect coverage changes](https://app.codecov.io/gh/ethereum-optimism/optimism/pull/12907/indirect-changes?src=pr&el=tree-more&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=ethereum-optimism)