From: Marcin Siodelski Date: Mon, 24 Jun 2019 11:18:52 +0000 (+0200) Subject: [#689] Added logging of the failed lease updates. X-Git-Tag: Kea-1.6.0-beta2~222 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=d320e75a4bcc4c648fa8871ceff43a343ad39292;p=thirdparty%2Fkea.git [#689] Added logging of the failed lease updates. --- diff --git a/src/hooks/dhcp/high_availability/ha_messages.cc b/src/hooks/dhcp/high_availability/ha_messages.cc index 38a65b867b..ef5e5661a3 100644 --- a/src/hooks/dhcp/high_availability/ha_messages.cc +++ b/src/hooks/dhcp/high_availability/ha_messages.cc @@ -1,4 +1,4 @@ -// File created from ../../../../src/hooks/dhcp/high_availability/ha_messages.mes on Fri Feb 08 2019 20:34 +// File created from ../../../../src/hooks/dhcp/high_availability/ha_messages.mes on Mon Jun 24 2019 12:19 #include #include @@ -51,6 +51,8 @@ extern const isc::log::MessageID HA_LEASE_SYNC_STALE_LEASE6_SKIP = "HA_LEASE_SYN extern const isc::log::MessageID HA_LEASE_UPDATES_DISABLED = "HA_LEASE_UPDATES_DISABLED"; extern const isc::log::MessageID HA_LEASE_UPDATES_ENABLED = "HA_LEASE_UPDATES_ENABLED"; extern const isc::log::MessageID HA_LEASE_UPDATE_COMMUNICATIONS_FAILED = "HA_LEASE_UPDATE_COMMUNICATIONS_FAILED"; +extern const isc::log::MessageID HA_LEASE_UPDATE_CREATE_UPDATE_FAILED_ON_PEER = "HA_LEASE_UPDATE_CREATE_UPDATE_FAILED_ON_PEER"; +extern const isc::log::MessageID HA_LEASE_UPDATE_DELETE_FAILED_ON_PEER = "HA_LEASE_UPDATE_DELETE_FAILED_ON_PEER"; extern const isc::log::MessageID HA_LEASE_UPDATE_FAILED = "HA_LEASE_UPDATE_FAILED"; extern const isc::log::MessageID HA_LOAD_BALANCING_DUID_MISSING = "HA_LOAD_BALANCING_DUID_MISSING"; extern const isc::log::MessageID HA_LOAD_BALANCING_IDENTIFIER_MISSING = "HA_LOAD_BALANCING_IDENTIFIER_MISSING"; @@ -118,6 +120,8 @@ const char* values[] = { "HA_LEASE_UPDATES_DISABLED", "lease updates will not be sent to the partner while in %1 state", "HA_LEASE_UPDATES_ENABLED", "lease updates will be sent to the partner while in %1 state", "HA_LEASE_UPDATE_COMMUNICATIONS_FAILED", "%1: failed to communicate with %2: %3", + "HA_LEASE_UPDATE_CREATE_UPDATE_FAILED_ON_PEER", "%1: failed to create or update the lease having type %2 for address %3 in subnet %4", + "HA_LEASE_UPDATE_DELETE_FAILED_ON_PEER", "%1: failed to delete the lease having type %2 for address %3 in subnet %4", "HA_LEASE_UPDATE_FAILED", "%1: lease update to %2 failed: %3", "HA_LOAD_BALANCING_DUID_MISSING", "load balancing failed for the DHCPv6 message (transaction id: %1) because DUID is missing", "HA_LOAD_BALANCING_IDENTIFIER_MISSING", "load balancing failed for the DHCPv4 message (transaction id: %1) because HW address and client identifier are missing", diff --git a/src/hooks/dhcp/high_availability/ha_messages.h b/src/hooks/dhcp/high_availability/ha_messages.h index 2c003fe746..0aa8d7104e 100644 --- a/src/hooks/dhcp/high_availability/ha_messages.h +++ b/src/hooks/dhcp/high_availability/ha_messages.h @@ -1,4 +1,4 @@ -// File created from ../../../../src/hooks/dhcp/high_availability/ha_messages.mes on Fri Feb 08 2019 20:34 +// File created from ../../../../src/hooks/dhcp/high_availability/ha_messages.mes on Mon Jun 24 2019 12:19 #ifndef HA_MESSAGES_H #define HA_MESSAGES_H @@ -52,6 +52,8 @@ extern const isc::log::MessageID HA_LEASE_SYNC_STALE_LEASE6_SKIP; extern const isc::log::MessageID HA_LEASE_UPDATES_DISABLED; extern const isc::log::MessageID HA_LEASE_UPDATES_ENABLED; extern const isc::log::MessageID HA_LEASE_UPDATE_COMMUNICATIONS_FAILED; +extern const isc::log::MessageID HA_LEASE_UPDATE_CREATE_UPDATE_FAILED_ON_PEER; +extern const isc::log::MessageID HA_LEASE_UPDATE_DELETE_FAILED_ON_PEER; extern const isc::log::MessageID HA_LEASE_UPDATE_FAILED; extern const isc::log::MessageID HA_LOAD_BALANCING_DUID_MISSING; extern const isc::log::MessageID HA_LOAD_BALANCING_IDENTIFIER_MISSING; diff --git a/src/hooks/dhcp/high_availability/ha_messages.mes b/src/hooks/dhcp/high_availability/ha_messages.mes index 9495ef715e..aaacf9b2fe 100644 --- a/src/hooks/dhcp/high_availability/ha_messages.mes +++ b/src/hooks/dhcp/high_availability/ha_messages.mes @@ -262,6 +262,17 @@ This warning message indicates that there was a problem in communication with a HA peer while processing a DHCP client query and sending lease update. The client's DHCP message will be dropped. +% HA_LEASE_UPDATE_DELETE_FAILED_ON_PEER %1: failed to delete the lease having type %2 for address %3 in subnet %4 +This informational message is issued when one of the leases failed to delete +on the HA peer while processing lease updates sent from this server. Typically, +the lease fails to delete when it doesn't exist in the peer's database. + +% HA_LEASE_UPDATE_CREATE_UPDATE_FAILED_ON_PEER %1: failed to create or update the lease having type %2 for address %3 in subnet %4 +This informational message is issued when one of the leases failed to be +created or updated on the HA peer whilw processing the lease updates sent +from this server. This may indicate an issue with communication between +the peer and its lease database. + % HA_LEASE_UPDATE_FAILED %1: lease update to %2 failed: %3 This warning message indicates that a peer returned an error status code in response to a lease update. The client's DHCP message will be dropped. diff --git a/src/hooks/dhcp/high_availability/ha_service.cc b/src/hooks/dhcp/high_availability/ha_service.cc index ee8e69fbab..8514fc48d6 100644 --- a/src/hooks/dhcp/high_availability/ha_service.cc +++ b/src/hooks/dhcp/high_availability/ha_service.cc @@ -800,7 +800,10 @@ HAService::asyncSendLeaseUpdate(const QueryPtrType& query, // Handle third group of errors. try { - verifyAsyncResponse(response); + auto args = verifyAsyncResponse(response); + // In the v6 case the server may return a list of failed lease + // updates and we should log them. + logFailedLeaseUpdates(query, args); } catch (const std::exception& ex) { LOG_WARN(ha_logger, HA_LEASE_UPDATE_FAILED) @@ -891,6 +894,62 @@ HAService::shouldSendLeaseUpdates(const HAConfig::PeerConfigPtr& peer_config) co return (false); } +void +HAService::logFailedLeaseUpdates(const PktPtr& query, + const ConstElementPtr& args) const { + // If there are no arguments, it means that the update was successful. + if (!args || (args->getType() != Element::map)) { + return; + } + + // Instead of duplicating the code between the failed-deleted-leases and + // failed-leases, let's just have one function that does it for both. + auto log_proc = [](const PktPtr query, const ConstElementPtr& args, + const std::string& param_name, const log::MessageID& mesid) { + + // Check if there are any failed leases. + auto failed_leases = args->get(param_name); + + // The failed leases must be a list. + if (failed_leases && (failed_leases->getType() == Element::list)) { + // Go over the failed leases and log each of them. + for (int i = 0; i < failed_leases->size(); ++i) { + auto lease = failed_leases->get(i); + if (lease->getType() == Element::map) { + // subnet-id + auto subnet_id = lease->get("subnet-id"); + std::ostringstream subnet_id_text; + if (subnet_id && subnet_id->getType() == Element::integer) { + subnet_id_text << subnet_id->intValue(); + + } else { + subnet_id_text << "(unknown)"; + } + + // ip-address + auto ip_address = lease->get("ip-address"); + // lease type + auto lease_type = lease->get("type"); + + LOG_INFO(ha_logger, mesid) + .arg(query->getLabel()) + .arg(lease_type && (lease_type->getType() == Element::string) ? + lease_type->stringValue() : "(uknown)") + .arg(ip_address && (ip_address->getType() == Element::string) ? + ip_address->stringValue() : "(unknown)") + .arg(subnet_id_text.str()); + } + } + } + }; + + // Process "failed-deleted-leases" + log_proc(query, args, "failed-deleted-leases", HA_LEASE_UPDATE_DELETE_FAILED_ON_PEER); + + // Process "failed-leases". + log_proc(query, args, "failed-leases", HA_LEASE_UPDATE_CREATE_UPDATE_FAILED_ON_PEER); +} + ConstElementPtr HAService::processHeartbeat() { ElementPtr arguments = Element::createMap(); diff --git a/src/hooks/dhcp/high_availability/ha_service.h b/src/hooks/dhcp/high_availability/ha_service.h index ccd5fb7f95..6acc3ac4f8 100644 --- a/src/hooks/dhcp/high_availability/ha_service.h +++ b/src/hooks/dhcp/high_availability/ha_service.h @@ -450,6 +450,18 @@ protected: const data::ConstElementPtr& command, const hooks::ParkingLotHandlePtr& parking_lot); + /// @brief Log failed lease updates. + /// + /// Logs failed lease updates included in the "failed-deleted-leases" + /// and/or "failed-leases" carried in the response to the + /// @c lease6-bulk-apply command. + /// + /// @param query Pointer to the DHCP client's query. + /// @param args Arguments of the response. It may be null, in which + /// case the function simply returns. + void logFailedLeaseUpdates(const dhcp::PktPtr& query, + const data::ConstElementPtr& args) const; + /// @brief Checks if the lease updates should be sent as result of leases /// allocation or release. /// diff --git a/src/hooks/dhcp/high_availability/tests/ha_service_unittest.cc b/src/hooks/dhcp/high_availability/tests/ha_service_unittest.cc index 54c4de5bda..55df42f5fc 100644 --- a/src/hooks/dhcp/high_availability/tests/ha_service_unittest.cc +++ b/src/hooks/dhcp/high_availability/tests/ha_service_unittest.cc @@ -1490,6 +1490,74 @@ TEST_F(HAServiceTest, sendUpdatesControlResultError6) { EXPECT_TRUE(update_request3); } +// This test verifies that the server accepts the response to the lease6-bulk-apply +// command including failed-deleted-leases and failed-leases parameters. +TEST_F(HAServiceTest, sendUpdatesFailedLeases6) { + // Create a dummy lease which failed to be deleted. + auto failed_deleted_lease = Element::createMap(); + failed_deleted_lease->set("type", Element::create("IA_NA")); + failed_deleted_lease->set("ip-address", Element::create("2001:db8:1::1")); + failed_deleted_lease->set("subnet-id", Element::create(1)); + + // Crate a dummy lease which failed to be created. + auto failed_lease = Element::createMap(); + failed_lease->set("type", Element::create("IA_PD")); + failed_lease->set("ip-address", Element::create("2001:db8:1::")); + failed_lease->set("subnet-id", Element::create(2)); + + // Create the "failed-deleted-leases" list. + auto failed_deleted_leases = Element::createList(); + failed_deleted_leases->add(failed_deleted_lease); + + // Create the "failed-leases" list. + auto failed_leases = Element::createList(); + failed_leases->add(failed_lease); + + // Add both lists to the arguments. + ElementPtr arguments = Element::createMap(); + arguments->set("failed-deleted-leases", failed_deleted_leases); + arguments->set("failed-leases", failed_leases); + + // Configure the server to return this response. + factory2_->getResponseCreator()->setArguments("lease6-bulk-apply", + arguments); + + // Start HTTP servers. + ASSERT_NO_THROW({ + listener_->start(); + listener2_->start(); + listener3_->start(); + }); + + // This flag will be set to true if unpark is called. + bool unpark_called = false; + testSendLeaseUpdates6([&unpark_called] { + unpark_called = true; + }, true, 2); + + // Expecting that the packet was unparked because lease updates are expected + // to be successful. + EXPECT_TRUE(unpark_called); + + // The server 2 should have received one command. + EXPECT_EQ(1, factory2_->getResponseCreator()->getReceivedRequests().size()); + + // Check that the server 2 has received lease6-bulk-apply command. + auto update_request2 = factory2_->getResponseCreator()->findRequest("lease6-bulk-apply", + "2001:db8:1::cafe", + "2001:db8:1::efac"); + EXPECT_TRUE(update_request2); + + // Lease updates should be successfully sent to server3. + EXPECT_EQ(1, factory3_->getResponseCreator()->getReceivedRequests().size()); + + // Check that the server 3 has received lease6-bulk-apply command. + auto update_request3 = factory3_->getResponseCreator()->findRequest("lease6-bulk-apply", + "2001:db8:1::cafe", + "2001:db8:1::efac"); + EXPECT_TRUE(update_request3); +} + // This test verifies that the heartbeat command is processed successfully. TEST_F(HAServiceTest, processHeartbeat) { // Create HA configuration for 3 servers. This server is