test: `wallet_importdescriptors.py --descriptors` failure #27282

issue fanquake opened this issue on March 20, 2023
  1. fanquake commented at 11:11 AM on March 20, 2023: member

    Seen on a aarch64 Alpine box. Master @ https://github.com/bitcoin/bitcoin/commit/40e1c4d4024b8ad35f2511b2e10bf80c5531dfde. Binaries compiled with Clang 15.0.7. Valgrind valgrind-3.21.0.GIT.

    We saw some issues with this test recently (#27229), but this looks like a different issue:

    261/262 - wallet_importdescriptors.py --descriptors failed, Duration: 411 s
    
    stdout:
    2023-03-20T10:39:03.422000Z TestFramework (INFO): PRNG seed is: 4441145092714460381
    2023-03-20T10:39:03.423000Z TestFramework (INFO): Initializing test directory /tmp/test_runner_₿_🏃_20230320_101936/wallet_importdescriptors_88
    2023-03-20T10:39:08.174000Z TestFramework (INFO): Setting up wallets
    2023-03-20T10:39:09.056000Z TestFramework (INFO): Mining coins
    2023-03-20T10:39:10.636000Z TestFramework (INFO): Import should fail if a descriptor is not provided
    2023-03-20T10:39:10.649000Z TestFramework (INFO): Should import a p2pkh descriptor
    2023-03-20T10:39:10.799000Z TestFramework (INFO): Test can import same descriptor with public key twice
    2023-03-20T10:39:10.835000Z TestFramework (INFO): Test can update descriptor label
    2023-03-20T10:39:10.870000Z TestFramework (INFO): Internal addresses cannot have labels
    2023-03-20T10:39:10.874000Z TestFramework (INFO): Internal addresses should be detected as such
    2023-03-20T10:39:10.915000Z TestFramework (INFO): Should not import a p2sh-p2wpkh descriptor without checksum
    2023-03-20T10:39:10.919000Z TestFramework (INFO): Should not import a p2sh-p2wpkh descriptor that has range specified
    2023-03-20T10:39:10.926000Z TestFramework (INFO): Should not import a p2sh-p2wpkh descriptor and have it set to active
    2023-03-20T10:39:10.930000Z TestFramework (INFO): Should import a (non-active) p2sh-p2wpkh descriptor
    2023-03-20T10:39:11.107000Z TestFramework (INFO): Should import a 1-of-2 bare multisig from descriptor
    2023-03-20T10:39:11.147000Z TestFramework (INFO): Should not treat individual keys from the imported bare multisig as watchonly
    2023-03-20T10:39:11.151000Z TestFramework (INFO): Ranged descriptors cannot have labels
    2023-03-20T10:39:11.160000Z TestFramework (INFO): Private keys required for private keys enabled wallet
    2023-03-20T10:39:11.177000Z TestFramework (INFO): Ranged descriptor import should warn without a specified range
    2023-03-20T10:39:11.234000Z TestFramework (INFO): Should not import a ranged descriptor that includes xpriv into a watch-only wallet
    2023-03-20T10:39:11.242000Z TestFramework (INFO): Should not import a descriptor with hardened derivations when private keys are disabled
    2023-03-20T10:39:11.281000Z TestFramework (INFO): Verify we can only extend descriptor's range
    2023-03-20T10:39:11.765000Z TestFramework (INFO): Check we can change descriptor internal flag
    2023-03-20T10:39:12.046000Z TestFramework (INFO): Key ranges should be imported in order
    2023-03-20T10:39:12.431000Z TestFramework (INFO): Check we can change next_index
    2023-03-20T10:39:12.709000Z TestFramework (INFO): Check imported descriptors are not active by default
    2023-03-20T10:39:12.754000Z TestFramework (INFO): Check can activate inactive descriptor
    2023-03-20T10:39:12.811000Z TestFramework (INFO): Check can deactivate active descriptor
    2023-03-20T10:39:12.862000Z TestFramework (INFO): Verify activation state is persistent
    2023-03-20T10:39:12.942000Z TestFramework (INFO): Should import a descriptor with a WIF private key as spendable
    2023-03-20T10:39:12.978000Z TestFramework (INFO): Test can import same descriptor with private key twice
    2023-03-20T10:39:14.574000Z TestFramework (INFO): Test that multisigs can be imported, signed for, and getnewaddress'd
    2023-03-20T10:39:35.707000Z TestFramework (INFO): Multisig with distributed keys
    2023-03-20T10:39:46.670000Z TestFramework (INFO): We can create and use a huge multisig under P2WSH
    2023-03-20T10:40:19.550000Z TestFramework (INFO): Under P2SH, multisig are standard with up to 15 compressed keys
    2023-03-20T10:40:45.496000Z TestFramework (INFO): Amending multisig with new private keys
    2023-03-20T10:40:51.063000Z TestFramework (INFO): Combo descriptors cannot be active
    2023-03-20T10:40:51.068000Z TestFramework (INFO): Descriptors with no type cannot be active
    2023-03-20T10:40:51.127000Z TestFramework (INFO): Test importing a descriptor to an encrypted wallet
    2023-03-20T10:41:54.188000Z TestFramework (INFO): Stopping nodes
    2023-03-20T10:45:54.240000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: ''''
        def is_node_stopped(self):
            """Checks whether the node has stopped.
    
            Returns True if the node has stopped. False otherwise.
            This method is responsible for freeing resources (self.process)."""
            if not self.running:
                return True
            return_code = self.process.poll()
            if return_code is None:
                return False
    
            # process has stopped. Assert that it didn't return an error code.
            assert return_code == 0, self._node_msg(
                "Node returned non-zero exit code (%d) when stopping" % return_code)
            self.running = False
            self.process = None
            self.rpc_connected = False
            self.rpc = None
            self.log.debug("Node stopped")
            return True
    '''
    [node 1] Cleaning up leftover process
    [node 0] Cleaning up leftover process
    
    
    stderr:
    Exception in thread Thread-1:
    Traceback (most recent call last):
      File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
        self.run()
      File "/usr/lib/python3.10/threading.py", line 953, in run
        self._target(*self._args, **self._kwargs)
      File "/bitcoin/test/functional/test_framework/coverage.py", line 49, in __call__
        return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
      File "/bitcoin/test/functional/test_framework/authproxy.py", line 149, in __call__
        raise JSONRPCException(response['error'], status)
    test_framework.authproxy.JSONRPCException: Error: Please enter the wallet passphrase with walletpassphrase first. (-13)
    Traceback (most recent call last):
      File "/bitcoin/test/functional/wallet_importdescriptors.py", line 717, in <module>
        ImportDescriptorsTest().main()
      File "/bitcoin/test/functional/test_framework/test_framework.py", line 155, in main
        exit_code = self.shutdown()
      File "/bitcoin/test/functional/test_framework/test_framework.py", line 314, in shutdown
        self.stop_nodes()
      File "/bitcoin/test/functional/test_framework/test_framework.py", line 582, in stop_nodes
        node.wait_until_stopped()
      File "/bitcoin/test/functional/test_framework/test_node.py", line 388, in wait_until_stopped
        wait_until_helper(self.is_node_stopped, timeout=timeout, timeout_factor=self.timeout_factor)
      File "/bitcoin/test/functional/test_framework/util.py", line 281, in wait_until_helper
        raise AssertionError("Predicate {} not true after {} seconds".format(predicate_source, timeout))
    AssertionError: Predicate ''''
        def is_node_stopped(self):
            """Checks whether the node has stopped.
    
            Returns True if the node has stopped. False otherwise.
            This method is responsible for freeing resources (self.process)."""
            if not self.running:
                return True
            return_code = self.process.poll()
            if return_code is None:
                return False
    
            # process has stopped. Assert that it didn't return an error code.
            assert return_code == 0, self._node_msg(
                "Node returned non-zero exit code (%d) when stopping" % return_code)
            self.running = False
            self.process = None
            self.rpc_connected = False
            self.rpc = None
            self.log.debug("Node stopped")
            return True
    ''' not true after 240 seconds
    
  2. fanquake added the label Tests on Mar 20, 2023
  3. maflcko commented at 12:22 PM on March 20, 2023: member

    What is the combined log?

  4. maflcko added the label Wallet on Mar 20, 2023
  5. maflcko commented at 4:22 PM on March 20, 2023: member

    Same error/cause in another test file:

    https://cirrus-ci.com/task/4914078427119616?logs=ci#L3898

    2023-03-20T15:27:58.304000Z TestFramework (INFO): Stopping nodes
    2023-03-20T15:27:58.935000Z TestFramework (INFO): Cleaning up /tmp/cirrus-ci-build/ci/scratch/test_runner/test_runner_₿_🏃_20230320_151651/wallet_transactiontime_rescan_149 on exit
    2023-03-20T15:27:58.935000Z TestFramework (INFO): Tests successful
    stderr:
    Exception in thread Thread-1:
    Traceback (most recent call last):
      File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
        self.run()
      File "/usr/lib/python3.8/threading.py", line 870, in run
        self._target(*self._args, **self._kwargs)
      File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/test_framework/coverage.py", line 49, in __call__
        return_val = self.auth_service_proxy_instance.__call__(*args, **kwargs)
      File "/tmp/cirrus-ci-build/ci/scratch/build/bitcoin-i686-pc-linux-gnu/test/functional/test_framework/authproxy.py", line 149, in __call__
        raise JSONRPCException(response['error'], status)
    test_framework.authproxy.JSONRPCException: Error: Please enter the wallet passphrase with walletpassphrase first. (-13)
    
  6. maflcko commented at 7:17 AM on March 21, 2023: member

    Can remove --valgrind from title? See also #27199#pullrequestreview-1349425797

  7. maflcko commented at 8:38 AM on March 21, 2023: member

    Looks like there are several issues here. The first one, unrelated to the test failure is that the return value is thrown away (thread.join() returns None, always)

  8. maflcko commented at 9:03 AM on March 21, 2023: member
  9. fanquake renamed this:
    test: `wallet_importdescriptors.py --descriptors` failure under `--valgrind`
    test: `wallet_importdescriptors.py --descriptors` failure
    on Mar 21, 2023
  10. fanquake commented at 11:49 AM on March 21, 2023: member
  11. maflcko commented at 3:44 PM on March 21, 2023: member

    See also https://gist.github.com/fanquake/a458badc73abb47f8c06f009d15e1916 (combined log).

    This just looks like a timeout factor error

  12. maflcko added this to the milestone 25.0 on Mar 27, 2023
  13. maflcko commented at 1:53 PM on March 28, 2023: member

    Is this still an issue with a recent version of Bitcoin Core? If yes, what are the steps to reproduce?

  14. fanquake commented at 2:42 PM on March 28, 2023: member

    If yes, what are the steps to reproduce?

    Haven't seen this lately. Can close.

  15. fanquake closed this on Mar 28, 2023

  16. maflcko commented at 7:53 AM on March 31, 2023: member

    Ok, this still happens: https://cirrus-ci.com/task/5541464030052352?logs=ci#L2622

    However, it looks like there is another unrelated bug in the rpc proxy to dispatch the same RPC twice? There really shouldn't be any reason to blindly run the same RPC twice without the user (test developer) asking for it.

    I presume running the RPC twice will also discard the earlier result, so still no luck debugging this issue.

  17. maflcko reopened this on Mar 31, 2023

  18. maflcko commented at 11:45 AM on April 15, 2023: member

    I wonder if this is still an issue, now that the RPC proxy was fixed to not dispatch the same call twice?

  19. fanquake commented at 11:47 AM on April 15, 2023: member

    I don't think I've seen this again, only occurence seemed to be Cirrus above (before the fix). Guess we can reclose for now? Will remove from the milestone in any case.

  20. fanquake removed this from the milestone 25.0 on Apr 15, 2023
  21. maflcko commented at 11:48 AM on April 15, 2023: member

    sgtm. Closing for now, until this happens again.

  22. maflcko closed this on Apr 15, 2023

  23. bitcoin deleted a comment on Nov 19, 2023
  24. fanquake referenced this in commit 03e94f8b90 on Apr 7, 2024
  25. bitcoin locked this on Nov 18, 2024

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2026-04-15 06:13 UTC

This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me