Skip to content
This repository has been archived by the owner on Feb 26, 2024. It is now read-only.

Tests randomly crashing at ProviderError.ExtendableError on Ubuntu (Linux) #729

Closed
1 task done
dwalintukan opened this issue Dec 21, 2017 · 81 comments
Closed
1 task done
Labels

Comments

@dwalintukan
Copy link

dwalintukan commented Dec 21, 2017


Issue

On a Ubuntu Linux environment (Trusty), tests randomly fail with this ExtendableError:

1) Contract: TopicEvent "after each" hook for "throws on an invalid result index":
Error: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at ProviderError.ExtendableError (/home/travis/.nvm/versions/node/v8.9.3/lib/node_modules/truffle/build/cli.bundled.js:9401:17)
      at new ProviderError (/home/travis/.nvm/versions/node/v8.9.3/lib/node_modules/truffle/build/cli.bundled.js:325054:24)
      at /home/travis/.nvm/versions/node/v8.9.3/lib/node_modules/truffle/build/cli.bundled.js:325137:17
      at /home/travis/.nvm/versions/node/v8.9.3/lib/node_modules/truffle/build/cli.bundled.js:325195:24
      at XMLHttpRequest.request.onreadystatechange (/home/travis/.nvm/versions/node/v8.9.3/lib/node_modules/truffle/build/cli.bundled.js:328229:7)
      at XMLHttpRequestEventTarget.dispatchEvent (/home/travis/.nvm/versions/node/v8.9.3/lib/node_modules/truffle/build/cli.bundled.js:176415:18)
      at XMLHttpRequest._setReadyState (/home/travis/.nvm/versions/node/v8.9.3/lib/node_modules/truffle/build/cli.bundled.js:176705:12)
      at XMLHttpRequest._onHttpRequestError (/home/travis/.nvm/versions/node/v8.9.3/lib/node_modules/truffle/build/cli.bundled.js:176895:12)
      at ClientRequest.<anonymous> (/home/travis/.nvm/versions/node/v8.9.3/lib/node_modules/truffle/build/cli.bundled.js:176765:24)
      at Socket.socketOnEnd (_http_client.js:423:9)
      at endReadableNT (_stream_readable.js:1056:12)
      at _combinedTickCallback (internal/process/next_tick.js:138:11)

Specifically, I have a Travis-CI (continuous integration) setup and this is where the tests are failing. My local Mac OSX environment passes these tests with no problem. Every once and a while, they will fail with the same error, but I just run the tests again and they pass.

I'd say it happens like 10-15% of the time on Mac OSX, but it happens like 60-80% of the time on the Travis-CI linux env.

It feels like it used to have this error less on earlier Truffle versions. I just updated to 4.0.4 and it seems way more often now.

Steps to Reproduce

  1. Clone this repo: https://github.com/bodhiproject/bodhi-core
  2. Use Truffle v4.0.4 on a Ubuntu Linux environment (see environment details)
  3. truffle test

Expected Behavior

Tests should pass like they do on Mac OSX env.

Actual Results

I test this on my local machine (mac osx), when all tests pass which they do, I push up to Github. Then it fires off a Travis-CI test on the linux env and fails pretty much every time.

Environment

Travis-CI Env (fails)

  • Operating System: Ubuntu 14.04 Trusty
  • Truffle version: 4.0.4
  • node version: v8.9.3
  • npm version: 5.5.1
  • nvm version: 0.33.8
  • Build language: node_js
  • Build group: stable
  • Build dist: trusty
  • Distributor ID: Ubuntu
  • Description: Ubuntu 14.04.5 LTS
  • Release: 14.04
  • Codename: trusty
  • Compiled with gcc 4.8.2 for Unix (Linux ELF) on Oct 21 2013.
  • OS/Arch: linux/amd64

Mac OSX Env (passes)

  • Mac OSX 10.12.6 Sierra
  • Truffle v4.0.4
  • node version: 8.9.1
  • npm version: 5.5.1

$ gcc --version:

Configured with: --prefix=/Applications/Xcode.app/Contents/Developer/usr --with-gxx-include-dir=/usr/include/c++/4.2.1
Apple LLVM version 9.0.0 (clang-900.0.39.2)
Target: x86_64-apple-darwin16.7.0
Thread model: posix
InstalledDir: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin
@dwalintukan dwalintukan changed the title Tests randomly crashing on Linux, but working fine on Mac OSX Tests randomly crashing at ProviderError.ExtendableError on Ubuntu (Linux) Dec 21, 2017
@Alonski
Copy link

Alonski commented Dec 31, 2017

This happens to me as well:

PS D:\Projects\Fun Stuff\daostack> truffle develop
Truffle Develop started at http://localhost:9545/

Accounts:
(0) 0x627306090abab3a6e1400e9345bc60c78a8bef57
(1) 0xf17f52151ebef6c7334fad080c5704d77216b732
(2) 0xc5fdf4076b8f3a5357c5e395ab970b5b54098fef
(3) 0x821aea9a577a9b44299b9c15c88cf3087f3b5544
(4) 0x0d1d4e623d10f9fba5db95830f7d3839406c6af2
(5) 0x2932b7a2355d6fecc4b5c0b6bd44cc31df247a2e
(6) 0x2191ef87e392377ec08e7c08eb105ef5448eced5
(7) 0x0f4f2ac550a1b4e2280d04c21cea7ebd822934b5
(8) 0x6330a553fc93768f612722bb8c2ec78ac90b3bbc
(9) 0x5aeda56215b167893e80b4fe645ba6d5bab767de

Private Keys:
(0) c87509a1c067bbde78beb793e6fa76530b6382a4c0241e5e4a9ec0a0f44dc0d3
(1) ae6ae8e5ccbfb04590405997ee2d52d2b330726137b875053c36d94e974d162f
(2) 0dbbe8e4ae425a6d2687f1a7e3ba17bc98c673636790f1b8ad91193c05875ef1
(3) c88b703fb08cbea894b6aeff5a544fb92e78a18e19814cd85da83b71f772aa6c
(4) 388c684f0ba1ef5017716adb5d21a053ea8e90277d0868337519f97bede61418
(5) 659cbb0e2411a44db63778987b1e22153c086a95eb6b18bdf89de078917abc63
(6) 82d052c865f5763aad42add438569276c00d3d88a2d062d36b2bae914d58b8c8
(7) aa3680d5d48a8283413f7a108367c7299ca73f553735860a87b08f39395618b7
(8) 0f62d96d6675f32685bbdb8ac13cda7c23436f63efbb9d07700d8669ff12b7c4
(9) 8d5366123cb560bb606379f90a0bfd4769eecc0557f1b362dcae9012b548b1e5

Mnemonic: candy maple cake sugar pudding cream honey rich smooth crumble sweet treat

