Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

chore: Reduce log verbosity in local e2e tests #5622

Merged
merged 4 commits into from
Apr 9, 2024
Merged

Conversation

spalladino
Copy link
Collaborator

Updates all debug logger uses to log with an explicit log level. The log level for every single usage definitely needs finer tuning, but it's a first step.

Defaults e2e tests run locally (not on CI) to verbose log level. Removes almost-unused trace log level (which was below debug).

@spalladino spalladino enabled auto-merge (squash) April 8, 2024 21:47
@AztecBot
Copy link
Collaborator

AztecBot commented Apr 8, 2024

Benchmark results

Metrics with a significant change:

  • note_successful_decrypting_time_in_ms (8): 205 (-18%)
  • note_trial_decrypting_time_in_ms (8): 106 (+100%)
  • note_trial_decrypting_time_in_ms (64): 85.4 (+152%)
Detailed results

All benchmarks are run on txs on the Benchmarking contract on the repository. Each tx consists of a batch call to create_note and increment_balance, which guarantees that each tx has a private call, a nested private call, a public call, and a nested public call, as well as an emitted private note, an unencrypted log, and public storage read and write.

This benchmark source data is available in JSON format on S3 here.

Values are compared against data from master at commit 7e4e9b98 and shown if the difference exceeds 1%.

L2 block published to L1

Each column represents the number of txs on an L2 block published to L1.

Metric 8 txs 32 txs 64 txs
l1_rollup_calldata_size_in_bytes 676 676 676
l1_rollup_calldata_gas 6,424 6,424 6,424
l1_rollup_execution_gas 585,757 585,757 585,757
l2_block_processing_time_in_ms 1,392 (+5%) 4,761 (+1%) 9,376 (-1%)
note_successful_decrypting_time_in_ms ⚠️ 205 (-18%) 542 (-13%) 965 (-7%)
note_trial_decrypting_time_in_ms ⚠️ 106 (+100%) 52.6 (+58%) ⚠️ 85.4 (+152%)
l2_block_building_time_in_ms 11,814 (-1%) 42,941 (-1%) 84,306 (-1%)
l2_block_rollup_simulation_time_in_ms 11,777 (-1%) 42,819 (-1%) 84,064 (-1%)
l2_block_public_tx_process_time_in_ms 6,122 (-1%) 24,077 (-1%) 48,159 (-2%)

L2 chain processing

Each column represents the number of blocks on the L2 chain where each block has 16 txs.

Metric 5 blocks 10 blocks
node_history_sync_time_in_ms 14,499 (+8%) 26,555 (-5%)
note_history_successful_decrypting_time_in_ms 1,256 (-5%) 2,443 (+7%)
note_history_trial_decrypting_time_in_ms 76.0 (-11%) 100 (+30%)
node_database_size_in_bytes 18,616,400 34,857,040 (-1%)
pxe_database_size_in_bytes 29,859 59,414

Circuits stats

Stats on running time and I/O sizes collected for every circuit run across all benchmarks.

Circuit circuit_simulation_time_in_ms circuit_input_size_in_bytes circuit_output_size_in_bytes
private-kernel-init 182 (+3%) 44,377 26,164
private-kernel-ordering 164 (+3%) 50,830 39,026
base-parity 3,987 (+5%) 128 311
root-parity 1,061 (-1%) 1,244 311
base-rollup 14,263 (+1%) 110,464 861
root-rollup 49.6 (+1%) 4,359 725
private-kernel-inner 220 (+3%) 71,744 26,164
public-kernel-app-logic 120 (+2%) 47,695 40,661
public-kernel-tail 164 (+2%) 53,372 7,125
merge-rollup 10.0 (-5%) 2,568 861
public-kernel-teardown 117 47,695 40,661
public-kernel-setup 116 47,695 40,661

Tree insertion stats

The duration to insert a fixed batch of leaves into each tree type.

