test: add wait_for_cookie_credentials() to framework for rpcwait tests #18691

pull jonatack wants to merge 2 commits into bitcoin:master from jonatack:fix-intermittent-credentials-issue changing 2 files +29 −17
  1. jonatack commented at 8:37 pm on April 17, 2020: member

    This PR adds a wait_for_cookie_credentials() method to the test framework and calls it before the -rpcwait tests, to avoid an intermittent race condition on the CI run with Valgrind where the cookie file isn’t written yet when the CLI call with -rpcwait arrives to get_auth_cookie().

    To reproduce/test, build with

    0diff --git a/src/httprpc.cpp b/src/httprpc.cpp
    1index 60c4d06f12..3dd06c4758 100644
    2--- a/src/httprpc.cpp
    3+++ b/src/httprpc.cpp
    4@@ -291,6 +291,7 @@ static bool InitRPCAuthentication()
    5 bool StartHTTPRPC()
    6 {
    7     LogPrint(BCLog::RPC, "Starting HTTP RPC server\n");
    8+    UninterruptibleSleep(std::chrono::seconds{11});
    9     if (!InitRPCAuthentication())
    

    then run the test normally and with valgrind

    0test/functional/interface_bitcoin_cli.py -l debug
    1valgrind test/functional/interface_bitcoin_cli.py -l debug
    

    Thanks to Marco Falke for all the help. Closes #18684.

  2. MarcoFalke commented at 8:45 pm on April 17, 2020: member
    The error was " Called Process failed with ’error: Could not locate RPC credentials. No authentication cookie could be found, and RPC password is not set. See -rpcpassword and -stdinrpcpass. Configuration file: (/home/travis/build/bitcoin/bitcoin/ci/scratch/test_runner/test_runner_₿_🏃_20200417_132645/interface_bitcoin_cli_109/node0/bitcoin.conf) "
  3. jonatack commented at 8:53 pm on April 17, 2020: member
    Yes. I’m still looking at it, but since valgrind runs don’t work out-of-repo, I wanted to see if the valgrind CI passes with this change while looking further.
  4. MarcoFalke commented at 9:08 pm on April 17, 2020: member
    get_auth_cookie is used by every single test. It reads the auth cookie from disk, though it fails when the file was not yet created.
  5. DrahtBot added the label Tests on Apr 17, 2020
  6. DrahtBot commented at 10:54 pm on April 17, 2020: member

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

    Conflicts

    Reviewers, this pull request conflicts with the following ones:

    • #18594 (cli: display multiwallet balances in -getinfo by jonatack)
    • #18453 (rpc, cli: add multiwallet balances rpc and use it in -getinfo by jonatack)

    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.

  7. jonatack renamed this:
    test: fix intermittent error in interface_bitcoin_cli
    test: add wait_for_cookie_credentials() to framework, improve rpcwait tests
    on Apr 18, 2020
  8. jonatack renamed this:
    test: add wait_for_cookie_credentials() to framework, improve rpcwait tests
    test: add wait_for_cookie_credentials() to framework for rpcwait tests
    on Apr 18, 2020
  9. jonatack force-pushed on Apr 18, 2020
  10. MarcoFalke commented at 3:39 pm on April 18, 2020: member
  11. MarcoFalke commented at 3:42 pm on April 18, 2020: member

    Or, if you want to test locally:

     0diff --git a/src/httprpc.cpp b/src/httprpc.cpp
     1index 60c4d06f12..3dd06c4758 100644
     2--- a/src/httprpc.cpp
     3+++ b/src/httprpc.cpp
     4@@ -291,6 +291,7 @@ static bool InitRPCAuthentication()
     5 bool StartHTTPRPC()
     6 {
     7     LogPrint(BCLog::RPC, "Starting HTTP RPC server\n");
     8+    UninterruptibleSleep(std::chrono::seconds{11});
     9     if (!InitRPCAuthentication())
    10         return false;
    11 
    
  12. jonatack force-pushed on Apr 18, 2020
  13. jonatack commented at 4:54 pm on April 18, 2020: member
    Thanks @MarcoFalke for your suggestions! Being able to reproduce makes all the difference. I updated the PR title and description and pushed a fix that seems to work.
  14. jonatack force-pushed on Apr 18, 2020
  15. in test/functional/test_framework/util.py:357 in 72a079e398 outdated
    353@@ -354,7 +354,7 @@ def get_auth_cookie(datadir, chain):
    354             password = split_userpass[1]
    355     except OSError:
    356         pass
    357-    if user is None or password is None:
    358+    if (user is None or password is None) and wait_for_cookie is False:
    


    MarcoFalke commented at 5:06 pm on April 18, 2020:

    I don’t really like offering two interfaces. The existing one that either returns an auth pair or thorws a ValueError should be sufficient.

    If you don’t like the generic ValueError, I believe python can create derived classes like this RpcCredentialsMissing(ValueError), which you can then throw/catch.


    jonatack commented at 7:15 pm on April 18, 2020:
    Thanks for reviewing and your help. If I understand your comment correctly, I modified the conditional here not to change the interface, but to not raise when we’re waiting for the cookie auth credentials. When they do become available, it still returns the auth pair which we’re waiting for in wait_for_cookie_credentials().

    jonatack commented at 7:17 pm on April 18, 2020:
    E.g. since wait_for_cookie is false by default, there is no change in behavior except when it’s called by wait_for_cookie_credentials.

    MarcoFalke commented at 7:36 pm on April 18, 2020:
    Yeah, I don’t understand why wait_for_cookie is needed? Just because it is turned off by default doesn’t mean that it doesn’t complicate the interface

    jonatack commented at 7:42 pm on April 18, 2020:
    Hm, maybe it isn’t. Good question.

    MarcoFalke commented at 7:47 pm on April 18, 2020:

    They should never be empty.

    Either both are a string of length of at least 1 or a ValueError is thrown


    jonatack commented at 8:06 pm on April 18, 2020:
    Good catch, fixed.
  16. jonatack commented at 6:44 pm on April 18, 2020: member
    I see that the CI for the latest merge on master (bump wallet_import timeout) failed for this same reason: https://travis-ci.org/github/bitcoin/bitcoin/jobs/676639823
  17. MarcoFalke approved
  18. jonatack force-pushed on Apr 18, 2020
  19. jonatack force-pushed on Apr 18, 2020
  20. jonatack commented at 8:17 pm on April 18, 2020: member

    Simplified.

    Edit: FWIW I considered adding the following but don’t think it’s necessary? IIUC wait_for_cookie_credentials shouldn’t see any other type of ValueError, nor ECONNREFUSED.

    0+            except OSError as e:
    1+                if e.errno != errno.ECONNREFUSED:  # Port not yet open?
    2+                    raise  # Unknown OS error
    3-            except ValueError:
    4-                pass
    5+            except ValueError as e:  # Cookie file not found and no rpcuser or rpcassword; bitcoind still starting.
    6+                if "No RPC credentials" not in str(e):
    7+                    raise
    
  21. in test/functional/test_framework/test_node.py:259 in 83b037921f outdated
    254+                self.log.debug("Cookie credentials retrieved: user={}, passphrase={}".format(user, passphrase))
    255+                return
    256+            except ValueError:
    257+                pass
    258+            time.sleep(1.0 / poll_per_s)
    259+        self._raise_assertion_error("Unable to retrieve cookie credentials")
    


    MarcoFalke commented at 10:42 pm on April 18, 2020:
    nit: Could rebase and adjust the error to mention the timeout (like the one above, which you can see after rebase)

    jonatack commented at 11:18 pm on April 18, 2020:
    good idea; done
  22. in test/functional/test_framework/test_node.py:254 in 83b037921f outdated
    249+        # Poll at a rate of four times per second
    250+        poll_per_s = 4
    251+        for _ in range(poll_per_s * self.rpc_timeout):
    252+            try:
    253+                user, passphrase = get_auth_cookie(self.datadir, self.chain)
    254+                self.log.debug("Cookie credentials retrieved: user={}, passphrase={}".format(user, passphrase))
    


    MarcoFalke commented at 10:43 pm on April 18, 2020:
    nit: the values aren’t needed, only their presence, so no need to log them?

    jonatack commented at 11:18 pm on April 18, 2020:
    done
  23. in test/functional/test_framework/test_node.py:256 in 83b037921f outdated
    251+        for _ in range(poll_per_s * self.rpc_timeout):
    252+            try:
    253+                user, passphrase = get_auth_cookie(self.datadir, self.chain)
    254+                self.log.debug("Cookie credentials retrieved: user={}, passphrase={}".format(user, passphrase))
    255+                return
    256+            except ValueError:
    


    MarcoFalke commented at 10:44 pm on April 18, 2020:
    nit: In a future cleanup the three occurrences of ValueError can be changed to a self-made error RpcMissingCred (or so). Not asking you to do this here.

    jonatack commented at 11:22 pm on April 18, 2020:

    nit: In a future cleanup the three occurrences of ValueError can be changed to a self-made error RpcMissingCred (or so). Not asking you to do this here.

    Good idea. Will look at a follow-up.

  24. MarcoFalke approved
  25. MarcoFalke commented at 10:44 pm on April 18, 2020: member

    ACK 83b037921fac34d4c85ce6a2e137407596fed91e

    Happy to merge with or without feedback addressed. Just let me know what you prefer.

  26. jonatack force-pushed on Apr 18, 2020
  27. jonatack commented at 11:25 pm on April 18, 2020: member
    Took the suggestions.
  28. jonatack force-pushed on Apr 18, 2020
  29. MarcoFalke approved
  30. DrahtBot added the label Needs rebase on Apr 19, 2020
  31. test: add wait_for_cookie_credentials() to test framework
    to be able to ensure the cookie file is written and auth credentials available
    when testing CLI/RPC commands before the RPC connection is up.
    c648e636b2
  32. test: fix intermittent race condition in interface_bitcoin_cli.py
    by calling wait_for_cookie_credentials() to ensure the cookie file is written
    and auth credentials available for testing the CLI -rpcwait option before the
    RPC connection is up.
    92fe537cf7
  33. jonatack force-pushed on Apr 19, 2020
  34. DrahtBot removed the label Needs rebase on Apr 19, 2020
  35. jonatack commented at 1:16 am on April 20, 2020: member
    Rebased and added a docstring to wait_for_cookie_credentials().
  36. in test/functional/interface_bitcoin_cli.py:80 in 92fe537cf7
    74@@ -76,20 +75,17 @@ def run_test(self):
    75         else:
    76             self.log.info("*** Wallet not compiled; cli getwalletinfo and -getinfo wallet tests skipped")
    77 
    78-        self.stop_node(0)
    79-
    80         self.log.info("Test -version with node stopped")
    81-        cli_response = self.nodes[0].cli("-version").send_cli()
    82+        self.stop_node(0)
    83+        cli_response = self.nodes[0].cli().send_cli('-version')
    


    MarcoFalke commented at 10:08 am on April 20, 2020:
    Why is this changed?

    MarcoFalke commented at 10:19 am on April 20, 2020:
    -version is not an rpc command, but a command line option
  37. MarcoFalke merged this on Apr 20, 2020
  38. MarcoFalke closed this on Apr 20, 2020

  39. in test/functional/interface_bitcoin_cli.py:54 in 92fe537cf7
    50@@ -52,7 +51,7 @@ def run_test(self):
    51         self.log.info("Test -getinfo returns expected network and blockchain info")
    52         if self.is_wallet_compiled():
    53             self.nodes[0].encryptwallet(password)
    54-        cli_get_info = self.nodes[0].cli('-getinfo').send_cli()
    55+        cli_get_info = self.nodes[0].cli().send_cli('-getinfo')
    


    MarcoFalke commented at 10:19 am on April 20, 2020:
    same here

    jonatack commented at 1:20 pm on April 20, 2020:

    I changed it to improve the debug log output:

    0- TestFramework.bitcoincli (DEBUG): Running bitcoin-cli command: None
    1+ TestFramework.bitcoincli (DEBUG): Running bitcoin-cli command: -getinfo
    2
    3- TestFramework.bitcoincli (DEBUG): Running bitcoin-cli command: None
    4+ TestFramework.bitcoincli (DEBUG): Running bitcoin-cli command: -version
    

    I can revert it in #18594 that also touches the testfile or look at improving the logging output for these cases.


    MarcoFalke commented at 1:36 pm on April 20, 2020:
    That should be fixed by logging the options, not passing the command line option as the rpc command

    jonatack commented at 9:38 pm on April 20, 2020:

    That should be fixed by logging the options, not passing the command line option as the rpc command

    Done in #18712.

  40. jonatack deleted the branch on Apr 20, 2020
  41. sidhujag referenced this in commit 767b73a827 on Apr 20, 2020
  42. MarcoFalke referenced this in commit d1aa0ae1ad on Apr 24, 2020
  43. sidhujag referenced this in commit 074dad0954 on Apr 24, 2020
  44. luke-jr referenced this in commit d457d73d2b on Jun 14, 2020
  45. luke-jr referenced this in commit e9839454fa on Jun 14, 2020
  46. Fabcien referenced this in commit bd45ab5e8e on Jan 26, 2021
  47. DrahtBot locked this on Feb 15, 2022

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: 2024-11-18 00:12 UTC

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