Running python tests fails #9996

After doing a git clean -dfx and rebuilding, the python tests started failing:

Test output:

root@0f51c0a75128:/home/bitcoin/bitcoin# python3 qa/pull-tester/rpc-tests.py receivedby
.
receivedby.py:
2017-03-15 02:31:58.943000 TestFramework (INFO): Initializing test directory /tmp/testmvbdk1ho/592
2017-03-15 02:31:59.240000 TestFramework (ERROR): Unexpected exception caught during testing
Traceback (most recent call last):
  File "/home/bitcoin/bitcoin/qa/rpc-tests/test_framework/test_framework.py", line 145, in main
    self.setup_chain()
  File "/home/bitcoin/bitcoin/qa/rpc-tests/test_framework/test_framework.py", line 49, in setup_chain
    initialize_chain(self.options.tmpdir, self.num_nodes, self.options.cachedir)
  File "/home/bitcoin/bitcoin/qa/rpc-tests/test_framework/util.py", line 258, in initialize_chain
    wait_for_bitcoind_start(bitcoind_processes[i], rpc_url(i), i)
  File "/home/bitcoin/bitcoin/qa/rpc-tests/test_framework/util.py", line 216, in wait_for_bitcoind_start
    raise Exception('bitcoind exited with status %i during initialization' % process.returncode)
Exception: bitcoind exited with status 1 during initialization
2017-03-15 02:31:59.264000 TestFramework (INFO): Stopping nodes

stderr:
: Error opening block database.
Please restart with -reindex or -reindex-chainstate to recover.
Traceback (most recent call last):
  File "/home/bitcoin/bitcoin/qa/rpc-tests/receivedby.py", line 147, in <module>
    ReceivedByTest().main()
  File "/home/bitcoin/bitcoin/qa/rpc-tests/test_framework/test_framework.py", line 162, in main
    stop_nodes(self.nodes)
  File "/home/bitcoin/bitcoin/qa/rpc-tests/test_framework/util.py", line 380, in stop_nodes
    for i, node in enumerate(nodes):
TypeError: 'NoneType' object is not iterable

Pass: False, Duration: 1 s

TEST          | PASSED | DURATION

receivedby.py | False  | 1 s

ALL           | False  | 1 s (accumulated)

Runtime: 1 s
root@0f51c0a75128:/home/bitcoin/bitcoin#

Debug Logs:

2017-03-15 02:31:59 
2017-03-15 02:31:59 Bitcoin version v0.14.99.0-ce01e62
2017-03-15 02:31:59 InitParameterInteraction: parameter interaction: -whitelistforcerelay=1 -> setting -whitelistrelay=1
2017-03-15 02:31:59 Validating signatures for all blocks.
2017-03-15 02:31:59 Default data directory /root/.bitcoin
2017-03-15 02:31:59 Using data directory /home/bitcoin/bitcoin/qa/cache/node0/regtest
2017-03-15 02:31:59 Using config file /home/bitcoin/bitcoin/qa/cache/node0/bitcoin.conf
2017-03-15 02:31:59 Using at most 125 automatic connections (1048576 file descriptors available)
2017-03-15 02:31:59 Using 32 MiB out of 32 requested for signature cache, able to store 1048576 elements
2017-03-15 02:31:59 Using 4 threads for script verification
2017-03-15 02:31:59 scheduler thread start
2017-03-15 02:31:59 HTTP: creating work queue of depth 16
2017-03-15 02:31:59 Config options rpcuser and rpcpassword will soon be deprecated. Locally-run instances may remove rpcuser to use cookie-based auth, or may be replaced with rpcauth. Please see share/rpcuser for rpcauth auth generation.
2017-03-15 02:31:59 HTTP: starting 4 worker threads
2017-03-15 02:31:59 init message: Verifying wallet...
2017-03-15 02:31:59 Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
2017-03-15 02:31:59 Using wallet wallet.dat
2017-03-15 02:31:59 CDBEnv::Open: LogDir=/home/bitcoin/bitcoin/qa/cache/node0/regtest/database ErrorFile=/home/bitcoin/bitcoin/qa/cache/node0/regtest/db.log
2017-03-15 02:31:59 Bound to [::]:15736
2017-03-15 02:31:59 Bound to 0.0.0.0:15736
2017-03-15 02:31:59 Cache configuration:
2017-03-15 02:31:59 * Using 2.0MiB for block index database
2017-03-15 02:31:59 * Using 8.0MiB for chain state database
2017-03-15 02:31:59 * Using 290.0MiB for in-memory UTXO set (plus up to 286.1MiB of unused mempool space)
2017-03-15 02:31:59 init message: Loading block index...
2017-03-15 02:31:59 Opening LevelDB in /home/bitcoin/bitcoin/qa/cache/node0/regtest/blocks/index
2017-03-15 02:31:59 IO error: /home/bitcoin/bitcoin/qa/cache/node0/regtest/blocks/index: Invalid argument
2017-03-15 02:31:59 : Error opening block database.
Please restart with -reindex or -reindex-chainstate to recover.
2017-03-15 02:31:59 Aborted block database rebuild. Exiting.
2017-03-15 02:31:59 Shutdown: In progress...
2017-03-15 02:31:59 scheduler thread interrupt
2017-03-15 02:31:59 Shutdown: done

Has anyone already got something like that ?

By playing a bit, I noticed it happen only if the datadir is inside my shared docker volume.

had there any change on leveldb recently which could provoke this change of behavior ?

Seems to be docker windows related (https://github.com/Level/levelup/issues/222) keeping open until I find the issue so people having the same problem can fix it.

Seeems to be normal #9482 now my big question is: Why in the hell it was working before. I also remember running bitcoind on network share without problem before.

Tried on old version of Bitcoin Core. Same problem. I guess something changed with my docker.

workaround it by changing this https://github.com/NicolasDorier/bitcoin/blob/8c373d5feedb428d234278d484e5d2a932010fae/qa/pull-tester/rpc-tests.py#L228 to another folder not on a share... root cause of this sudden change of behavior still unknown.

It turns out that fsync fails with error EINVAL because cifs volume does not support synching. This makes sense, but still does not explain why it already worked before for me.

So the root of the problem about why it works before and not now is that the cache for unit tests is created on /qa/cache, before there was no cache. I propose to move /qa/cache to /tmp.

Closing this issue as the immediate problem is solved.

Also, test_runner deletes and reseeds the cache by default since #10197, so problems with stale caches should not happen anymore.

I propose to move /qa/cache to /tmp.

Agree that moving it to /tmp at some point makes sense, although that complicates sharing it between multiple tests - hardcoding a directory name in /tmp is not-done because of shared systems.

You can already choose a custom cache dir when running individual tests with --cachedir, btw.