truffle(develop)> test
Compiling .\contracts\Migrations.sol...
Compiling .\contracts\VotingMachines\AbsoluteVote.sol...
Compiling .\contracts\VotingMachines\EmergentVoteScheme.sol...
Compiling .\contracts\VotingMachines\IntVoteInterface.sol...
Compiling .\contracts\VotingMachines\QuorumVote.sol...
Compiling .\contracts\controller\Avatar.sol...
Compiling .\contracts\controller\Controller.sol...
Compiling .\contracts\controller\DAOToken.sol...
Compiling .\contracts\controller\Reputation.sol...
Compiling .\contracts\globalConstraints\GlobalConstraintInterface.sol...
Compiling .\contracts\globalConstraints\TokenCapGC.sol...
Compiling .\contracts\test\ActionMock.sol...
Compiling .\contracts\test\Debug.sol...
Compiling .\contracts\test\ExecutableTest.sol...
Compiling .\contracts\test\GlobalConstraintMock.sol...
Compiling .\contracts\universalSchemes\ContributionReward.sol...
Compiling .\contracts\universalSchemes\ExecutableInterface.sol...
Compiling .\contracts\universalSchemes\GenesisScheme.sol...
Compiling .\contracts\universalSchemes\GlobalConstraintRegistrar.sol...
Compiling .\contracts\universalSchemes\OrganizationRegister.sol...
Compiling .\contracts\universalSchemes\SchemeRegistrar.sol...
Compiling .\contracts\universalSchemes\SimpleICO.sol...
Compiling .\contracts\universalSchemes\UniversalScheme.sol...
Compiling .\contracts\universalSchemes\UniversalSchemeInterface.sol...
Compiling .\contracts\universalSchemes\UpgradeScheme.sol...
Compiling .\contracts\universalSchemes\VestingScheme.sol...
Compiling .\contracts\universalSchemes\VoteInOrganizationScheme.sol...
Compiling zeppelin-solidity/contracts/lifecycle/Destructible.sol...
Compiling zeppelin-solidity/contracts/math/SafeMath.sol...
Compiling zeppelin-solidity/contracts/mocks/StandardTokenMock.sol...
Compiling zeppelin-solidity/contracts/ownership/Ownable.sol...
Compiling zeppelin-solidity/contracts/token/BurnableToken.sol...
Compiling zeppelin-solidity/contracts/token/MintableToken.sol...
Compiling zeppelin-solidity/contracts/token/StandardToken.sol...
Compiling zeppelin-solidity\contracts\math\SafeMath.sol...
Compiling zeppelin-solidity\contracts\ownership\Ownable.sol...
Compiling zeppelin-solidity\contracts\token\BasicToken.sol...
Compiling zeppelin-solidity\contracts\token\ERC20.sol...
Compiling zeppelin-solidity\contracts\token\ERC20Basic.sol...
Compiling zeppelin-solidity\contracts\token\StandardToken.sol...


  Contract: AbsoluteVote
    √ Sanity checks (3485ms)
    √ log the LogNewProposal event on proposing new proposal (1565ms)
    √ should log the LogCancelProposal event on canceling a proposal (982ms)
    √ should log the LogVoteProposal and LogCancelVoting events on voting and canceling the vote (1029ms)
    √ should log the LogExecuteProposal event (1395ms)
    √ All options can be voted (0-9) (2639ms)
    √ Double vote shouldn't double proposal's 'Option 2' count (1205ms)
    √ Vote cancellation should revert proposal's counters (1117ms)
    √ As allowOwner is set to true, Vote on the behalf of someone else should work (1014ms)
    √ As allowOwner is set to false, Vote on the behalf of someone else should NOT work (938ms)
    √ if the voter is not the proposal's owner, he shouldn't be able to vote on the behalf of someone else (892ms)
    √ Non-existent parameters hash shouldn't work (1085ms)
    √ Invalid percentage required( < 0 || > 100) shouldn't work (2029ms)
    √ Proposal voting or cancelling shouldn't be able after proposal has been executed (1180ms)
    √ the vote function should behave as expected (1976ms)
    √ cannot vote for another user (866ms)
    √ Should behave sensibly when voting with an empty reputation system (333ms)
    √ Should behave sensibly without an executable [TODO] execution isn't implemented yet (483ms)
    √ Proposal with wrong num of options (876ms)
    √ Test voteWithSpecifiedAmounts - More reputation than I own, negative reputation, etc.. (1139ms)
    √ Internal functions can not be called externally (963ms)
    √ Try to send wrong proposal id to the voting/cancel functions (1063ms)
    √ 2 proposals, 1 Reputation system (1703ms)
    as _not_ proposal owner - vote for myself
      √ vote "Option 1" then vote "Option 2" should register "Option 2" (1139ms)
      √ vote "Option 3" then vote "Option 4" should register "Option 4" (1206ms)
    as proposal owner - vote for another user
      √ vote "Option 1" then vote "Option 2" should register "Option 2" (1163ms)
      √ vote "Option 3" then vote "Option 4" should register "Option 4" (1015ms)

  Contract: Avatar
    √ genericAction no owner (466ms)
    √ generic call (553ms)
    √ pay ether to avatar (1282ms)
    √ sendEther from  (2278ms)
    √ externalTokenTransfer   (592ms)
    √ externalTokenTransferFrom & ExternalTokenIncreaseApproval (648ms)
    √ externalTokenTransferFrom & externalTokenDecreaseApproval (784ms)

  Contract: ContributionReward
    √ constructor (138ms)
    √ setParameters (1422ms)
    √ registerOrganization - check fee payment  (2066ms)
    √ submitContribution log (1745ms)
    √ submitContribution fees (1779ms)
    √ submitContribution without registration -should fail (1371ms)
    √ submitContribution check owner vote (1457ms)
    √ submitContribution check beneficiary==0 (1716ms)
    √ execute submitContribution  yes  (1778ms)
    √ execute submitContribution  mint reputation  (1759ms)
    √ execute submitContribution  mint tokens  (1519ms)
    √ execute submitContribution  send ethers  (2403ms)
    √ execute submitContribution  send externalToken  (2165ms)
    √ execute submitContribution proposal decision=='no' send externalToken   (1932ms)

  Contract: Controller
    √ mint reputation via controller (667ms)
    √ mint tokens via controller (633ms)
    √ register schemes (606ms)
    √ register schemes - check permissions for register new scheme (24778ms)
    √ register schemes - check permissions for updating existing scheme (1408ms)
    √ unregister schemes (646ms)
    √ unregister none registered scheme (590ms)
    √ unregister schemes - check permissions unregister scheme (20398ms)
    √ unregister self (753ms)
    √ isSchemeRegistered  (1787ms)
    √ addGlobalConstraint  (1804ms)
    √ removeGlobalConstraint  (2442ms)
    √ upgrade controller  (945ms)
    √ upgrade controller check permission (873ms)
    √ generic call (887ms)
    √ sendEther (2555ms)
    √ externalTokenTransfer (1030ms)
    √ externalTokenTransferFrom & ExternalTokenIncreaseApproval (1196ms)
    √ externalTokenTransferFrom & externalTokenDecreaseApproval (1799ms)
    √ globalConstraints mintReputation add & remove (1035ms)
    √ globalConstraints mintTokens add & remove (1211ms)
    √ globalConstraints register schemes add & remove (1071ms)
    √ globalConstraints unregister schemes add & remove (1001ms)
    √ globalConstraints generic call  add & remove (1551ms)
    √ globalConstraints sendEther  add & remove (3490ms)
    √ globalConstraints externalTokenTransfer  add & remove (1294ms)
    √ globalConstraints externalTokenTransferFrom , externalTokenIncreaseApproval , externalTokenDecreaseApproval (2016ms)

  Contract: DAOToken
    √ should put 0 Coins in the first account (70ms)
    √ should be owned by its creator (83ms)
    √ should be destructible (87ms)
    √ should mint tokens to owner account (7614ms)
    √ should allow minting tokens only by owner (6067ms)
    √ log the Mint event on mint (101ms)
    √ mint should be reflected in totalSupply (220ms)
    √ mint should be reflected in balances (110ms)
    √ totalSupply is 0 on init (77ms)
    √ burn (190ms)
    onlyOwner
      √ mint by owner (96ms)
      √ mint by not owner (71ms)

  Contract: GenesisScheme
    √ founders should get their share in reputation and tokens (2426ms)
    √ forgeOrg check avatar (383ms)
    √ forgeOrg check reputations and tokens to founders (328ms)
    √ forgeOrg check transfer ownership (405ms)
    √ setSchemes log (391ms)
    √ setSchemes from account that does not hold the lock (306ms)
    √ setSchemes increase approval for scheme  (413ms)
    √ setSchemes increase approval for scheme without fee (346ms)
    √ setSchemes check register (359ms)
    √ setSchemes check unregisterSelf (466ms)
    √ setSchemes delete lock (373ms)

  Contract: GlobalConstraintRegistrar
    √ constructor (142ms)
    √ setParameters (777ms)
    √ registerOrganization - check fee payment  (1457ms)
    √ proposeGlobalConstraint log (1580ms)
    √ proposeGlobalConstraint without registration -should fail (1292ms)
    √ proposeGlobalConstraint check owner vote (1269ms)
    √ execute proposeGlobalConstraint  (1612ms)
    √ proposeToRemoveGC log (1717ms)
    √ proposeToRemoveGC without registration -should fail (1189ms)
    √ proposeToRemoveGC check owner vote (1829ms)
    √ execute proposeToRemoveGC  (2184ms)
    √ execute proposeToRemoveGC (same as proposeGlobalConstraint) vote=NO  (1693ms)

  Contract: Migrations
    √ should have deployed entire DAOStack

  Contract: OrganizationRegister
    √ constructor (150ms)
    √ setParameters (192ms)
    √ registerOrganization - check fee payment  (1804ms)
    √ addOrPromoteAddress add and promote  (2300ms)
    √ addOrPromoteAddress add without enough fee should fail  (1163ms)
    √ addOrPromoteAddress add  without regisration -should fail  (1266ms)

  Contract: QuorumVote
    √ Sanity checks (1451ms)
    √ Quorum proposals should be executed when reaching the percentage required (1332ms)
    √ Invalid inputs shouldn't work (precReq, vote) (6588ms)
    √ All options can be voted (0-9) (2502ms)
    √ Double vote shouldn't double proposal's 'Option 2' count (1068ms)
    √ Vote cancellation should revert proposal's counters (1067ms)
    √ As allowOwner is set to true, Vote on the behalf of someone else should work (2654ms)
    √ As allowOwner is set to false, Vote on the behalf of someone else should NOT work (1128ms)
    √ if the voter is not the proposal's owner, he shouldn't be able to vote on the behalf of someone else (1200ms)
    √ Should not able to vote / cancel vote / proposal after proposal has been executed (1289ms)
    √ Only the owner of the proposal can cancel it (1463ms)
    √ log the LogNewProposal event on proposing new proposal (1231ms)
    √ Should log the LogCancelProposal event on canceling a proposal (857ms)
    √ Should log the LogVoteProposal and LogCancelVoting events on voting and canceling the vote (999ms)
    √ Should log the LogExecuteProposal event on executing quorum proposal with 'no' decision (925ms)
    √ cannot vote for another user (998ms)
    √ Should behave sensibly without an executable [TODO] execution isn't implemented yet (458ms)
    √ Test voteWithSpecifiedAmounts - More reputation than I own, negative reputation, etc.. (982ms)
    √ Internal functions can not be called externally (2591ms)
    √ Try to send wrong proposal id to the voting/cancel functions (1798ms)

  Contract: Reputation
    1) "before all" hook: prepare suite

  Contract: SchemeRegistrar
    2) "before all" hook: prepare suite

  Contract: SimpleICO
    3) "before all" hook: prepare suite

  Contract: TokenCapGC
    4) "before all" hook: prepare suite

  Contract: UpgradeScheme
    5) "before all" hook: prepare suite

  Contract: VestingScheme
    6) "before all" hook: prepare suite

  Contract: VoteInOrganizationScheme
    7) "before all" hook: prepare suite


  137 passing (4m)
  7 failing

  1) Contract: Reputation "before all" hook: prepare suite:
     Error: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at ProviderError.ExtendableError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:9401:17)
      at new ProviderError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325054:24)
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325137:17
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325195:24
      at XMLHttpRequest.request.onreadystatechange (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:328229:7)
      at XMLHttpRequestEventTarget.dispatchEvent (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176415:18)
      at XMLHttpRequest._setReadyState (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176705:12)
      at XMLHttpRequest._onHttpRequestError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176895:12)
      at ClientRequest.<anonymous> (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176765:24)

  2) Contract: SchemeRegistrar "before all" hook: prepare suite:
     Error: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at ProviderError.ExtendableError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:9401:17)
      at new ProviderError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325054:24)
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325137:17
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325195:24
      at XMLHttpRequest.request.onreadystatechange (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:328229:7)
      at XMLHttpRequestEventTarget.dispatchEvent (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176415:18)
      at XMLHttpRequest._setReadyState (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176705:12)
      at XMLHttpRequest._onHttpRequestError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176895:12)
      at ClientRequest.<anonymous> (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176765:24)

  3) Contract: SimpleICO "before all" hook: prepare suite:
     Error: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at ProviderError.ExtendableError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:9401:17)
      at new ProviderError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325054:24)
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325137:17
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325195:24
      at XMLHttpRequest.request.onreadystatechange (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:328229:7)
      at XMLHttpRequestEventTarget.dispatchEvent (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176415:18)
      at XMLHttpRequest._setReadyState (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176705:12)
      at XMLHttpRequest._onHttpRequestError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176895:12)
      at ClientRequest.<anonymous> (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176765:24)

  4) Contract: TokenCapGC "before all" hook: prepare suite:
     Error: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at ProviderError.ExtendableError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:9401:17)
      at new ProviderError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325054:24)
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325137:17
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325195:24
      at XMLHttpRequest.request.onreadystatechange (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:328229:7)
      at XMLHttpRequestEventTarget.dispatchEvent (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176415:18)
      at XMLHttpRequest._setReadyState (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176705:12)
      at XMLHttpRequest._onHttpRequestError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176895:12)
      at ClientRequest.<anonymous> (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176765:24)

  5) Contract: UpgradeScheme "before all" hook: prepare suite:
     Error: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at ProviderError.ExtendableError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:9401:17)
      at new ProviderError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325054:24)
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325137:17
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325195:24
      at XMLHttpRequest.request.onreadystatechange (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:328229:7)
      at XMLHttpRequestEventTarget.dispatchEvent (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176415:18)
      at XMLHttpRequest._setReadyState (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176705:12)
      at XMLHttpRequest._onHttpRequestError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176895:12)
      at ClientRequest.<anonymous> (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176765:24)

  6) Contract: VestingScheme "before all" hook: prepare suite:
     Error: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at ProviderError.ExtendableError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:9401:17)
      at new ProviderError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325054:24)
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325137:17
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325195:24
      at XMLHttpRequest.request.onreadystatechange (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:328229:7)
      at XMLHttpRequestEventTarget.dispatchEvent (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176415:18)
      at XMLHttpRequest._setReadyState (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176705:12)
      at XMLHttpRequest._onHttpRequestError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176895:12)
      at ClientRequest.<anonymous> (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176765:24)

  7) Contract: VoteInOrganizationScheme "before all" hook: prepare suite:
     Error: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at ProviderError.ExtendableError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:9401:17)
      at new ProviderError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325054:24)
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325137:17
      at C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:325195:24
      at XMLHttpRequest.request.onreadystatechange (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:328229:7)
      at XMLHttpRequestEventTarget.dispatchEvent (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176415:18)
      at XMLHttpRequest._setReadyState (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176705:12)
      at XMLHttpRequest._onHttpRequestError (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176895:12)
      at ClientRequest.<anonymous> (C:\Users\Alon\AppData\Roaming\nvm\v8.9.3\node_modules\truffle\build\cli.bundled.js:176765:24)

