search

cryptoadvance / specter-desktop

A desktop GUI for Bitcoin Core optimised to work with hardware wallets
MIT License
793 stars 237 forks source link

Flaky CI is flaky #1699

Open k9ert opened 2 years ago

k9ert commented 2 years ago

Since some time, flaky builds are on the rise again. This issue is collecting them and maybe links to extra-issues addressing them one after another.

k9ert commented 2 years ago

Cypress: TypeError: doc.createTreeWalker is not a function https://cirrus-ci.com/task/5177875295895552?logs=cypress#L1166

[   INFO] in       _internal: 127.0.0.1 - - [03/May/2022 15:12:56] "GET /static/styles.css HTTP/1.1" 304 -
[   INFO] in       _internal: 127.0.0.1 - - [03/May/2022 15:12:56] "GET /wallets/wallet/utxo_wallet/pending_psbt_list HTTP/1.1" 200 -
    1) Managing unsigned transactions
  2 passing (53s)
  1 failing
  1) Test the actions in UTXO list
       Managing unsigned transactions:
     TypeError: doc.createTreeWalker is not a function
      at findShadowRoots (http://localhost:25444/__cypress/runner/cypress_runner.js:184565:22)
      at collectRoots (http://localhost:25444/__cypress/runner/cypress_runner.js:184545:24)
      at Object.findAllShadowRoots (http://localhost:25444/__cypress/runner/cypress_runner.js:184555:10)
      at HTMLElement.<anonymous> (http://localhost:25444/__cypress/runner/cypress_runner.js:162319:67)
      at http://localhost:25444/__cypress/runner/cypress_runner.js:108173:20
      at Function.map (http://localhost:25444/__cypress/runner/cypress_runner.js:108468:13)
      at jQuery.fn.init.map (http://localhost:25444/__cypress/runner/cypress_runner.js:108172:33)
      at find (http://localhost:25444/__cypress/runner/cypress_runner.js:162318:23)
      at getEl (http://localhost:25444/__cypress/runner/cypress_runner.js:162440:18)
      at getElements (http://localhost:25444/__cypress/runner/cypress_runner.js:162468:17)
      at tryCatcher (http://localhost:25444/__cypress/runner/cypress_runner.js:13022:23)
      at Function.Promise.attempt.Promise.try (http://localhost:25444/__cypress/runner/cypress_runner.js:10296:29)
      at whenStable (http://localhost:25444/__cypress/runner/cypress_runner.js:168808:63)
      at http://localhost:25444/__cypress/runner/cypress_runner.js:168305:14
      at tryCatcher (http://localhost:25444/__cypress/runner/cypress_runner.js:13022:23)
      at Promise._settlePromiseFromHandler (http://localhost:25444/__cypress/runner/cypress_runner.js:10957:31)
  (Results)
  ┌────────────────────────────────────────────────────────────────────────────────────────────────┐
  │ Tests:        3                                                                                │
  │ Passing:      2                                                                                │
  │ Failing:      1                                                                                │
  │ Pending:      0                                                                                │
  │ Skipped:      0                                                                                │
  │ Screenshots:  1                                                                                │
  │ Video:        true                                                                             │
  │ Duration:     52 seconds                                                                       │
  │ Spec Ran:     spec_wallet_utxo.js                                                              │
  └────────────────────────────────────────────────────────────────────────────────────────────────┘
  (Screenshots)
  -  /tmp/cirrus-ci-build/cypress/screenshots/spec_wallet_utxo.js/Test the actions in     (1280x720)
      UTXO list -- Managing unsigned transactions (failed).png                                      
  (Video)
  -  Started processing:  Compressing to 32 CRF                                                     
  -  Finished processing: /tmp/cirrus-ci-build/cypress/videos/spec_wallet_utxo.js.mp4    (7 seconds)
────────────────────────────────────────────────────────────────────────────────────────────────────

  Running:  spec_plugins.js                                                                (8 of 10)
[987:0503/151305.986064:ERROR:zygote_host_impl_linux.cc(263)] Failed to adjust OOM score of renderer with pid 5281: Permission denied (13)
2
  plugins are working
[   INFO] in       _internal: 127.0.0.1 - - [03/May/2022 15:13:07] "GET / HTTP/1.1" 302 -
[   INFO] in       _internal: 127.0.0.1 - - [03/May/2022 15:13:07] "GET /welcome/ HTTP/1.1" 302 -

This issue is known by cypress here: https://github.com/cypress-io/cypress/issues/20813

k9ert commented 2 years ago

Timeout after 0.001 secs

https://github.com/cryptoadvance/specter-desktop/pull/1692/checks?check_run_id=6286376458 https://cirrus-ci.com/task/4571963740913664?logs=test#L254-L276

Traceback (most recent call last):
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/rpc.py", line 364, in multi
    r = self.session.post(
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/requests/sessions.py", line 590, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/requests/sessions.py", line 542, in request
    resp = self.send(prep, **send_kwargs)
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/requests/sessions.py", line 655, in send
    r = adapter.send(request, **kwargs)
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/requests/adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPConnectionPool(host='localhost', port=18543): Read timed out. (read timeout=0.001)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/node.py", line 178, in get_rpc
    res = rpc.getblockchaininfo()
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/rpc.py", line 441, in fn
    r = self.multi([(method, *args)], **kwargs)[0]
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/rpc.py", line 386, in multi
    raise SpecterError(
cryptoadvance.specter.specter_error.SpecterError: Timeout after 0.001 secs while BitcoinRPC call(                            ). Check the logs for more details.

Question here is: Why is there a timeout of 0.001 seconds? Searching the code only set such a timeout once in the multi-call https://github.com/cryptoadvance/specter-desktop/blob/master/src/cryptoadvance/specter/rpc.py#L355-L357

        if kwargs.get("no_wait"):
            # Zero is treated like None, i.e. infinite wait
            timeout = 0.001

But in such cases, the Exception is suppressed (some lines later in the except-block). This is really quite strange.

relativisticelectron commented 2 years ago

But in such cases, the Exception is suppressed (some lines later in the except-block). This is really quite strange.

Well yes the exception is caught https://github.com/cryptoadvance/specter-desktop/blob/7472e16a029803b1f7933ac85902f4fba3fa8ee7/src/cryptoadvance/specter/rpc.py#L369 but then raised again as https://github.com/cryptoadvance/specter-desktop/blob/7472e16a029803b1f7933ac85902f4fba3fa8ee7/src/cryptoadvance/specter/rpc.py#L388

I don't understand how https://github.com/cryptoadvance/specter-desktop/blob/7472e16a029803b1f7933ac85902f4fba3fa8ee7/src/cryptoadvance/specter/rpc.py#L359 ever could be useful.... a post request cannot be so fast, right? So no_wait=True guarantees here an exception....

k9ert commented 2 years ago

I've found the issue and fixed it in e733c70ffa072136b07163fe6d3e0dcebc92bae0 with a try/finally-block. I'm not sure why i haven't stumbled on that earlier (and why i introduced that stupid bug in the first place).

I think a timeout like this is useful if you want to transform a sync-call into an asynchronous call. It's a long running process on the other side and you know you don't want to wait on it. But you also know that you have some way to know when it's read by subsequent other calls, e.g.:

https://github.com/cryptoadvance/specter-desktop/blob/9dbde39c2d36b33cce38729a987964127f6be2e3/src/cryptoadvance/specter/server_endpoints/wallets.py#L325

k9ert commented 2 years ago

Timeout after 15 secs. This time in elements-calls:

[  ERROR] in             rpc: Timeout after 15 secs while LiquidRPC call(wallet/specter123456_hotstorage/elm_multisig_device_2) payload:[{'method': 'importdescriptors', 'params': [[{'desc': 'wpkh(tprv8ZgxMBicQKsPeQU7jBLu6PXKNnvYxjvVaXSKFgsXRzHqZqMaVkzv8kEkSo4idGFyZMfSzPxNhKCT8w9xZRzUWbRNF6kXadA6C8j3shZvS3M/49h/1h/0h/0/*)#2h9qn2gz', 'range': [0, 1000], 'timestamp': 'now'}, {'desc': 'wpkh(tprv8ZgxMBicQKsPeQU7jBLu6PXKNnvYxjvVaXSKFgsXRzHqZqMaVkzv8kEkSo4idGFyZMfSzPxNhKCT8w9xZRzUWbRNF6kXadA6C8j3shZvS3M/84h/1h/0h/0/*)#k7s6020z', 'range': [0, 1000], 'timestamp': 'now'}, {'desc': 'wpkh(tprv8ZgxMBicQKsPeQU7jBLu6PXKNnvYxjvVaXSKFgsXRzHqZqMaVkzv8kEkSo4idGFyZMfSzPxNhKCT8w9xZRzUWbRNF6kXadA6C8j3shZvS3M/48h/1h/0h/1h/0/*)#xwalhw07', 'range': [0, 1000], 'timestamp': 'now'}, {'desc': 'wpkh(tprv8ZgxMBicQKsPeQU7jBLu6PXKNnvYxjvVaXSKFgsXRzHqZqMaVkzv8kEkSo4idGFyZMfSzPxNhKCT8w9xZRzUWbRNF6kXadA6C8j3shZvS3M/48h/1h/0h/2h/0/*)#c2d4zu9s', 'range': [0, 1000], 'timestamp': 'now'}, {'desc': 'wpkh(tprv8ZgxMBicQKsPeQU7jBLu6PXKNnvYxjvVaXSKFgsXRzHqZqMaVkzv8kEkSo4idGFyZMfSzPxNhKCT8w9xZRzUWbRNF6kXadA6C8j3shZvS3M/49h/1h/0h/1/*)#mrqpwlc6', 'range': [0, 1000], 'timestamp': 'now'}, {'desc': 'wpkh(tprv8ZgxMBicQKsPeQU7jBLu6PXKNnvYxjvVaXSKFgsXRzHqZqMaVkzv8kEkSo4idGFyZMfSzPxNhKCT8w9xZRzUWbRNF6kXadA6C8j3shZvS3M/84h/1h/0h/1/*)#824mjll6', 'range': [0, 1000], 'timestamp': 'now'}, {'desc': 'wpkh(tprv8ZgxMBicQKsPeQU7jBLu6PXKNnvYxjvVaXSKFgsXRzHqZqMaVkzv8kEkSo4idGFyZMfSzPxNhKCT8w9xZRzUWbRNF6kXadA6C8j3shZvS3M/48h/1h/0h/1h/1/*)#h6c72mlx', 'range': [0, 1000], 'timestamp': 'now'}, {'desc': 'wpkh(tprv8ZgxMBicQKsPeQU7jBLu6PXKNnvYxjvVaXSKFgsXRzHqZqMaVkzv8kEkSo4idGFyZMfSzPxNhKCT8w9xZRzUWbRNF6kXadA6C8j3shZvS3M/48h/1h/0h/2h/1/*)#f7g5lf4g', 'range': [0, 1000], 'timestamp': 'now'}]], 'jsonrpc': '2.0', 'id': 0}] Exception: HTTPConnectionPool(host='localhost', port=8040): Read timed out. (read timeout=15)
[  ERROR] in   specter_error: Unexpected error:
[  ERROR] in   specter_error: ----START-TRACEBACK-----------------------------------------------------------------
[  ERROR] in   specter_error: Timeout after 15 secs while LiquidRPC call(wallet/specter123456_hotstorage/elm_multisig_device_2). Check the logs for more details.
Traceback (most recent call last):
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/urllib3/connectionpool.py", line 445, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/urllib3/connectionpool.py", line 440, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.8/http/client.py", line 1348, in getresponse
    response.begin()
  File "/usr/lib/python3.8/http/client.py", line 316, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.8/http/client.py", line 277, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
  File "/usr/lib/python3.8/socket.py", line 669, in readinto
    return self._sock.recv_into(b)
socket.timeout: timed out
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/urllib3/connectionpool.py", line 755, in urlopen
    retries = retries.increment(
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/urllib3/util/retry.py", line 532, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/urllib3/packages/six.py", line 770, in reraise
    raise value
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/urllib3/connectionpool.py", line 699, in urlopen
    httplib_response = self._make_request(
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/urllib3/connectionpool.py", line 447, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/urllib3/connectionpool.py", line 336, in _raise_timeout
    raise ReadTimeoutError(
urllib3.exceptions.ReadTimeoutError: HTTPConnectionPool(host='localhost', port=8040): Read timed out. (read timeout=15)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/rpc.py", line 366, in multi
    r = self.session.post(
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/requests/sessions.py", line 590, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/requests/sessions.py", line 542, in request
    resp = self.send(prep, **send_kwargs)
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/requests/sessions.py", line 655, in send
    r = adapter.send(request, **kwargs)
  File "/tmp/cirrus-ci-build/.env/lib/python3.8/site-packages/requests/adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPConnectionPool(host='localhost', port=8040): Read timed out. (read timeout=15)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/server_endpoints/devices.py", line 128, in new_device_keys
    device.add_hot_wallet_keys(
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/devices/elements_core.py", line 33, in add_hot_wallet_keys
    super().add_hot_wallet_keys(
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/devices/bitcoin_core.py", line 148, in add_hot_wallet_keys
    rpc.importdescriptors(args, timeout=15)
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/liquid/rpc.py", line 116, in importdescriptors
    res = super().__getattr__("importdescriptors")(arr, *args, **kwargs)
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/rpc.py", line 444, in fn
    r = self.multi([(method, *args)], **kwargs)[0]
  File "/tmp/cirrus-ci-build/src/cryptoadvance/specter/rpc.py", line 389, in multi
    raise SpecterError(
cryptoadvance.specter.specter_error.SpecterError: Timeout after 15 secs while LiquidRPC call(wallet/specter123456_hotstorage/elm_multisig_device_2). Check the logs for more details.
[  ERROR] in   specter_error: ----END---TRACEBACK-----------------------------------------------------------------

https://cirrus-ci.com/task/5400943784099840

k9ert commented 1 year ago

Most of this stuff is solved, i guess but not the doc.createTreeWalker is not a function issue. Check this comment for potential solution: https://github.com/cypress-io/cypress/issues/20813#issuecomment-1297390114