From 08b421023c635939d915cc877e77cbbcf230fd2f Mon Sep 17 00:00:00 2001 From: Remi Gacogne Date: Thu, 13 Feb 2025 17:14:08 +0100 Subject: [PATCH 1/2] dnsdist: Handle response dnstap messages arriving before the query ones Since we now use more than one TCP connection, it is entirely possible for the response message to arrive before the query one, and our tests should just deal with that. --- regression-tests.dnsdist/test_Dnstap.py | 37 ++++++++++++++++--------- 1 file changed, 24 insertions(+), 13 deletions(-) diff --git a/regression-tests.dnsdist/test_Dnstap.py b/regression-tests.dnsdist/test_Dnstap.py index c9457afbe6d8..c40f52f497db 100644 --- a/regression-tests.dnsdist/test_Dnstap.py +++ b/regression-tests.dnsdist/test_Dnstap.py @@ -380,12 +380,23 @@ def startResponders(cls): cls._remoteLoggerListener.daemon = True cls._remoteLoggerListener.start() - def getFirstDnstap(self): + def getFirstDnstap(self, messageType=None): self.assertFalse(self._remoteLoggerQueue.empty()) - data = self._remoteLoggerQueue.get(False) - self.assertTrue(data) - dnstap = dnstap_pb2.Dnstap() - dnstap.ParseFromString(data) + unused = [] + dnstap = None + while not self._remoteLoggerQueue.empty(): + data = self._remoteLoggerQueue.get(False) + self.assertTrue(data) + dnstap = dnstap_pb2.Dnstap() + dnstap.ParseFromString(data) + if not messageType or dnstap.message.type == messageType: + break + unused.append(data) + + # put back non-matching messages for later + for msg in reversed(unused): + self._remoteLoggerQueue.put(msg) + return dnstap def testDnstap(self): @@ -423,13 +434,13 @@ def testDnstap(self): time.sleep(1) # check the dnstap message corresponding to the UDP query - dnstap = self.getFirstDnstap() + dnstap = self.getFirstDnstap(dnstap_pb2.Message.CLIENT_QUERY) checkDnstapQuery(self, dnstap, dnstap_pb2.UDP, query) checkDnstapNoExtra(self, dnstap) # check the dnstap message corresponding to the UDP response - dnstap = self.getFirstDnstap() + dnstap = self.getFirstDnstap(dnstap_pb2.Message.CLIENT_RESPONSE) checkDnstapResponse(self, dnstap, dnstap_pb2.UDP, response) checkDnstapNoExtra(self, dnstap) @@ -444,13 +455,13 @@ def testDnstap(self): time.sleep(1) # check the dnstap message corresponding to the TCP query - dnstap = self.getFirstDnstap() + dnstap = self.getFirstDnstap(dnstap_pb2.Message.CLIENT_QUERY) checkDnstapQuery(self, dnstap, dnstap_pb2.TCP, query) checkDnstapNoExtra(self, dnstap) # check the dnstap message corresponding to the TCP response - dnstap = self.getFirstDnstap() + dnstap = self.getFirstDnstap(dnstap_pb2.Message.CLIENT_RESPONSE) checkDnstapResponse(self, dnstap, dnstap_pb2.TCP, response) checkDnstapNoExtra(self, dnstap) @@ -489,12 +500,12 @@ def testDnstapExtra(self): time.sleep(1) # check the dnstap message corresponding to the UDP query - dnstap = self.getFirstDnstap() + dnstap = self.getFirstDnstap(dnstap_pb2.Message.CLIENT_QUERY) checkDnstapQuery(self, dnstap, dnstap_pb2.UDP, query) checkDnstapExtra(self, dnstap, b"Type,Query") # check the dnstap message corresponding to the UDP response - dnstap = self.getFirstDnstap() + dnstap = self.getFirstDnstap(dnstap_pb2.Message.CLIENT_RESPONSE) checkDnstapResponse(self, dnstap, dnstap_pb2.UDP, response) checkDnstapExtra(self, dnstap, b"Type,Response") @@ -509,12 +520,12 @@ def testDnstapExtra(self): time.sleep(1) # check the dnstap message corresponding to the TCP query - dnstap = self.getFirstDnstap() + dnstap = self.getFirstDnstap(dnstap_pb2.Message.CLIENT_QUERY) checkDnstapQuery(self, dnstap, dnstap_pb2.TCP, query) checkDnstapExtra(self, dnstap, b"Type,Query") # check the dnstap message corresponding to the TCP response - dnstap = self.getFirstDnstap() + dnstap = self.getFirstDnstap(dnstap_pb2.Message.CLIENT_RESPONSE) checkDnstapResponse(self, dnstap, dnstap_pb2.TCP, response) checkDnstapExtra(self, dnstap, b"Type,Response") From fe36ae3e8df7a5bf4af1696f43e785fdeecb3cf5 Mon Sep 17 00:00:00 2001 From: Remi Gacogne Date: Mon, 17 Feb 2025 11:29:49 +0100 Subject: [PATCH 2/2] dnsdist: Put the dnstap messages back to the queue in the correct order As noticed by Miod, the previous solution was not removing all messages from the queue, possibly putting back old messages behind newer ones. --- regression-tests.dnsdist/test_Dnstap.py | 72 ++++++++++--------------- 1 file changed, 29 insertions(+), 43 deletions(-) diff --git a/regression-tests.dnsdist/test_Dnstap.py b/regression-tests.dnsdist/test_Dnstap.py index c40f52f497db..0d902f5ef46c 100644 --- a/regression-tests.dnsdist/test_Dnstap.py +++ b/regression-tests.dnsdist/test_Dnstap.py @@ -77,6 +77,29 @@ def checkDnstapResponse(testinstance, dnstap, protocol, response, initiator='127 testinstance.assertEqual(wire_message, response) +def getFirstMatchingMessageFromQueue(queue, messageType=None): + unused_messages = [] + selected = None + while True: + data = queue.get(True, timeout=2.0) + if not data: + break + decoded_message = dnstap_pb2.Dnstap() + decoded_message.ParseFromString(data) + if not selected and (not messageType or decoded_message.message.type == messageType): + selected = decoded_message + else: + unused_messages.append(data) + + if queue.empty(): + break + + # put back non-matching messages for later + for msg in reversed(unused_messages): + queue.put(msg) + + return selected + class TestDnstapOverRemoteLogger(DNSDistTest): _remoteLoggerServerPort = pickAvailablePort() _remoteLoggerQueue = Queue() @@ -155,12 +178,7 @@ def startResponders(cls): cls._remoteLoggerListener.start() def getFirstDnstap(self): - self.assertFalse(self._remoteLoggerQueue.empty()) - data = self._remoteLoggerQueue.get(False) - self.assertTrue(data) - dnstap = dnstap_pb2.Dnstap() - dnstap.ParseFromString(data) - return dnstap + return getFirstMatchingMessageFromQueue(self._remoteLoggerQueue) def testDnstap(self): """ @@ -381,23 +399,7 @@ def startResponders(cls): cls._remoteLoggerListener.start() def getFirstDnstap(self, messageType=None): - self.assertFalse(self._remoteLoggerQueue.empty()) - unused = [] - dnstap = None - while not self._remoteLoggerQueue.empty(): - data = self._remoteLoggerQueue.get(False) - self.assertTrue(data) - dnstap = dnstap_pb2.Dnstap() - dnstap.ParseFromString(data) - if not messageType or dnstap.message.type == messageType: - break - unused.append(data) - - # put back non-matching messages for later - for msg in reversed(unused): - self._remoteLoggerQueue.put(msg) - - return dnstap + return getFirstMatchingMessageFromQueue(self._remoteLoggerQueue, messageType=messageType) def testDnstap(self): """ @@ -628,11 +630,7 @@ def startResponders(cls): cls._fstrmLoggerListener.start() def getFirstDnstap(self): - data = self._fstrmLoggerQueue.get(True, timeout=2.0) - self.assertTrue(data) - dnstap = dnstap_pb2.Dnstap() - dnstap.ParseFromString(data) - return dnstap + return getFirstMatchingMessageFromQueue(self._fstrmLoggerQueue) def testDnstapOverFrameStreamUnix(self): """ @@ -724,11 +722,7 @@ def startResponders(cls): cls._fstrmLoggerListener.start() def getFirstDnstap(self): - data = self._fstrmLoggerQueue.get(True, timeout=2.0) - self.assertTrue(data) - dnstap = dnstap_pb2.Dnstap() - dnstap.ParseFromString(data) - return dnstap + return getFirstMatchingMessageFromQueue(self._fstrmLoggerQueue) def testDnstapOverFrameStreamUnix(self): """ @@ -807,11 +801,7 @@ def startResponders(cls): cls._fstrmLoggerListener.start() def getFirstDnstap(self): - data = self._fstrmLoggerQueue.get(True, timeout=2.0) - self.assertTrue(data) - dnstap = dnstap_pb2.Dnstap() - dnstap.ParseFromString(data) - return dnstap + return getFirstMatchingMessageFromQueue(self._fstrmLoggerQueue) def testDnstapOverFrameStreamTcp(self): """ @@ -899,11 +889,7 @@ def startResponders(cls): cls._fstrmLoggerListener.start() def getFirstDnstap(self): - data = self._fstrmLoggerQueue.get(True, timeout=2.0) - self.assertTrue(data) - dnstap = dnstap_pb2.Dnstap() - dnstap.ParseFromString(data) - return dnstap + return getFirstMatchingMessageFromQueue(self._fstrmLoggerQueue) def testDnstapOverFrameStreamTcp(self): """