bitcoin icon indicating copy to clipboard operation
bitcoin copied to clipboard

Published 20 hours ago • verified publisher icon bitcoin

failure in wallet_basic.py --descriptors

Open fanquake opened this issue 2 years ago • 6 comments

https://cirrus-ci.com/task/6282049166770176?logs=ci#L3112

 node0 2023-03-12T18:59:07.047547Z [scheduler] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] AddToWallet 0a94aab7b4dc8ba22b88ccd6b2c9898936c7d36bf8b3e1789f6083b85f6d752a  new 
 test  2023-03-12T18:59:07.053000Z TestFramework (ERROR): Assertion failed 
                                   Traceback (most recent call last):
                                     File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 134, in main
                                       self.run_test()
                                     File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/wallet_basic.py", line 727, in run_test
                                       assert_equal(len(coins), 2)
                                     File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/test_framework/util.py", line 56, in assert_equal
                                       raise AssertionError("not(%s)" % " == ".join(str(arg) for arg in (thing1, thing2) + args))
                                   AssertionError: not(1 == 2)
 test  2023-03-12T18:59:07.054000Z TestFramework (DEBUG): Closing down network thread

fanquake avatar Mar 12 '23 19:03 fanquake

Looks like a bug in the wallet? Wild guess:

  • Tx is added to mempool (validationinterface event is scheduled)
  • Tx is mined (and recorded by wallet as mined)
  • event is executed and tx is marked as not in mempool and untrusted??

maflcko avatar Mar 13 '23 10:03 maflcko

