[go: up one dir, main page]

EVM/Kernel: log verbosity is set by the runtime

What

Following !14847 (merged), this MR implements verbosity level in the runtime directly. The verbosity is now ordered: Fatal < Error < Info < Debug < Benchmarks, so that enabling a level enables the previous one properly. Info remains the default level.

Why

Sometimes debugging a transaction or a block is difficult, as we don't enable the debug logs in production. The verbosity is set at compile time(*), as such debugging means compiling the kernel and patching it in the node for debug purpose. This MR is the first step to make the verbosity configurable by a flag in the storage.

(*) The idea was that we hoped that constant propagation would cut the verbosity check and we would gain few ticks by not having to test the verbosity.

How

  1. The verbosity levels are ordered, and representend by an integer so that it can be read from the storage (in a future MR). Making it explicitly represented by a u8 makes it shareable without needing to implement Copy (you can remove the commit and see that it doesn't compile anymore).
  2. Level::default() is set by the compile flag, so that it mimics the current behavior
  3. Introduce a Verbosity trait, that the Runtime implements to give the current verbosity of log
  4. log!` uses this trait to know the verbosity level and decide to show the logs or not

Manually testing the MR

Run the kernel before the MR, with and without EVM_KERNEL_FEATURES=debug, for example you can use the scenario below to test with and without the debug flag to witness that the logs are working as expected.

Here is a simple benchmark result of using the runtime for verbosity, with logs to Info:

node etherlink/kernel_evm/benchmarks/scripts/benchmarks/bench_imbricated_calls.js > evm-inputs/imbricated-calls.json

Before the MR:

./octez-smart-rollup-wasm-debugger --kernel evm_kernel.wasm --inputs evm-inputs/imbricated-calls.json --installer-config etherlink/config/benchmarking.yaml
> profile
Starting the profiling until new messages are expected. Please note that it will take some time and does not reflect a real computation time.
------------------ Kernel Invocation ------------------
[Info] Storing block 0 at 1970-01-01T00:00:00Z containing 3 transaction(s) for 22303401 gas used.
Profiling result can be found in /tmp/wasm-debugger-profiling-2024-09-12T13:38:01.420-00:00.out
----------------------
Detailed results for a `kernel_run`:
%interpreter(decode): 3956325 ticks (5.931s)
%interpreter(link): 17 ticks (7.22us)
%interpreter(init): 64812885 ticks (17.939s)
kernel_run: 17523627 ticks (4.641s)

Full execution: 86292854 ticks (28.512s)
----------------------
Detailed results for a `kernel_run`:
%interpreter(decode): 3956325 ticks (5.646s)
%interpreter(link): 17 ticks (7.615us)
%interpreter(init): 64812885 ticks (18.1s)
kernel_run: 273832773 ticks (1min15s)

Full execution: 342602000 ticks (1min38s)
----------------------
Full execution with padding: 100000000000000 ticks

After the MR:

 ./octez-smart-rollup-wasm-debugger --kernel evm_kernel.wasm --inputs evm-inputs/imbricated-calls.json --installer-config etherlink/config/benchmarking.yaml
> profile
Starting the profiling until new messages are expected. Please note that it will take some time and does not reflect a real computation time.
------------------ Kernel Invocation ------------------
[Info] Storing block 0 at 1970-01-01T00:00:00Z containing 3 transaction(s) for 22303401 gas used.
Profiling result can be found in /tmp/wasm-debugger-profiling-2024-09-12T13:31:10.642-00:00.out
----------------------
Detailed results for a `kernel_run`:
%interpreter(decode): 4017736 ticks (6.20s)
%interpreter(link): 17 ticks (7.270us)
%interpreter(init): 65319195 ticks (18.50s)
kernel_run: 17523215 ticks (4.692s)

Full execution: 86860163 ticks (28.762s)
----------------------
Detailed results for a `kernel_run`:
%interpreter(decode): 4017736 ticks (6.161s)
%interpreter(link): 17 ticks (11.824us)
%interpreter(init): 65319195 ticks (17.944s)
kernel_run: 273881663 ticks (1min15s)

Full execution: 343218611 ticks (1min39s)
----------------------
Full execution with padding: 100000000000000 ticks

We can see that for both execution, the difference for kernel_run is basically the same, so it doesn't affect the performance.

Checklist

  • Document the interface of any function added or modified (see the coding guidelines)
  • Document any change to the user interface, including configuration parameters (see node configuration)
  • Provide automatic testing (see the testing guide).
  • For new features and bug fixes, add an item in the appropriate changelog (docs/protocols/alpha.rst for the protocol and the environment, CHANGES.rst at the root of the repository for everything else).
  • Select suitable reviewers using the Reviewers field below.
  • Select as Assignee the next person who should take action on that MR
Edited by Pierrick Couderc

Merge request reports

Loading