Metric 1 leaves 16 leaves 64 leaves 128 leaves 512 leaves 1024 leaves 2048 leaves 4096 leaves 32 leaves
batch_insert_into_append_only_tree_16_depth_ms 10.1 (+2%) 16.2 (+1%) N/A N/A N/A N/A N/A N/A N/A
batch_insert_into_append_only_tree_16_depth_hash_count 16.8 31.6 N/A N/A N/A N/A N/A N/A N/A
batch_insert_into_append_only_tree_16_depth_hash_ms 0.587 (+2%) 0.499 (+1%) N/A N/A N/A N/A N/A N/A N/A
batch_insert_into_append_only_tree_32_depth_ms N/A N/A 46.0 (+1%) 72.2 (+2%) 231 447 (+3%) 869 1,735 N/A
batch_insert_into_append_only_tree_32_depth_hash_count N/A N/A 96.0 159 543 1,055 2,079 4,127 N/A
batch_insert_into_append_only_tree_32_depth_hash_ms N/A N/A 0.471 (+1%) 0.445 (+2%) 0.420 0.418 (+4%) 0.412 0.414 N/A
batch_insert_into_indexed_tree_20_depth_ms N/A N/A 54.3 (+1%) 107 (+2%) 340 (+1%) 661 (+4%) 1,317 2,620 (-2%) N/A
batch_insert_into_indexed_tree_20_depth_hash_count N/A N/A 105 207 691 1,363 2,707 5,395 N/A
batch_insert_into_indexed_tree_20_depth_hash_ms N/A N/A 0.479 (+2%) 0.482 (+2%) 0.461 (+1%) 0.455 (+4%) 0.456 (+1%) 0.454 (-2%) N/A
batch_insert_into_indexed_tree_40_depth_ms N/A N/A N/A N/A N/A N/A N/A N/A 61.2 (+2%)
batch_insert_into_indexed_tree_40_depth_hash_count N/A N/A N/A N/A N/A N/A N/A N/A 109
batch_insert_into_indexed_tree_40_depth_hash_ms N/A N/A N/A N/A N/A N/A N/A N/A 0.534 (+2%)

Miscellaneous

Transaction sizes based on how many contract classes are registered in the tx.

Metric 0 registered classes 1 registered classes
tx_size_in_bytes 40,372 496,534

Transaction size based on fee payment method

Metric native fee payment method fpc_public fee payment method fpc_private fee payment method
tx_with_fee_size_in_bytes 905 1,161 1,377

Transaction processing duration by data writes.

Metric 0 new note hashes 1 new note hashes 2 new note hashes
tx_pxe_processing_time_ms 1,688 (-1%) 1,092 (+2%) 5,360 (-1%)
Metric 1 public data writes 2 public data writes 3 public data writes 4 public data writes 5 public data writes 8 public data writes
tx_sequencer_processing_time_ms 579 (+1%) 396 (-1%) 1,064 517 1,734 579 (-1%)

Copy link
Contributor

@fcarreiro fcarreiro left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes please!

Maybe you can also modify logger.ts so the created object does not act as a function, and you are forced to choose a log level?

@spalladino
Copy link
Collaborator Author

Maybe you can also modify logger.ts so the created object does not act as a function, and you are forced to choose a log level?

I had actually done that to find out all uses without an unspecified level, and then reverted it back. But I agree, sounds like a good change to keep.

@spalladino spalladino merged commit c496a10 into master Apr 9, 2024
147 checks passed
@spalladino spalladino deleted the palla/review-logs branch April 9, 2024 13:31
rahul-kothari pushed a commit that referenced this pull request Apr 10, 2024
🤖 I have created a release *beep* *boop*
---


<details><summary>aztec-package: 0.34.0</summary>

##
[0.34.0](aztec-package-v0.33.0...aztec-package-v0.34.0)
(2024-04-10)


### Miscellaneous

