Skip to content

Commit

Permalink
test-flake: stop looking for a "sometimes there, sometimes not" log
Browse files Browse the repository at this point in the history
We only get the "daemon died before signed PSBT returned" broken error in race-y conditions.

Instead let's just assert on the disconnect/die instead of expecting the specific (race prone)
log line.

2023-11-03T20:52:02.0064217Z         # COMMITMENT_SIGNED disconnects *during* the reconnect
2023-11-03T20:52:02.0065244Z         # We can't bump because the last negotiation is in the wrong state
2023-11-03T20:52:02.0066514Z         with pytest.raises(RpcError, match=r'Funding sigs for this channel not secured'):
2023-11-03T20:52:02.0067758Z             l1.rpc.openchannel_bump(chan_id, chan_amount, initpsbt['psbt'])
2023-11-03T20:52:02.0068946Z         # l2 reconnects, but doesn't have l1's commitment
2023-11-03T20:52:02.0069867Z >       l2.daemon.wait_for_logs([r'Got dualopend reestablish',
2023-11-03T20:52:02.0070778Z                                  r'No commitment, not sending our sigs',
2023-11-03T20:52:02.0071668Z                                  # This is a BROKEN log, it's expected!
2023-11-03T20:52:02.0072644Z                                  r'dualopend daemon died before signed PSBT returned'])
2023-11-03T20:52:02.0073243Z
2023-11-03T20:52:02.0073434Z tests/test_opening.py:955:
2023-11-03T20:52:02.0074094Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2023-11-03T20:52:02.0074687Z
2023-11-03T20:52:02.0075062Z self = <pyln.testing.utils.LightningD object at 0x7fdbb61b7a00>
2023-11-03T20:52:02.0076684Z regexs = ['Got dualopend reestablish', 'No commitment, not sending our sigs', 'dualopend daemon died before signed PSBT returned']
2023-11-03T20:52:02.0077897Z timeout = 180
2023-11-03T20:52:02.0078150Z
2023-11-03T20:52:02.0078421Z     def wait_for_logs(self, regexs, timeout=TIMEOUT):
2023-11-03T20:52:02.0079129Z         """Look for `regexs` in the logs.
2023-11-03T20:52:02.0079652Z
2023-11-03T20:52:02.0080272Z         The logs contain tailed stdout of the process. We look for each regex
2023-11-03T20:52:02.0081344Z         in `regexs`, starting from `logsearch_start` which normally is the
2023-11-03T20:52:02.0082482Z         position of the last found entry of a previous wait-for logs call.
2023-11-03T20:52:02.0083430Z         The ordering inside `regexs` doesn't matter.
2023-11-03T20:52:02.0084037Z
2023-11-03T20:52:02.0084614Z         We fail if the timeout is exceeded or if the underlying process
2023-11-03T20:52:02.0085599Z         exits before all the `regexs` were found.
2023-11-03T20:52:02.0086315Z
2023-11-03T20:52:02.0086835Z         If timeout is None, no time-out is applied.
2023-11-03T20:52:02.0087434Z         """
2023-11-03T20:52:02.0087990Z         logging.debug("Waiting for {} in the logs".format(regexs))
2023-11-03T20:52:02.0088796Z         exs = [re.compile(r) for r in regexs]
2023-11-03T20:52:02.0089594Z         start_time = time.time()
2023-11-03T20:52:02.0090110Z         while True:
2023-11-03T20:52:02.0090626Z             if self.logsearch_start >= len(self.logs):
2023-11-03T20:52:02.0091300Z                 if not self.logs_catchup():
2023-11-03T20:52:02.0091898Z                     time.sleep(0.25)
2023-11-03T20:52:02.0092405Z
2023-11-03T20:52:02.0092961Z                 if timeout is not None and time.time() > start_time + timeout:
2023-11-03T20:52:02.0093989Z                     print("Time-out: can't find {} in logs".format(exs))
2023-11-03T20:52:02.0094702Z                     for r in exs:
2023-11-03T20:52:02.0095238Z                         if self.is_in_log(r):
2023-11-03T20:52:02.0095956Z                             print("({} was previously in logs!)".format(r))
2023-11-03T20:52:02.0096978Z >                   raise TimeoutError('Unable to find "{}" in logs.'.format(exs))
2023-11-03T20:52:02.0098480Z E                   TimeoutError: Unable to find "[re.compile('dualopend daemon died before signed PSBT returned')]" in logs.
2023-11-03T20:52:02.0099448Z
2023-11-03T20:52:02.0099886Z contrib/pyln-testing/pyln/testing/utils.py:327: TimeoutError
  • Loading branch information
niftynei authored and cdecker committed Feb 9, 2024
1 parent 1e023a1 commit 41ef7a7
Showing 1 changed file with 1 addition and 2 deletions.
3 changes: 1 addition & 2 deletions tests/test_opening.py
Original file line number Diff line number Diff line change
Expand Up @@ -953,8 +953,7 @@ def test_rbf_reconnect_tx_construct(node_factory, bitcoind, chainparams):
# l2 reconnects, but doesn't have l1's commitment
l2.daemon.wait_for_logs([r'Got dualopend reestablish',
r'No commitment, not sending our sigs',
# This is a BROKEN log, it's expected!
r'dualopend daemon died before signed PSBT returned'])
r' Owning subdaemon dualopend died'])

# We don't have the commtiments yet, there's no scratch_txid
inflights = only_one(l1.rpc.listpeerchannels()['channels'])['inflight']
Expand Down

0 comments on commit 41ef7a7

Please sign in to comment.