Possible race condition in `GovernorPreventLateQuorum` tests #4049

r0qs · 2023-02-15T16:48:54Z

Hi, we recently noticed some random failures in our external tests of the openzeppelin-contracts. You can see two sample logs from our CI here:

Debugging it locally and isolating one of the failed tests (the first one). The test finishes successfully, so I suspect that there may be some race conditions in the tests.

💻 Environment

Solc compiler version: 0.8.18+commit.87f61d96.Linux.g++
Openzeppelin-solidity version: 4.8.0

Our tests run with a combination of settings of the solidity compiler, but all those pass when running individual openzeppelin tests (i.e. using it.only), but some of them randomly fail when running the full openzeppelin test suit.

For reference, you can see the full log of that test case (i.e. Delay is extended to prevent last minute take-over) that fails when running all tests in the CI but passes if ran alone:

Configuring Hardhat...
-------------------------------------
Config file: hardhat.config.js
Settings preset: ir-optimize-evm+yul
Settings: {evmVersion: 'paris', viaIR: true,  optimizer: {enabled: true, details: {yul: true}}}
EVM version: paris
Compiler version: 0.8.18
Compiler version (full): 0.8.18+commit.87f61d96.Linux.g++
-------------------------------------
Running compile function...

> openzeppelin-solidity@4.8.0 compile
> hardhat compile

Solidity 0.8.18 is not fully supported yet. You can still use Hardhat, but some features, like stack traces, might not work correctly.

Learn more at https://hardhat.org/hardhat-runner/docs/reference/solidity-support

Compiled 249 Solidity files successfully

real	5m40.086s
user	5m38.894s
sys	0m1.291s
Verify that the correct version (0.8.18/0.8.18+commit.87f61d96.Linux.g++) of the compiler was used to compile the contracts...
Running test function...

> openzeppelin-solidity@4.8.0 test
> hardhat test


  Contract: GovernorPreventLateQuorum
    using $ERC20Votes
      ✓ Delay is extended to prevent last minute take-over
    using $ERC20VotesTimestampMock
      ✓ Delay is extended to prevent last minute take-over


  2 passing (5s)

Configuring Hardhat...
-------------------------------------
Config file: hardhat.config.js
Settings preset: legacy-no-optimize
Settings: {evmVersion: 'paris', viaIR: false, optimizer: {enabled: false}}
EVM version: paris
Compiler version: 0.8.18
Compiler version (full): 0.8.18+commit.87f61d96.Linux.g++
-------------------------------------
Running compile function...

> openzeppelin-solidity@4.8.0 compile
> hardhat compile

Solidity 0.8.18 is not fully supported yet. You can still use Hardhat, but some features, like stack traces, might not work correctly.

Learn more at https://hardhat.org/hardhat-runner/docs/reference/solidity-support

Compiled 249 Solidity files successfully

real	0m23.623s
user	0m23.293s
sys	0m1.715s
Verify that the correct version (0.8.18/0.8.18+commit.87f61d96.Linux.g++) of the compiler was used to compile the contracts...
Running test function...

> openzeppelin-solidity@4.8.0 test
> hardhat test


  Contract: GovernorPreventLateQuorum
    using $ERC20Votes
      ✓ Delay is extended to prevent last minute take-over
    using $ERC20VotesTimestampMock
      ✓ Delay is extended to prevent last minute take-over


  2 passing (8s)

Configuring Hardhat...
-------------------------------------
Config file: hardhat.config.js
Settings preset: legacy-optimize-evm-only
Settings: {evmVersion: 'paris', viaIR: false, optimizer: {enabled: true, details: {yul: false}}}
EVM version: paris
Compiler version: 0.8.18
Compiler version (full): 0.8.18+commit.87f61d96.Linux.g++
-------------------------------------
Running compile function...

> openzeppelin-solidity@4.8.0 compile
> hardhat compile

Solidity 0.8.18 is not fully supported yet. You can still use Hardhat, but some features, like stack traces, might not work correctly.

Learn more at https://hardhat.org/hardhat-runner/docs/reference/solidity-support

Compiled 249 Solidity files successfully

real	0m49.706s
user	0m49.420s
sys	0m1.597s
Verify that the correct version (0.8.18/0.8.18+commit.87f61d96.Linux.g++) of the compiler was used to compile the contracts...
Running test function...

> openzeppelin-solidity@4.8.0 test
> hardhat test


  Contract: GovernorPreventLateQuorum
    using $ERC20Votes
      ✓ Delay is extended to prevent last minute take-over
    using $ERC20VotesTimestampMock
      ✓ Delay is extended to prevent last minute take-over


  2 passing (6s)

Configuring Hardhat...
-------------------------------------
Config file: hardhat.config.js
Settings preset: legacy-optimize-evm+yul
Settings: {evmVersion: 'paris', viaIR: false, optimizer: {enabled: true, details: {yul: true}}}
EVM version: paris
Compiler version: 0.8.18
Compiler version (full): 0.8.18+commit.87f61d96.Linux.g++
-------------------------------------
Running compile function...

> openzeppelin-solidity@4.8.0 compile
> hardhat compile

Solidity 0.8.18 is not fully supported yet. You can still use Hardhat, but some features, like stack traces, might not work correctly.

Learn more at https://hardhat.org/hardhat-runner/docs/reference/solidity-support

