[WIP] [test] Test abortrescan command. #10367
Closed
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
jnewbery
suggested changes
May 15, 2017
There was a problem hiding this comment.
Still flakey for me:
→ ./test_runner.py
WARNING! The following scripts are not being run: ['p2p-fullblocktest.py', 'mempool_spendcoinbase.py', 'fundrawtransaction.py', 'mempool_resurrect_test.py', 'net.py', 'import-rescan.py', 'disconnect_ban.py', 'zapwallettxes.py', 'mempool_limit.py', 'multi_rpc.py', 'preciousblock.py', 'rawtransactions.py', 'importmulti.py', 'blockchain.py', 'bip68-112-113-p2p.py', 'httpbasics.py', 'listsinceblock.py', 'disablewallet.py', 'prioritise_transaction.py', 'invalidtxrequest.py', 'receivedby.py', 'importprunedfunds.py', 'listtransactions.py', 'wallet.py', 'p2p-compactblocks.py', 'wallet-accounts.py', 'signrawtransactions.py', 'nodehandling.py', 'p2p-segwit.py', 'nulldummy.py', 'keypool.py', 'signmessages.py', 'p2p-leaktests.py', 'wallet-hd.py', 'segwit.py', 'merkle_blocks.py', 'reindex.py', 'bumpfee.py', 'mempool_persist.py', 'wallet-dump.py', 'rest.py', 'invalidblockrequest.py', 'getchaintips.py', 'sendheaders.py', 'rpcnamedargs.py', 'proxy_test.py', 'decodescript.py', 'p2p-mempool.py', 'zmq_test.py', 'mempool_reorg.py', 'walletbackup.py', 'maxblocksinflight.py', 'p2p-versionbits-warning.py', 'abandonconflict.py']. Check the test lists in test_runner.py.
...........................................................
import-abort-rescan.py --portseed=3 passed, Duration: 30 s
......
import-abort-rescan.py --portseed=2 failed, Duration: 33 s
stdout:
2017-05-15 18:41:26.479000 TestFramework (INFO): Initializing test directory /tmp/user/1000/test3cj9jwid/166
2017-05-15 18:41:31.202000 TestFramework (INFO): Creating blocks with transactions ...
2017-05-15 18:41:50.352000 TestFramework (INFO): Sending to shared address ...
2017-05-15 18:41:50.422000 TestFramework (INFO): Importing address in background thread ...
2017-05-15 18:41:50.423000 TestFramework (INFO): Attempting to abort scan ...
2017-05-15 18:41:50.437000 TestFramework (INFO): Waiting for import thread to die ...
2017-05-15 18:41:50.538000 TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
File "/home/ubuntu/bitcoin/test/functional/test_framework/test_framework.py", line 148, in main
self.run_test()
File "/home/ubuntu/bitcoin/test/functional/import-abort-rescan.py", line 62, in run_test
assert_equal(self.nodes[1].getbalance(), balances[1])
File "/home/ubuntu/bitcoin/test/functional/test_framework/util.py", line 408, in assert_equal
raise AssertionError("not(%s)" % " == ".join(str(arg) for arg in (thing1, thing2) + args))
AssertionError: not(2475.12300000 == 2475.00000000)
2017-05-15 18:41:50.539000 TestFramework (INFO): Stopping nodes
2017-05-15 18:41:59.604000 TestFramework (WARNING): Not cleaning up dir /tmp/user/1000/test3cj9jwid/166
2017-05-15 18:41:59.604000 TestFramework (ERROR): Test failed. Test logging available at /tmp/user/1000/test3cj9jwid/166/test_framework.log
stderr:
..........
import-abort-rescan.py --portseed=1 failed, Duration: 39 s
stdout:
2017-05-15 18:41:26.476000 TestFramework (INFO): Initializing test directory /tmp/user/1000/test89_pqhmk/167
2017-05-15 18:41:31.503000 TestFramework (INFO): Creating blocks with transactions ...
2017-05-15 18:41:50.205000 TestFramework (INFO): Sending to shared address ...
2017-05-15 18:41:50.333000 TestFramework (INFO): Importing address in background thread ...
2017-05-15 18:41:50.334000 TestFramework (INFO): Attempting to abort scan ...
2017-05-15 18:41:54.919000 TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
File "/home/ubuntu/bitcoin/test/functional/test_framework/test_framework.py", line 148, in main
self.run_test()
File "/home/ubuntu/bitcoin/test/functional/import-abort-rescan.py", line 52, in run_test
assert abortres # if false, we failed to abort
AssertionError
2017-05-15 18:41:54.919000 TestFramework (INFO): Stopping nodes
2017-05-15 18:42:05.038000 TestFramework (WARNING): Not cleaning up dir /tmp/user/1000/test89_pqhmk/167
2017-05-15 18:42:05.038000 TestFramework (ERROR): Test failed. Test logging available at /tmp/user/1000/test89_pqhmk/167/test_framework.log
stderr:
Try running in parallel with pruning.py to reproduce this.
kallewoof
changed the title
kallewoof
force-pushed
the
test-abort-rescan-2
branch
from
ecbac5a
to
0e002cb
Compare
|
@jnewbery Sorry for taking so long. Assuming there is a race condition where your side ends up scanning the chain before the abort makes it through, this should definitely fix it, I think. The tests take ~4 mins on my machine, but they're already in extended tests. |
|
This may be specific to my local environment, but if I try to run this test multiple times in parallel, I get failures: I'm running this in an ubuntu VM with quite slow spinning disk i/o. @kallewoof - if you run |
|
Just fyi ./test_runner.py $(for i in {1..40}; do echo -n 'import-abort-rescan '; done)is passing for me on an ssd. |
|
Thanks @MarcoFalke - probably caused by my slow disk in that case. |
|
Yeah. Though, I think tests should run and pass on all platforms that are capable of running Bitcoin Core. |
jnewbery
reviewed
Aug 14, 2017
| import time # for sleep | ||
|
|
||
| class ImportAbortRescanTest(BitcoinTestFramework): | ||
| def __init__(self): |
There was a problem hiding this comment.
No need to override method if you're just calling into super()
| self.log.info("Creating blocks with transactions ...") | ||
| # Make blocks with spam to cause rescan delay | ||
| for i in range(200): | ||
| if i % 50 == 0: self.log.info("... %2.f%%", 100.0 / 200.0 * i) |
There was a problem hiding this comment.
nit: if block should appear on the next line. Same for the if xxxxx: break lines below
| deadres = not importthread.isAlive() | ||
| if deadres: break | ||
|
|
||
| assert deadres # if false, importthread did not die soon enough |
There was a problem hiding this comment.
nit: prefer assert deadres, "importthread did not die soon enough" (so the error message is delivered to the user)
There was a problem hiding this comment.
Nice.. I didn't know you could do that.
|
@jnewbery your bash line runs fine on my end.
|
maflcko
reviewed
Aug 15, 2017
| from test_framework.test_framework import BitcoinTestFramework | ||
| from test_framework.util import (assert_equal, get_rpc_proxy) | ||
|
|
||
| class ImportAbortRescanTest(BitcoinTestFramework): |
There was a problem hiding this comment.
It seems you are not specifying the constructor (__init__). Thus 2 additional nodes are spun up and remain unused.
|
|
jnewbery
reviewed
Aug 15, 2017
| abortres = self.nodes[1].abortrescan() | ||
| if abortres: | ||
| break | ||
| assert abortres # if false, we failed to abort |
There was a problem hiding this comment.
nit: could change this to:
assert abortres, "abortrescan call failed"
|
Please squash your commits if this is no longer WIP |
kallewoof
force-pushed
the
test-abort-rescan-2
branch
from
e90d996
to
fef5ec5
Compare
kallewoof
changed the title
|
@MarcoFalke Squashed & removed '[WIP]' from title. |
promag
reviewed
Sep 13, 2017
| from test_framework.util import (assert_equal, get_rpc_proxy) | ||
|
|
||
| class ImportAbortRescanTest(BitcoinTestFramework): | ||
| def __init__(self): |
There was a problem hiding this comment.
Replace with
def set_test_params(self):
self.num_nodes = 2|
|
||
| from decimal import Decimal | ||
| import threading # for bg importprivkey | ||
| import time # for sleep |
There was a problem hiding this comment.
Change and remove comment:
from time import sleepThe same above.
|
|
||
| Test rescan behavior of importprivkey when aborted. The test ensures that: | ||
| 1. The abortrescan command indeed stops the rescan process. | ||
| 2. Subsequent rescan catches the aborted address UTXO |
| """Test wallet import RPCs. | ||
|
|
||
| Test rescan behavior of importprivkey when aborted. The test ensures that: | ||
| 1. The abortrescan command indeed stops the rescan process. |
There was a problem hiding this comment.
Nit, use unordered, ie, - The abortrescan ... .
There was a problem hiding this comment.
I'm not sure what the reason for this is. It is easier to refer to a point by number, e.g. "this test is no longer checking the 3rd point mentioned in the comment".
| def run_test(self): | ||
| # Generate for BTC | ||
| self.nodes[0].generate(300) | ||
| self.log.info("Creating blocks with transactions ...") |
There was a problem hiding this comment.
@jnewbery wdyt about moving this to util.py, like def generate_load(node, blocks, transactions): or whatever?
There was a problem hiding this comment.
I don't think it makes sense to move code up into the test_framework directory unless it's being used by more than one test script. I don't see the need here (unless you think you can refactor other test scripts to use this and reduce LOC)
There was a problem hiding this comment.
Would it make sense to take advantage of mine_large_block or is that overkill in this context? Might make this test more concise.
kallewoof
force-pushed
the
test-abort-rescan-2
branch
from
fef5ec5
to
adc27e0
Compare
jnewbery
reviewed
Sep 19, 2017
|
|
||
| from decimal import Decimal | ||
| import threading # for bg importprivkey | ||
| import sleep from time |
There was a problem hiding this comment.
invalid syntax. Should be from time import sleep
kallewoof
force-pushed
the
test-abort-rescan-2
branch
from
adc27e0
to
91b3f90
Compare
|
I was able to get most of the tests to pass running in parallel on the following:
Error: |
|
@maxgiraldo Thanks for testing! I tried on same mac set up (except more cores) doing ./test_runner.py $(for i in {1..40}; do echo -n 'import-abort-rescan '; done)and it is working on my end. What command are you using to run the tests? |
|
@kallewoof No problem! I'm using |
|
@maxgiraldo After running it for a long time I managed to reproduce. Looking into it now. |
|
Hum. I can't reproduce this without running for hours. It feels like something is being exhausted, triggering the issue, but even after running for several hours I don't see any spikes in resource usage and drive has 100 GB free. @jnewbery any thoughts on why "OSError: [Errno 41] Protocol wrong type for socket" would happen occasionally for ( |
|
@kallewoof Seems to be a MacOS/OS X-specific kernel issue, which throws the error code |
|
Hmmm, I've definitely read that blog post before, but I can't remember what exactly the context was! @maxgiraldo - perhaps you could add additional exception handling here: Something like: You could add a print statement or pdb breakpoint in there to confirm that you can reproduce and that this fixes this: Do you think this error is specific to this new test, or are you able to reproduce it on other tests? If it's not specific to this test, perhaps you can open a new issue or PR to track it. |
|
I can reproduce as well, but it sometimes takes hours. Will try your patch in a couple hours on my end. I'll push a commit so @maxgiraldo can test it too if he hasn't tried it manually already. |
|
Different error now. Something very weird is going on with networking here. |
|
Pushed commit with fix in it. This still breaks on my end after running for awhile. |
kallewoof
force-pushed
the
test-abort-rescan-2
branch
from
e8d683b
to
e4f51c1
Compare
kallewoof
force-pushed
the
test-abort-rescan-2
branch
from
e4f51c1
to
da91c46
Compare
maxgiraldo
reviewed
Dec 18, 2017
| @@ -112,6 +112,16 @@ def _request(self, method, path, postdata): | |||
| return self._get_response() | |||
| else: | |||
| raise | |||
| except OSError as e: | |||
| if e.errno == 42: | |||
There was a problem hiding this comment.
The errno is actually 41; to avoid hardcoding the value, I would use from errno import EPROTOTYPE and then:
if e.errno == EPROTOTYPE:
...
|
Connection reset by peer after a shortish while. Very curious. |
kallewoof
changed the title
|
Closing for now, as this PR seems to be dormant, let me know when you want to pick it up again and I'll reopen. |
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Replaces #10225 as it caused intermittent failures for some users.
Difference: gave up on making a "fast running" test and upped the blockchain size and spam count to avoid the scan finishing before the abort call. Moved test down to extended tests.
Test runs in roughly 2 minutes on my local machine. The blockchain generation part takes roughly 1m20s.
@jnewbery Does this work on your end?