Repo: https://github.com/daostack/daostack

I am running Windows 10 so this doesn't seem related to OS

For me it happens around 50% of the time locally and also happens during Travis build.

@cgewecke
Copy link
Contributor

This issue has been open for a while and looks a lot like the non-deterministic ganache bug which @benjamincburns fixed recently. Downloading the latest ganache-cli (read the release notes!) should resolve this problem.

Closing but if anyone continues to see this error please re-open or comment. Thanks for reporting.

@nickjm
Copy link

nickjm commented Feb 21, 2018

I'm getting this error message when connecting to Rinkeby with Infura, truffle-wallet-provider, and ethereumjs-wallet. I'm not convinced this is Ganache, but maybe my error is caused my something else.

@cgewecke
Copy link
Contributor

cgewecke commented Feb 21, 2018

@nickjm Could you provide context (what are you doing in your code) or a reproduction path? A stacktrace might also be helpful.

@cgewecke cgewecke reopened this Feb 21, 2018
@hickscorp
Copy link

hickscorp commented Feb 27, 2018

I have this issue around 10% of my builds, with 128 tests active, randomly.
The tests are running on the default dummy node (Ganache?), with the latest version of Truffle.
Interestingly enough, it only fails when built in our CI (Drone, dockerized), not locally.
Our environments are based on Ubuntu and use standard docker NodeJS:Carbon images.

