Wrong or strange time stamps #435
Description
Below is a printout from zonemaster-cli. The first messages has the time stamp 40.21 sec and then the time decreases down to 0.00 sec after which the time increases again.
The first message must have a time stamp that gives the lowest time, and then the time must increase or be the same for each message. Or else the time stamps cannot give any meaning.
$ zonemaster-cli --hints=hintfile.zone --test=basic02 --level=debug --show-testcase good-undel-8.basic02.xa --ns dns1.good-undel-8.basic02.xa/127.12.2.33 --ns dns1.good-undel-8.basic02.xa/fda1:b2:c3:0:127:12:2:33 --ns dns2.good-undel-8.basic02.xa/127.12.2.34 --ns dns2.good-undel-8.basic02.xa/fda1:b2:c3:0:127:12:2:34
Seconds Level Testcase Message
======= ======== ============== =======
40.21 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.22; name=ns2.basic02.xa; type=AAAA
40.21 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:24; name=ns2.basic02.xa; type=AAAA
40.21 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.22; name=ns2.basic02.xa; type=A
40.21 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:24; name=ns2.basic02.xa; type=A
40.20 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.21; name=basic02.xa; type=NS
40.20 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.22; name=ns1.basic02.xa; type=AAAA
40.20 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:24; name=ns1.basic02.xa; type=AAAA
40.20 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.22; name=ns1.basic02.xa; type=A
40.20 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:24; name=ns1.basic02.xa; type=A
40.20 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.23; name=basic02.xa; type=NS
40.20 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:24; name=xa; type=SOA
40.19 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.22; name=basic02.xa; type=SOA
40.19 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:24; name=basic02.xa; type=SOA
40.19 DEBUG Unspecified DNS query to dns1.good-undel-8.basic02.xa/127.12.2.31 for good-undel-8.basic02.xa/SOA/IN failed with error: Could not send or receive, because of network error.
30.18 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.31; name=good-undel-8.basic02.xa; type=SOA
30.18 DEBUG Unspecified DNS query to dns1.good-undel-8.basic02.xa/fda1:b2:c3:0:127:12:2:31 for good-undel-8.basic02.xa/SOA/IN failed with error: Could not send or receive, because of network error.
20.17 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:31; name=good-undel-8.basic02.xa; type=SOA
20.17 DEBUG Unspecified DNS query to dns2.good-undel-8.basic02.xa/127.12.2.32 for good-undel-8.basic02.xa/SOA/IN failed with error: Could not send or receive, because of network error.
10.16 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.32; name=good-undel-8.basic02.xa; type=SOA
10.16 DEBUG Unspecified DNS query to dns2.good-undel-8.basic02.xa/fda1:b2:c3:0:127:12:2:32 for good-undel-8.basic02.xa/SOA/IN failed with error: Could not send or receive, because of network error.
0.15 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:32; name=good-undel-8.basic02.xa; type=SOA
0.15 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.22; name=good-undel-8.basic02.xa; type=SOA
0.14 DEBUG Unspecified System:Unspecified:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:24; name=good-undel-8.basic02.xa; type=SOA
0.00 DEBUG Unspecified System:Unspecified:START_TIME string=2025-05-05 15:57:27 +0000; time_t=1746460647
0.00 DEBUG Unspecified System:Unspecified:TEST_TARGET module=basic; testcase=basic02; zone=good-undel-8.basic02.xa
0.00 INFO Unspecified Using version v7.1.0 of the Zonemaster engine.
0.00 DEBUG Unspecified Using prerequisite module Zonemaster::LDNS version 4.1.0.
0.00 DEBUG Unspecified Using prerequisite module IO::Socket::INET6 version 2.73.
0.00 DEBUG Unspecified Using prerequisite module Module::Find version 0.15.
0.00 DEBUG Unspecified Using prerequisite module File::ShareDir version 1.118.
0.00 DEBUG Unspecified Using prerequisite module File::Slurp version 9999.32.
0.00 DEBUG Unspecified Using prerequisite module Net::IP::XS version 0.21.
0.00 DEBUG Unspecified Using prerequisite module List::MoreUtils version 0.430.
0.00 DEBUG Unspecified Using prerequisite module Clone version 0.45.
0.00 DEBUG Unspecified Using prerequisite module Readonly version 2.05.
0.00 DEBUG Unspecified Using module Zonemaster::Engine::Test::Basic version v1.0.19.
0.00 DEBUG Basic02 TEST_CASE_START Basic02.
0.01 DEBUG Basic02 System:Basic02:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:34; name=good-undel-8.basic02.xa; type=SOA
0.02 DEBUG Basic02 IPv4 is enabled, can send "SOA" query to dns1.good-undel-8.basic02.xa/127.12.2.33.
0.02 DEBUG Basic02 System:Basic02:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.33; name=good-undel-8.basic02.xa; type=SOA
0.02 DEBUG Basic02 IPv6 is enabled, can send "SOA" query to dns1.good-undel-8.basic02.xa/fda1:b2:c3:0:127:12:2:33.
0.02 DEBUG Basic02 System:Basic02:EXTERNAL_QUERY flags={"class":"IN"}; ip=fda1:b2:c3:0:127:12:2:33; name=good-undel-8.basic02.xa; type=SOA
0.02 DEBUG Basic02 IPv4 is enabled, can send "SOA" query to dns2.good-undel-8.basic02.xa/127.12.2.34.
0.02 DEBUG Basic02 System:Basic02:EXTERNAL_QUERY flags={"class":"IN"}; ip=127.12.2.34; name=good-undel-8.basic02.xa; type=SOA
0.02 DEBUG Basic02 IPv6 is enabled, can send "SOA" query to dns2.good-undel-8.basic02.xa/fda1:b2:c3:0:127:12:2:34.
0.02 INFO Basic02 Authoritative answer on SOA query for "good-undel-8.basic02.xa" is returned by name servers "dns1.good-undel-8.basic02.xa/127.12.2.33;dns1.good-undel-8.basic02.xa/fda1:b2:c3:0:127:12:2:33;dns2.good-undel-8.basic02.xa/127.12.2.34;dns2.good-undel-8.basic02.xa/fda1:b2:c3:0:127:12:2:34".
0.02 DEBUG Basic02 TEST_CASE_END Basic02.
0.02 DEBUG Unspecified Module Basic finished running.