dnstap system test appears to be timing sensitive

Job #594683 failed for b3f06729:

Looking at the output below the overall counts are correct but some are are on the wrong side of the reopens.

S:dnstap:Thu Jan 23 01:57:23 UTC 2020
T:dnstap:1:A
A:dnstap:System test dnstap
I:dnstap:PORTRANGE:14300 - 14399
I:dnstap:checking that named-checkconf detects error in bad-fstrm-reopen-interval.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-buffer-hint-max.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-buffer-hint-min.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-flush-timeout-max.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-flush-timeout-min.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-input-queue-size-max.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-input-queue-size-min.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-input-queue-size-po2.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-output-notify-threshold.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-output-queue-size-max.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-output-queue-size-min.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-reopen-interval-max.conf
I:dnstap:checking that named-checkconf detects error in bad-fstrm-set-reopen-interval-min.conf
I:dnstap:checking that named-checkconf detects error in bad-missing-dnstap-output-view.conf
I:dnstap:checking that named-checkconf detects error in bad-missing-dnstap-output.conf
I:dnstap:checking that named-checkconf detects error in bad-size-version.conf
I:dnstap:checking that named-checkconf detects no error in good-dnstap-in-options.conf
I:dnstap:checking that named-checkconf detects no error in good-dnstap-in-view.conf
I:dnstap:checking that named-checkconf detects no error in good-fstrm-reopen-interval.conf
I:dnstap:checking that named-checkconf detects no error in good-fstrm-set-buffer-hint.conf
I:dnstap:checking that named-checkconf detects no error in good-fstrm-set-flush-timeout.conf
I:dnstap:checking that named-checkconf detects no error in good-fstrm-set-input-queue-size.conf
I:dnstap:checking that named-checkconf detects no error in good-fstrm-set-output-notify-threshold.conf
I:dnstap:checking that named-checkconf detects no error in good-fstrm-set-output-queue-model-mpsc.conf
I:dnstap:checking that named-checkconf detects no error in good-fstrm-set-output-queue-model-spsc.conf
I:dnstap:checking that named-checkconf detects no error in good-fstrm-set-output-queue-size.conf
I:dnstap:checking that named-checkconf detects no error in good-fstrm-set-reopen-interval.conf
I:dnstap:checking that named-checkconf detects no error in good-size-unlimited.conf
I:dnstap:checking that named-checkconf detects no error in good-size-version.conf
I:dnstap:checking initial message counts
I:dnstap:checking UDP message counts
I:dnstap:checking TCP message counts
I:dnstap:ns1        4 expected 6
I:dnstap:failed
I:dnstap:checking AUTH_QUERY message counts
I:dnstap:ns1        2 exepcted 3
I:dnstap:failed
I:dnstap:checking AUTH_RESPONSE message counts
I:dnstap:ns1        1 expected 2
I:dnstap:failed
I:dnstap:checking CLIENT_QUERY message counts
I:dnstap:checking CLIENT_RESPONSE message counts
I:dnstap:checking RESOLVER_QUERY message counts
I:dnstap:checking RESOLVER_RESPONSE message counts
I:dnstap:checking UPDATE_QUERY message counts
I:dnstap:checking UPDATE_RESPONSE message counts
I:dnstap:checking reopened message counts
I:dnstap:checking UDP message counts
I:dnstap:checking TCP message counts
I:dnstap:ns1        2 expected 0
I:dnstap:failed
I:dnstap:checking AUTH_QUERY message counts
I:dnstap:ns1        1 exepcted 0
I:dnstap:failed
I:dnstap:checking AUTH_RESPONSE message counts
I:dnstap:ns1        1 expected 0
I:dnstap:failed
I:dnstap:checking CLIENT_QUERY message counts
I:dnstap:checking CLIENT_RESPONSE message counts
I:dnstap:checking RESOLVER_QUERY message counts
I:dnstap:checking RESOLVER_RESPONSE message counts
I:dnstap:checking UPDATE_QUERY message counts
I:dnstap:checking UPDATE_RESPONSE message counts
I:dnstap:checking dnstap-read hex output
I:dnstap:checking unix socket message counts
I:dnstap:checking UDP message counts
I:dnstap:checking TCP message counts
I:dnstap:checking AUTH_QUERY message counts
I:dnstap:checking AUTH_RESPONSE message counts
I:dnstap:checking CLIENT_QUERY message counts
I:dnstap:checking CLIENT_RESPONSE message counts
I:dnstap:checking RESOLVER_QUERY message counts
I:dnstap:checking RESOLVER_RESPONSE message counts
I:dnstap:checking UPDATE_QUERY message counts
I:dnstap:checking UPDATE_RESPONSE message counts
I:dnstap:checking reopened unix socket message counts
I:dnstap:checking UDP message counts
I:dnstap:checking TCP message counts
I:dnstap:checking AUTH_QUERY message counts
I:dnstap:checking AUTH_RESPONSE message counts
I:dnstap:checking CLIENT_QUERY message counts
I:dnstap:checking CLIENT_RESPONSE message counts
I:dnstap:checking RESOLVER_QUERY message counts
I:dnstap:checking RESOLVER_RESPONSE message counts
I:dnstap:checking UPDATE_QUERY message counts
I:dnstap:checking UPDATE_RESPONSE message counts
I:dnstap:checking large packet printing
I:dnstap:exit status: 6
R:dnstap:FAIL
E:dnstap:Thu Jan 23 01:57:39 UTC 2020

ns1/named.run

23-Jan-2020 01:57:32.093 query client=0x804949178 thread=0x8011e6400 (a.example/A): query_reset

23-Jan-2020 01:57:32.115 received control channel command 'dnstap-reopen'
23-Jan-2020 01:57:32.156 reopening dnstap destination 'dnstap.out'

23-Jan-2020 01:57:32.157 query client=0x804e3c178 thread=0x8011e5a00 (./NS): query_reset