@barakman
Copy link

barakman commented Mar 15, 2018

Same problem on Windows 10:

  • Ganache CLI v6.1.0 (ganache-core: 2.1.0)
  • Truffle v4.1.3
  • npm v5.5.1
  • node v8.9.3
  1) Contract: ...
     AssertionError: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at Context.it (...)
      at <anonymous>
      at process._tickCallback (internal/process/next_tick.js:188:7)

  2) Contract: ... "after each" hook: after test for "...":
     Error: Could not connect to your Ethereum client. Please check that your Ethereum client:
    - is running
    - is accepting RPC connections (i.e., "--rpc" option is used in geth)
    - is accessible over the network
    - is properly configured in your Truffle configuration file (truffle.js)

      at ProviderError.ExtendableError (C:\Users\...\AppData\Roaming\npm\node_modules\truffle\build\webpack:\~\truffle-error\index.js:10:1)
      at new ProviderError (C:\Users\...\AppData\Roaming\npm\node_modules\truffle\build\webpack:\~\truffle-provider\error.js:17:1)
      at C:\Users\...\AppData\Roaming\npm\node_modules\truffle\build\webpack:\~\truffle-provider\wrapper.js:71:1
      at C:\Users\...\AppData\Roaming\npm\node_modules\truffle\build\webpack:\~\truffle-provider\wrapper.js:129:1
      at XMLHttpRequest.request.onreadystatechange (C:\Users\...\AppData\Roaming\npm\node_modules\truffle\build\webpack:\~\web3\lib\web3\httpprovider.js:128:1)
      at XMLHttpRequestEventTarget.dispatchEvent (C:\Users\...\AppData\Roaming\npm\node_modules\truffle\build\webpack:\~\xhr2\lib\xhr2.js:64:1)
      at XMLHttpRequest._setReadyState (C:\Users\...\AppData\Roaming\npm\node_modules\truffle\build\webpack:\~\xhr2\lib\xhr2.js:354:1)
      at XMLHttpRequest._onHttpRequestError (C:\Users\...\AppData\Roaming\npm\node_modules\truffle\build\webpack:\~\xhr2\lib\xhr2.js:544:1)
      at ClientRequest.<anonymous> (C:\Users\...\AppData\Roaming\npm\node_modules\truffle\build\webpack:\~\xhr2\lib\xhr2.js:414:1)
      at Socket.socketErrorListener (_http_client.js:387:9)
      at emitErrorNT (internal/streams/destroy.js:64:8)
      at _combinedTickCallback (internal/process/next_tick.js:138:11)
      at process._tickCallback (internal/process/next_tick.js:180:9)

@barakman
Copy link

barakman commented Apr 6, 2018

@cgewecke:
Any news on this?

@cgewecke
Copy link
Contributor

cgewecke commented Apr 6, 2018

@barakman No, everyone's seeing it intermittently, AFAIK it predates recent work to stabilize the test client and it's possible that it's related to issue 453 at ganache-cli which is under bounty and currently being worked on. There's more detail over there if you're interested.

Unfortunately this looks like (as @benjamincburns would say) a heisenbug. If anyone finds a consistent way of reproducing it they will be greeted with delight.

@barakman
Copy link

barakman commented Apr 6, 2018

@cgewecke:
Thank you for the info.
P.S.: To me, heisenbug is kind of instinctively associated with Heisenberg (Uncertainty Principle's Heisenberg, not Breaking Bad's Heisenberg). More specifically, something like - "if you touch it, you change it", or in other words - this bug is unsolvable by definition, which I sincerely hope is not the case here... Or perhaps you were referring to the bug being uncertain, not the actual solution (and perhaps I went slightly off track with my "associativity")...

In my case, I see this occurring at random indeed, but - and this is actually very deterministic - in only 1 out of 23 scripts which truffle test executes.
I've been banging my head for a while, trying to figure out in what sense this script is different from all the others, which could explain this. But I have failed to find any notable difference, so I cannot think of any sustainable workaround.

Thanks

@cgewecke
Copy link
Contributor

cgewecke commented Apr 6, 2018

@barakman Ahhh!! That's pretty good isolation of the problem. It could be something in the script you identified. Could also be related to the test execution that precedes it.