* Reduce log verbosity in local e2e tests
([#5622](#5622))
([c496a10](c496a10))
</details>

<details><summary>barretenberg.js: 0.34.0</summary>

##
[0.34.0](barretenberg.js-v0.33.0...barretenberg.js-v0.34.0)
(2024-04-10)


### Miscellaneous

* **barretenberg.js:** Synchronize aztec-packages versions
</details>

<details><summary>aztec-cli: 0.34.0</summary>

##
[0.34.0](aztec-cli-v0.33.0...aztec-cli-v0.34.0)
(2024-04-10)


### Miscellaneous

* Reduce log verbosity in local e2e tests
([#5622](#5622))
([c496a10](c496a10))
</details>

<details><summary>aztec-packages: 0.34.0</summary>

##
[0.34.0](aztec-packages-v0.33.0...aztec-packages-v0.34.0)
(2024-04-10)


### ⚠ BREAKING CHANGES

* remove fixed-length keccak256
([#5617](#5617))

### Features

* **acvm_js:** Execute program
(noir-lang/noir#4694)
([ff28080](ff28080))
* Add `remove_enable_side_effects` SSA pass
(noir-lang/noir#4224)
([ff28080](ff28080))
* Allow slices to brillig entry points
(noir-lang/noir#4713)
([ff28080](ff28080))
* **avm:** Basic AVM-ACVM interoperability
([#5595](#5595))
([d872445](d872445))
* **avm:** Make authwit work with avm
([#5594](#5594))
([b02d1e1](b02d1e1))
* **docs:** Documenting noir codegen
(noir-lang/noir#4454)
([ff28080](ff28080))
* Generalize protogalaxy to multiple instances
([#5510](#5510))
([f038b70](f038b70))
* Improve nargo check cli with --override flag and feedback for existing
files (noir-lang/noir#4575)
([ff28080](ff28080))
* Improve optimisations on range constraints
(noir-lang/noir#4690)
([ff28080](ff28080))
* Improve SSA type-awareness in EQ and MUL instructions
(noir-lang/noir#4691)
([ff28080](ff28080))
* **nargo:** Multiple circuits info for binary programs
(noir-lang/noir#4719)
([ff28080](ff28080))
* Stdlib databus
([#5598](#5598))
([633a711](633a711))


### Bug Fixes

* **acvm:** Mark outputs of Opcode::Call solvable
(noir-lang/noir#4708)
([ff28080](ff28080))
* Do not retry RPC requests on 4xx errors
([#5634](#5634))
([5af2b95](5af2b95))
* Field comparisons (noir-lang/noir#4704)
([ff28080](ff28080))
* Last use analysis & make it an SSA pass
(noir-lang/noir#4686)
([ff28080](ff28080))
* **ssa:** Do not use get_value_max_num_bits when we want pure type
information (noir-lang/noir#4700)
([ff28080](ff28080))
* Unknown slice lengths coming from as_slice
(noir-lang/noir#4725)
([ff28080](ff28080))
* Use empty artifact in test
([#5640](#5640))
([1d18a5e](1d18a5e))


### Miscellaneous

* Check for references to private functions during path resolution
(noir-lang/noir#4622)
([ff28080](ff28080))
* **ci:** Fix cutting new versions of the docs
(noir-lang/noir#4737)
([ff28080](ff28080))
* **ci:** Replace `yarn build:js:only` script
(noir-lang/noir#4735)
([ff28080](ff28080))
* **ci:** Stop updating version list before cutting new docs version
(noir-lang/noir#4726)
([ff28080](ff28080))
* Disable earthly cloud
([#5639](#5639))
([47e9c25](47e9c25))
* Fix clippy errors (noir-lang/noir#4684)
([ff28080](ff28080))
* Reduce log verbosity in local e2e tests
([#5622](#5622))
([c496a10](c496a10))
* Remove `FunctionInput::dummy`
(noir-lang/noir#4723)
([ff28080](ff28080))
* Remove conditional compilation around `acvm_js` package
(noir-lang/noir#4702)
([ff28080](ff28080))
* Remove docker CI flow (noir-lang/noir#4724)
([ff28080](ff28080))
* Remove fixed-length keccak256
([#5617](#5617))
([40480b3](40480b3))
* Remove last traces of nix
(noir-lang/noir#4679)
([ff28080](ff28080))
* Remove unused env vars from `Cross.toml`
(noir-lang/noir#4717)
([ff28080](ff28080))
* Replace relative paths to noir-protocol-circuits
([bc214c5](bc214c5))
* Simplify how `acvm_backend.wasm` is embedded
(noir-lang/noir#4703)
([ff28080](ff28080))
* Simplify how blns is loaded into tests
(noir-lang/noir#4705)
([ff28080](ff28080))
* Update condition for clearing warning comment on release PRs
(noir-lang/noir#4739)
([ff28080](ff28080))
* Update from vulnerable version of h2
(noir-lang/noir#4714)
([ff28080](ff28080))
* Update JS publish workflow to upload build artifacts correctly.
(noir-lang/noir#4734)
([ff28080](ff28080))
* Use is_entry_point helper on RuntimeType
(noir-lang/noir#4678)
([ff28080](ff28080))
</details>

<details><summary>barretenberg: 0.34.0</summary>

##
[0.34.0](barretenberg-v0.33.0...barretenberg-v0.34.0)
(2024-04-10)


### ⚠ BREAKING CHANGES

* remove fixed-length keccak256
([#5617](#5617))

### Features

* Generalize protogalaxy to multiple instances
([#5510](#5510))
([f038b70](f038b70))
* Stdlib databus
([#5598](#5598))
([633a711](633a711))


### Miscellaneous

* Remove fixed-length keccak256
([#5617](#5617))
([40480b3](40480b3))
</details>

---
This PR was generated with [Release
Please](https://github.com/googleapis/release-please). See
[documentation](https://github.com/googleapis/release-please#release-please).
AztecBot added a commit to AztecProtocol/barretenberg that referenced this pull request Apr 11, 2024
🤖 I have created a release *beep* *boop*
---


<details><summary>aztec-package: 0.34.0</summary>

##
[0.34.0](AztecProtocol/aztec-packages@aztec-package-v0.33.0...aztec-package-v0.34.0)
(2024-04-10)


### Miscellaneous

* Reduce log verbosity in local e2e tests
([#5622](AztecProtocol/aztec-packages#5622))
([c496a10](AztecProtocol/aztec-packages@c496a10))
</details>

<details><summary>barretenberg.js: 0.34.0</summary>

##
[0.34.0](AztecProtocol/aztec-packages@barretenberg.js-v0.33.0...barretenberg.js-v0.34.0)
(2024-04-10)


### Miscellaneous

* **barretenberg.js:** Synchronize aztec-packages versions
</details>

<details><summary>aztec-cli: 0.34.0</summary>

##
[0.34.0](AztecProtocol/aztec-packages@aztec-cli-v0.33.0...aztec-cli-v0.34.0)
(2024-04-10)


### Miscellaneous

* Reduce log verbosity in local e2e tests
([#5622](AztecProtocol/aztec-packages#5622))
([c496a10](AztecProtocol/aztec-packages@c496a10))
</details>

<details><summary>aztec-packages: 0.34.0</summary>

##
[0.34.0](AztecProtocol/aztec-packages@aztec-packages-v0.33.0...aztec-packages-v0.34.0)
(2024-04-10)


### ⚠ BREAKING CHANGES

* remove fixed-length keccak256
([#5617](AztecProtocol/aztec-packages#5617))

### Features

* **acvm_js:** Execute program
(noir-lang/noir#4694)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Add `remove_enable_side_effects` SSA pass
(noir-lang/noir#4224)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Allow slices to brillig entry points
(noir-lang/noir#4713)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* **avm:** Basic AVM-ACVM interoperability
([#5595](AztecProtocol/aztec-packages#5595))
([d872445](AztecProtocol/aztec-packages@d872445))
* **avm:** Make authwit work with avm
([#5594](AztecProtocol/aztec-packages#5594))
([b02d1e1](AztecProtocol/aztec-packages@b02d1e1))
* **docs:** Documenting noir codegen
(noir-lang/noir#4454)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Generalize protogalaxy to multiple instances
([#5510](AztecProtocol/aztec-packages#5510))
([f038b70](AztecProtocol/aztec-packages@f038b70))
* Improve nargo check cli with --override flag and feedback for existing
files (noir-lang/noir#4575)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Improve optimisations on range constraints
(noir-lang/noir#4690)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Improve SSA type-awareness in EQ and MUL instructions
(noir-lang/noir#4691)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* **nargo:** Multiple circuits info for binary programs
(noir-lang/noir#4719)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Stdlib databus
([#5598](AztecProtocol/aztec-packages#5598))
([633a711](AztecProtocol/aztec-packages@633a711))


### Bug Fixes

* **acvm:** Mark outputs of Opcode::Call solvable
(noir-lang/noir#4708)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Do not retry RPC requests on 4xx errors
([#5634](AztecProtocol/aztec-packages#5634))
([5af2b95](AztecProtocol/aztec-packages@5af2b95))
* Field comparisons (noir-lang/noir#4704)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Last use analysis & make it an SSA pass
(noir-lang/noir#4686)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* **ssa:** Do not use get_value_max_num_bits when we want pure type
information (noir-lang/noir#4700)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Unknown slice lengths coming from as_slice
(noir-lang/noir#4725)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Use empty artifact in test
([#5640](AztecProtocol/aztec-packages#5640))
([1d18a5e](AztecProtocol/aztec-packages@1d18a5e))


### Miscellaneous

* Check for references to private functions during path resolution
(noir-lang/noir#4622)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* **ci:** Fix cutting new versions of the docs
(noir-lang/noir#4737)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* **ci:** Replace `yarn build:js:only` script
(noir-lang/noir#4735)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* **ci:** Stop updating version list before cutting new docs version
(noir-lang/noir#4726)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Disable earthly cloud
([#5639](AztecProtocol/aztec-packages#5639))
([47e9c25](AztecProtocol/aztec-packages@47e9c25))
* Fix clippy errors (noir-lang/noir#4684)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Reduce log verbosity in local e2e tests
([#5622](AztecProtocol/aztec-packages#5622))
([c496a10](AztecProtocol/aztec-packages@c496a10))
* Remove `FunctionInput::dummy`
(noir-lang/noir#4723)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Remove conditional compilation around `acvm_js` package
(noir-lang/noir#4702)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Remove docker CI flow (noir-lang/noir#4724)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Remove fixed-length keccak256
([#5617](AztecProtocol/aztec-packages#5617))
([40480b3](AztecProtocol/aztec-packages@40480b3))
* Remove last traces of nix
(noir-lang/noir#4679)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Remove unused env vars from `Cross.toml`
(noir-lang/noir#4717)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Replace relative paths to noir-protocol-circuits
([bc214c5](AztecProtocol/aztec-packages@bc214c5))
* Simplify how `acvm_backend.wasm` is embedded
(noir-lang/noir#4703)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Simplify how blns is loaded into tests
(noir-lang/noir#4705)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Update condition for clearing warning comment on release PRs
(noir-lang/noir#4739)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Update from vulnerable version of h2
(noir-lang/noir#4714)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Update JS publish workflow to upload build artifacts correctly.
(noir-lang/noir#4734)
([ff28080](AztecProtocol/aztec-packages@ff28080))
* Use is_entry_point helper on RuntimeType
(noir-lang/noir#4678)
([ff28080](AztecProtocol/aztec-packages@ff28080))
</details>

<details><summary>barretenberg: 0.34.0</summary>

##
[0.34.0](AztecProtocol/aztec-packages@barretenberg-v0.33.0...barretenberg-v0.34.0)
(2024-04-10)


### ⚠ BREAKING CHANGES

* remove fixed-length keccak256
([#5617](AztecProtocol/aztec-packages#5617))

### Features

* Generalize protogalaxy to multiple instances
([#5510](AztecProtocol/aztec-packages#5510))
([f038b70](AztecProtocol/aztec-packages@f038b70))
* Stdlib databus
([#5598](AztecProtocol/aztec-packages#5598))
([633a711](AztecProtocol/aztec-packages@633a711))


### Miscellaneous

* Remove fixed-length keccak256
([#5617](AztecProtocol/aztec-packages#5617))
([40480b3](AztecProtocol/aztec-packages@40480b3))
</details>

---
This PR was generated with [Release
Please](https://github.com/googleapis/release-please). See
[documentation](https://github.com/googleapis/release-please#release-please).
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants