fix: Sporadic failure of GoblinRecursionTests.Vanilla

[codygunton]

The test in question would fail sporadically. It was fixed by disabling multithreading for certain loops in the MSM builder. This introduces a small regression which is probably not worth fixing (.16s in WASM).

A deep investigation showed that is due to one of these four values

aztec-packages/barretenberg/cpp/src/barretenberg/eccvm/eccvm_flavor.hpp

Line 590 in e85dde9

msm_lambda1[i] = msm_state[i].add_state[0].lambda;

aztec-packages/barretenberg/cpp/src/barretenberg/eccvm/eccvm_flavor.hpp

Line 591 in e85dde9

msm_lambda2[i] = msm_state[i].add_state[1].lambda;

aztec-packages/barretenberg/cpp/src/barretenberg/eccvm/eccvm_flavor.hpp

Line 592 in e85dde9

msm_lambda3[i] = msm_state[i].add_state[2].lambda;

aztec-packages/barretenberg/cpp/src/barretenberg/eccvm/eccvm_flavor.hpp

Line 593 in e85dde9

msm_lambda4[i] = msm_state[i].add_state[3].lambda;

being zero in the failing run. Even with reproducible randomness, a subsequent run would show a passing test, and a henceforth reproducible value of the value that had been zero. Also of note is the fact that the circuit_size value read from the transcript in the Translator verifier in the failing run would be a seemingly random 32-bit integer.

A similar failure is encountered much more rarely in ECCVMCircuitBuilderTests.MSM. There the circuit builder failure indicates that an execution of one of the doubling subrelations

aztec-packages/barretenberg/cpp/src/barretenberg/relations/ecc_vm/ecc_msm_relation.cpp

Line 246 in fcac844

std::get<10>(accumulator) += q_double * (acc_x_shift - x_d4) * scaling_factor;

aztec-packages/barretenberg/cpp/src/barretenberg/relations/ecc_vm/ecc_msm_relation.cpp

Line 247 in fcac844

std::get<11>(accumulator) += q_double * (acc_y_shift - y_d4) * scaling_factor;

aztec-packages/barretenberg/cpp/src/barretenberg/relations/ecc_vm/ecc_msm_relation.cpp

Line 248 in fcac844

std::get<12>(accumulator) += q_double * double_relation * scaling_factor;

is to blame.

The thread sanitizer gives nothing, but the fix is apparently due to threading, as disabling multithreading in two loops in the MSM causes the test to not fail over the course of more than 5000 runs.

I also tweak some benchmarking scripts to give better comparisons. Here is the regression:

Benchmark                               Time             CPU      Time Old      Time New       CPU Old       CPU New
--------------------------------------------------------------------------------------------------------------------
ClientIVCBench/Full/6                +0.0023         -0.0041         20571         20617         15444         15381
OVERALL_GEOMEAN                      +0.0023         -0.0041            21            21            15            15

Or, more manually:

Before

Breakdown

Benchmarking lock created at ~/BENCHMARK_IN_PROGRESS.
client_ivc_bench                                                                                                                                                                                        100%   19MB  57.9MB/s   00:00    
2024-05-06T14:26:13+00:00
Running ./client_ivc_bench
Run on (16 X 3604.95 MHz CPU s)
CPU Caches:
  L1 Data 32 KiB (x8)
  L1 Instruction 32 KiB (x8)
  L2 Unified 1024 KiB (x8)
  L3 Unified 36608 KiB (x1)
Load Average: 0.28, 0.81, 0.43
--------------------------------------------------------------------------------
Benchmark                      Time             CPU   Iterations UserCounters...
--------------------------------------------------------------------------------
ClientIVCBench/Full/6      20476 ms        15330 ms            1 Decider::construct_proof=1 Decider::construct_proof(t)=561.707M ECCVMProver(CircuitBuilder&)=1 ECCVMProver(CircuitBuilder&)(t)=129.19M ECCVMProver::construct_proof=1 ECCVMProver::construct_proof(t)=1.76198G Goblin::merge=11 Goblin::merge(t)=137.338M GoblinTranslatorCircuitBuilder::constructor=1 GoblinTranslatorCircuitBuilder::constructor(t)=61.9434M GoblinTranslatorProver=1 GoblinTranslatorProver(t)=58.0111M GoblinTranslatorProver::construct_proof=1 GoblinTranslatorProver::construct_proof(t)=947.523M ProtoGalaxyProver_::accumulator_update_round=10 ProtoGalaxyProver_::accumulator_update_round(t)=284.299M ProtoGalaxyProver_::combiner_quotient_round=10 ProtoGalaxyProver_::combiner_quotient_round(t)=5.07493G ProtoGalaxyProver_::perturbator_round=10 ProtoGalaxyProver_::perturbator_round(t)=1.15172G ProtoGalaxyProver_::preparation_round=10 ProtoGalaxyProver_::preparation_round(t)=3.89712G ProtogalaxyProver::fold_instances=10 ProtogalaxyProver::fold_instances(t)=10.4081G ProverInstance(Circuit&)=11 ProverInstance(Circuit&)(t)=1.92464G batch_mul_with_endomorphism=30 batch_mul_with_endomorphism(t)=564.102M commit=459 commit(t)=4.23739G compute_combiner=10 compute_combiner(t)=5.07289G compute_perturbator=9 compute_perturbator(t)=1.15142G compute_univariate=48 compute_univariate(t)=1.20953G construct_circuits=6 construct_circuits(t)=4.46081G
Benchmarking lock deleted.
client_ivc_bench.json                                                                                                                                                                                   100% 3581   119.9KB/s   00:00    
function                                        ms     % sum
construct_circuits(t)                         4461    21.94%
ProverInstance(Circuit&)(t)                   1925     9.47%
ProtogalaxyProver::fold_instances(t)         10408    51.19%
Decider::construct_proof(t)                    562     2.76%
ECCVMProver(CircuitBuilder&)(t)                129     0.64%
ECCVMProver::construct_proof(t)               1762     8.67%
GoblinTranslatorProver::construct_proof(t)     948     4.66%
Goblin::merge(t)                               137     0.68%

Total time accounted for: 20331ms/20476ms = 99.29%

Major contributors:
function                                        ms    % sum
commit(t)                                     4237   20.84%
compute_combiner(t)                           5073   24.95%
compute_perturbator(t)                        1151    5.66%
compute_univariate(t)                         1210    5.95%

Breakdown of ProtogalaxyProver::fold_instances:
ProtoGalaxyProver_::preparation_round(t)           3897    37.44%
ProtoGalaxyProver_::perturbator_round(t)           1152    11.07%
ProtoGalaxyProver_::combiner_quotient_round(t)     5075    48.76%
ProtoGalaxyProver_::accumulator_update_round(t)     284     2.73%

WASM

Benchmarking lock created at ~/BENCHMARK_IN_PROGRESS.
client_ivc_bench                                                                                                                                                                                        100%   33MB  65.0MB/s   00:00    
failed to open /proc/cpuinfo
***WARNING*** Failed to set thread affinity. Estimated CPU frequency may be incorrect.
2024-05-06T14:42:56+00:00
Running client_ivc_bench
Run on (-1 X 0.999999 MHz CPU )
----------------------------------------------------------------
Benchmark                      Time             CPU   Iterations
----------------------------------------------------------------
ClientIVCBench/Full/6      79592 ms   7.9592e+10 ms            1

After

Breakdown

Benchmarking lock created at ~/BENCHMARK_IN_PROGRESS.
client_ivc_bench                                                                                                                                                                                        100%   19MB  54.2MB/s   00:00    
2024-05-06T14:23:04+00:00
Running ./client_ivc_bench
Run on (16 X 3000 MHz CPU s)
CPU Caches:
  L1 Data 32 KiB (x8)
  L1 Instruction 32 KiB (x8)
  L2 Unified 1024 KiB (x8)
  L3 Unified 36608 KiB (x1)
Load Average: 0.83, 0.61, 0.25
--------------------------------------------------------------------------------
Benchmark                      Time             CPU   Iterations UserCounters...
--------------------------------------------------------------------------------
ClientIVCBench/Full/6      20599 ms        15438 ms            1 Decider::construct_proof=1 Decider::construct_proof(t)=569.231M ECCVMProver(CircuitBuilder&)=1 ECCVMProver(CircuitBuilder&)(t)=170.572M ECCVMProver::construct_proof=1 ECCVMProver::construct_proof(t)=1.76239G Goblin::merge=11 Goblin::merge(t)=136.71M GoblinTranslatorCircuitBuilder::constructor=1 GoblinTranslatorCircuitBuilder::constructor(t)=62.0289M GoblinTranslatorProver=1 GoblinTranslatorProver(t)=60.1652M GoblinTranslatorProver::construct_proof=1 GoblinTranslatorProver::construct_proof(t)=953.785M ProtoGalaxyProver_::accumulator_update_round=10 ProtoGalaxyProver_::accumulator_update_round(t)=284.362M ProtoGalaxyProver_::combiner_quotient_round=10 ProtoGalaxyProver_::combiner_quotient_round(t)=5.09441G ProtoGalaxyProver_::perturbator_round=10 ProtoGalaxyProver_::perturbator_round(t)=1.15814G ProtoGalaxyProver_::preparation_round=10 ProtoGalaxyProver_::preparation_round(t)=3.91269G ProtogalaxyProver::fold_instances=10 ProtogalaxyProver::fold_instances(t)=10.4496G ProverInstance(Circuit&)=11 ProverInstance(Circuit&)(t)=1.91455G batch_mul_with_endomorphism=30 batch_mul_with_endomorphism(t)=565.174M commit=459 commit(t)=4.25227G compute_combiner=10 compute_combiner(t)=5.09235G compute_perturbator=9 compute_perturbator(t)=1.15783G compute_univariate=48 compute_univariate(t)=1.21867G construct_circuits=6 construct_circuits(t)=4.4946G
Benchmarking lock deleted.
client_ivc_bench.json                                                                                                                                                                                   100% 3581   108.1KB/s   00:00    
function                                        ms     % sum
construct_circuits(t)                         4495    21.98%
ProverInstance(Circuit&)(t)                   1915     9.36%
ProtogalaxyProver::fold_instances(t)         10450    51.09%
Decider::construct_proof(t)                    569     2.78%
ECCVMProver(CircuitBuilder&)(t)                171     0.83%
ECCVMProver::construct_proof(t)               1762     8.62%
GoblinTranslatorProver::construct_proof(t)     954     4.66%
Goblin::merge(t)                               137     0.67%

Total time accounted for: 20451ms/20599ms = 99.28%

Major contributors:
function                                        ms    % sum
commit(t)                                     4252   20.79%
compute_combiner(t)                           5092   24.90%
compute_perturbator(t)                        1158    5.66%
compute_univariate(t)                         1219    5.96%

Breakdown of ProtogalaxyProver::fold_instances:
ProtoGalaxyProver_::preparation_round(t)           3913    37.44%
ProtoGalaxyProver_::perturbator_round(t)           1158    11.08%
ProtoGalaxyProver_::combiner_quotient_round(t)     5094    48.75%
ProtoGalaxyProver_::accumulator_update_round(t)     284     2.72%

After

Benchmarking lock created at ~/BENCHMARK_IN_PROGRESS.
client_ivc_bench                                                                                                                                                                                        100%   33MB  68.4MB/s   00:00    
failed to open /proc/cpuinfo
***WARNING*** Failed to set thread affinity. Estimated CPU frequency may be incorrect.
2024-05-06T14:46:31+00:00
Running client_ivc_bench
Run on (-1 X 0.999999 MHz CPU )
----------------------------------------------------------------
Benchmark                      Time             CPU   Iterations
----------------------------------------------------------------
ClientIVCBench/Full/6      79748 ms   7.9748e+10 ms            1

[codygunton]

Core change. Adding this leads to about 35 lines changing, almost all of which are due to the formatter, when I construct a diff manually, but github renders the change as much larger.

[codygunton]

Ditto the above. All I did was add these two bounds to suppress multithreading.

[ludamad]

Can you take a peek at turning on the other DISABLED_ tests?

[codygunton]

I checked ClientIVC and it doesn't help there.

[ludamad]

I was expecting to see multithreading code just go away but LGTM