Skip to content

Conversation

@furszy
Copy link
Member

@furszy furszy commented Jul 24, 2023

Coming from #28089 (comment).

Several test cases are relying on the node1 default wallet, which thanks to 'test_locked_wallet' is encrypted.
And can be only accessed within a specific timeframe (100ms), a duration internally set by the same test.

This situation introduces a potential race condition, where other tests must complete their operations within
the specified 100ms window to pass (otherwise the wallet gets re-locked and they fail).

This can be seen running the test in valgrind (#28089), where other test cases fail due the wallet re-locking
itself after the 100ms.

@DrahtBot
Copy link
Contributor

DrahtBot commented Jul 24, 2023

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

Reviews

See the guideline for information on the review process.

Type Reviewers
ACK MarcoFalke, ishaanam

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #20892 (tests: Run both descriptor and legacy tests within a single test invocation by achow101)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

@DrahtBot DrahtBot added the Tests label Jul 24, 2023
Other tests are also relying on the node1 default wallet,
which thanks to 'test_locked_wallet' is encrypted.
And can only be accessed within a specific timeframe (100ms)
set internally by the same test.

This make other tests susceptible to races. They can only
perform their operations successfully within the specified
time.

This can be seen running the test in valgrind, where other
test cases fail due the wallet re-locking itself after the
100ms.
@furszy furszy force-pushed the 2023_isolate_test_locked_wallet branch from 6a47a3d to c648bdb Compare July 24, 2023 14:03
@maflcko
Copy link
Member

maflcko commented Jul 24, 2023

lgtm ACK c648bdb

@fanquake
Copy link
Member

cc @ishaanam

@ishaanam
Copy link
Contributor

utACK c648bdb

@maflcko maflcko added this to the 26.0 milestone Jul 25, 2023
@fanquake fanquake merged commit f033a98 into bitcoin:master Jul 26, 2023
@furszy furszy deleted the 2023_isolate_test_locked_wallet branch July 26, 2023 13:52
rawtx = wallet.createrawtransaction(inputs, outputs)
# fund a transaction that does not require a new key for the change output
self.nodes[1].fundrawtransaction(rawtx)
funded_tx = wallet.fundrawtransaction(rawtx)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This fails locally:

 node1 2023-08-02T03:08:04.791676Z [httpworker.2] [rpc/request.cpp:181] [parse] [rpc] ThreadRPCServer method=getnewaddress user=__cookie__ 
 node1 2023-08-02T03:08:04.798619Z [httpworker.2] [wallet/scriptpubkeyman.h:254] [WalletLogPrintf] [locked_wallet] keypool reserve 3 
 node1 2023-08-02T03:08:04.807232Z [httpworker.2] [wallet/scriptpubkeyman.h:254] [WalletLogPrintf] [locked_wallet] keypool keep 3 
 node1 2023-08-02T03:08:04.883158Z [http] [httpserver.cpp:255] [http_request_cb] [http] Received a POST request for /wallet/locked_wallet from 127.0.0.1:37278 
 node1 2023-08-02T03:08:04.883976Z [httpworker.0] [rpc/request.cpp:181] [parse] [rpc] ThreadRPCServer method=getrawchangeaddress user=__cookie__ 
 node1 2023-08-02T03:08:04.889129Z [httpworker.0] [wallet/scriptpubkeyman.h:254] [WalletLogPrintf] [locked_wallet] keypool reserve 4 
 node1 2023-08-02T03:08:04.893017Z [httpworker.0] [wallet/scriptpubkeyman.h:254] [WalletLogPrintf] [locked_wallet] keypool keep 4 
 node1 2023-08-02T03:08:04.897331Z [http] [httpserver.cpp:255] [http_request_cb] [http] Received a POST request for /wallet/locked_wallet from 127.0.0.1:37278 
 node1 2023-08-02T03:08:04.898090Z [httpworker.1] [rpc/request.cpp:181] [parse] [rpc] ThreadRPCServer method=listunspent user=__cookie__ 
 node0 2023-08-02T03:08:05.004756Z [http] [httpserver.cpp:255] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:59058 
 node0 2023-08-02T03:08:05.005782Z [httpworker.1] [rpc/request.cpp:181] [parse] [rpc] ThreadRPCServer method=getnewaddress user=__cookie__ 
 node0 2023-08-02T03:08:05.198476Z [httpworker.1] [wallet/scriptpubkeyman.h:254] [WalletLogPrintf] [default wallet] keypool added 1 keys (1 internal), size=2 (1 internal) 
 node0 2023-08-02T03:08:05.201311Z [httpworker.1] [wallet/scriptpubkeyman.h:254] [WalletLogPrintf] [default wallet] keypool reserve 30 
 node0 2023-08-02T03:08:05.288462Z [httpworker.1] [wallet/scriptpubkeyman.h:254] [WalletLogPrintf] [default wallet] keypool keep 30 
 node1 2023-08-02T03:08:05.299953Z [http] [httpserver.cpp:255] [http_request_cb] [http] Received a POST request for /wallet/locked_wallet from 127.0.0.1:37278 
 node1 2023-08-02T03:08:05.301853Z [httpworker.3] [rpc/request.cpp:181] [parse] [rpc] ThreadRPCServer method=createrawtransaction user=__cookie__ 
 node1 2023-08-02T03:08:05.593637Z [http] [httpserver.cpp:255] [http_request_cb] [http] Received a POST request for /wallet/locked_wallet from 127.0.0.1:37278 
 node1 2023-08-02T03:08:05.595303Z [httpworker.2] [rpc/request.cpp:181] [parse] [rpc] ThreadRPCServer method=fundrawtransaction user=__cookie__ 
 node1 2023-08-02T03:08:06.194715Z [httpworker.2] [policy/fees.cpp:382] [EstimateMedianVal] [estimatefee] FeeEst: 1 > 60% decay 0.96200: feerate: 1000 from (0 - 1e+99) 100.00% 14.2/(14.2 0 mem 0.0 out) Fail: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) 
 node1 2023-08-02T03:08:06.198808Z [httpworker.2] [policy/fees.cpp:382] [EstimateMedianVal] [estimatefee] FeeEst: 3 > 85% decay 0.96200: feerate: 1000 from (0 - 1e+99) 100.00% 14.2/(14.2 0 mem 0.0 out) Fail: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) 
 node1 2023-08-02T03:08:06.200053Z [httpworker.2] [policy/fees.cpp:382] [EstimateMedianVal] [estimatefee] FeeEst: 6 > 95% decay 0.96200: feerate: 1000 from (0 - 1e+99) 100.00% 14.2/(14.2 0 mem 0.0 out) Fail: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) 
 node1 2023-08-02T03:08:06.204141Z [httpworker.2] [policy/fees.cpp:382] [EstimateMedianVal] [estimatefee] FeeEst: 1 > 60% decay 0.96200: feerate: 1000 from (0 - 1e+99) 100.00% 14.2/(14.2 0 mem 0.0 out) Fail: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) 
 node1 2023-08-02T03:08:06.205478Z [httpworker.2] [policy/fees.cpp:382] [EstimateMedianVal] [estimatefee] FeeEst: 3 > 85% decay 0.96200: feerate: 1000 from (0 - 1e+99) 100.00% 14.2/(14.2 0 mem 0.0 out) Fail: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) 
 node1 2023-08-02T03:08:06.206162Z [httpworker.2] [policy/fees.cpp:382] [EstimateMedianVal] [estimatefee] FeeEst: 6 > 95% decay 0.96200: feerate: 1000 from (0 - 1e+99) 100.00% 14.2/(14.2 0 mem 0.0 out) Fail: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) 
 test  2023-08-02T03:08:06.709000Z TestFramework (ERROR): JSONRPC error 
                                   Traceback (most recent call last):
                                     File "/root/b-c-ci/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 131, in main
                                       self.run_test()
                                     File "/root/b-c-ci/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/wallet_fundrawtransaction.py", line 135, in run_test
                                       self.test_locked_wallet()
                                     File "/root/b-c-ci/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/wallet_fundrawtransaction.py", line 607, in test_locked_wallet
                                       funded_tx = wallet.fundrawtransaction(rawtx)
                                                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
                                     File "/root/b-c-ci/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/coverage.py", line 50, in __call__
                                       return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
                                                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
                                     File "/root/b-c-ci/ci/scratch/build/bitcoin-x86_64-pc-linux-gnu/test/functional/test_framework/authproxy.py", line 129, in __call__
                                       raise JSONRPCException(response['error'], status)
                                   test_framework.authproxy.JSONRPCException: Transaction needs a change address, but we can't generate it. Error: Keypool ran out, please call keypoolrefill first (-4)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Haven't been able to reproduce it. It is always passing here. But, I imagine that it's related to the dynamic fee rate calculation. Which.. is not needed in this test case; the test exercises the creation of a changeless transaction, the fee rate used is not really important.
So, when you can, try furszy@557c50d.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder why implicit fee estimation passed in the first place. Previously there were two inputs and a fee of 550sat. Now there is a fee of 2200 sat with one input.

Mind creating a pull, as I can't test intermittent issues? I think this needs clarification/fixup even absent an intermittent issue.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder why implicit fee estimation passed in the first place. Previously there were two inputs and a fee of 550sat. Now there is a fee of 2200 sat with one input.

That is because the default wallets have a custom tx fee (set here), which is much lower than the one used in the wallet created by this test case (which runs the default fee estimation).

Side note; the implicit fee estimation suffered other adaptations already:

So.. seems that this number has been adapted every now and then. And wouldn't be bad to provide a specific fee rate to fundrawtransaction() and document the expected behavior as I did in furszy@557c50d.

Mind creating a pull, as I can't test intermittent issues? I think this needs clarification/fixup even absent an intermittent issue.

Sure. Let me know if we are sync and will create the PR.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yeah, if the fee was hardcoded before, it makes sense to keep it hardcoded. Especially if removing the hard code makes the test fail.

sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Aug 9, 2023
…let case

c648bdb test: create wallet specific for test_locked_wallet case (furszy)

Pull request description:

  Coming from bitcoin#28089 (comment).

  Several test cases are relying on the node1 default wallet, which thanks to 'test_locked_wallet' is encrypted.
  And can be only accessed within a specific timeframe (100ms), a duration internally set by the same test.

  This situation introduces a potential race condition, where other tests must complete their operations within
  the specified 100ms window to pass (otherwise the wallet gets re-locked and they fail).

  This can be seen running the test in valgrind (bitcoin#28089), where other test cases fail due the wallet re-locking
  itself after the 100ms.

ACKs for top commit:
  MarcoFalke:
    lgtm ACK c648bdb
  ishaanam:
    utACK c648bdb

Tree-SHA512: 01cde5a4a0cb3405adb9ea3c1f73841f3fa237d1162268ed06f0d49ca38541006b423a029e0b5e5955e1aa7e018c4600d894e555a68cf17ff60a4b8be58f4aa9
fanquake added a commit to bitcoin-core/gui that referenced this pull request Aug 14, 2023
…timation

5364dd8 test: locked_wallet, skip default fee estimation (furszy)

Pull request description:

  Coming from bitcoin/bitcoin#28139 (comment).

  No test case in this file is meant to exercise fee estimation. All default wallets have a
  custom tx fee set [here](https://github.com/bitcoin/bitcoin/blob/b7138252ace6d21476964774e094ed1143cd7a1c/test/functional/wallet_fundrawtransaction.py#L100). The only one missing is the one created for `locked_wallet`.

ACKs for top commit:
  theStack:
    ACK 5364dd8

Tree-SHA512: 514c02708081d18330d759d10e306cee16c6350de243c68f0973777d2582f5d81968a237393c1f59aba245297e03f3f98d3ae5249a042469d0d016255f568719
sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Aug 15, 2023
5364dd8 test: locked_wallet, skip default fee estimation (furszy)

Pull request description:

  Coming from bitcoin#28139 (comment).

  No test case in this file is meant to exercise fee estimation. All default wallets have a
  custom tx fee set [here](https://github.com/bitcoin/bitcoin/blob/b7138252ace6d21476964774e094ed1143cd7a1c/test/functional/wallet_fundrawtransaction.py#L100). The only one missing is the one created for `locked_wallet`.

ACKs for top commit:
  theStack:
    ACK 5364dd8

Tree-SHA512: 514c02708081d18330d759d10e306cee16c6350de243c68f0973777d2582f5d81968a237393c1f59aba245297e03f3f98d3ae5249a042469d0d016255f568719
@bitcoin bitcoin locked and limited conversation to collaborators Aug 6, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants