Assertion failure in test/jmclient/test_wallet_rpc.py:TrialTestWRPC_JWT.test_refresh_token_request

[whitslack]

___________________________________________ TrialTestWRPC_JWT.test_refresh_token_request ___________________________________________

self = <test_wallet_rpc.TrialTestWRPC_JWT testMethod=test_refresh_token_request>
response = <twisted.web._newclient.Response object at 0x7fe4e5185150>

    @defer.inlineCallbacks
    def failed_refresh_response_handler(
        self, response, *, message=None, error_description=None
    ):
>       assert response.code == 400
E       assert 200 == 400
E        +  where 200 = <twisted.web._newclient.Response object at 0x7fe4e5185150>.code

error_description = None
message    = 'unsupported_grant_type'
response   = <twisted.web._newclient.Response object at 0x7fe4e5185150>
self       = <test_wallet_rpc.TrialTestWRPC_JWT testMethod=test_refresh_token_request>

test/jmclient/test_wallet_rpc.py:849: AssertionError
------------------------------------------------------- Captured stdout call -------------------------------------------------------
User data location: .
2024-02-22 17:25:39,955 [DEBUG]  rpc: getblockchaininfo []
2024-02-22 17:25:39,957 [DEBUG]  rpc: listwallets []
2024-02-22 17:25:39,958 [DEBUG]  rpc: getwalletinfo []
2024-02-22 17:25:40,186 [DEBUG]  rpc: getnewaddress []
2024-02-22 17:25:40,212 [DEBUG]  rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
2024-02-22 17:25:40,247 [DEBUG]  rpc: sendtoaddress ['bcrt1q77qr9mtjxp0djhtt2q54w2jx280vf0wxls7peg', 2.0]
2024-02-22 17:25:40,933 [DEBUG]  rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
2024-02-22 17:25:40,954 [DEBUG]  rpc: sendtoaddress ['bcrt1qek2y7dj4juxf6k8xzsyhrkwfn3psc20wg2jp6u', 2.0]
2024-02-22 17:25:41,646 [DEBUG]  rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
2024-02-22 17:25:41,660 [DEBUG]  rpc: sendtoaddress ['bcrt1qgxql6pgr962draau6q8wvxezraedyuc76ya6ey', 2.0]
2024-02-22 17:25:42,351 [DEBUG]  rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
2024-02-22 17:25:42,365 [DEBUG]  rpc: sendtoaddress ['bcrt1qmncavekhsz49kjg69xpm49037l3hz7f647acmm', 2.0]
2024-02-22 17:25:43,054 [DEBUG]  rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
2024-02-22 17:25:43,060 [DEBUG]  rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
2024-02-22 17:25:43,066 [DEBUG]  rpc: listaddressgroupings []
2024-02-22 17:25:43,583 [INFO]  Detected new wallet, performing initial import
2024-02-22 17:25:43,584 [DEBUG]  requesting detailed wallet history
2024-02-22 17:25:43,585 [DEBUG]  rpc: listlabels []
2024-02-22 17:25:43,624 [DEBUG]  rpc: listunspent [0]
2024-02-22 17:25:44,457 [DEBUG]  bitcoind sync_unspent took 0.8334989547729492sec
------------------------------------------------------- Captured stderr call -------------------------------------------------------
Unhandled error in Deferred:

Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/twisted/internet/defer.py", line 2000, in _inlineCallbacks
    result = context.run(gen.send, result)
  File "/var/tmp/portage/net-p2p/joinmarket-0.9.11/work/joinmarket-clientserver-0.9.11/test/jmclient/test_wallet_rpc.py", line 757, in do_request
    handler(response)
  File "/usr/lib/python3.11/site-packages/twisted/internet/defer.py", line 2256, in unwindGenerator
    return _cancellableInlineCallbacks(gen)
  File "/usr/lib/python3.11/site-packages/twisted/internet/defer.py", line 2168, in _cancellableInlineCallbacks
    _inlineCallbacks(None, gen, status, _copy_context())
--- <exception caught here> ---
  File "/usr/lib/python3.11/site-packages/twisted/internet/defer.py", line 2000, in _inlineCallbacks
    result = context.run(gen.send, result)
  File "/var/tmp/portage/net-p2p/joinmarket-0.9.11/work/joinmarket-clientserver-0.9.11/test/jmclient/test_wallet_rpc.py", line 849, in failed_refresh_response_handler
    assert response.code == 400
builtins.AssertionError: assert 200 == 400
 +  where 200 = <twisted.web._newclient.Response object at 0x7fe4e5185150>.code

-------------------------------------------------------- Captured log call ---------------------------------------------------------
DEBUG    joinmarket:blockchaininterface.py:433 rpc: getblockchaininfo []
DEBUG    joinmarket:blockchaininterface.py:433 rpc: listwallets []
DEBUG    joinmarket:blockchaininterface.py:433 rpc: getwalletinfo []
DEBUG    joinmarket:blockchaininterface.py:433 rpc: getnewaddress []
DEBUG    joinmarket:blockchaininterface.py:433 rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
DEBUG    joinmarket:blockchaininterface.py:433 rpc: sendtoaddress ['bcrt1q77qr9mtjxp0djhtt2q54w2jx280vf0wxls7peg', 2.0]
DEBUG    joinmarket:blockchaininterface.py:433 rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
DEBUG    joinmarket:blockchaininterface.py:433 rpc: sendtoaddress ['bcrt1qek2y7dj4juxf6k8xzsyhrkwfn3psc20wg2jp6u', 2.0]
DEBUG    joinmarket:blockchaininterface.py:433 rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
DEBUG    joinmarket:blockchaininterface.py:433 rpc: sendtoaddress ['bcrt1qgxql6pgr962draau6q8wvxezraedyuc76ya6ey', 2.0]
DEBUG    joinmarket:blockchaininterface.py:433 rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
DEBUG    joinmarket:blockchaininterface.py:433 rpc: sendtoaddress ['bcrt1qmncavekhsz49kjg69xpm49037l3hz7f647acmm', 2.0]
DEBUG    joinmarket:blockchaininterface.py:433 rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
DEBUG    joinmarket:blockchaininterface.py:433 rpc: generatetoaddress [1, 'bcrt1q3vdl7ln49sa2yz2mf46dxrttk6q5k34jkg2x0s']
DEBUG    joinmarket:blockchaininterface.py:433 rpc: listaddressgroupings []
INFO     joinmarket:wallet_service.py:560 Detected new wallet, performing initial import
DEBUG    joinmarket:wallet_service.py:755 requesting detailed wallet history
DEBUG    joinmarket:blockchaininterface.py:433 rpc: listlabels []
DEBUG    joinmarket:blockchaininterface.py:433 rpc: listunspent [0]
DEBUG    joinmarket:wallet_service.py:868 bitcoind sync_unspent took 0.8334989547729492sec

This was testing the 0.9.11 release with Twisted 23.10.0.

A second run of the same test suite, having made no changes to anything, passed, so there is apparently some non-determinism at play here.

[kristapsk]

This is known issue, not related to Twisted upgrade.

Probably #1565 solves this, at least @roshii thinks so.

[roshii]

My PR is a possible fix to requests timing out, this issue has another root cause though, with an unsupported_grant_type error.

I can recall seeing it while implementing JWT but I could not reproduce either at the time. So I don't think it's related to Twisted upgrade, it can be my (test) implementation, something else... I will dig it up if it shows up more often.