Compiled 249 Solidity files successfully

real	1m8.565s
user	1m8.364s
sys	0m1.354s
Verify that the correct version (0.8.18/0.8.18+commit.87f61d96.Linux.g++) of the compiler was used to compile the contracts...
Running test function...

> openzeppelin-solidity@4.8.0 test
> hardhat test


  Contract: GovernorPreventLateQuorum
    using $ERC20Votes
      ✓ Delay is extended to prevent last minute take-over
    using $ERC20VotesTimestampMock
      ✓ Delay is extended to prevent last minute take-over


  2 passing (6s)

Done.

📝 Details

I suspect that the bug was introduced by the new test/helpers/time.js added by this PR #3934.

You can see that the extendedDeadline was changed here to use clockFromReceipt: 790cc5b#diff-9b993baaba0944c3ab49a694eb5e65a5b2067339f3b62fbfcfdd0be2aaf859c9L110 for one of the test cases that is failing.

It now does:

// compute new extended schedule
const extendedDeadline = web3.utils.toBN(await clockFromReceipt[mode](txVote.receipt)).add(lateQuorumVoteExtension);

But before that PR it was:

const extendedDeadline = new BN(txVote.receipt.blockNumber).add(lateQuorumVoteExtension);

As clockFromReceipt is a global object in which mode can be set to blocknumber or timestamp property, and the blocknumber is a future that returns the blocknumber, I wonder if it may be the case of a race condition accessing blocknumber in multiple tests when using waitForDeadline (which in turn calls time.advanceBlockTo) and clockFromReceipt.

The text was updated successfully, but these errors were encountered:

Amxx · 2023-02-15T17:03:26Z

As clockFromReceipt is a global object in which mode can be set to blocknumber or timestamp property, and the blocknumber is a future: blocknumber: receipt => Promise.resolve(receipt.blockNumber) I wonder if it may be the case of a race condition accessing blocknumber in multiple tests when using waitForDeadline (which in turn calls time.advanceBlockTo) and clockFromReceipt.

Hello @r0qs

We also noticed some issues running test since the transition to test/helpers/time.js

Note that in the case of the particular test you are pointing, clockFromReceipt[mode](txVote.receipt) is returning (txVote.)receipt.blockNumber. I'm not exactly sure what the race condition would be here.

Amxx · 2023-02-15T17:03:45Z

Related: #4046

r0qs · 2023-02-15T17:48:15Z

Hi @Amxx , thanks for the prompt reply!

Right, yeah, to be honest, don't take my words as definitive for the real cause of the problem. I only had a quick look and I don't really know the whole code base, so I'm probably completely wrong in my assumptions.

But my guess was due to a stacktrace like this one, which sometimes I got:

  1) Contract: GovernorPreventLateQuorum
       using $ERC20VotesTimestampMock
         Delay is extended to prevent last minute take-over:
     Error: VM Exception while processing transaction: reverted with reason string 'Governor: vote not currently active'
      at $GovernorPreventLateQuorumMock.castVote (contracts/governance/Governor.sol:454)
      at $GovernorPreventLateQuorumMock.castVote (contracts/governance/Governor.sol:456)
      at TruffleContract.castVote (node_modules/@nomiclabs/truffle-contract/lib/execute.js:189:26)
      at GovernorHelper.vote (test/helpers/governance.js:115:23)
      at Context.<anonymous> (test/governance/extensions/GovernorPreventLateQuorum.test.js:134:42)
      at runMicrotasks (<anonymous>)
      at processTicksAndRejections (node:internal/process/task_queues:96:5)

So I imagined that it would be a problem on writing/reading the Governor's contract state in an unexpected sequence of blocks in your tests.

frangio · 2023-02-15T21:55:55Z

Pretty sure it's not a race condition, just flakiness due to how the test chain's timestamps are manipulated in the test suite.

frangio · 2023-02-15T22:44:20Z

Fixed by #4046.

r0qs mentioned this issue Feb 15, 2023

External test for OpenZeppelin failing on legacy codegen at ERC20VotesTimestampMock ethereum/solidity#13975

Closed

frangio mentioned this issue Feb 15, 2023

Fix flaky timestamp tests #4046

Merged

frangio closed this as completed Feb 15, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Possible race condition in `GovernorPreventLateQuorum` tests #4049

Possible race condition in `GovernorPreventLateQuorum` tests #4049

r0qs commented Feb 15, 2023 •

edited

Amxx commented Feb 15, 2023

Amxx commented Feb 15, 2023

r0qs commented Feb 15, 2023 •

edited

frangio commented Feb 15, 2023

frangio commented Feb 15, 2023

Possible race condition in GovernorPreventLateQuorum tests #4049

Possible race condition in GovernorPreventLateQuorum tests #4049

Comments

r0qs commented Feb 15, 2023 • edited

Amxx commented Feb 15, 2023

Amxx commented Feb 15, 2023

r0qs commented Feb 15, 2023 • edited

frangio commented Feb 15, 2023

frangio commented Feb 15, 2023

Possible race condition in `GovernorPreventLateQuorum` tests #4049

Possible race condition in `GovernorPreventLateQuorum` tests #4049

r0qs commented Feb 15, 2023 •

edited

r0qs commented Feb 15, 2023 •

edited