test: Extend salvage test for wallet tool

maflcko commented at 12:41 pm on May 27, 2020: member

Extend the test to check the balance remains the same before and after the salvage

fanquake added the label Tests on May 27, 2020

jonasschnelli commented at 7:39 am on May 28, 2020: contributor

Test seems to fail: https://bitcoinbuilds.org/index.php?job=b27a270b-c15a-4a48-bf46-26b3cc36a464

DrahtBot commented at 2:43 am on June 2, 2020: contributor

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Conflicts

No conflicts as of last run.

maflcko closed this on Jun 5, 2020

maflcko reopened this on Jun 5, 2020

DrahtBot closed this on Jun 5, 2020

DrahtBot reopened this on Jun 5, 2020

maflcko force-pushed on Jun 5, 2020

jonatack commented at 6:05 pm on June 5, 2020: contributor

Concept ACK.

Seeing this error: Assertion `new_tx’ failed:

 02020-06-05T18:01:34.518000Z TestFramework (INFO): Initializing test directory /tmp/bitcoin_func_test_hf5xwzyh
 12020-06-05T18:01:34.975000Z TestFramework (INFO): Testing that various invalid commands raise with specific error messages
 22020-06-05T18:01:35.809000Z TestFramework (INFO): Calling wallet tool info, testing output
 32020-06-05T18:01:36.535000Z TestFramework (INFO): Generating transaction to mutate wallet
 42020-06-05T18:01:39.036000Z TestFramework (INFO): Calling wallet tool info after generating a transaction, testing output
 52020-06-05T18:01:39.238000Z TestFramework (INFO): Calling wallet tool create on an existing wallet, testing output
 62020-06-05T18:01:41.947000Z TestFramework (INFO): Starting node with arg -wallet=foo
 72020-06-05T18:01:42.716000Z TestFramework (INFO): Calling getwalletinfo on a different wallet ("foo"), testing output
 82020-06-05T18:01:42.975000Z TestFramework (INFO): Check salvage
 92020-06-05T18:01:51.543000Z TestFramework (ERROR): Assertion failed
10Traceback (most recent call last):
11  File "/home/jon/projects/bitcoin/bitcoin/test/functional/test_framework/test_framework.py", line 119, in main
12    self.run_test()
13  File "test/functional/tool_wallet.py", line 245, in run_test
14    self.test_salvage()
15  File "test/functional/tool_wallet.py", line 232, in test_salvage
16    self.assert_tool_output('', '-wallet=salvage', 'salvage')
17  File "test/functional/tool_wallet.py", line 52, in assert_tool_output
18    assert_equal(stderr, '')
19  File "/home/jon/projects/bitcoin/bitcoin/test/functional/test_framework/util.py", line 46, in assert_equal
20    raise AssertionError("not(%s)" % " == ".join(str(arg) for arg in (thing1, thing2) + args))
21AssertionError: not(bitcoin-wallet: wallet/walletdb.cpp:289: auto ReadKeyValue(CWallet *, CDataStream &, CDataStream &, CWalletScanState &, std::string &, std::string &)::(anonymous class)::operator()(CWalletTx &, bool) const: Assertion `new_tx' failed.
22 == )
232020-06-05T18:01:51.595000Z TestFramework (INFO): Stopping nodes

maflcko force-pushed on Jul 2, 2020

in test/functional/tool_wallet.py:233 in fab4fa1cad outdated

229+        balances_before = self.nodes[0].getbalances()
230         self.stop_node(0)
231 
232         self.assert_tool_output('', '-wallet=salvage', 'salvage')
233 
234+        self.start_node(0, ['-wallet=salvage'])

achow101 commented at 4:36 pm on July 22, 2020:

I had to add self.nodes[0].rescanblockchain(0) to make this pass after merging with #19457

maflcko force-pushed on Aug 15, 2020

achow101 commented at 5:29 pm on August 25, 2020: member

#19805 is a potential solution to the test failure as it just avoids deserializing those records entirely.

#19793 is a another potential solution to the test failure where the assert is removed.

ryanofsky commented at 6:56 pm on August 25, 2020: contributor

#19805 is a potential solution to the test failure as it just avoids deserializing those records entirely.

#19793 is a another potential solution to the test failure where the assert is removed.

Maybe I should look at the test to understand better, but both of these changes are avoiding failures when there are duplicate transactions in the database. But we still don’t know how duplicate transactions are winding up in the database to begin with?

achow101 commented at 7:03 pm on August 25, 2020: member

But we still don’t know how duplicate transactions are winding up in the database to begin with?

The duplicate transactions are showing up in the records the salvage pulls from the database. This doesn’t mean the database actually contains duplicate transactions but is actually more of an artifact of the aggressive salvage.

Specifically, the aggressive salvage will likely recover deleted data as such data is not actually overwritten, just marked deleted. The aggressive salvage ignores the deletion flag so it will pull up those records. In this test, the Btree ends up being rebalanced which involves moving data around and this is done via copy and delete. So the aggressive salvage is finding records in the “deleted space”.

fanquake referenced this in commit 68f0ab26bc on Sep 3, 2020

sidhujag referenced this in commit 709fc98a8f on Sep 3, 2020

maflcko force-pushed on Oct 15, 2020

in test/functional/tool_wallet.py:331 in fa6154b3aa outdated

228+        self.nodes[0].sendmany(amounts={gna(): 0.05 for _ in range(50)})
229+        self.nodes[0].sendmany(amounts={gna(): 0.05 for _ in range(50)})
230+        balances_before = self.nodes[0].getbalances()
231         self.stop_node(0)
232 
233         self.assert_tool_output('', '-wallet=salvage', 'salvage')

ryanofsky commented at 11:46 pm on October 21, 2020:

In commit “test: Add salvage test for wallet tool” (fa6154b3aa904eb39e6e537ff99106b6e022701b)

It seems the test is failing on this line due to stderr output https://travis-ci.org/github/bitcoin/bitcoin/jobs/735969416#L2582:

0Salvage: WARNING: Number of keys in data does not match number of values.
1Salvage: WARNING: Unexpected end of file while reading salvage output.
2WARNING: WalletBatch::Recover skipping key: CDataStream::read(): end of data: unspecified iostream_category error
3WARNING: WalletBatch::Recover skipping key: CDataStream::read(): end of data: unspecified iostream_category error
4WARNING: WalletBatch::Recover skipping key: Error reading wallet database: CPubKey/CPrivKey corrupt

maflcko commented at 7:17 am on October 22, 2020:

#20151

ryanofsky approved

ryanofsky commented at 11:50 pm on October 21, 2020: contributor

Code review ACK fa6154b3aa904eb39e6e537ff99106b6e022701b

Test looks right to me but there is an travis failure on one platform

DrahtBot added the label Needs rebase on Oct 29, 2020

maflcko force-pushed on Oct 30, 2020

DrahtBot removed the label Needs rebase on Oct 30, 2020

ryanofsky approved

ryanofsky commented at 6:11 pm on November 3, 2020: contributor

Code review ACK 66660e440d888e0cd1a16a769b7c06fc0d8e8345. Only change since last review is rebase. Also travis seems to pass now.

I’m confused about why the test was failing before #19078 (review) but succeeding now. The bug report #20151 just points back to this PR for steps to reproduce (which I guess no longer work?) and doesn’t mention whether the problem happens reliably or is maybe random or platform specific.

maflcko commented at 6:40 pm on November 3, 2020: member

Please don’t merge this. The failure still happens intermittently.

DrahtBot added the label Needs rebase on Dec 16, 2020

meshcollider commented at 9:33 am on September 28, 2021: contributor

@MarcoFalke how often does the intermittent test failure occur? I’ve rebased this on a branch which incorporates a few other salvage things, which fixes the assert(new_tx) thing again. I haven’t been able to hit #20151 yet after multiple re-runs locally.

maflcko force-pushed on Sep 28, 2021

maflcko commented at 10:12 am on September 28, 2021: member

How often did you try? I am running

0while test/functional/tool_wallet.py --legacy-wallet ; do ( echo 1 >> /tmp/runs )  ; done

and it fails after 36 tries:

0$ wc -l  /tmp/runs 
136 /tmp/runs

DrahtBot removed the label Needs rebase on Sep 28, 2021

PastaPastaPasta referenced this in commit d91df6dbf7 on Jun 7, 2022

PastaPastaPasta referenced this in commit bb70e84b72 on Jun 7, 2022

PastaPastaPasta referenced this in commit 9efc177bd1 on Jun 7, 2022

achow101 commented at 6:08 pm on October 12, 2022: member

Are you still working on this?

achow101 commented at 5:12 pm on November 10, 2022: member

Closing this as it has not had any activity in a while. If you are interested in continuing work on this, please leave a comment so that it can be reopened.

achow101 closed this on Nov 10, 2022

maflcko renamed this:
~~test: Add salvage test for wallet tool~~
test: Extend salvage test for wallet tool
on Nov 11, 2022

test: Extend salvage test for wallet tool fa60b70a0f

maflcko commented at 12:23 pm on November 11, 2022: member

Ok, I’ll rebase

maflcko reopened this on Nov 11, 2022

maflcko force-pushed on Nov 11, 2022

maflcko commented at 12:41 pm on November 11, 2022: member

The test still fails locally after a sufficient number of iterations, so I guess it is best to remove the command along with the removal of bdb

maflcko closed this on Nov 11, 2022

maflcko deleted the branch on Nov 11, 2022

bitcoin locked this on Nov 11, 2023

test: Extend salvage test for wallet tool #19078

Conflicts