ksr system test failing on main
Running the ksr system test is failing on my Mac. It would also be useful for stdout and stderr to be dumped on error.
[ant:bin/tests/system] marka% sh run.sh ksr
====================================================================== test session starts ======================================================================
platform darwin -- Python 3.10.15, pytest-7.4.3, pluggy-1.5.0 -- /opt/local/bin/python3
cachedir: .pytest_cache
hypothesis profile 'default' -> database=DirectoryBasedExampleDatabase(PosixPath('/Users/marka/git/bind9/bin/tests/system/ksr/.hypothesis/examples'))
rootdir: /Users/marka/git/bind9/bin/tests/system
configfile: pytest.ini
plugins: hypothesis-6.103.2
collected 7 items
tests_ksr.py::test_ksr_errors
------------------------------------------------------------------------ live log setup -------------------------------------------------------------------------
2024-10-18 15:18:51 INFO:ksr switching to tmpdir: /Users/marka/git/bind9/bin/tests/system/ksr_tmp__5p25do1
2024-10-18 15:18:51 INFO:ksr test started: ksr/tests_ksr.py
2024-10-18 15:18:51 INFO:ksr using port range: <6787, 6806>
PASSED [ 14%]
tests_ksr.py::test_ksr_common PASSED [ 28%]
tests_ksr.py::test_ksr_lastbundle PASSED [ 42%]
tests_ksr.py::test_ksr_inthemiddle PASSED [ 57%]
tests_ksr.py::test_ksr_rekey_logs_error FAILED [ 71%]
tests_ksr.py::test_ksr_unlimited PASSED [ 85%]
tests_ksr.py::test_ksr_twotone PASSED [100%]
----------------------------------------------------------------------- live log teardown -----------------------------------------------------------------------
2024-10-18 15:19:40 INFO:ksr test artifacts in: ksr_ksr
=========================================================================== FAILURES ============================================================================
___________________________________________________________________ test_ksr_rekey_logs_error ___________________________________________________________________
/Users/marka/git/bind9/bin/tests/system/ksr/tests_ksr.py:832: in test_ksr_rekey_logs_error
check_ksr_rekey_logs_error(
/Users/marka/git/bind9/bin/tests/system/ksr/tests_ksr.py:789: in check_ksr_rekey_logs_error
out, _ = ksr(zone, policy, "request", options=f"-K {zskdir} -i {then} -e {until}")
/Users/marka/git/bind9/bin/tests/system/ksr/tests_ksr.py:92: in ksr
out = isctest.run.cmd(
/Users/marka/git/bind9/bin/tests/system/isctest/run.py:64: in cmd
raise exc
/Users/marka/git/bind9/bin/tests/system/isctest/run.py:49: in cmd
proc = subprocess.run(
/opt/local/Library/Frameworks/Python.framework/Versions/3.10/lib/python3.10/subprocess.py:526: in run
raise CalledProcessError(retcode, process.args,
E subprocess.CalledProcessError: Command '['/Users/marka/git/bind9/bin/dnssec/dnssec-ksr', '-l', 'ns1/named.conf', '-k', 'common', '-K', 'ns1', '-i', '20221019041905', '-e', '20231019041905', 'request', 'past.test']' returned non-zero exit status 1.
============================================================================ PASSES =============================================================================
________________________________________________________________________ test_ksr_errors ________________________________________________________________________
---------------------------------------------------------------------- Captured log setup -----------------------------------------------------------------------
2024-10-18 15:18:51 INFO:ksr switching to tmpdir: /Users/marka/git/bind9/bin/tests/system/ksr_tmp__5p25do1
2024-10-18 15:18:51 INFO:ksr test started: ksr/tests_ksr.py
2024-10-18 15:18:51 INFO:ksr using port range: <6787, 6806>
--------------------------------------------------------------------- Captured log teardown ---------------------------------------------------------------------
2024-10-18 15:19:40 INFO:ksr test artifacts in: ksr_ksr
==================================================================== short test summary info ====================================================================
PASSED tests_ksr.py::test_ksr_errors
PASSED tests_ksr.py::test_ksr_common
PASSED tests_ksr.py::test_ksr_lastbundle
PASSED tests_ksr.py::test_ksr_inthemiddle
PASSED tests_ksr.py::test_ksr_unlimited
PASSED tests_ksr.py::test_ksr_twotone
FAILED tests_ksr.py::test_ksr_rekey_logs_error - subprocess.CalledProcessError: Command '['/Users/marka/git/bind9/bin/dnssec/dnssec-ksr', '-l', 'ns1/named.conf', '-k', 'common', '-K', 'ns1', '-i', '2022101...
================================================================= 1 failed, 6 passed in 48.96s ==================================================================
[ant:bin/tests/system] marka% cd ksr_tmp__5p25do1
[ant:tests/system/ksr_tmp__5p25do1] marka% '/Users/marka/git/bind9/bin/dnssec/dnssec-ksr' '-l' 'ns1/named.conf' '-k' 'common' '-K' 'ns1' '-i' '20221019041905' '-e' '20231019041905' 'request' 'past.test'
;; KeySigningRequest 1.0 20221019041905 (Wed Oct 19 15:19:05 2022)
dnssec-ksr: fatal: no past.test/ECDSAP256SHA256 zsk key pair found for bundle Wed Oct 19 15:19:05 2022
[ant:tests/system/ksr_tmp__5p25do1] marka% head -30 ns1/Kpast.test.+013+*
==> ns1/Kpast.test.+013+00489.key <==
; This is a zone-signing key, keyid 489, for past.test.
; Created: 20241018041905 (Fri Oct 18 15:19:05 2024)
; Publish: 20221019131405 (Thu Oct 20 00:14:05 2022)
; Activate: 20221019151905 (Thu Oct 20 02:19:05 2022)
; Inactive: 20230423151905 (Mon Apr 24 01:19:05 2023)
; Delete: 20230503162405 (Thu May 4 02:24:05 2023)
past.test. 3600 IN DNSKEY 256 3 13 YF9dZstLxodA/zNQKojSmA0NlA7uR5/wZhCOWVZv+bNVeAau1o90/NlX IX7AqsAUigSirftRZEQHIlqPpoIRLA==
==> ns1/Kpast.test.+013+00489.private <==
Private-key-format: v1.3
Algorithm: 13 (ECDSAP256SHA256)
PrivateKey: cXMWdumVRO7k0b7S+df84rVrEYCUl7f6yjOwe8wcLBQ=
Created: 20241018041905
Publish: 20221019131405
Activate: 20221019151905
Inactive: 20230423151905
Delete: 20230503162405
==> ns1/Kpast.test.+013+00489.state <==
; This is the state of key 489, for past.test.
Algorithm: 13
Length: 256
Lifetime: 16070400
KSK: no
ZSK: yes
Generated: 20241018041905 (Fri Oct 18 15:19:05 2024)
Published: 20221019131405 (Thu Oct 20 00:14:05 2022)
Active: 20221019151905 (Thu Oct 20 02:19:05 2022)
Retired: 20230423151905 (Mon Apr 24 01:19:05 2023)
Removed: 20230503162405 (Thu May 4 02:24:05 2023)
==> ns1/Kpast.test.+013+38030.key <==
; This is a zone-signing key, keyid 38030, for past.test.
; Created: 20241018041905 (Fri Oct 18 15:19:05 2024)
; Publish: 20230423131405 (Sun Apr 23 23:14:05 2023)
; Activate: 20230423151905 (Mon Apr 24 01:19:05 2023)
; Inactive: 20231026151905 (Fri Oct 27 02:19:05 2023)
; Delete: 20231105162405 (Mon Nov 6 03:24:05 2023)
past.test. 3600 IN DNSKEY 256 3 13 qBmzY4grSNfokFGqKW53xRjbnJ2eCyeHDDzaWYGpG9v9QKNMfd2vLVjy uhVDFcjqvNn1Md0hd2EZ9ftW72WRig==
==> ns1/Kpast.test.+013+38030.private <==
Private-key-format: v1.3
Algorithm: 13 (ECDSAP256SHA256)
PrivateKey: eG8eldQ9hp4dTrCwLk0HuLmSBwY+jP0B9x+JkF7AbbE=
Created: 20241018041905
Publish: 20230423131405
Activate: 20230423151905
Inactive: 20231026151905
Delete: 20231105162405
==> ns1/Kpast.test.+013+38030.state <==
; This is the state of key 38030, for past.test.
Algorithm: 13
Length: 256
Lifetime: 16070400
KSK: no
ZSK: yes
Generated: 20241018041905 (Fri Oct 18 15:19:05 2024)
Published: 20230423131405 (Sun Apr 23 23:14:05 2023)
Active: 20230423151905 (Mon Apr 24 01:19:05 2023)
Retired: 20231026151905 (Fri Oct 27 02:19:05 2023)
Removed: 20231105162405 (Mon Nov 6 03:24:05 2023)Edited by Mark Andrews