zombie-instance of testrpc sometimes remains running in background

[SCBuergel]

Expected behaviour: Running npm test should run tests, start testrpc (if needed) in background, produce output messages and/or errors and then terminate the testrpc that is running in background.

Actual behaviour: Upon running the Zeppelin test setup against some other smart contracts, testrpc sometimes remains running in the background. This breaks all following attempts to run a test because testrpc attempts to start anew with the same port. (It seems that you are running testrpc on port 8555?).

Both the initial output as well as the log file are not really helpful. The console output looks as follows:

npm run test

> coverage-tmp@1.0.0 test /Volumes/DEV/coverage-tmp
> scripts/test.sh

Starting our own testrpc instance
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)

scripts/test.sh: line 66:  2895 Segmentation fault: 11  testrpc --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501200,1000000000000000000000000" --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501201,1000000000000000000000000" --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501202,1000000000000000000000000" --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501203,1000000000000000000000000" --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501204,1000000000000000000000000" --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501205,1000000000000000000000000" --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501206,1000000000000000000000000" --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501207,1000000000000000000000000" --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501208,1000000000000000000000000" --account="0x2bdd21761a483f71054e14f5b827213567971c676928d9a1808cbfa4b7501209,1000000000000000000000000" > /dev/null
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! coverage-tmp@1.0.0 test: `scripts/test.sh`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the coverage-tmp@1.0.0 test script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

and here the output of the debug.log file:

0 info it worked if it ends with ok
1 verbose cli [ '/usr/local/Cellar/node/8.4.0/bin/node',
1 verbose cli   '/usr/local/bin/npm',
1 verbose cli   'run',
1 verbose cli   'test' ]
2 info using npm@5.3.0
3 info using node@v8.4.0
4 verbose run-script [ 'pretest', 'test', 'posttest' ]
5 info lifecycle coverage-tmp@1.0.0~pretest: coverage-tmp@1.0.0
6 info lifecycle coverage-tmp@1.0.0~test: coverage-tmp@1.0.0
7 verbose lifecycle coverage-tmp@1.0.0~test: unsafe-perm in lifecycle true
8 verbose lifecycle coverage-tmp@1.0.0~test: PATH: /usr/local/lib/node_modules/npm/bin/node-gyp-bin:/Volumes/DEV/coverage-tmp/node_modules/.bin:/Volumes/DEV/coverage-tmp/node_modules/.bin:/Users/me/.rbenv/shims:/Users/me/.rbenv/bin:/usr/local/opt/php71/bin:/usr/local/bin:/usr/local/sbin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/opt/X11/bin:/Applications/Wireshark.app/Contents/MacOS
9 verbose lifecycle coverage-tmp@1.0.0~test: CWD: /Volumes/DEV/coverage-tmp
10 silly lifecycle coverage-tmp@1.0.0~test: Args: [ '-c', 'scripts/test.sh' ]
11 silly lifecycle coverage-tmp@1.0.0~test: Returned: code: 1  signal: null
12 info lifecycle coverage-tmp@1.0.0~test: Failed to exec test script
13 verbose stack Error: coverage-tmp@1.0.0 test: `scripts/test.sh`
13 verbose stack Exit status 1
13 verbose stack     at EventEmitter.<anonymous> (/usr/local/lib/node_modules/npm/lib/utils/lifecycle.js:289:16)
13 verbose stack     at emitTwo (events.js:125:13)
13 verbose stack     at EventEmitter.emit (events.js:213:7)
13 verbose stack     at ChildProcess.<anonymous> (/usr/local/lib/node_modules/npm/lib/utils/spawn.js:40:14)
13 verbose stack     at emitTwo (events.js:125:13)
13 verbose stack     at ChildProcess.emit (events.js:213:7)
13 verbose stack     at maybeClose (internal/child_process.js:927:16)
13 verbose stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:211:5)
14 verbose pkgid coverage-tmp@1.0.0
15 verbose cwd /Volumes/DEV/coverage-tmp
16 verbose Darwin 16.7.0
17 verbose argv "/usr/local/Cellar/node/8.4.0/bin/node" "/usr/local/bin/npm" "run" "test"
18 verbose node v8.4.0
19 verbose npm  v5.3.0
20 error code ELIFECYCLE
21 error errno 1
22 error coverage-tmp@1.0.0 test: `scripts/test.sh`
22 error Exit status 1
23 error Failed at the coverage-tmp@1.0.0 test script.
23 error This is probably not a problem with npm. There is likely additional logging output above.
24 verbose exit [ 1, true ]

This issue surfaces only sometimes and is hard to reproduce for us.

indeed we see something is still running on port 8555:

lsof -n -i4TCP:8555 | grep LISTEN
node    2918 me   12u  IPv6 0x8debd291692ede99      0t0  TCP *:d-fence (LISTEN)

Upon manually killing that process, the test runs again.

It would be good to prevent testrpc from running as a zombie instance in the background to begin with.

[cgewecke]

@SCBuergel Are you only seeing this issue on port 8555? Could you post a link to the repo you're testing, or the contents of your .solcover.js config file?

8555 is the port solidity-coverage uses and it will launch a testrpc in the background on its own unless norpc is set to true in its config file.

[frangio]

Hi @SCBuergel, I've noticed this as well and have already pinned down the cause, I think. It was introduced in #369 and is due to testrpc being a function which is run in the background.

Sorry for the inconvenience! I will fix it asap.

[frangio]

It's odd that this is happening on port 8555, though. That port should be used only with SOLIDITY_COVERAGE=true.

[SCBuergel]

@frangio you are right, we were running with solidity-coverage hence that port but the behaviour seems to be the same disregarding if we have coverage on or not (just on the normal port then).

[frangio]

@SCBuergel Please check out the changes I merged in #445 and let me know if the issue was fixed on your side.