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
- 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
u8makes it shareable without needing to implementCopy(you can remove the commit and see that it doesn't compile anymore). - Level::default() is set by the compile flag, so that it mimics the current behavior
- Introduce a
Verbositytrait, that the Runtime implements to give the current verbosity of log - 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.rstfor the protocol and the environment,CHANGES.rstat the root of the repository for everything else). -
Select suitable reviewers using the Reviewersfield below. -
Select as Assigneethe next person who should take action on that MR