If there's any possibility of having another set of eyes look at the codebase, we'd definitely be interested.

@barakman
Copy link

barakman commented Apr 6, 2018

@cgewecke:
Most likely not related to the preceding script, as I also tried to truffle test this script alone, and the problem persisted.
I'm not sure that I'm allowed to post the code publicly at this point, so I will try to minimize both the Solidity contract and the Javascript test, and if I am still able to reproduce the problem then I will post it here.
Another interesting point of attention, is the fact that I haven't seen it happening when using testrpc-sc instead of ganache-cli.
So the bug can probably be reduced to the differences between those two (and also, we can probably eliminate the chances of it being related to the truffle suite itself or to mocha).

@cgewecke
Copy link
Contributor

cgewecke commented Apr 6, 2018

@barakman Ok great, thank you. One thing about testrpc-sc is that it's much slower. If the underlying issue is a race condition, testrpc-sc could be introducing delays that mask it. Another important difference is that it uses an older version of ethereumjs-vm (from the fall). Possible clue there too, although have been seeing these disconnections all year.

@barakman
Copy link

barakman commented Apr 7, 2018

@cgewecke:
I can consistently reproduce the problem with the code below.

MyContract.sol:

pragma solidity ^0.4.18;

contract MyContract {
    uint256 public constant ONE = 1000000000;
    uint256 public constant GAMMA = 179437500000000000000000000000000000000000;
    uint256 public constant DELTA = 29437500;

    function buy(uint256 x, uint256 y, uint256 alpha, uint256 beta) external pure returns (uint256) {
        uint256 temp = alpha - beta * y;
        return x * (temp * ONE) / (temp * (ONE - DELTA) + GAMMA);
    }

    function sell(uint256 x, uint256 y, uint256 alpha, uint256 beta) external pure returns (uint256) {
        uint256 temp = alpha - beta * y;
        return x * (temp * (ONE + DELTA) - GAMMA) / (temp * ONE);
    }
}

MyContractUnitTest.js:

contract("MyContractUnitTest", () => {
    let interval = ["0", "20000000000000000000000000", "10000000000000000000000000000000000", "0"];
    let NUM_OF_TESTS_PER_INTERVAL = 10;

    function buyFunc(x, y, alpha, beta) {
        let temp = alpha.minus(beta.times(y));
        return x.times(temp.times(ONE)).dividedBy(temp.times(ONE.minus(DELTA)).plus(GAMMA));
    }

    function sellFunc(x, y, alpha, beta) {
        let temp = alpha.minus(beta.times(y));
        return x.times(temp.times(ONE.plus(DELTA)).minus(GAMMA)).dividedBy(temp.times(ONE));
    }

    async function buy(x, y, alpha, beta) {
        let fixedPoint = await myContract.buy(x, y, alpha, beta);
        let floatPoint = buyFunc(x, y, alpha, beta);
        return [fixedPoint, floatPoint];
    }

    async function sell(x, y, alpha, beta) {
        let fixedPoint = await myContract.sell(x, y, alpha, beta);
        let floatPoint = sellFunc(x, y, alpha, beta);
        return [fixedPoint, floatPoint];
    }

    let myContract;
    let ONE;
    let GAMMA;
    let DELTA;
    before(async () => {
        myContract = await artifacts.require("MyContract.sol").new();
        ONE = await myContract.ONE();
        GAMMA = await myContract.GAMMA();
        DELTA = await myContract.DELTA();
    });

    let AMOUNT = web3.toBigNumber(1000000);

    for (let func of [buy, sell]) {
        describe(`${func.name}:`, async () => {
            for (let row = 0; row < 100; row++) {
                for (let col = 0; col < 10; col++) {
                    let [minN, maxN, alpha, beta] = interval.map(x => web3.toBigNumber(x));
                    let incN = maxN.minus(minN).dividedBy(NUM_OF_TESTS_PER_INTERVAL - 1);
                    for (let i = 0; i < NUM_OF_TESTS_PER_INTERVAL; i++) {
                        let y = minN.plus(incN.times(i)).truncated();
                        it(`interval ${row} ${col}, test ${i}`, async () => {
                            try {
                                let [fixedPoint, floatPoint] = await func(AMOUNT, y, alpha, beta);
                                let ratio = fixedPoint.dividedBy(floatPoint);
                                assert(ratio.greaterThanOrEqualTo("0.99999") && ratio.lessThanOrEqualTo("1"), `ratio = ${ratio.toFixed()}`);
                            }
                            catch (error) {
                                assert(false, error.message);
                            }
                        });
                    }
                }
            }
        });
    }
});

My setup (as mentioned in a previous comment on this thread) is:

  • Windows 10
  • Ganache CLI v6.1.0 (ganache-core: 2.1.0)
  • Truffle v4.1.3
  • npm v5.5.1
  • node v8.9.3

Thanks

@cgewecke
Copy link
Contributor

cgewecke commented Apr 7, 2018

@barakman Great!! Thank you. Going to open a companion issue over at ganache-cli and will talk to @benjamincburns about this and get his input.

@barakman
Copy link

@cgewecke: Also happens on testrpc-sc if you try "hard enough"...

@barakman
Copy link

@cgewecke : I am circulating around the conclusion that this problem stems from improper usage of the Mocha framework. More precisely, improper usage of the before, beforeEach, afterEach and after hooks.

The typical error messages, although poorly phrased, imply this conjecture as well:

  • "before all" hook....
  • "before each" hook...
  • "after each" hook...
  • "after all" hook...

You can read the relevant information here, namely:

You may also pick any file and add “root”-level hooks. For example, add beforeEach() outside of all describe() blocks. This will cause the callback to beforeEach() to run before any test case, regardless of the file it lives in.

So using these hooks on the root-level might be a bad idea in this case, since due to the nature of the tested system (communication with a TestRPC or Ganache process), they typically execute asynchronous code.

@cgewecke
Copy link
Contributor

@barakman Agree it seems like disconnections happen at the 'seams' of the suites where the hooks are. The code at truffle-core here that sets up the 'contract' suite looks to me like it safely binds hooks within a describe and executes them asynchronously via Mocha's done callback. Do you see another place where they might be invoked?

@barakman
Copy link

@cgewecke:
I have removed all my root-level hooks, and i'm still encountering disconnections.
However, in opposed to before, the errors that I am getting are always "after each" hook....
And to be absolutely clear on that, I don't even have an afterEach hook in any of my tests!
Maybe Mocha adds implicit calls to afterEach, when an explicit call to beforeEach exists in the code.
However, so long as these implicit calls are not added at the root-level, it does not support my conjecture of hooked code running in the wrong scope to begin with.
In short, I'm at a loss here...

By the way, in the code that you linked, there doesn't seem to be support for the after hook, and I am using this hook in my tests.

@cgewecke
Copy link
Contributor

@barakman Hmmm....that's a nice observation about after - I wonder if that's causing problems.

@barakman
Copy link

barakman commented Apr 30, 2018

