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.

Sign up for GitHub

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

Jump to bottom

Consensus tests fail in AppVeyor intermittently #305

Closed
yperbasis opened this issue Jul 19, 2021 · 16 comments · Fixed by #335
Closed

Consensus tests fail in AppVeyor intermittently #305

yperbasis opened this issue Jul 19, 2021 · 16 comments · Fixed by #335
Labels
bug Something isn't working

Comments

@yperbasis
Copy link
Member

yperbasis commented Jul 19, 2021 •
edited
Loading

For example, randomStatetest445_d0g0v0_Berlin in https://ci.appveyor.com/project/torquem/silkworm/builds/40042149
@yperbasis yperbasis added the bug Something isn't working label Jul 19, 2021
@AndreaLanfranchi AndreaLanfranchi mentioned this issue Jul 24, 2021
Merged
@AndreaLanfranchi
Copy link
Contributor

Seems like the test name is constant. https://ci.appveyor.com/project/torquem/silkworm/builds/40115019

cmd\Release\consensus.exe
Validation error 26
randomStatetest445_d0g0v0_Berlin ...............................................  Failed
50710 tests passed, 1 failed, 3 skipped
Command exited with code 1

@AndreaLanfranchi
Copy link
Contributor

Reproduced locally. Launched consensus three times in a row

PS C:\Users\Andrea\CMakeBuilds\silkworm\build\x64-Release\cmd\Release> .\consensus.exe
50711 tests passed, 0 failed, 3 skipped
PS C:\Users\Andrea\CMakeBuilds\silkworm\build\x64-Release\cmd\Release> .\consensus.exe
50711 tests passed, 0 failed, 3 skipped
PS C:\Users\Andrea\CMakeBuilds\silkworm\build\x64-Release\cmd\Release> .\consensus.exe
Validation error 26
randomStatetest445_d0g0v0_Berlin ...............................................  Failed
50710 tests passed, 1 failed, 3 skipped

@AndreaLanfranchi
Copy link
Contributor

Added magic_enum to the build and some more text and the output changes. Now Instabul

PS C:\Users\Andrea\CMakeBuilds\silkworm\build\x64-Release\cmd\Release> .\consensus.exe
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Istanbul .............................................  Failed
50710 tests passed, 1 failed, 3 skipped

@AndreaLanfranchi
Copy link
Contributor

Another

PS C:\Users\Andrea\CMakeBuilds\silkworm\build\x64-Release\cmd\Release> .\consensus.exe
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_London ...............................................  Failed

Chain changes but the test file is always the same

@AndreaLanfranchi
Copy link
Contributor

Running a batch of 256 consecutive tests on branch issue-305. Let's see if it's an Heisenbug

@AndreaLanfranchi
Copy link
Contributor

Hmmm not looking good. Less than 50 tests and already >10% failures
Failing test is always the same but the referred chain changes

