checkds test is unstable on OpenBSD
Job #2213656 failed for 5d677c1b on OpenBSD:
wait_for_log()
fails to find zone multiple-dspublished.checkds/IN (signed): checkds: DS response from 10.53.0.4
line in ns9/named.run
which supposedly appears in the log at 07-Jan-2022 09:21:12.195
but it was able to find zone multiple-dspublished.checkds/IN (signed): checkds: DS response from 10.53.0.2
, which in the log appears at 07-Jan-2022 09:21:11.688
- just 507 ms before. But this should not happen because wait_for_log()
is polling 10 seconds for the line.
...
D:checkds:# DS correctly published in all parents.
D:checkds:zone_check(server, "multiple-dspublished.checkds.")
D:checkds:wait_for_log("ns9/named.run",
D:checkds:"zone multiple-dspublished.checkds/IN (signed): checkds: "
D:checkds:"DS response from 10.53.0.2")
D:checkds:> wait_for_log("ns9/named.run",
D:checkds:"zone multiple-dspublished.checkds/IN (signed): checkds: "
D:checkds:"DS response from 10.53.0.4")
D:checkds:
D:checkds:tests-checkds.py:269:
D:checkds:_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
D:checkds:
D:checkds:filename = 'ns9/named.run'
D:checkds:log = 'zone multiple-dspublished.checkds/IN (signed): checkds: DS response from 10.53.0.4'
D:checkds:
D:checkds:def wait_for_log(filename, log):
D:checkds:found = False
D:checkds:
D:checkds:for _ in range(10):
D:checkds:print("read log file {}".format(filename))
D:checkds:
D:checkds:try:
D:checkds:with open(filename, 'r', encoding='utf-8') as file:
D:checkds:s = mmap.mmap(file.fileno(), 0, access=mmap.ACCESS_READ)
D:checkds:if s.find(bytes(log, "ascii")) != -1:
D:checkds:found = True
D:checkds:except FileNotFoundError:
D:checkds:print("file not found {}".format(filename))
D:checkds:
D:checkds:if found:
D:checkds:break
D:checkds:
D:checkds:print("sleep")
D:checkds:time.sleep(1)
D:checkds:
D:checkds:> assert found
D:checkds:E assert False
D:checkds:
D:checkds:tests-checkds.py:219: AssertionError
D:checkds:----------------------------- Captured stdout call -----------------------------
D:checkds:read log file ns9/named.run
D:checkds:read state file ns9/Kdspublished.checkds.+013+46589.state
D:checkds:read log file ns9/named.run
D:checkds:read state file ns9/Kreference.checkds.+013+33843.state
D:checkds:read log file ns9/named.run
D:checkds:read state file ns9/Kmissing-dspublished.checkds.+013+18135.state
D:checkds:read log file ns9/named.run
D:checkds:read state file ns9/Kbad-dspublished.checkds.+013+20215.state
D:checkds:read log file ns9/named.run
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:read log file ns9/named.run
D:checkds:sleep
D:checkds:===================== 1 failed, 1 passed in 11.14 seconds ======================
named.run
: named.run