@cgewecke:
Thanks.
I removed all the after hooks in my code (replaced them with its), and now I'm getting a "before each" hook... error.
So I'm suspecting that one way or another - these hooks are not incorporated properly into Truffle.
In order to bring an empirical evidence for this conjecture, I am now trying the following workaround:

  • Replace each before hook with an it
  • Replace each after hook with an it
  • Move the contents of each beforeEach hook to the beginning of each one of the its which follow
  • Move the contents of each afterEach hook to the end of each one of the its which follow

If all tests pass without disconnections, then I'm pretty sure that we can stamp this as the cause of the problem. And even if not, I think that it could still be related to hooks which are added implicitly by the Mocha framework.

@barakman
Copy link

barakman commented May 3, 2018

@cgewecke:

I take back my previous conjecture of this error occurring on a given test as a result of something which has executed on a previous test.
This is because the error occurs when I execute truffle test separately for each test file (i.e., running truffle test test/SomeFile.js sequentially for each JS file).
Moreover, in between calls to truffle test, I close and reopen the ganache-cli process.
So this error cannot be related to any previous state stored by either truffle test or ganache-cli (unless one of them saves some "global information" in the operating-system's temp folder or something like that, which I sincerely doubt).

In addition to that, I have recently tested the new ganache-cli beta version (7.0.0-beta.0), where the problem persists.

I have posted my findings on a similar GIT thread which is closed by now, but I am hoping will reopen.

Thanks

@barakman
Copy link

barakman commented May 8, 2018

@cgewecke:

I have conducted a more extensive research, by modifying file /node_modules/truffle/build/cli.bundled.js.

I started off by checking which path leads to the NOT_CONNECTED_MESSAGE error message ('Invalid JSON RPC response: ""'):

  • The synchronous path (send: function(originalSend, preHook, postHook))
  • The asynchronous path (sendAsync: function(originalSendAsync, preHook, postHook))

As expected, this error occurs only in the asynchronous path.

Second, I added some logging in this path, just before invoking callback(error, result):

if (payload.params == undefined)
    console.log(result.id, payload.method, 'no params');
else
    console.log(result.id, payload.method, payload.params.length);

Here is the consistency that I have observed:

  1. During normal execution:
    • result.id starts from a very large value, and grows on each evm operation, for example:
      • id = 1525799814567, method = evm_revert
      • id = 1525799814727, method = evm_snapshot
    • result.id starts from 1 and increments by 1 on each net or eth operation, for example:
      • id = 1, method = net_version
      • id = 2, method = eth_sendTransaction
      • id = 3, method = eth_getTransactionReceipt
      • id = 4, method = eth_call
      • id = 5, method = eth_newBlockFilter
      • id = 6, method = eth_getCode
      • id = 7, method = eth_blockNumber
      • id = 8, method = eth_uninstallFilter
    • In some cases, both result.id and payload.method are undefined.
      When that happens, result.id increments by 2 on the next net or eth operation, for example:
      • id = 12, method = eth_blockNumber
      • id = undefined, method = undefined
      • id = 14, method = eth_uninstallFilter
  2. Right before the error occurs:
    • In the last one or two cases, result.id is undefined but payload.method is valid.
    • In the last case, payload.method is sometimes eth_getLogs for the first time in the entire test.
    • Here are several examples for that:
      • Test 1 ended with:
        • id = undefined, method = net_version
        • id = 1525791759176, method = eth_getLogs
      • Test 2 ended with:
        • id = undefined, method = eth_call
        • id = undefined, method = eth_getLogs
      • Test 3 ended with:
        • id = undefined, method = eth_blockNumber
      • Test 4 ended with:
        • id = undefined, method = eth_call
        • id = undefined, method = eth_getLogs
      • Test 5 ended with:
        • id = undefined, method = eth_blockNumber

I am hopeful that the above information will provide some clues towards the source of this problem.
And since I am able to reproduce it repeatedly, I will be happy to generate more logging in case you have any specific requests.

Thanks

@barakman
Copy link

barakman commented May 9, 2018

@cgewecke:

Update to the above:

I later realized that:

  • In some cases:
    • The id is in result
    • The method is in payload
  • In other cases:
    • The id is in result[0]
    • The method is in payload[0]

I therefore changed the logging as follows:

if (result.id != undefined)
    console.log(`Normal: id = ${result.id}, method = ${payload.method}`);
else if (result[0] != undefined)
    console.log(`In [0]: id = ${result[0].id}, method = ${payload[0].method}`);
else
    console.log(`Problem: result = ${result}, payload = ${JSON.stringify(payload, null, 4)}`);

The new logging has improved my previous observation from this:

result.id = undefined
payload.method = undefined

To this:

result[0].id = <the previous id + 1>
payload[0].method = eth_getFilterChanges

All of that, during normal execution of course.

What happens right before the error can be described as follows:
In the last one or two cases, the result is empty.
The contents which the result normally holds:

  • jsonrpc is still available in the payload
  • id is still available in the payload
  • result is not available anywhere

Is it possible that somewhere in ganache-cli code, the payload is initialized but the result is not?

That could most certainly be classified as an "Invalid JSON RPC response" (which you guys can easily resolve).

Thanks

@barakman
Copy link

barakman commented May 9, 2018

Some more observations:

When the last two result objects are empty:

  1. The last payload object always contains:
    • method = eth_getLogs
    • id = <some very large number>
  2. The error reported by truffle test is always "after each" hook: after test for...

When only the last result object are empty:

  1. The last payload object always contains:
    • method != eth_getLogs
    • id = <the previous id + 1>
  2. The error reported by truffle test is either "before each" hook: before test for... or No events were emitted

@cgewecke
Copy link
Contributor

cgewecke commented May 9, 2018

@barakman Thank you. . . this analysis is really helpful.

Is it possible that somewhere in ganache-cli code, the payload is initialized but the result is not?

@benjamincburns Does anything jump out at you as a possibility in the preceding three comments?

@cgewecke
Copy link
Contributor

cgewecke commented May 19, 2018

@barakman

  1. Web3 has introduced the use of XHR2 some time ago.
  2. Web3 has revoked the use of XHR2 some time ago.

Unfortunately it looks like case 1 is true. XHR2 is used in the latest web3 0.x as wells as web3 1.0. Have also tried running your reproduction case using web3 1.0 over websockets without luck. . .

This issue raises questions about whether web3 / truffle / ganache are really suited to running simulations with tens of thousands of calls. There might be significant value in building a tool that ran tests directly on top of ethereumjs-vm, or perhaps inside ganache, avoiding http overhead and other constraints.

@barakman
Copy link

barakman commented May 20, 2018

@cgewecke:

I did a little reading, and it seems that connections are closed by default in HTTP 1.0 and kept alive by default in HTTP 1.1. And I'm guessing that XMLHttpRequest supports HTTP 1.0 while XHR2 supports HTTP 1.1, so it makes sense that Web3 has switched from XMLHttpRequest to XHR2 and not vice-versa.

As with regards to the second part of your comment, please note that I have experienced the same problem when using solidity-coverage along with testrpc-sc. And as far as I understand, those two are designated specifically for the purpose of "running simulations with tens of thousands of calls" (how else would you achieve a complete coverage of your contracts?).

For now, I have added the following workaround on my system:

  1. Next to file package.json, added file fix-truffle.js :
FILE_NAME = "./node_modules/truffle/build/cli.bundled.js";
let fs = require("fs");
let oldData = fs.readFileSync(FILE_NAME, {encoding: "utf8"});
let newData = oldData.replace(/new XHR2/g, "new XMLHttpRequest");
fs.writeFileSync(FILE_NAME, newData, {encoding: "utf8"});
  1. In file package.json, added:
  "scripts": {
    "install": "node fix-truffle.js"
  }

Thanks.

@barakman
Copy link

barakman commented May 22, 2018

@cgewecke - just to finalize this issue (also for future readers):
The fix suggested above indeed seems to resolve the Could not connect to your Ethereum client problem discussed in this thread.
However, it exposes yet another problem:

Invalid JSON RPC response: "Error: socket hang up
  at createHangUpError (_http_client.js:331:15)
  at Socket.socketOnEnd (_http_client.js:423:23)
  at emitNone (events.js:111:20)
  at Socket.emit (events.js:208:7)
  at endReadableNT (_stream_readable.js:1056:12)
  at _combinedTickCallback (internal/process/next_tick.js:138:11)
  at process._tickCallback (internal/process/next_tick.js:180:9)"
  at ProviderError.ExtendableError (C:\Users\...\webpack:\~\truffle-error\index.js:10:1)
  at new ProviderError (C:\Users\...\webpack:\~\truffle-provider\error.js:17:1)
  at C:\Users\...\webpack:\~\truffle-provider\wrapper.js:71:1
  at C:\Users\...\webpack:\~\truffle-provider\wrapper.js:129:1
  at exports.XMLHttpRequest.request.onreadystatechange (C:\Users\...\webpack:\~\web3\lib\web3\httpprovider.js:128:1)
  at exports.XMLHttpRequest.dispatchEvent (C:\Users\...\webpack:\~\xmlhttprequest\lib\XMLHttpRequest.js:591:1)
  at setState (C:\Users\...\webpack:\~\xmlhttprequest\lib\XMLHttpRequest.js:610:1)
  at exports.XMLHttpRequest.handleError (C:\Users\...\webpack:\~\xmlhttprequest\lib\XMLHttpRequest.js:532:1)
  at ClientRequest.errorHandler (C:\Users\...\webpack:\~\xmlhttprequest\lib\XMLHttpRequest.js:459:1)
  at Socket.socketOnEnd (_http_client.js:423:9)
  at endReadableNT (_stream_readable.js:1056:12)
  at _combinedTickCallback (internal/process/next_tick.js:138:11)
  at process._tickCallback (internal/process/next_tick.js:180:9)

This problem seems to be of the following nature:

  • It happens only at the beginning of a test which is conducted after a "massive" one
  • It is a subset of the original problem, i.e.:
    • Without the fix, the old problem will necessarily appear where the new problem does
    • With the fix, the new problem will not necessarily appear where the old problem does

I believe that a possible fix for this problem is in the XMLHttpRequest function, around the area of:

request = doRequest(options, responseHandler).on("error", errorHandler);

Perhaps there's a missing handler for this request, for its socket, for its response or for its response's socket.

In either case, I have not been able to resolve it.
Most of my attempts were focused on searching NodeJS HTTP API for functions and/or events which might be used here.

The fact that a "massive" test completes successfully, but only when it takes place, does the next test emit this error (immediately when it begins) should give some hints, but I'm not sure what. It seems that the "massive" test does not release the socket when it is held for a long period (cutting this test shorter resolves the problem).

A simple workaround for this problem is to execute truffle test separately for each test file.
In other words, closing and reopening Truffle solves the problem, which implies that some resource (a socket?) is not released until Truffle is closed.

Unfortunately, this workaround is insufficient for solidity-coverage users (myself being among them), since this utility cannot be executed separately for each test file.

If someone can find a way to apply this ("close and reopen after every test file") in Truffle source code itself, then it might be a good solution.

I tried that too - in the Test.run function, at line js_tests.forEach(function(file)... - but couldn't quite get it to work.

@barakman
Copy link

barakman commented Jun 3, 2018

@cgewecke:

I have managed to fix (or if you will, find a workaround for) the socket hang up issue described above, which has emerged after I had resolved the original issue (by replacing XHR2 with XMLHttpRequest).

As mentioned before, this socket hang up error seems to be pretty consistent in the fact that it happens only at the end of a massive test (or perhaps at the beginning of the test that follows).

A deeper investigation has shown that it always happens as a result of a request consisting of payload.method === 'evm_revert', to which the response is an error message (and obviously an invalid JSON).

A glimpse at Ganache source code reveals that evm_revert is indeed executed at the end of each test (using afterEach).

Though I don't have any real evidence to support this, I think that it is possibly because an evm_revert executed after a massive test takes a very long time to complete, during which the connection is timed out.

By the way, the status of this response is 0. I previously bumped into some GitHub thread referring to why you've decided not to ignore status 0 in Truffle (the reason being that a test might fail silently, if I remember correctly). I can't find this thread now, but you were in it, so you might find the remaining of this comment relevant.

In any case, in order to workaround the socket hang up error, I simply fixed Truffle source code to ignore an error in the response if the request's payload.method is evm_revert.

Since evm_revert is not really a part of any test which I could possibly run on Truffle, I am confident that this fix cannot do any harm, for example (yet again), allow a test to fail silently.

Here is the extended workaround (for both problems), for any future readers:

  1. Next to file package.json, add file fix-truffle.js:
let FILE_NAME = "./node_modules/truffle/build/cli.bundled.js";

let TOKENS = [
    {prev: "request = new XHR2", next: "request = new XMLHttpRequest"},
    {prev: "error = errors.InvalidResponse", next: "error = payload.method === 'evm_revert' ? null : errors.InvalidResponse"}
];

let fs = require("fs");
let data = fs.readFileSync(FILE_NAME, {encoding: "utf8"});
for (let token of TOKENS) {
    data = data.replace(new RegExp(token.prev, "g"), token.next);
    console.log(`replaced "${token.prev}" with "${token.next}"`);
}
fs.writeFileSync(FILE_NAME, data, {encoding: "utf8"});
  1. In file package.json, add:
  "scripts": {
    "install": "node fix-truffle.js"
  }

Thanks

UPDATE:

It seems that even if a socket hang up error which occurs as a result of an evm_revert request at the end of a test is resolved (by ignoring it), a similar error may then occur as a result of an evm_snapshot request at the end of the next test.

We can slightly extend the workaround above to handle both cases, by changing this:

payload.method === 'evm_revert'

To this:

payload.method.startsWith('evm')

As evm requests are not something likely to be invoked directly from a testing script, I think that this extension is quite safe (i.e., will not cast away "real" errors in a given test).

However, generally speaking, I get the feeling that while Ganache takes a very long time to complete these requests in some cases (more specifically, after a massive test is conducted), the connection is simply (and abruptly) terminated.
The fact that restarting truffle test resolves this issue, implies that even if it is "Ganache's fault" (for taking so long to complete), it is "Truffle's fault" in handling it.

I am not very "happy" with the workaround proposed above, and I believe that a better approach would be to:

  1. Investigate why Ganache takes so long to complete evm_revert and evm_snapshot.
  2. Investigate why Truffle "has a problem" with the fact that Ganache takes so long to do it.

UPDATE 2:

For safety, extend this:

payload.method.startsWith('evm')

To this:

typeof payload.method === 'string' && payload.method.startsWith('evm')

Or even to this:

payload.method === 'evm_revert' || payload.method === 'evm_snapshot'

@cgewecke
Copy link
Contributor

cgewecke commented Jun 4, 2018

@barakman Thanks so much. The workaround you've proposed seems reasonable to me. There might be some kind of connection timeout at the HTTP layer - I've also seen this disconnection when running long solidity loops that validate bytecode in a call.

@barakman Out of curiosity, would making revert and snapshot optional help with your use case?

@barakman
Copy link

barakman commented Jun 4, 2018

@cgewecke:

Thank you.
I assume that the purpose of these two functions is to reset the EVM emulation back to an initial state, so that each one of the tests executed by Truffle will start under the exact same conditions, regardless of the order in which the tests are executed (and of course, the exact same conditions will continue to apply every time you invoke truffle test).
All of this is designated to ensure deterministic execution, I assume, so making these functions optional is probably in contrast with correct testing methodologies.

That said, since it's optional, I guess that there's no harm done (i.e., Truffle users can choose that on their own risk).

That said #2, I've already added an npm-post-install script to fix Truffle source code, so I'm not in any dire need for this feature (though, I suppose I'll have to do some maintenance work on that script every time I update Truffle version, so perhaps it WILL help me in the future).

It would help for sure if you could check with Ganache developers what might cause the execution of evm_revert and evm_snapshot be so lengthy.

Thank you for your help.

@cgewecke
Copy link
Contributor

cgewecke commented Jun 4, 2018

@barakman

It would help for sure if you could check with Ganache developers what might cause the execution of evm_revert and evm_snapshot be so lengthy.

I will. In your current suite, approximately how many blocks are being snapshotted / reverted?

@barakman
Copy link

barakman commented Jun 4, 2018

@cgewecke:
I have a total of 27 tests, so each one of these functions is invoked 27 times if that's what you mean.
Otherwise, can you please elaborate on what you mean by "how many blocks"?
Should I use web3 in order to get the block-number at the beginning and end of my longest test, and calculate the difference?

@cgewecke
Copy link
Contributor

cgewecke commented Jun 4, 2018

Apologies @barakman - yes you could do that or estimate the number of transactions that occur in the suite, since ganache executes a single tx per block.

I'd just like to give the ganache engineers a some guidance about what magnitude of tests triggers this.

@barakman
Copy link

barakman commented Jun 4, 2018

@cgewecke:
Just by looking at the code, I estimate that:

  • The test in which the evm_revert request fails, executes approximately 16943 RPCs.
  • The test in which the evm_revert request fails and the evm_snapshot request of following test also fails, executes approximately 28954 RPCs.

I could give you more accurate figures by getting the block number before and after, but that would take me a while (each one of them runs for about 15-20 minutes or so).

Thanks

@cgewecke
Copy link
Contributor

cgewecke commented Jun 4, 2018

That's perfect, thanks @barakman.

@vicnaum
Copy link

vicnaum commented Jul 7, 2018

Would there be an universal fix available any time soon?

I have random Error: CONNECTION ERROR: Couldn't connect to node http://127.0.0.1:7545/ errors when I do truffle test too (have 39 tests, 3 of which fail by that reason).

In May everything was still okay, today - it's not :(

@cgewecke
Copy link
Contributor

cgewecke commented Jul 7, 2018

@vicnaum Could you provide more detail about your suite or a link to project? At the moment we think this error is limited to very large suites. The principal reporter above has a battery of 50,000 tests.

Do the same 3 tests fail each time?

@vicnaum
Copy link

vicnaum commented Jul 7, 2018

@cgewecke it's always different tests. Can be only one test failing, but can be at most five. Usually near three. I'm using Windows 10.

The sources are here: https://github.com/vicnaum/hourlyPay

@barakman
Copy link

barakman commented Jul 9, 2018

@cgewecke : The error specified by vicnaum (connection error) does not seem to have any relation whatsoever with the issue described in this thread, which appears to be the result of limited resources (more precisely, the system runs out of HTTP connections).

@cgewecke
Copy link
Contributor

cgewecke commented Jul 9, 2018

@vicnaum I think @barakman is correct - I looked through the hourlyPay code a bit and see you're using a lot of methods to move time around on the chain. Would you like to open a separate issue so we can investigate further?

ganache-cli shouldn't disconnect from truffle under any circumstances so this is likely a bug. Could you display the entire contents of your error and stack trace as well?

@benjamincburns
Copy link
Contributor

@cgewecke & @barakman & others having this issue: I haven't dug into this too deeply, but my guess is that either Truffle or the tests in question are creating new instances of provider very frequently.

Optimal resource management would be to take advantage of HTTP keep alive by reusing provider instances between tests rather than recreating them.

I can say from experience that sending Connection: close in the request or explicitly closing the client socket only kicks the can down the road for this problem as you'll still exhaust the local address space due to ports sitting in FIN_WAIT.

@cgewecke
Copy link
Contributor

@benjamincburns Yes, it turns out this originates at web3 and they're fixing it in beta.36.

(It was keep-alive - the change).

@gnidan
Copy link
Contributor

gnidan commented Jan 16, 2019

Closing this since it seems to have been addressed as a duplicate of the issue above. Let us know if it's still a problem. Thank you!

@gnidan gnidan closed this as completed Jan 16, 2019
@barakman
Copy link

barakman commented Jan 21, 2019

@gnidan:
AFAIK, this is still a problem on Truffle 4.1.15 (which still uses XHR2 instead of XMLHttpRequest).

In Truffle 5.x this is possibly fix, since this part of the code has changed, though I haven't verified that, as it requires a bit of work on both my contracts and my tests.

To my understanding, you have released 4.1.15 specifically for this reason (i.e., for those who aren't rushing to upgrade their Solc and Web3 major versions).

So you might want to keep this issue opened until fixed in the Truffle 4 branch (or at least leave a note somewhere to mention that this problem is as viable as ever).

Thanks

@chris-shyft
Copy link

hey fyi I'm having this issue w/ Truffle v5.3.3 (core: 5.3.3) web3 in my project is ^1.2.6,
only popped up recently, 431 tests with a good density of numbers of calls per-test.

seems like it might be connected to assert manager function recently added.. this has been the first time that tests have been expected to perform any logic past the return to this (await ofc) function in the middle of the test functions.

async function assertReverts(promise, errorMessage = "") {
  try {
    await promise;
  } catch (error) {
    assert(error.toString().indexOf("VM Exception while processing transaction: revert"), "Expected VM revert error");
    assert(error.toString().indexOf(errorMessage) != -1, `Expected error: "${errorMessage}", actual error: "${error}"`);
    return;
  }

  assert.fail('Expected VM revert :: ' + errorMessage);
}

anyone aware of anything recently changed that could cause this to re-appear?

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

10 participants