Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

23.2.7rc1: feature_pak.py test failure: assert nopak_pegout_txid in self.nodes[0].getrawmempool() #1403

Open
whitslack opened this issue Feb 11, 2025 · 4 comments

Comments

@whitslack
Copy link

whitslack commented Feb 11, 2025

./configure \
	--prefix=/usr --build=x86_64-pc-linux-gnu --host=x86_64-pc-linux-gnu \
	--mandir=/usr/share/man --infodir=/usr/share/info --datadir=/usr/share \
	--sysconfdir=/etc --localstatedir=/var/lib --datarootdir=/usr/share \
	--disable-dependency-tracking --disable-silent-rules --disable-static \
	--docdir=/usr/share/doc/elements-23.2.7_rc1 \
	--htmldir=/usr/share/doc/elements-23.2.7_rc1/html --with-sysroot=/ \
	--libdir=/usr/lib64 --disable-static --enable-wallet --with-sqlite \
	--with-bdb --disable-usdt --without-miniupnpc --without-natpmp \
	--enable-tests --disable-bench --disable-fuzz --disable-fuzz-binary \
	--without-qrencode --disable-ccache --enable-asm --disable-zmq \
	--enable-man --enable-external-signer --with-utils --enable-util-cli \
	--enable-util-tx --enable-util-wallet --disable-util-util \
	--without-seccomp --without-libs --with-daemon --without-gui \
	--without-qtdbus --with-system-libsecp256k1
2025-02-11T14:14:51.611000Z TestFramework (DEBUG): PRNG seed is: 2230596805722387695
2025-02-11T14:14:51.611000Z TestFramework (DEBUG): Setting up network thread
2025-02-11T14:14:51.612000Z TestFramework (INFO): Initializing test directory /var/tmp/portage/net-p2p/elements-23.2.7_rc1/temp/test_runner_₿_🏃_20250211_141412/feature_pak_246
2025-02-11T14:14:51.619000Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up
2025-02-11T14:14:51.626000Z TestFramework.node1 (DEBUG): bitcoind started, waiting for RPC to come up
2025-02-11T14:14:51.634000Z TestFramework.node2 (DEBUG): bitcoind started, waiting for RPC to come up
2025-02-11T14:14:51.896000Z TestFramework.node0 (DEBUG): RPC successfully started
2025-02-11T14:14:52.151000Z TestFramework.node1 (DEBUG): RPC successfully started
2025-02-11T14:14:52.156000Z TestFramework.node2 (DEBUG): RPC successfully started
2025-02-11T14:14:52.554000Z TestFramework (INFO): Test wallet PAK
2025-02-11T14:14:52.632000Z TestFramework.node0 (DEBUG): Stopping node
2025-02-11T14:14:52.633000Z TestFramework.node1 (DEBUG): Stopping node
2025-02-11T14:14:52.635000Z TestFramework.node2 (DEBUG): Stopping node
2025-02-11T14:14:52.786000Z TestFramework.node0 (DEBUG): Node stopped
2025-02-11T14:14:52.787000Z TestFramework.node1 (DEBUG): Node stopped
2025-02-11T14:14:52.787000Z TestFramework.node2 (DEBUG): Node stopped
2025-02-11T14:14:52.793000Z TestFramework.node0 (DEBUG): bitcoind started, waiting for RPC to come up
2025-02-11T14:14:52.801000Z TestFramework.node1 (DEBUG): bitcoind started, waiting for RPC to come up
2025-02-11T14:14:52.815000Z TestFramework.node2 (DEBUG): bitcoind started, waiting for RPC to come up
2025-02-11T14:14:53.341000Z TestFramework.node0 (DEBUG): RPC successfully started
2025-02-11T14:14:53.357000Z TestFramework.node1 (DEBUG): RPC successfully started
2025-02-11T14:14:53.373000Z TestFramework.node2 (DEBUG): RPC successfully started
2025-02-11T14:14:53.532000Z TestFramework (INFO): Test mempool enforcement of PAK peg-outs
2025-02-11T14:14:59.447000Z TestFramework (INFO): Test various RPC arguments
2025-02-11T14:15:00.417000Z TestFramework (INFO): Test that pak-less pegouts are rejected
2025-02-11T14:15:00.491000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/var/tmp/portage/net-p2p/elements-23.2.7_rc1/work/elements-elements-23.2.7rc1/test/functional/test_framework/test_framework.py", line 132, in main
    self.run_test()
    ~~~~~~~~~~~~~^^
  File "/var/tmp/portage/net-p2p/elements-23.2.7_rc1/work/elements-elements-23.2.7rc1/test/functional/feature_pak.py", line 260, in run_test
    assert nopak_pegout_txid in self.nodes[0].getrawmempool()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError
2025-02-11T14:15:00.498000Z TestFramework (DEBUG): Closing down network thread
2025-02-11T14:15:00.550000Z TestFramework (INFO): Stopping nodes
2025-02-11T14:15:00.550000Z TestFramework.node0 (DEBUG): Stopping node
2025-02-11T14:15:00.554000Z TestFramework.node1 (DEBUG): Stopping node
2025-02-11T14:15:00.559000Z TestFramework.node2 (DEBUG): Stopping node
2025-02-11T14:15:00.763000Z TestFramework.node0 (DEBUG): Node stopped
2025-02-11T14:15:00.763000Z TestFramework.node1 (DEBUG): Node stopped
2025-02-11T14:15:00.763000Z TestFramework.node2 (DEBUG): Node stopped
2025-02-11T14:15:00.764000Z TestFramework (WARNING): Not cleaning up dir /var/tmp/portage/net-p2p/elements-23.2.7_rc1/temp/test_runner_₿_🏃_20250211_141412/feature_pak_246
2025-02-11T14:15:00.764000Z TestFramework (ERROR): Test failed. Test logging available at /var/tmp/portage/net-p2p/elements-23.2.7_rc1/temp/test_runner_₿_🏃_20250211_141412/feature_pak_246/test_framework.log
2025-02-11T14:15:00.764000Z TestFramework (ERROR): 
2025-02-11T14:15:00.764000Z TestFramework (ERROR): Hint: Call /var/tmp/portage/net-p2p/elements-23.2.7_rc1/work/elements-elements-23.2.7rc1/test/functional/combine_logs.py '/var/tmp/portage/net-p2p/elements-23.2.7_rc1/temp/test_runner_₿_🏃_20250211_141412/feature_pak_246' to consolidate all logs
2025-02-11T14:15:00.765000Z TestFramework (ERROR): 
2025-02-11T14:15:00.765000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-02-11T14:15:00.765000Z TestFramework (ERROR): https://github.com/ElementsProject/elements/issues
2025-02-11T14:15:00.765000Z TestFramework (ERROR): 

Expected behavior

All tests pass.

Actual behavior

feature_pak.py had an assertion failure.

To reproduce

This has happened both times I've tried it. I'll continue retesting.

System information

Elements 23.2.7rc1 compiled with GCC Gentoo 15.0.0_pre20241222 p34.

Linux x86_64

Combined log: http://www.mattwhitlock.com/feature_pak_246_20250311.log

@whitslack
Copy link
Author

Now I can't get this unit test to fail. I suspect a synchronization issue. Is it possible for a transaction submitted via sendtomainchain not to appear immediately in the return from getrawmempool? Like maybe there is an asynchronous hand-off inside elementsd such that a transaction submitted to the wallet might not immediately appear in the mempool?

@grubles
Copy link

grubles commented Feb 11, 2025

I've noticed other tests doing the same thing intermittently. This is on an Ubuntu 24.04.2 machine. For example:

$ test/functional/feature_discount_ct.py                                  
2025-02-11T20:08:34.328000Z TestFramework (INFO): Initializing test directory /tmp/bitcoin_func_test_55fv_a7i                                                                                                      
2025-02-11T20:08:35.986000Z TestFramework (INFO): Create UTXOs                                           
2025-02-11T20:08:36.981000Z TestFramework (INFO): Send explicit tx to node 0                             
2025-02-11T20:08:37.054000Z TestFramework (INFO): Send confidential tx to node 0                         
2025-02-11T20:08:37.277000Z TestFramework (INFO): Send explicit tx to node 1                             
2025-02-11T20:08:37.401000Z TestFramework (ERROR): Assertion failed                                      
Traceback (most recent call last):                                                                                                                                                                                 
  File "/home/user/builds/elements/test/functional/test_framework/test_framework.py", line 132, in main
    self.run_test()                                                                                                                                                                                                
  File "/home/user/builds/elements/test/functional/feature_discount_ct.py", line 117, in run_test
    assert_equal(tx['fee']['bitcoin'], Decimal('-0.00000326'))              
  File "/home/user/builds/elements/test/functional/test_framework/util.py", line 63, in assert_equal
    raise AssertionError("not(%s)" % " == ".join(str(arg) for arg in (thing1, thing2) + args))       
AssertionError: not(-0.00001451 == -0.00000326)                                                                                                                                                                    
2025-02-11T20:08:37.453000Z TestFramework (INFO): Stopping nodes                             
2025-02-11T20:08:37.606000Z TestFramework (WARNING): Not cleaning up dir /tmp/bitcoin_func_test_55fv_a7i                                                                                                           
2025-02-11T20:08:37.606000Z TestFramework (ERROR): Test failed. Test logging available at /tmp/bitcoin_func_test_55fv_a7i/test_framework.log                                                                       
2025-02-11T20:08:37.606000Z TestFramework (ERROR):                                                       
2025-02-11T20:08:37.607000Z TestFramework (ERROR): Hint: Call /home/user/builds/elements/test/functional/combine_logs.py '/tmp/bitcoin_func_test_55fv_a7i' to consolidate all logs                                 
2025-02-11T20:08:37.607000Z TestFramework (ERROR):                                                       
2025-02-11T20:08:37.607000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.                                    
2025-02-11T20:08:37.607000Z TestFramework (ERROR): https://github.com/ElementsProject/elements/issues
2025-02-11T20:08:37.607000Z TestFramework (ERROR):                                                              

This is with elements-23.3.0rc3 however.

@grubles
Copy link

grubles commented Feb 11, 2025

Ran that same test (functional_discount_ct.py) a few more times successfully but then hit another assertion fail:

$ test/functional/feature_discount_ct.py
2025-02-11T20:26:56.818000Z TestFramework (INFO): Initializing test directory /tmp/bitcoin_func_test_nh__wask
2025-02-11T20:26:58.477000Z TestFramework (INFO): Create UTXOs
2025-02-11T20:26:59.227000Z TestFramework (INFO): Send explicit tx to node 0
2025-02-11T20:26:59.292000Z TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/home/user/builds/elements/test/functional/test_framework/test_framework.py", line 132, in main
    self.run_test()
  File "/home/user/builds/elements/test/functional/feature_discount_ct.py", line 83, in run_test
    assert_equal(decoded['weight'], 1302)
  File "/home/user/builds/elements/test/functional/test_framework/util.py", line 63, in assert_equal
    raise AssertionError("not(%s)" % " == ".join(str(arg) for arg in (thing1, thing2) + args))
AssertionError: not(1301 == 1302)
2025-02-11T20:26:59.343000Z TestFramework (INFO): Stopping nodes
2025-02-11T20:26:59.496000Z TestFramework (WARNING): Not cleaning up dir /tmp/bitcoin_func_test_nh__wask
2025-02-11T20:26:59.497000Z TestFramework (ERROR): Test failed. Test logging available at /tmp/bitcoin_func_test_nh__wask/test_framework.log
2025-02-11T20:26:59.497000Z TestFramework (ERROR): 
2025-02-11T20:26:59.497000Z TestFramework (ERROR): Hint: Call /home/user/builds/elements/test/functional/combine_logs.py '/tmp/bitcoin_func_test_nh__wask' to consolidate all logs
2025-02-11T20:26:59.497000Z TestFramework (ERROR): 
2025-02-11T20:26:59.497000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2025-02-11T20:26:59.497000Z TestFramework (ERROR): https://github.com/ElementsProject/elements/issues
2025-02-11T20:26:59.497000Z TestFramework (ERROR): 

@whitslack
Copy link
Author

@grubles: Yes, I filed feature_discount_ct.py separately in #1406.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants