Weird bug with truffle/testrpc interplay (duplicate transaction)

[skozin]

I have the following Solidity contract:

pragma solidity ^0.4.12;

contract Test {
  event Called(address sender, uint data, uint countBefore);

  uint public count;

  function test(uint data) external {
    Called(msg.sender, data, count);
    count++;
  }

}

I use truffle to call Test.test two times in succession, from two different addresses (addr1 and addr2), each time passing different argument:

let contract = await Test.new({from: addr0})

await contract.test(1, {from: addr1})
await contract.test(2, {from: addr2})

Then I call it third time, once again from a different address addr3, but this time I pass the same argument as in the first call, 1:

await contract.test(1, {from: addr3})

Expected Behavior

In the beginning of the third call I expect the count variable to contain 2. Also, I expect that, after the third call, count contains 3.

Current Behavior

But, for some reason, in the beginning of the third call count contains 0 instead. After all three calls are made, inspecting count variable reveals that it contains 2 instead of the expected 3.

Also, I noticed that hashes of transactions corresponding to the first and third calls are the same, which is clearly not right.

If I make the third call from addr1 or from the address that created the contract (addr0), things start behaving normally. The same if during the third call I pass some different argument, e.g. 3.

The bug does not reproduce consistently even when all conditions are met. But it does reproduce every time after TestRPC restart. Then, if you continue running tests without restarting TestRPC, it would reproduce at least in half of the runs (according to my observations).

Everything works correctly when I use geth instead of TestRPC. Also, I tested the same scenario in Remix IDE and the contract behaved as it should. So I suppose this has something to do with TestRPC specifically, or with interplay between Truffle and TestRPC.

Steps to Reproduce (for bugs)

See this repo with a minimal example: https://github.com/skozin/testrpc-bug-repro. Run npm install, then run TestRPC (./run-testrpc.sh) and tests (npm test) in different terminals.

Context

I extracted this minimal reproduction from test suite of some complex contract. We noticed that some tests were intermittently failing when using TestRPC as Ethereum client.

Your Environment

• Version used: TestRPC 4.1.3, Truffle 3.4.11
• Operating System and version: OS X 10.12.2
• Link to your project: https://github.com/skozin/testrpc-bug-repro

---

UPDATE: I simplified it further to avoid using maps.

[skozin]

@benjamincburns have you had a chance to run reproduction from the repo I linked? I've tried to make it as simple and minimalistic as possible. All you need to do is run npm install, then start testrpc by running ./run-testrpc.sh and then npm test. The contract itself contains one storage variable and one function that just increments that storage variable. All tests do is calling this function three times.

[skozin]

I am sorry for pinging you, but this breaks significant percentage of our tests and I really don't know how to work around this. I'm not even sure that this bug is in testrpc itself, though it seems so, since it doesn't reproduce if I swap it to geth or parity.

[benjamincburns]

@skozin no apology necessary! I'm traveling at the moment, but I have a bit of downtime, so I'll give it a try now. In the mean time, have you tried the latest release, ethereumjs-testrpc@6.0.1? I can't promise anything is fixed there, but you might as well give it a go.

[benjamincburns]

@skozin I do reproduce this issue, even against v6.0.1 - I'll try to dig into it over the next couple of days as I have time. I'm not certain that it's a TestRPC bug just yet - may be some web3 weirdness. Either way, thanks for reporting, and thanks for the kick ass repro repo!

[benjamincburns]

@skozin this is likely a bug in the way we're handling interval mining. If you drop the -b 1 from your run-testrpc.sh script, things work as expected.

My suspicion is that either we're not detecting/handling the nonce correctly, or you're running into something related to issue #234.

[benjamincburns]

I've spent a couple of days digging into this. I think this is the race reported in #234, triggered by the mining intreval. Still digging into it to prove this theory, however.

[benjamincburns]

The issue where transactions produce events with incorrect state seems to be fixed. However we still have the problem where TestRPC is producing duplicate (colliding) transaction hashes. Resolving that problem is blocked by ethereumjs/ethereumjs-tx#80.

[benjamincburns]

I've submitted a PR with the fix. ethereumjs/ethereumjs-tx#81

[mikeseese]

This should no longer be waiting as ethereumjs/ethereumjs-tx#81 was merged

[davidmurdoch]

Possibly related to trufflesuite/ganache#547

[davidmurdoch]

Should be fixed in ganache-cli@6.2.4. Please open a new issue if you are still finding hash collisions.

[skozin]

Awesome! Thank you @benjamincburns and @davidmurdoch for working on this!