]> git.ipfire.org Git - thirdparty/kea.git/commitdiff
[#2865] Tweaking some pkt DROP prints
authorPiotrek Zadroga <piotrek@isc.org>
Wed, 7 Jun 2023 15:38:24 +0000 (17:38 +0200)
committerPiotrek Zadroga <piotrek@isc.org>
Wed, 7 Jun 2023 15:38:24 +0000 (17:38 +0200)
src/bin/dhcp4/client_handler.cc
src/bin/dhcp4/dhcp4_messages.cc
src/bin/dhcp4/dhcp4_messages.mes
src/bin/dhcp4/dhcp4_srv.cc
src/bin/dhcp6/client_handler.cc
src/bin/dhcp6/dhcp6_messages.cc
src/bin/dhcp6/dhcp6_messages.mes
src/bin/dhcp6/dhcp6_srv.cc
src/lib/dhcp/pkt4.cc
src/lib/dhcp/pkt4.h
src/lib/dhcp/tests/pkt4_unittest.cc

index 38384f3919184b363a1e367e0bed4771da46a6c5..8fa4a55b2b67369094694f25c85e9794d3b9c5cd 100644 (file)
@@ -238,8 +238,10 @@ ClientHandler::tryLock(Pkt4Ptr query, ContinuationPtr cont) {
                 // Logging a warning as it is supposed to be a rare event
                 // with well behaving clients...
                 LOG_DEBUG(bad_packet4_logger, DBGLVL_PKT_HANDLING, DHCP4_PACKET_DROP_0011)
+                    .arg(next_query_id->getHWAddrLabel())
                     .arg(next_query_id->toText())
                     .arg(this_thread::get_id())
+                    .arg(holder_id->query_->getHWAddrLabel())
                     .arg(holder_id->query_->toText())
                     .arg(holder_id->thread_);
                 stats::StatsMgr::instance().addValue("pkt4-receive-drop",
@@ -249,8 +251,10 @@ ClientHandler::tryLock(Pkt4Ptr query, ContinuationPtr cont) {
             // Logging a warning as it is supposed to be a rare event
             // with well behaving clients...
             LOG_DEBUG(bad_packet4_logger, DBGLVL_PKT_HANDLING, DHCP4_PACKET_DROP_0011)
+                .arg(query->getHWAddrLabel())
                 .arg(query->toText())
                 .arg(this_thread::get_id())
+                .arg(holder_id->query_->getHWAddrLabel())
                 .arg(holder_id->query_->toText())
                 .arg(holder_id->thread_);
             stats::StatsMgr::instance().addValue("pkt4-receive-drop",
@@ -263,8 +267,10 @@ ClientHandler::tryLock(Pkt4Ptr query, ContinuationPtr cont) {
                 // Logging a warning as it is supposed to be a rare event
                 // with well behaving clients...
                 LOG_DEBUG(bad_packet4_logger, DBGLVL_PKT_HANDLING, DHCP4_PACKET_DROP_0012)
+                    .arg(next_query_hw->getHWAddrLabel())
                     .arg(next_query_hw->toText())
                     .arg(this_thread::get_id())
+                    .arg(holder_hw->query_->getHWAddrLabel())
                     .arg(holder_hw->query_->toText())
                     .arg(holder_hw->thread_);
                 stats::StatsMgr::instance().addValue("pkt4-receive-drop",
@@ -274,8 +280,10 @@ ClientHandler::tryLock(Pkt4Ptr query, ContinuationPtr cont) {
             // Logging a warning as it is supposed to be a rare event
             // with well behaving clients...
             LOG_DEBUG(bad_packet4_logger, DBGLVL_PKT_HANDLING, DHCP4_PACKET_DROP_0012)
+                .arg(query->getHWAddrLabel())
                 .arg(query->toText())
                 .arg(this_thread::get_id())
+                .arg(holder_hw->query_->getHWAddrLabel())
                 .arg(holder_hw->query_->toText())
                 .arg(holder_hw->thread_);
             stats::StatsMgr::instance().addValue("pkt4-receive-drop",
index 4b6d285b0a8b84b8b66f7757f85d4d33c4c25286..8bb9b02a4d9200baf9e3c099432df4dcbea0037e 100644 (file)
@@ -275,7 +275,7 @@ const char* values[] = {
     "DHCP4_OPEN_SOCKETS_FAILED", "maximum number of open service sockets attempts: %1, has been exhausted without success",
     "DHCP4_OPEN_SOCKETS_NO_RECONNECT_CTL", "unexpected error in bind service sockets.",
     "DHCP4_OPEN_SOCKET_FAIL", "failed to open socket: %1",
-    "DHCP4_PACKET_DROP_0001", "failed to parse packet from %1 to %2, received over interface %3, reason: %4",
+    "DHCP4_PACKET_DROP_0001", "failed to parse packet from %1 to %2, received over interface %3, reason: %4, %5",
     "DHCP4_PACKET_DROP_0002", "%1, from interface %2: no suitable subnet configured for a direct client",
     "DHCP4_PACKET_DROP_0003", "%1, from interface %2: it contains a foreign server identifier",
     "DHCP4_PACKET_DROP_0004", "%1, from interface %2: missing msg-type option",
@@ -284,11 +284,11 @@ const char* values[] = {
     "DHCP4_PACKET_DROP_0007", "%1: failed to process packet: %2",
     "DHCP4_PACKET_DROP_0008", "%1: DHCP service is globally disabled",
     "DHCP4_PACKET_DROP_0009", "%1: Option 53 missing (no DHCP message type), is this a BOOTP packet?",
-    "DHCP4_PACKET_DROP_0010", "dropped as member of the special class 'DROP': hwaddr=%1, %2",
-    "DHCP4_PACKET_DROP_0011", "dropped as sent by the same client than a packet being processed by another thread: dropped %1 by thread %2 as duplicate of %3 processed by %4",
-    "DHCP4_PACKET_DROP_0012", "dropped as sent by the same client than a packet being processed by another thread: dropped %1 by thread %2 as duplicate of %3 processed by %4",
-    "DHCP4_PACKET_DROP_0013", "dropped as member of the special class 'DROP' after host reservation lookup: hwaddr=%1, %2",
-    "DHCP4_PACKET_DROP_0014", "dropped as member of the special class 'DROP' after early global host reservations lookup: hwaddr=%1, %2",
+    "DHCP4_PACKET_DROP_0010", "dropped as member of the special class 'DROP': %1, %2",
+    "DHCP4_PACKET_DROP_0011", "dropped as sent by the same client than a packet being processed by another thread: dropped %1, %2 by thread %3 as duplicate of %4, %5 processed by %6",
+    "DHCP4_PACKET_DROP_0012", "dropped as sent by the same client than a packet being processed by another thread: dropped %1, %2 by thread %3 as duplicate of %4, %5 processed by %6",
+    "DHCP4_PACKET_DROP_0013", "dropped as member of the special class 'DROP' after host reservation lookup: %1, %2",
+    "DHCP4_PACKET_DROP_0014", "dropped as member of the special class 'DROP' after early global host reservations lookup: %1, %2",
     "DHCP4_PACKET_NAK_0001", "%1: failed to select a subnet for incoming packet, src %2, type %3",
     "DHCP4_PACKET_NAK_0002", "%1: invalid address %2 requested by INIT-REBOOT",
     "DHCP4_PACKET_NAK_0003", "%1: failed to advertise a lease, client sent ciaddr %2, requested-ip-address %3",
index 88a44440656a84799e92d46331e1bfbe46bbeccb..5e37eb8a2a6182af509ac6614ae5d7709780126e 100644 (file)
@@ -580,7 +580,7 @@ are unavailable, and the server exits. This error should be reported.
 A warning message issued when IfaceMgr fails to open and bind a socket. The reason
 for the failure is appended as an argument of the log message.
 
-% DHCP4_PACKET_DROP_0001 failed to parse packet from %1 to %2, received over interface %3, reason: %4
+% DHCP4_PACKET_DROP_0001 failed to parse packet from %1 to %2, received over interface %3, reason: %4, %5
 The DHCPv4 server has received a packet that it is unable to
 interpret. The reason why the packet is invalid is included in the message.
 
@@ -637,30 +637,30 @@ This debug message is issued when a packet is dropped because it did contain
 option 53 and thus has no DHCP message type. The most likely explanation is
 that it was BOOTP packet.
 
-% DHCP4_PACKET_DROP_0010 dropped as member of the special class 'DROP': hwaddr=%1, %2
+% DHCP4_PACKET_DROP_0010 dropped as member of the special class 'DROP': %1, %2
 This debug message is emitted when an incoming packet was classified
 into the special class 'DROP' and dropped. The packet details are displayed.
 
-% DHCP4_PACKET_DROP_0011 dropped as sent by the same client than a packet being processed by another thread: dropped %1 by thread %2 as duplicate of %3 processed by %4
+% DHCP4_PACKET_DROP_0011 dropped as sent by the same client than a packet being processed by another thread: dropped %1, %2 by thread %3 as duplicate of %4, %5 processed by %6
 Currently multi-threading processing avoids races between packets sent by
 a client using the same client id option by dropping new packets until
 processing is finished.
 Packet details and thread identifiers are included for both packets in
 this warning message.
 
-% DHCP4_PACKET_DROP_0012 dropped as sent by the same client than a packet being processed by another thread: dropped %1 by thread %2 as duplicate of %3 processed by %4
+% DHCP4_PACKET_DROP_0012 dropped as sent by the same client than a packet being processed by another thread: dropped %1, %2 by thread %3 as duplicate of %4, %5 processed by %6
 Currently multi-threading processing avoids races between packets sent by
 a client using the same hardware address by dropping new packets until
 processing is finished.
 Packet details and thread identifiers are included for both packets in
 this warning message.
 
-% DHCP4_PACKET_DROP_0013 dropped as member of the special class 'DROP' after host reservation lookup: hwaddr=%1, %2
+% DHCP4_PACKET_DROP_0013 dropped as member of the special class 'DROP' after host reservation lookup: %1, %2
 This debug message is emitted when an incoming packet was classified
 after host reservation lookup into the special class 'DROP' and dropped.
 The packet details are displayed.
 
-% DHCP4_PACKET_DROP_0014 dropped as member of the special class 'DROP' after early global host reservations lookup: hwaddr=%1, %2
+% DHCP4_PACKET_DROP_0014 dropped as member of the special class 'DROP' after early global host reservations lookup: %1, %2
 This debug message is emitted when an incoming packet was classified
 after early global host reservations lookup into the special class 'DROP'
 and dropped. The packet details are displayed.
index ff3a93736870cff35a97134cbfc150bec17ac9c4..ec1f56f475648121d6879e7e86c6065ae9cc0b60 100644 (file)
@@ -262,7 +262,7 @@ Dhcpv4Exchange::Dhcpv4Exchange(const AllocEnginePtr& alloc_engine,
     // Check the DROP special class.
     if (query_->inClass("DROP")) {
         LOG_DEBUG(packet4_logger, DBGLVL_PKT_HANDLING, DHCP4_PACKET_DROP_0013)
-            .arg(query_->getHWAddr() ? query_->getHWAddr()->toText(false) : "(undefined)")
+            .arg(query_->getHWAddrLabel())
             .arg(query_->toText());
         isc::stats::StatsMgr::instance().addValue("pkt4-receive-drop",
                                                   static_cast<int64_t>(1));
@@ -984,7 +984,7 @@ Dhcpv4Srv::earlyGHRLookup(const Pkt4Ptr& query,
             if (query->inClass("DROP")) {
                 LOG_DEBUG(packet4_logger, DBGLVL_PKT_HANDLING,
                           DHCP4_PACKET_DROP_0014)
-                    .arg(query->getHWAddr() ? query->getHWAddr()->toText(false) : "(undefined)")
+                    .arg(query->getHWAddrLabel())
                     .arg(query->toText());
                 isc::stats::StatsMgr::instance().addValue("pkt4-receive-drop",
                                                           static_cast<int64_t>(1));
@@ -1219,7 +1219,8 @@ Dhcpv4Srv::processPacket(Pkt4Ptr& query, Pkt4Ptr& rsp, bool allow_packet_park) {
                 .arg(query->getRemoteAddr().toText())
                 .arg(query->getLocalAddr().toText())
                 .arg(query->getIface())
-                .arg(e.what());
+                .arg(e.what())
+                .arg(query->getHWAddrLabel());
 
             // Increase the statistics of parse failures and dropped packets.
             isc::stats::StatsMgr::instance().addValue("pkt4-parse-failed",
@@ -1301,7 +1302,7 @@ Dhcpv4Srv::processPacket(Pkt4Ptr& query, Pkt4Ptr& rsp, bool allow_packet_park) {
     // Check the DROP special class.
     if (query->inClass("DROP")) {
         LOG_DEBUG(packet4_logger, DBGLVL_PKT_HANDLING, DHCP4_PACKET_DROP_0010)
-            .arg(query->getHWAddr() ? query->getHWAddr()->toText(false) : "(undefined)")
+            .arg(query->getHWAddrLabel())
             .arg(query->toText());
         isc::stats::StatsMgr::instance().addValue("pkt4-receive-drop",
                                                   static_cast<int64_t>(1));
index c70643b6b4a6dabaadce14d5fe3211b833351f5f..8349047c0b7de37919253700159b4fa0bdc8167b 100644 (file)
@@ -128,8 +128,10 @@ ClientHandler::tryLock(Pkt6Ptr query, ContinuationPtr cont) {
             // Logging a warning as it is supposed to be a rare event
             // with well behaving clients...
             LOG_DEBUG(bad_packet6_logger, DBGLVL_PKT_HANDLING, DHCP6_PACKET_DROP_DUPLICATE)
+                .arg(next_query->makeLabel(next_query->getClientId(), nullptr))
                 .arg(next_query->toText())
                 .arg(this_thread::get_id())
+                .arg(holder->query_->makeLabel(holder->query_->getClientId(), nullptr))
                 .arg(holder->query_->toText())
                 .arg(holder->thread_);
             stats::StatsMgr::instance().addValue("pkt6-receive-drop",
@@ -139,8 +141,10 @@ ClientHandler::tryLock(Pkt6Ptr query, ContinuationPtr cont) {
         // Logging a warning as it is supposed to be a rare event
         // with well behaving clients...
         LOG_DEBUG(bad_packet6_logger, DBGLVL_PKT_HANDLING, DHCP6_PACKET_DROP_DUPLICATE)
+            .arg(query->makeLabel(query->getClientId(), nullptr))
             .arg(query->toText())
             .arg(this_thread::get_id())
+            .arg(holder->query_->makeLabel(holder->query_->getClientId(), nullptr))
             .arg(holder->query_->toText())
             .arg(holder->thread_);
         stats::StatsMgr::instance().addValue("pkt6-receive-drop",
index 2445b44c7d1a4cc2106328963fcd4a6ecacaded0..613d343d9317ab716208a2e048ef897bb5cc5c37 100644 (file)
@@ -272,8 +272,8 @@ const char* values[] = {
     "DHCP6_PACKET_DROP_DROP_CLASS", "dropped as member of the special class 'DROP': %1 %2",
     "DHCP6_PACKET_DROP_DROP_CLASS2", "dropped as member of the special class 'DROP' after host reservation lookup: %1 %2",
     "DHCP6_PACKET_DROP_DROP_CLASS_EARLY", "dropped as member of the special class 'DROP' after early global host reservations lookup: %1 %2",
-    "DHCP6_PACKET_DROP_DUPLICATE", "dropped as sent by the same client than a packet being processed by another thread: dropped %1 by thread %2 as duplicate of %3 processed by %4",
-    "DHCP6_PACKET_DROP_PARSE_FAIL", "failed to parse packet from %1 to %2, received over interface %3, reason: %4",
+    "DHCP6_PACKET_DROP_DUPLICATE", "dropped as sent by the same client than a packet being processed by another thread: dropped %1 %2 by thread %3 as duplicate of %4 %5 processed by %6",
+    "DHCP6_PACKET_DROP_PARSE_FAIL", "failed to parse packet from %1 to %2, received over interface %3, reason: %4, %5",
     "DHCP6_PACKET_DROP_SERVERID_MISMATCH", "%1: dropping packet with server identifier: %2, server is using: %3",
     "DHCP6_PACKET_DROP_UNICAST", "%1: dropping unicast %2 packet as this packet should be sent to multicast",
     "DHCP6_PACKET_OPTIONS_SKIPPED", "An error unpacking an option, caused subsequent options to be skipped: %1",
index ace9aeecc4aab44440a0afc283da0319faa3edf0..042be281b7bf680a8664f8a4cb05fb82ad76f362 100644 (file)
@@ -593,13 +593,13 @@ This debug message is emitted when an incoming packet was classified
 after early global host reservations lookup into the special class 'DROP'
 and dropped. The packet details are displayed.
 
-% DHCP6_PACKET_DROP_DUPLICATE dropped as sent by the same client than a packet being processed by another thread: dropped %1 by thread %2 as duplicate of %3 processed by %4
+% DHCP6_PACKET_DROP_DUPLICATE dropped as sent by the same client than a packet being processed by another thread: dropped %1 %2 by thread %3 as duplicate of %4 %5 processed by %6
 Currently multi-threading processing avoids races between packets sent by
 the same client by dropping new packets until processing is finished.
 Packet details and thread identifiers are included for both packets in
 this warning message.
 
-% DHCP6_PACKET_DROP_PARSE_FAIL failed to parse packet from %1 to %2, received over interface %3, reason: %4
+% DHCP6_PACKET_DROP_PARSE_FAIL failed to parse packet from %1 to %2, received over interface %3, reason: %4, %5
 The DHCPv6 server has received a packet that it is unable to
 interpret. The reason why the packet is invalid is included in the message.
 
index 8eaa5c9e92d9b9dd81791bb4deb7dd87be427d4e..d334b12aa0954b2bb38578b23533776f563a38fe 100644 (file)
@@ -806,7 +806,8 @@ Dhcpv6Srv::processPacket(Pkt6Ptr& query, Pkt6Ptr& rsp) {
                 .arg(query->getRemoteAddr().toText())
                 .arg(query->getLocalAddr().toText())
                 .arg(query->getIface())
-                .arg(e.what());
+                .arg(e.what())
+                .arg(query->makeLabel(query->getClientId(), nullptr));
 
             // Increase the statistics of parse failures and dropped packets.
             StatsMgr::instance().addValue("pkt6-parse-failed",
index f6947da40dfa8a60d5893a77a6bcf41653e3fd94..00bd99ad792350b4befd96e66b71a887b79016dc 100644 (file)
@@ -602,5 +602,13 @@ Pkt4::isRelayed() const {
     return (!giaddr_.isV4Zero() && !giaddr_.isV4Bcast());
 }
 
+std::string
+Pkt4::getHWAddrLabel() const {
+    std::ostringstream label;
+    label << "hwaddr=";
+    hwaddr_ ? label << hwaddr_->toText(false) : label << "(undefined)";
+    return (label.str());
+}
+
 } // end of namespace isc::dhcp
 } // end of namespace isc
index dd36168033e977f42979ff9df82000d31c4c9f38..83282155ad352f5ef559a2eeb99e3b2a58e26f8f 100644 (file)
@@ -323,6 +323,14 @@ public:
     /// @return hardware address structure
     HWAddrPtr getHWAddr() const { return (hwaddr_); }
 
+    /// @brief Returns text representation of the hardware address
+    ///
+    /// Returns text representation of the hardware address (e.g. hwaddr=00:01:02:03:04:05).
+    /// If there is no defined hardware address, it returns @c hwaddr=(undefined).
+    ///
+    /// @return string with text representation
+    std::string getHWAddrLabel() const;
+
     /// @brief Add an option.
     ///
     /// @note: to avoid throwing when adding multiple options
index 7df927c641bb2828cb79f6068534ffe42a474258..70bc624d6b5200c9bca131a1d3ddd9648ea2c53b 100644 (file)
@@ -1506,4 +1506,24 @@ TEST_F(Pkt4Test, testSkipThisOptionError) {
     EXPECT_EQ("def", opstr->getValue());
 }
 
+// Tests that getHWAddrLabel method produces the expected strings based on
+// packet content.
+TEST_F(Pkt4Test, getHWAddrLabel) {
+    Pkt4 pkt(DHCPOFFER, 1234);
+
+    // Verify getHWAddrLabel() handles empty values
+    EXPECT_EQ ("hwaddr=", pkt.getHWAddrLabel());
+
+    // Testing undefined hwaddr case is not possible
+    EXPECT_THROW(pkt.setHWAddr(nullptr), BadValue);
+
+    // Set that packet hardware address, then verify getLabel
+    const uint8_t hw[] = { 2, 4, 6, 8, 10, 12 }; // MAC
+    const uint8_t hw_type = 123; // hardware type
+    HWAddrPtr dummy_hwaddr(new HWAddr(hw, sizeof(hw), hw_type));
+    pkt.setHWAddr(dummy_hwaddr);
+
+    EXPECT_EQ ("hwaddr=02:04:06:08:0a:0c", pkt.getHWAddrLabel());
+}
+
 } // end of anonymous namespace