longer log 
 test  2023-03-12T18:59:06.353000Z TestFramework (INFO): Testing 'listunspent' outputs the parent descriptor(s) of coins 
 node0 2023-03-12T18:59:06.354968Z [http] [httpserver.cpp:257] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:59490 
 node0 2023-03-12T18:59:06.355165Z [httpworker.0] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=deriveaddresses user=__cookie__ 
 node0 2023-03-12T18:59:06.369434Z [http] [httpserver.cpp:257] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:59490 
 node0 2023-03-12T18:59:06.369577Z [httpworker.3] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=deriveaddresses user=__cookie__ 
 node0 2023-03-12T18:59:06.386205Z [http] [httpserver.cpp:257] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:59490 
 node0 2023-03-12T18:59:06.386339Z [httpworker.1] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=sendtoaddress user=__cookie__ 
 node0 2023-03-12T18:59:06.407475Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 27 > 60% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.407543Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 60% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.421795Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 54 > 85% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 89.90% 8.9/(8.9 1 mem 0.0 out) 
 node0 2023-03-12T18:59:06.421889Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 48 > 85% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.421938Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 85% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.426844Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 108 > 95% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 89.90% 8.9/(8.9 1 mem 0.0 out) 
 node0 2023-03-12T18:59:06.426892Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 48 > 95% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.426934Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.427073Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 3 > 60% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.427152Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 6 > 85% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.427194Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.427429Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.442808Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 89.90% 8.9/(8.9 1 mem 0.0 out) 
 node0 2023-03-12T18:59:06.446709Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] Fee Calculation: Fee:3300 Bytes:165 Tgt:6 (requested 6) Reason:"Fallback fee" Decay 0.96200: Estimation: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.447068Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 27 > 60% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.447125Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 60% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.452884Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 54 > 85% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 89.90% 8.9/(8.9 1 mem 0.0 out) 
 node0 2023-03-12T18:59:06.452953Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 48 > 85% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.453000Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 85% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.457788Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 108 > 95% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 89.90% 8.9/(8.9 1 mem 0.0 out) 
 node0 2023-03-12T18:59:06.457848Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 48 > 95% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.457891Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.457998Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 3 > 60% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.458096Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 6 > 85% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.458140Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.458369Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.463439Z [httpworker.1] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 89.90% 8.9/(8.9 1 mem 0.0 out) 
 node0 2023-03-12T18:59:06.467940Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] Fee Calculation: Fee:3300 Bytes:165 Tgt:6 (requested 6) Reason:"Fallback fee" Decay 0.96200: Estimation: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.467993Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] Fee non-grouped = 3300, grouped = 3300, using grouped 
 node0 2023-03-12T18:59:06.468106Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] CommitTransaction: 
                                   CTransaction(hash=d8a78b8208, ver=2, vin.size=1, vout.size=2, nLockTime=219)
                                       CTxIn(COutPoint(fd47fa2191, 1), scriptSig=, nSequence=4294967293)
                                       CScriptWitness(304402202f6a64614b25e4dd6efaafe93e0b22251b73afc57d8a4e2685df12281d447ced02205d99513af2d6e9440d62024f9ea0b179c35fa418e90ba7cd07bc7c56510a68c501, 023732eb8672978b45cfe5c5b1d0825f029d59e7b4f97100d31890dc1cbf026614)
                                       CTxOut(nValue=21.98889710, scriptPubKey=5120a4d9ae94fe500d0af27a737028)
                                       CTxOut(nValue=0.01000000, scriptPubKey=002085f036f0b3c3328a2df724932d)
 node0 2023-03-12T18:59:06.468406Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] AddToWallet d8a78b82086b72d23587b0212bb82f86f8a82eabdef2f692d731b54ac276510b  newupdate 
 node0 2023-03-12T18:59:06.468578Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] Submitting wtx d8a78b82086b72d23587b0212bb82f86f8a82eabdef2f692d731b54ac276510b to mempool for relay 
 node0 2023-03-12T18:59:06.469146Z [httpworker.1] [txmempool.cpp:644] [check] [mempool] Checking mempool with 1 transactions and 1 inputs 
 node0 2023-03-12T18:59:06.469484Z [httpworker.1] [validationinterface.cpp:213] [TransactionAddedToMempool] [validation] Enqueuing TransactionAddedToMempool: txid=d8a78b82086b72d23587b0212bb82f86f8a82eabdef2f692d731b54ac276510b wtxid=2bc449a05edac3b9466c2e5f86816d05e75683b0297d5eb1933684d8f9e995ff 
 node0 2023-03-12T18:59:06.469556Z [httpworker.1] [txmempool.cpp:644] [check] [mempool] Checking mempool with 2 transactions and 2 inputs 
 node0 2023-03-12T18:59:06.470538Z [http] [httpserver.cpp:257] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:59490 
 node0 2023-03-12T18:59:06.470667Z [httpworker.2] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=sendtoaddress user=__cookie__ 
 node0 2023-03-12T18:59:06.489102Z [scheduler] [validationinterface.cpp:213] [operator()] [validation] TransactionAddedToMempool: txid=d8a78b82086b72d23587b0212bb82f86f8a82eabdef2f692d731b54ac276510b wtxid=2bc449a05edac3b9466c2e5f86816d05e75683b0297d5eb1933684d8f9e995ff 
 node0 2023-03-12T18:59:06.489153Z [scheduler] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1390 started 
 node0 2023-03-12T18:59:06.490697Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 27 > 60% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.490751Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 60% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.497377Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 54 > 85% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 81.66% 8.9/(8.9 2 mem 0.0 out) 
 node0 2023-03-12T18:59:06.497442Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 48 > 85% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.497484Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 85% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.501936Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 108 > 95% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 81.66% 8.9/(8.9 2 mem 0.0 out) 
 node0 2023-03-12T18:59:06.501980Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 48 > 95% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.502018Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.502133Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 3 > 60% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.502202Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 6 > 85% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.502241Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.502460Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.507348Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 81.66% 8.9/(8.9 2 mem 0.0 out) 
 node0 2023-03-12T18:59:06.527593Z [httpworker.2] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] Fee Calculation: Fee:3080 Bytes:154 Tgt:6 (requested 6) Reason:"Fallback fee" Decay 0.96200: Estimation: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.527931Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 27 > 60% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.527982Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 60% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.532941Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 54 > 85% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 81.66% 8.9/(8.9 2 mem 0.0 out) 
 node0 2023-03-12T18:59:06.533001Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 48 > 85% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.533064Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 85% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.537871Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 108 > 95% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 81.66% 8.9/(8.9 2 mem 0.0 out) 
 node0 2023-03-12T18:59:06.537923Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 48 > 95% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.537965Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.538090Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 3 > 60% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.538165Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 6 > 85% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.538206Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.96200: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.538443Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.99520: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 8.4/(8.4 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.543636Z [httpworker.2] [policy/fees.cpp:381] [EstimateMedianVal] [estimatefee] FeeEst: 12 > 95% decay 0.99931: feerate: -1 from (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 81.66% 8.9/(8.9 2 mem 0.0 out) 
 node0 2023-03-12T18:59:06.547887Z [httpworker.2] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] Fee Calculation: Fee:3080 Bytes:154 Tgt:6 (requested 6) Reason:"Fallback fee" Decay 0.96200: Estimation: (-1 - -1) 0.00% 0.0/(0.0 0 mem 0.0 out) Fail: (0 - 1e+99) 100.00% 7.1/(7.1 0 mem 0.0 out) 
 node0 2023-03-12T18:59:06.547929Z [httpworker.2] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] Fee non-grouped = 3080, grouped = 3080, using grouped 
 node0 2023-03-12T18:59:06.548001Z [httpworker.2] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] CommitTransaction: 
                                   CTransaction(hash=1399916770, ver=2, vin.size=1, vout.size=2, nLockTime=219)
                                       CTxIn(COutPoint(d8a78b8208, 0), scriptSig=, nSequence=4294967293)
                                       CScriptWitness(923e2671bf9d191577f450ba14cb1b5affd6f88b0faa0011f90d78ad178cdb3780f33e60cf2a8a8b4f194b068cb1eab6a36c3026dcf4407f3aab00ae69bd4db7)
                                       CTxOut(nValue=0.01000000, scriptPubKey=0020c70f46e61842dacb435c3746f0)
                                       CTxOut(nValue=21.97886630, scriptPubKey=51208fafd40181749359fd9ddde200)
 node0 2023-03-12T18:59:06.548327Z [httpworker.2] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] AddToWallet 13999167707bae7fd486d18cad074547734c7713023c74604e99c0cd2886b9e9  newupdate 
 node0 2023-03-12T18:59:06.548504Z [httpworker.2] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] Submitting wtx 13999167707bae7fd486d18cad074547734c7713023c74604e99c0cd2886b9e9 to mempool for relay 
 node0 2023-03-12T18:59:06.549028Z [httpworker.2] [txmempool.cpp:644] [check] [mempool] Checking mempool with 2 transactions and 2 inputs 
 node0 2023-03-12T18:59:06.549410Z [httpworker.2] [validationinterface.cpp:213] [TransactionAddedToMempool] [validation] Enqueuing TransactionAddedToMempool: txid=13999167707bae7fd486d18cad074547734c7713023c74604e99c0cd2886b9e9 wtxid=decfbc6f175a384508606885d3f31fdc67c1971cee57599f90bf2ee7d8a42c48 
 node0 2023-03-12T18:59:06.549467Z [httpworker.2] [txmempool.cpp:644] [check] [mempool] Checking mempool with 3 transactions and 3 inputs 
 node0 2023-03-12T18:59:06.549685Z [scheduler] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1390 completed (60495μs) 
 test  2023-03-12T18:59:06.550000Z TestFramework.node0 (DEBUG): TestNode.generate() dispatches `generate` call to `generatetoaddress` 
 node0 2023-03-12T18:59:06.550601Z [http] [httpserver.cpp:257] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:59490 
 node0 2023-03-12T18:59:06.550793Z [httpworker.0] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=generatetoaddress user=__cookie__ 
 node0 2023-03-12T18:59:06.551618Z [httpworker.0] [node/miner.cpp:162] [CreateNewBlock] CreateNewBlock(): block weight: 2738 txs: 3 fees: 9200 sigops 402 
 node0 2023-03-12T18:59:06.551824Z [httpworker.0] [validation.cpp:2138] [ConnectBlock] [bench]     - Sanity checks: 0.03ms [0.00s (0.05ms/blk)] 
 node0 2023-03-12T18:59:06.551931Z [httpworker.0] [validation.cpp:2240] [ConnectBlock] [bench]     - Fork checks: 0.11ms [0.00s (0.23ms/blk)] 
 node0 2023-03-12T18:59:06.552070Z [httpworker.0] [validation.cpp:2330] [ConnectBlock] [bench]       - Connect 4 transactions: 0.11ms (0.027ms/tx, 0.036ms/txin) [0.00s (0.22ms/blk)] 
 node0 2023-03-12T18:59:06.552102Z [httpworker.0] [validation.cpp:2348] [ConnectBlock] [bench]     - Verify 3 txins: 0.17ms (0.057ms/txin) [0.00s (0.27ms/blk)] 
 node0 2023-03-12T18:59:06.552129Z [httpworker.0] [node/miner.cpp:181] [CreateNewBlock] [bench] CreateNewBlock() packages: 0.18ms (3 packages, 1 updated descendants), validity: 0.59ms (total 0.77ms) 
 node0 2023-03-12T18:59:06.553130Z [httpworker.0] [validationinterface.cpp:260] [NewPoWValidBlock] [validation] NewPoWValidBlock: block hash=5c9ad1f5199b3a9e656dd3f7fe6b28d01fc3868645238ddb6e217eec5ada45bb 
 node0 2023-03-12T18:59:06.554313Z [httpworker.0] [validation.cpp:2810] [ConnectTip] [bench]   - Using cached block 
 node0 2023-03-12T18:59:06.554343Z [httpworker.0] [validation.cpp:2821] [ConnectTip] [bench]   - Load block from disk: 0.03ms [0.00s (0.02ms/blk)] 
 node0 2023-03-12T18:59:06.554382Z [httpworker.0] [validation.cpp:2138] [ConnectBlock] [bench]     - Sanity checks: 0.00ms [0.00s (0.04ms/blk)] 
 node0 2023-03-12T18:59:06.554489Z [httpworker.0] [validation.cpp:2240] [ConnectBlock] [bench]     - Fork checks: 0.11ms [0.00s (0.20ms/blk)] 
 node0 2023-03-12T18:59:06.554598Z [httpworker.0] [validation.cpp:2330] [ConnectBlock] [bench]       - Connect 4 transactions: 0.10ms (0.026ms/tx, 0.035ms/txin) [0.00s (0.19ms/blk)] 
 node0 2023-03-12T18:59:06.554630Z [httpworker.0] [validation.cpp:2348] [ConnectBlock] [bench]     - Verify 3 txins: 0.14ms (0.047ms/txin) [0.00s (0.24ms/blk)] 
 node0 2023-03-12T18:59:06.554726Z [httpworker.0] [validation.cpp:2362] [ConnectBlock] [bench]     - Write undo data: 0.09ms [0.00s (0.07ms/blk)] 
 node0 2023-03-12T18:59:06.554748Z [httpworker.0] [validation.cpp:2377] [ConnectBlock] [bench]     - Index writing: 0.03ms [0.00s (0.01ms/blk)] 
 node0 2023-03-12T18:59:06.554774Z [httpworker.0] [validationinterface.cpp:255] [BlockChecked] [validation] BlockChecked: block hash=5c9ad1f5199b3a9e656dd3f7fe6b28d01fc3868645238ddb6e217eec5ada45bb state=Valid 
 node0 2023-03-12T18:59:06.554809Z [httpworker.0] [validation.cpp:2837] [ConnectTip] [bench]   - Connect total: 0.47ms [0.00s (0.34ms/blk)] 
 node0 2023-03-12T18:59:06.554848Z [httpworker.0] [validation.cpp:2846] [ConnectTip] [bench]   - Flush: 0.04ms [0.00s (0.03ms/blk)] 
 node0 2023-03-12T18:59:06.554877Z [httpworker.0] [validation.cpp:2856] [ConnectTip] [bench]   - Writing chainstate: 0.03ms [0.00s (0.01ms/blk)] 
 node0 2023-03-12T18:59:06.555753Z [httpworker.0] [policy/fees.cpp:667] [processBlock] [estimatefee] Blockpolicy estimates updated by 2 of 3 block txs, since last block 2 of 3 tracked, mempool map size 0, max target 54 from historical 
 node0 2023-03-12T18:59:06.555831Z [httpworker.0] [txmempool.cpp:952] [RemoveUnbroadcastTx] [mempool] Removed d8a78b82086b72d23587b0212bb82f86f8a82eabdef2f692d731b54ac276510b from set of unbroadcast txns before confirmation that txn was sent out 
 node0 2023-03-12T18:59:06.555887Z [httpworker.0] [txmempool.cpp:952] [RemoveUnbroadcastTx] [mempool] Removed c3e6e6dd2ec1d4b3b0bf149848cf06174e0ee5347057d39b8a3cea00cc260f81 from set of unbroadcast txns before confirmation that txn was sent out 
 node0 2023-03-12T18:59:06.555938Z [httpworker.0] [txmempool.cpp:952] [RemoveUnbroadcastTx] [mempool] Removed 13999167707bae7fd486d18cad074547734c7713023c74604e99c0cd2886b9e9 from set of unbroadcast txns before confirmation that txn was sent out 
 node0 2023-03-12T18:59:06.556012Z [httpworker.0] [validation.cpp:2616] [UpdateTipLog] UpdateTip: new best=5c9ad1f5199b3a9e656dd3f7fe6b28d01fc3868645238ddb6e217eec5ada45bb height=220 version=0x30000000 log2_work=8.787903 tx=254 date='2023-03-12T18:59:06Z' progress=1.000000 cache=0.0MiB(21txo) 
 node0 2023-03-12T18:59:06.556031Z [httpworker.0] [validation.cpp:2872] [ConnectTip] [bench]   - Connect postprocess: 1.15ms [0.00s (0.81ms/blk)] 
 node0 2023-03-12T18:59:06.556073Z [httpworker.0] [validation.cpp:2876] [ConnectTip] [bench] - Connect block: 1.72ms [0.00s (1.21ms/blk)] 
 node0 2023-03-12T18:59:06.556101Z [httpworker.0] [txmempool.cpp:644] [check] [mempool] Checking mempool with 0 transactions and 0 inputs 
 node0 2023-03-12T18:59:06.556154Z [httpworker.0] [validationinterface.cpp:232] [BlockConnected] [validation] Enqueuing BlockConnected: block hash=5c9ad1f5199b3a9e656dd3f7fe6b28d01fc3868645238ddb6e217eec5ada45bb block height=220 
 node0 2023-03-12T18:59:06.556223Z [httpworker.0] [validationinterface.cpp:204] [UpdatedBlockTip] [validation] Enqueuing UpdatedBlockTip: new block hash=5c9ad1f5199b3a9e656dd3f7fe6b28d01fc3868645238ddb6e217eec5ada45bb fork block hash=1e0be5c042cd285ba79bd08ddf01ea84cb6a2cccc17f4ff9fbbcfa841014a1dd (in IBD=false) 
 node0 2023-03-12T18:59:06.557800Z [http] [httpserver.cpp:257] [http_request_cb] [http] Received a POST request for / from 127.0.0.1:59490 
 node0 2023-03-12T18:59:06.557993Z [httpworker.3] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=createwallet user=__cookie__ 
 node0 2023-03-12T18:59:06.558297Z [httpworker.3] [wallet/sqlite.cpp:91] [SQLiteDatabase] Using SQLite Version 3.38.5 
 node0 2023-03-12T18:59:06.558324Z [httpworker.3] [wallet/sqlite.cpp:92] [SQLiteDatabase] Using wallet /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20230312_185526/wallet_basic_235/node0/regtest/wallets/wo 
 node0 2023-03-12T18:59:06.571175Z [httpworker.3] [wallet/sqlite.cpp:261] [Open] WARNING SQLite is configured to not wait for data to be flushed to disk. Data loss and corruption may occur. 
 node0 2023-03-12T18:59:06.571894Z [httpworker.3] [noui.cpp:56] [noui_InitMessage] init message: Loading wallet… 
 node0 2023-03-12T18:59:06.572269Z [httpworker.3] [wallet/wallet.h:840] [WalletLogPrintf] [wo] Wallet file version = 10500, last client version = 249900 
 node0 2023-03-12T18:59:06.572368Z [httpworker.3] [wallet/wallet.h:840] [WalletLogPrintf] [wo] Keys: 0 plaintext, 0 encrypted, 0 w/ metadata, 0 total. Unknown wallet records: 0 
 node0 2023-03-12T18:59:06.572490Z [httpworker.3] [wallet/wallet.h:840] [WalletLogPrintf] [wo] Setting minversion to 169900 
 node0 2023-03-12T18:59:06.573125Z [httpworker.3] [wallet/wallet.h:840] [WalletLogPrintf] [wo] Wallet completed loading in               1ms 
 node0 2023-03-12T18:59:06.573555Z [httpworker.3] [wallet/wallet.h:840] [WalletLogPrintf] [wo] setKeyPool.size() = 0 
 node0 2023-03-12T18:59:06.573581Z [httpworker.3] [wallet/wallet.h:840] [WalletLogPrintf] [wo] mapWallet.size() = 0 
 node0 2023-03-12T18:59:06.573598Z [httpworker.3] [wallet/wallet.h:840] [WalletLogPrintf] [wo] m_address_book.size() = 0 
 node0 2023-03-12T18:59:06.575143Z [http] [httpserver.cpp:257] [http_request_cb] [http] Received a POST request for /wallet/wo from 127.0.0.1:59490 
 node0 2023-03-12T18:59:06.575351Z [httpworker.1] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=importdescriptors user=__cookie__ 
 node0 2023-03-12T18:59:06.579435Z [scheduler] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] AddToWallet d8a78b82086b72d23587b0212bb82f86f8a82eabdef2f692d731b54ac276510b 
 node0 2023-03-12T18:59:06.579542Z [scheduler] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1390 started 
 node0 2023-03-12T18:59:06.854336Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [wo] RescanFromTime: Rescanning last 220 blocks 
 node0 2023-03-12T18:59:06.854380Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [wo] Rescan started from block 5e06a7078461623cb62056fa0ebc5eb58dfbc1bceea8b664b4ca266f394c5f0b... (slow variant inspecting all blocks) 
 node0 2023-03-12T18:59:06.858132Z [scheduler] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1390 completed (278551μs) 
 node0 2023-03-12T18:59:06.858220Z [httpworker.1] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1910 started 
 node0 2023-03-12T18:59:06.858285Z [scheduler] [wallet/scriptpubkeyman.h:251] [WalletLogPrintf] [wo] MarkUnusedAddresses: Detected a used keypool item at index 0, mark all keypool items up to this item as used 
 node0 2023-03-12T18:59:06.923695Z [scheduler] [wallet/wallet.h:840] [WalletLogPrintf] [wo] AddToWallet d8a78b82086b72d23587b0212bb82f86f8a82eabdef2f692d731b54ac276510b  new 
 node0 2023-03-12T18:59:06.923888Z [httpworker.1] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1910 completed (65631μs) 
 node0 2023-03-12T18:59:06.933296Z [scheduler] [validationinterface.cpp:213] [operator()] [validation] TransactionAddedToMempool: txid=13999167707bae7fd486d18cad074547734c7713023c74604e99c0cd2886b9e9 wtxid=decfbc6f175a384508606885d3f31fdc67c1971cee57599f90bf2ee7d8a42c48 
 node0 2023-03-12T18:59:06.950954Z [scheduler] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] AddToWallet 13999167707bae7fd486d18cad074547734c7713023c74604e99c0cd2886b9e9 
 node0 2023-03-12T18:59:06.951078Z [scheduler] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1390 started 
 node0 2023-03-12T18:59:06.964322Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [wo] AddToWallet d8a78b82086b72d23587b0212bb82f86f8a82eabdef2f692d731b54ac276510b  update 
 node0 2023-03-12T18:59:06.964580Z [httpworker.1] [wallet/scriptpubkeyman.h:251] [WalletLogPrintf] [wo] MarkUnusedAddresses: Detected a used keypool item at index 0, mark all keypool items up to this item as used 
 node0 2023-03-12T18:59:06.994750Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [wo] AddToWallet 13999167707bae7fd486d18cad074547734c7713023c74604e99c0cd2886b9e9  new 
 node0 2023-03-12T18:59:06.994953Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [wo] Scanning current mempool transactions. 
 node0 2023-03-12T18:59:06.995012Z [httpworker.1] [wallet/wallet.h:840] [WalletLogPrintf] [wo] Rescan completed in             140ms 
 node0 2023-03-12T18:59:06.995220Z [scheduler] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1390 completed (44102μs) 
 node0 2023-03-12T18:59:06.995980Z [http] [httpserver.cpp:257] [http_request_cb] [http] Received a POST request for /wallet/wo from 127.0.0.1:59490 
 node0 2023-03-12T18:59:06.996135Z [httpworker.2] [rpc/request.cpp:179] [parse] [rpc] ThreadRPCServer method=listunspent user=__cookie__ 
 node0 2023-03-12T18:59:06.996473Z [httpworker.2] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1476 started 
 node0 2023-03-12T18:59:07.044334Z [scheduler] [wallet/wallet.h:840] [WalletLogPrintf] [wo] AddToWallet 13999167707bae7fd486d18cad074547734c7713023c74604e99c0cd2886b9e9  update 
 node0 2023-03-12T18:59:07.044587Z [httpworker.2] [logging/timer.h:58] [Log] [lock] Enter: lock contention cs_wallet, wallet/wallet.cpp:1476 completed (48078μs) 
 node0 2023-03-12T18:59:07.046763Z [scheduler] [validationinterface.cpp:232] [operator()] [validation] BlockConnected: block hash=5c9ad1f5199b3a9e656dd3f7fe6b28d01fc3868645238ddb6e217eec5ada45bb block height=220 
 node0 2023-03-12T18:59:07.047547Z [scheduler] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] AddToWallet 0a94aab7b4dc8ba22b88ccd6b2c9898936c7d36bf8b3e1789f6083b85f6d752a  new 
 test  2023-03-12T18:59:07.053000Z TestFramework (ERROR): Assertion failed 
                                   Traceback (most recent call last):
                                     File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 134, in main
                                       self.run_test()
                                     File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/wallet_basic.py", line 727, in run_test
                                       assert_equal(len(coins), 2)
                                     File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/test_framework/util.py", line 56, in assert_equal
                                       raise AssertionError("not(%s)" % " == ".join(str(arg) for arg in (thing1, thing2) + args))
                                   AssertionError: not(1 == 2)
 test  2023-03-12T18:59:07.054000Z TestFramework (DEBUG): Closing down network thread 
 node0 2023-03-12T18:59:07.059348Z [scheduler] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] AddToWallet d8a78b82086b72d23587b0212bb82f86f8a82eabdef2f692d731b54ac276510b  update 
 node0 2023-03-12T18:59:07.059555Z [scheduler] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] Transaction c3e6e6dd2ec1d4b3b0bf149848cf06174e0ee5347057d39b8a3cea00cc260f81 (in block 5c9ad1f5199b3a9e656dd3f7fe6b28d01fc3868645238ddb6e217eec5ada45bb) conflicts with wallet transaction 61ab8c73f257851c4b68e6bfeed5e1afe69386e2d5cdf82d47cc65df5edfce65 (both spend c7000015c1b3642d48623a4ea8854d1c556b401a6fa4e10ff75bcf801389b8ca:1) 
 node0 2023-03-12T18:59:07.078759Z [scheduler] [wallet/wallet.h:840] [WalletLogPrintf] [default_wallet] AddToWallet c3e6e6dd2ec1d4b3b0bf149848cf06174e0ee5347057d39b8a3cea00cc260f81  update 
 test  2023-03-12T18:59:07.106000Z TestFramework (INFO): Stopping nodes

maflcko avatar Mar 13 '23 10:03 maflcko

https://cirrus-ci.com/task/5029024158711808?logs=ci#L2900

 node0 2023-06-23T16:51:00.034382Z [scheduler] [wallet/sqlite.cpp:47] [TraceSqlCallback] [/tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20230623_164625/wallet_basic_242/node0/regtest/wallets/default_wallet/wallet.dat] SQLite Statement: INSERT or REPLACE into main values(?, ?) 
 test  2023-06-23T16:51:00.043000Z TestFramework (ERROR): Assertion failed 
                                   Traceback (most recent call last):
                                     File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 132, in main
                                       self.run_test()
                                     File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/wallet_basic.py", line 746, in run_test
                                       assert_equal(len(coins), 2)
                                     File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/test_framework/util.py", line 57, in assert_equal
                                       raise AssertionError("not(%s)" % " == ".join(str(arg) for arg in (thing1, thing2) + args))
                                   AssertionError: not(1 == 2)
 test  2023-06-23T16:51:00.044000Z TestFramework (DEBUG): Closing down network thread

fanquake avatar Jun 29 '23 08:06 fanquake

From those logs, it seems like the second transaction is taking a while to get into the mempool, long after the wallet submitted it. I believe it's only being accepting after we've the listunspent call, which then causes the assertion to fail.

I'm wondering why it's taking so long to get into the mempool - in a lot of tests, we assume that send* commands are basically instantaneous, otherwise I'd expect to see similar failures in a lot of other places.

achow101 avatar Jun 29 '23 14:06 achow101

I think adding it to the mempool should always be instantaneous. However, the background thread will still handle the AddedToMempool event, which may fire in the wallet when the transaction has already been removed from the mempool, and thus cause a wrong transaction state.

Not sure if this is what happened here, though.

maflcko avatar Jun 29 '23 15:06 maflcko

Reproduced locally: https://drahtbot.space/temp_scratch/wallet_basic_coins_2.tar.xz

maflcko avatar Dec 22 '23 09:12 maflcko