Non-deterministic exceptions when running truffle tests

Question

I have been writing automated tests to test my crowdsale functionality in Truffle using their test service (which I believe uses Mocha and Chai). I am having trouble understanding why the tests fail non-deterministically (i.e. they seem to fail at random points, with random exceptions).

Eg/ I run my tests and sometimes they all pass

I run my tests and sometimes get this error message:

✓ deadline is set when beneficiary clicks start
✓ should return a State of 'Funding' after start is clicked (101ms)
✓ should allow someone to invest and record balance
✓ should send 1 ERC20 token to participant (184ms)
✓ softcap should not return reached when amountRaised is smaller
✓ softcap should return reached when amountRaised is bigger
✓ hardcap should not return reached when amountRaised is smaller
✓ hardcap should return reached when amountRaised is bigger
1) should give 1 ETH in change as hard cap was exceeded
> No events were emitted
✓ should return a State of 'Successful' when hardcap reached
✓ beneficiary should be able to withdraw funds
✓ should return a State of 'Finished' when beneficiary has funds


22 passing (2s)
1 failing

1) Contract: Sale should give 1 ETH in change as hard cap was exceeded:
 Uncaught AssertionError: deadline was not set after start pressed by beneficiary: expected '0' to not equal 0
  at test/2Crowdsale_Test.js:119:14
  at <anonymous>
  at process._tickDomainCallback (internal/process/next_tick.js:228:7)



 1
 truffle(develop)> 
 /usr/local/lib/node_modules/truffle/build/cli.bundled.js:320098
    throw reason;
    ^

 TypeError: Cannot read property 'currentRetry' of undefined
at 

/usr/local/lib/node_modules/truffle/node_modules/mocha/lib/runner.js: 
552:28
at done 
(/usr/local/lib/node_modules/truffle/node_modules/mocha/lib/runnable.js 
:295:5)
at 
/usr/local/lib/node_modules/truffle/node_modules/mocha/lib/runnable.js: 
359:11
at <anonymous>
at process._tickDomainCallback (internal/process/next_tick.js:228:7)

This is confusing as the Assertion does not match the error message - the change assert fails however, the message that is returned is part of an earlier test which passed (deadline is set when beneficiary clicks start).

Running the tests again I got:

✓ approves contract by beneficiary
✓ should return a State of 'Not Started' before start is clicked (134ms)
✓ deadline is set when beneficiary clicks start
✓ should return a State of 'Funding' after start is clicked (98ms)
✓ should allow someone to invest and record balance
✓ should send 1 ERC20 token to participant (143ms)
✓ softcap should not return reached when amountRaised is smaller
✓ softcap should return reached when amountRaised is bigger
✓ hardcap should not return reached when amountRaised is smaller
✓ hardcap should return reached when amountRaised is bigger
1) should give 1 ETH in change as hard cap was exceeded
> No events were emitted
2) should return a State of 'Successful' when hardcap reached

Events emitted during test:
---------------------------

Transfer(_from: <indexed>, _to: <indexed>, _value: 5)
FundTransfer(backer: 0xf17f52151ebef6c7334fad080c5704d77216b732, amount: 5000000000000000000, isContribution: true)
reachedSoftCap(recipient: 0x627306090abab3a6e1400e9345bc60c78a8bef57, totalAmountRaised: 6000000000000000000)

---------------------------
✓ beneficiary should be able to withdraw funds
✓ should return a State of 'Finished' when beneficiary has funds


21 passing (2s)
2 failing

1) Contract: Sale should give 1 ETH in change as hard cap was exceeded:
 Uncaught AssertionError: deadline was not set after start pressed by beneficiary: expected '0' to not equal 0
  at test/2Crowdsale_Test.js:119:14
  at <anonymous>
  at process._tickDomainCallback (internal/process/next_tick.js:228:7)

2) Contract: Sale should return a State of 'Successful' when hardcap reached:
 Uncaught AssertionError: hardcap was not met when amountRaised was bigger: expected false to equal true
  at test/2Crowdsale_Test.js:195:14
  at <anonymous>
  at process._tickDomainCallback (internal/process/next_tick.js:228:7)



  2
  truffle(develop)> 
  /usr/local/lib/node_modules/truffle/build/cli.bundled.js:320098
    throw reason;
    ^

  TypeError: Cannot set property 'state' of undefined
  at 
  /usr/local/lib/node_modules/truffle/node_modules/mocha/lib/runner.js: 
  576:20
  at done 
(/usr/local/lib/node_modules/truffle/node_modules/mocha/lib/runnable.js 
:295:5)
at /usr/local/lib/node_modules/truffle/node_modules/mocha/lib/runnable.js:353:11
at <anonymous>
at process._tickDomainCallback (internal/process/next_tick.js:228:7)

I now have the previous error message, and now another one throws when again, the error message does not match the assertion error.

Running the tests for a fourth time I got:

✓ should allow someone to invest and record balance
✓ should send 1 ERC20 token to participant (120ms)
✓ softcap should not return reached when amountRaised is smaller
✓ softcap should return reached when amountRaised is bigger
✓ hardcap should not return reached when amountRaised is smaller
✓ hardcap should return reached when amountRaised is bigger
✓ should give 1 ETH in change as hard cap was exceeded (275ms)
✓ should return a State of 'Successful' when hardcap reached (61ms)
✓ beneficiary should be able to withdraw funds
1) should return a State of 'Finished' when beneficiary has funds
> No events were emitted


 22 passing (2s)
 1 failing

 1) Contract: Sale should return a State of 'Finished' when beneficiary has funds:
 AssertionError: State of contract was not 'Finished': expected '4' to equal 6
  at test/2Crowdsale_Test.js:243:14
  at <anonymous>
  at process._tickDomainCallback (internal/process/next_tick.js:228:7)

Which is a completely different error to the previous two. This one again is also confusing as the previous test (beneficiary should be able to withdraw funds) also tests for the state to equal 6 and this test passes.

Each time before the tests, I exit the truffle console, delete my build folder from the project, re-enter the truffle console and test(so that I can assume the chain has been reset), yet I still receive errors that firstly, don't make sense as I do not get these results when testing it myself through the Dapp and secondly, dont show up everytime, it seems to be random times with random errors.

Has anyone else had trouble with this?

Answer 1

• This is confusing as the Assertion does not match the error message - the change assert fails however, the message that is returned is part of an earlier test which passed (deadline is set when beneficiary clicks start).

This is very typical of javaScript asynchronous testing, wether you're making ethereum truffle tests or just plain Karma-Jasmine tests fom the front-end.

I'm pretty confident you have assertions within callbacks in some specs that aren't properly set. The spec pass due to lack of calling the 'done' callback parameter, or because you're not properly returning a Promise inside the it call, so the test just pass as a false positive, ignoring the callback content.

Some time later, the code inside the callback gets run and fail, thus making the running test to fail, but giving the error message from its test, and a false negative -since you're getting an exception in the wrong test, thus making it to fail.

This can be caused also by .catch statements swalloging done calls.

of course, maybe I'm just wrong and your issue is trully related with Truffle itself, or with testrpc.

If you're absolutely sure all your it specs are properly dealing with asynchrony -either returning a Promise or calling done-, then you should paste your testing code and wait for more feedback :-S

Also, are you using testrpc as your blockchain during the tests?