PS C:\Users\Andrea\CMakeBuilds\silkworm\build\x64-Release\cmd\Release> $count = 0; $failures = 0; do {$count++; write-host "Attempt $($count) : Failures $($failures)/$($count)"; .\consensus.exe; if($LastExitCode -ne 0) {$failures++}} while ($count -le 256)
Attempt 1 : Failures 0/1
50711 tests passed, 0 failed, 3 skipped
Attempt 2 : Failures 0/2
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Berlin ...............................................  Failed
50710 tests passed, 1 failed, 3 skipped
Attempt 3 : Failures 1/3
50711 tests passed, 0 failed, 3 skipped
Attempt 4 : Failures 1/4
50711 tests passed, 0 failed, 3 skipped
Attempt 5 : Failures 1/5
50711 tests passed, 0 failed, 3 skipped
Attempt 6 : Failures 1/6
50711 tests passed, 0 failed, 3 skipped
Attempt 7 : Failures 1/7
50711 tests passed, 0 failed, 3 skipped
Attempt 8 : Failures 1/8
50711 tests passed, 0 failed, 3 skipped
Attempt 9 : Failures 1/9
50711 tests passed, 0 failed, 3 skipped
Attempt 10 : Failures 1/10
50711 tests passed, 0 failed, 3 skipped
Attempt 11 : Failures 1/11
50711 tests passed, 0 failed, 3 skipped
Attempt 12 : Failures 1/12
50711 tests passed, 0 failed, 3 skipped
Attempt 13 : Failures 1/13
50711 tests passed, 0 failed, 3 skipped
Attempt 14 : Failures 1/14
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Istanbul .............................................  Failed
50710 tests passed, 1 failed, 3 skipped
Attempt 15 : Failures 2/15
50711 tests passed, 0 failed, 3 skipped
Attempt 16 : Failures 2/16
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Berlin ...............................................  Failed
50710 tests passed, 1 failed, 3 skipped
Attempt 17 : Failures 3/17
50711 tests passed, 0 failed, 3 skipped
Attempt 18 : Failures 3/18
50711 tests passed, 0 failed, 3 skipped
Attempt 19 : Failures 3/19
50711 tests passed, 0 failed, 3 skipped
Attempt 20 : Failures 3/20
50711 tests passed, 0 failed, 3 skipped
Attempt 21 : Failures 3/21
50711 tests passed, 0 failed, 3 skipped
Attempt 22 : Failures 3/22
50711 tests passed, 0 failed, 3 skipped
Attempt 23 : Failures 3/23
50711 tests passed, 0 failed, 3 skipped
Attempt 24 : Failures 3/24
50711 tests passed, 0 failed, 3 skipped
Attempt 25 : Failures 3/25
50711 tests passed, 0 failed, 3 skipped
Attempt 26 : Failures 3/26
50711 tests passed, 0 failed, 3 skipped
Attempt 27 : Failures 3/27
50711 tests passed, 0 failed, 3 skipped
Attempt 28 : Failures 3/28
50711 tests passed, 0 failed, 3 skipped
Attempt 29 : Failures 3/29
50711 tests passed, 0 failed, 3 skipped
Attempt 30 : Failures 3/30
50711 tests passed, 0 failed, 3 skipped
Attempt 31 : Failures 3/31
50711 tests passed, 0 failed, 3 skipped
Attempt 32 : Failures 3/32
50711 tests passed, 0 failed, 3 skipped
Attempt 33 : Failures 3/33
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Berlin ...............................................  Failed
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_London ...............................................  Failed
50709 tests passed, 2 failed, 3 skipped
Attempt 34 : Failures 4/34
50711 tests passed, 0 failed, 3 skipped
Attempt 35 : Failures 4/35
50711 tests passed, 0 failed, 3 skipped
Attempt 36 : Failures 4/36
50711 tests passed, 0 failed, 3 skipped
Attempt 37 : Failures 4/37
50711 tests passed, 0 failed, 3 skipped
Attempt 38 : Failures 4/38
50711 tests passed, 0 failed, 3 skipped
Attempt 39 : Failures 4/39
50711 tests passed, 0 failed, 3 skipped
Attempt 40 : Failures 4/40
50711 tests passed, 0 failed, 3 skipped
Attempt 41 : Failures 4/41
50711 tests passed, 0 failed, 3 skipped
Attempt 42 : Failures 4/42
50711 tests passed, 0 failed, 3 skipped
Attempt 43 : Failures 4/43
50711 tests passed, 0 failed, 3 skipped
Attempt 44 : Failures 4/44
50711 tests passed, 0 failed, 3 skipped
Attempt 45 : Failures 4/45
50711 tests passed, 0 failed, 3 skipped
Attempt 46 : Failures 4/46
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Berlin ...............................................  Failed
50710 tests passed, 1 failed, 3 skipped
Attempt 47 : Failures 5/47
50711 tests passed, 0 failed, 3 skipped
Attempt 48 : Failures 5/4

@AndreaLanfranchi
Copy link
Contributor

So the batch completed. 256 attempts and 25 failures
In a couple of cases the same test file fails twice

Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Berlin ...............................................  Failed
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Istanbul .............................................  Failed
50709 tests passed, 2 failed, 3 skipped

@AndreaLanfranchi
Copy link
Contributor

AndreaLanfranchi commented Jul 25, 2021 •
edited
Loading

I just modded consensus loop to execute only test silkworm\tests\BlockchainTests\GeneralStateTests\stRandom2\randomStatetest445.json and launched a batch of 1000.
At attempt 916 I got this

Attempt 916 : Failures 0/915
Gas used 56295 expected 18216493
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_London ...............................................  Failed

Hence it might not be a memory problem or something related to directory recursion order

@AndreaLanfranchi
Copy link
Contributor

AndreaLanfranchi commented Jul 25, 2021 •
edited
Loading

Amendment of the above ... i run a full batch of 4096 consensus (with only the above mentioned test enabled) and final result is :

Attempt 4095 : Failures 9/4094
3 tests passed, 0 failed, 1 skipped
Attempt 4096 : Failures 9/4095
3 tests passed, 0 failed, 1 skipped
Attempt 4097 : Failures 9/4096
3 tests passed, 0 failed, 1 skipped
Final Failures 9/4097

The failure ratio is way lower than executing a fully fledged consensus (see above around 10%)

Edit ... just ran the very same test on Linux (well ... WSL) and not a single failure on 10k runs

@AndreaLanfranchi
Copy link
Contributor

Definitely an MSVC problem which is somewhere into Receipt ExecutionProcessor::execute_transaction(const Transaction& txn) noexcept.

Transactions are all executed (number of receipts matches number of transactions) but for some reason gas_used is computed (intermittently) wrong

@AndreaLanfranchi
Copy link
Contributor

Interestingly the failures on Berlin network give different cumulative_gas_used (last two)

Gas used 29695 expected 18216493
Receipts 1 expected 1
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Istanbul .............................................  Failed

Gas used 29695 expected 18216493
Receipts 1 expected 1
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Istanbul .............................................  Failed

Attempt 207 : Failures 0/206
Gas used 56295 expected 18216493
Receipts 1 expected 1
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_London ...............................................  Failed

Gas used 56295 expected 18216493
Receipts 1 expected 1
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_London ...............................................  Failed

Gas used 56295 expected 18216493
Receipts 1 expected 1
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_London ...............................................  Failed

Gas used 32295 expected 18216493
Receipts 1 expected 1
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Berlin ...............................................  Failed

Gas used 32298 expected 18216493
Receipts 1 expected 1
Validation error kWrongBlockGas at block 1
randomStatetest445_d0g0v0_Berlin ...............................................  Failed

@AndreaLanfranchi
Copy link
Contributor

My gut feelings lean towards some issue related to MSVC with intx

@AndreaLanfranchi
Copy link
Contributor

AndreaLanfranchi commented Jul 25, 2021 •
edited
Loading

Under Debug build the issue never happens (just ran 20k times consensus with not a single failure). Way slower though
Under Release build (which is the one appveyor uses) it happens (even with /Od set)

@yperbasis
Copy link
Member Author

Have you tried running it under Address and Undefined Behaviour Sanitizers?

@AndreaLanfranchi
Copy link
Contributor

Not yet. Returning in office now and will do

@AndreaLanfranchi
Copy link
Contributor

Crap. If I try to build MSVC with address sanitizer ABSEIL complains it does not find his own address sanitizer

#ifdef ABSL_HAVE_ADDRESS_SANITIZER
#include <sanitizer/asan_interface.h>
#endif

@yperbasis yperbasis mentioned this issue Jul 29, 2021
Closed
@chfast chfast mentioned this issue Aug 3, 2021
Merged
@yperbasis yperbasis mentioned this issue Aug 3, 2021
Merged
@yperbasis yperbasis linked a pull request Aug 3, 2021 that will close this issue
Update evmone to 0.8.1 #335
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
2 participants
@AndreaLanfranchi @yperbasis