From: Marcin Siodelski Date: Wed, 17 Feb 2021 11:08:51 +0000 (+0100) Subject: [#1701] Improved v4 alloc failure logs X-Git-Tag: Kea-1.9.5~43 X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=30432d6a64a3335636720c9a5feb0a67a733bc96;p=thirdparty%2Fkea.git [#1701] Improved v4 alloc failure logs In case of lease allocation failure, the allocation engine now logs: - which shared network the client belongs to - which subnet (if not shared network) the client belongs to - which subnets were tried - for which subnets there were allocation attempts - for which subnets there were no allocation attempts --- diff --git a/src/lib/dhcpsrv/alloc_engine.cc b/src/lib/dhcpsrv/alloc_engine.cc index d7ecb0925c..fcd7297ca8 100644 --- a/src/lib/dhcpsrv/alloc_engine.cc +++ b/src/lib/dhcpsrv/alloc_engine.cc @@ -36,6 +36,7 @@ #include #include #include +#include #include #include #include @@ -4196,8 +4197,19 @@ AllocEngine::allocateUnreservedLease4(ClientContext4& ctx) { Subnet4Ptr original_subnet = subnet; uint64_t total_attempts = 0; - while (subnet) { + // subnets_tried tracks the ids of the subnets for which the allocation engine + // has made an attempt to allocate a lease. The first value of the pair is a + // subnet id. The second value in the pair is a pool capacity provided the + // client belongs to certain classes. The value of 0 indicates that no pool + // had any addresses available for that client. Other value indicates that + // a number of attempts were made but no address could be assigned because + // the addresses were either reserved to other clients or there were valid + // leases for these addresses. Based on this information we will be able to + // produce a meaningful log message to an operator. + std::list > subnets_tried; + + while (subnet) { ClientIdPtr client_id; if (subnet->getMatchClientId()) { client_id = ctx.clientid_; @@ -4212,6 +4224,10 @@ AllocEngine::allocateUnreservedLease4(ClientContext4& ctx) { max_attempts = 0; } + // Remember an id of the current subnet and how many leases are potentially + // available for this client. + subnets_tried.push_back(std::make_pair(subnet->getID(), max_attempts)); + CalloutHandle::CalloutNextStep callout_status = CalloutHandle::NEXT_STEP_CONTINUE; for (uint64_t i = 0; i < max_attempts; ++i) { @@ -4276,10 +4292,56 @@ AllocEngine::allocateUnreservedLease4(ClientContext4& ctx) { } } - // Unable to allocate an address, return an empty lease. - LOG_WARN(alloc_engine_logger, ALLOC_ENGINE_V4_ALLOC_FAIL) - .arg(ctx.query_->getLabel()) - .arg(total_attempts); + if (network) { + // The client is in the shared network. Let's log the high level message + // indicating which shared network the client belongs to. + LOG_WARN(alloc_engine_logger, ALLOC_ENGINE_V4_ALLOC_FAIL_SHARED_NETWORK) + .arg(ctx.query_->getLabel()) + .arg(network->getName()); + + // The allocation engine could have tried several subnets in this shared + // network. We want to log which subnets it tried to use. + for (auto subnet_tried : subnets_tried) { + // If the allocation engine tried allocate any addresses in this subnet + // we want to indicate that the failure was related to a problem with + // allocations rather than with access to the address pools. Otherwise, + // we want to log that there were zero attempts to allocate a lease, + // which is likely because address pools were guarded by the client + // classes that the client did not belong to. + if (subnet_tried.second > 0) { + LOG_WARN(alloc_engine_logger, ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_TRIED) + .arg(ctx.query_->getLabel()) + .arg(subnet_tried.first); + } else { + LOG_WARN(alloc_engine_logger, ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_POOLS_UNAVAIL) + .arg(ctx.query_->getLabel()) + .arg(subnet_tried.first); + } + } + + } else { + // The client is not connected to a shared network. It is connected + // to a subnet. Let's log the ID of that subnet. + LOG_WARN(alloc_engine_logger, ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET) + .arg(ctx.query_->getLabel()) + .arg(ctx.subnet_->getID()); + } + if (total_attempts == 0) { + // In this case, it seems that none of the pools in the subnets could + // be used for that client, both in case the client is connected to + // a shared network or to a single subnet. Apparently, the client was + // rejected to use the pools because of the client classes' mismatch. + LOG_WARN(alloc_engine_logger, ALLOC_ENGINE_V4_ALLOC_FAIL_NO_POOLS) + .arg(ctx.query_->getLabel()); + } else { + // This is an old log message which provides a number of attempts + // made by the allocation engine to allocate a lease. The only case + // when we don't want to log this message is when the number of + // attempts is zero (condition above), because it would look silly. + LOG_WARN(alloc_engine_logger, ALLOC_ENGINE_V4_ALLOC_FAIL) + .arg(ctx.query_->getLabel()) + .arg(total_attempts); + } const ClientClasses& classes = ctx.query_->getClasses(); if (!classes.empty()) { diff --git a/src/lib/dhcpsrv/alloc_engine_messages.cc b/src/lib/dhcpsrv/alloc_engine_messages.cc index f2fcb1f332..44b4f95e90 100644 --- a/src/lib/dhcpsrv/alloc_engine_messages.cc +++ b/src/lib/dhcpsrv/alloc_engine_messages.cc @@ -12,6 +12,11 @@ extern const isc::log::MessageID ALLOC_ENGINE_REMOVAL_NCR_FAILED = "ALLOC_ENGINE extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_ERROR = "ALLOC_ENGINE_V4_ALLOC_ERROR"; extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL = "ALLOC_ENGINE_V4_ALLOC_FAIL"; extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_CLASSES = "ALLOC_ENGINE_V4_ALLOC_FAIL_CLASSES"; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_NO_POOLS = "ALLOC_ENGINE_V4_ALLOC_FAIL_NO_POOLS"; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_SHARED_NETWORK = "ALLOC_ENGINE_V4_ALLOC_FAIL_SHARED_NETWORK"; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET = "ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET"; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_POOLS_UNAVAIL = "ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_POOLS_UNAVAIL"; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_TRIED = "ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_TRIED"; extern const isc::log::MessageID ALLOC_ENGINE_V4_DECLINED_RECOVERED = "ALLOC_ENGINE_V4_DECLINED_RECOVERED"; extern const isc::log::MessageID ALLOC_ENGINE_V4_DISCOVER_ADDRESS_CONFLICT = "ALLOC_ENGINE_V4_DISCOVER_ADDRESS_CONFLICT"; extern const isc::log::MessageID ALLOC_ENGINE_V4_DISCOVER_HR = "ALLOC_ENGINE_V4_DISCOVER_HR"; @@ -86,6 +91,11 @@ const char* values[] = { "ALLOC_ENGINE_V4_ALLOC_ERROR", "%1: error during attempt to allocate an IPv4 address: %2", "ALLOC_ENGINE_V4_ALLOC_FAIL", "%1: failed to allocate an IPv4 address after %2 attempt(s)", "ALLOC_ENGINE_V4_ALLOC_FAIL_CLASSES", "%1: Failed to allocate an IPv4 address for client with classes: %2", + "ALLOC_ENGINE_V4_ALLOC_FAIL_NO_POOLS", "%1: no pools were available for the address allocation", + "ALLOC_ENGINE_V4_ALLOC_FAIL_SHARED_NETWORK", "%1: failed to allocate an IPv4 address in the shared network %2", + "ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET", "%1: failed to allocate an IPv4 address in the subnet with id %2", + "ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_POOLS_UNAVAIL", "%1: no suitable pools found in the subnet with id %2", + "ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_TRIED", "%1: no available leases found in the subnet with id %2", "ALLOC_ENGINE_V4_DECLINED_RECOVERED", "IPv4 address %1 was recovered after %2 seconds of probation-period", "ALLOC_ENGINE_V4_DISCOVER_ADDRESS_CONFLICT", "%1: conflicting reservation for address %2 with existing lease %3", "ALLOC_ENGINE_V4_DISCOVER_HR", "client %1 sending DHCPDISCOVER has reservation for the address %2", diff --git a/src/lib/dhcpsrv/alloc_engine_messages.h b/src/lib/dhcpsrv/alloc_engine_messages.h index 0d9389b826..b142fad9cf 100644 --- a/src/lib/dhcpsrv/alloc_engine_messages.h +++ b/src/lib/dhcpsrv/alloc_engine_messages.h @@ -13,6 +13,11 @@ extern const isc::log::MessageID ALLOC_ENGINE_REMOVAL_NCR_FAILED; extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_ERROR; extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL; extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_CLASSES; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_NO_POOLS; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_SHARED_NETWORK; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_POOLS_UNAVAIL; +extern const isc::log::MessageID ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_TRIED; extern const isc::log::MessageID ALLOC_ENGINE_V4_DECLINED_RECOVERED; extern const isc::log::MessageID ALLOC_ENGINE_V4_DISCOVER_ADDRESS_CONFLICT; extern const isc::log::MessageID ALLOC_ENGINE_V4_DISCOVER_HR; diff --git a/src/lib/dhcpsrv/alloc_engine_messages.mes b/src/lib/dhcpsrv/alloc_engine_messages.mes index 595fe4b109..3e0488a3dc 100644 --- a/src/lib/dhcpsrv/alloc_engine_messages.mes +++ b/src/lib/dhcpsrv/alloc_engine_messages.mes @@ -25,12 +25,12 @@ return a message to the client refusing a lease. The first argument includes the client identification information. % ALLOC_ENGINE_V4_ALLOC_FAIL %1: failed to allocate an IPv4 address after %2 attempt(s) -The DHCP allocation engine gave up trying to allocate an IPv4 address -after the specified number of attempts. This probably means that the -address pool from which the allocation is being attempted is either -empty, or very nearly empty. As a result, the client will have been -refused a lease. The first argument includes the client identification -information. +This is an old warning message issued when the allocation engine fails to allocate a +lease for a client. This message includes a number of lease allocation attempts +that the engine made before giving up. If the number of attempts is 0 because the +engine was unable to use any of the address pools for the particular client, this +message is not logged. Even though, several more detailed logs precede this message, +it was left for backward compatibility. This message may indicate that your address pool is too small for the number of clients you are trying to service and should be expanded. @@ -50,6 +50,74 @@ useful is to point out that the pool reserved to a given class has ran out of addresses. When you see this message, you may consider checking your pool size and your classification definitions. +% ALLOC_ENGINE_V4_ALLOC_FAIL_NO_POOLS %1: no pools were available for the address allocation +This warning message is issued when the allocation engine fails to +allocate a lease because it could not use any configured pools for the +particular client. It is also possible that all of the subnets from +which the allocation engine attempted to assign an address lack address +pools. In this case, it should be considered misconfiguration if an +operator expects that some clients should be assigned dynamic addresses. +A subnet may lack any pools only when all clients should be assigned +reserved IP addresses. + +Suppose the subnets connected to a shared network or a single subnet to +which the client belongs have pools configured. In that case, this +message is an indication that none of the pools could be used for the +client because the client does not belong to appropriate client classes. + +% ALLOC_ENGINE_V4_ALLOC_FAIL_SHARED_NETWORK %1: failed to allocate an IPv4 address in the shared network %2 +This warning message is issued when the allocation engine fails to allocate +a lease for a client connected to a shared network. The first argument +includes the client identification information. The second argument specifies +the shared network name. The shared network should contain at least one subnet, +but typically it aggregates multiple subnets. This log message indicates that +the allocation engine could not find and allocate any suitable lease in any of +the subnets within the shared network. + +Further log messages print the subnets in this shared network from which the +allocation engine attempted to assign a lease. The allocation engine does not +use the subnets in the shared network, which are unavailable to the DHCP client +due to non-matching client classes. Such subnets are not included in the log +messages following this message. In the extreme case, the allocation engine +may use none of the subnets in the shared network for the lease allocation. +It is the case when the address pools are available to certain client classes, +but the requesting client does not belong to them. A suitable log message +informing about the occurrence of this situation is issued after this log +message. + +% ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET %1: failed to allocate an IPv4 address in the subnet with id %2 +This warning message is issued when the allocation engine fails to allocate +a lease for a client connected to a subnet that does not belong to a shared +network. The first argument includes the client identification information. +The second argument specifies the subnet identifier. + +There are many reasons for failing lease allocations. One of them may be the +address pools exhaustion or existing reservations for the free leases. +However, in some cases, the allocation engine may fail to find a suitable +pool for the client when the pools are only available to certain client +classes, but the requesting client does not belong to them. Further log +messages provide more information to distinguish between these different +cases. + +% ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_POOLS_UNAVAIL %1: no suitable pools found in the subnet with id %2 +This warning message is issued when the allocation engine fails to allocate +a lease for a client connected to a shared network. The engine tried to +allocate addresses from different subnets belonging to this shared network, +but the pools in some of the subnets were apparently guarded by client classes +that the client did not belong to. All such subnets are logged with this +message. The log message includes the client identification information +and a subnet identifier. + +% ALLOC_ENGINE_V4_ALLOC_FAIL_SUBNET_TRIED %1: no available leases found in the subnet with id %2 +This warning message is issued when the allocation engine fails to allocate +a lease for a client connected to a shared network. The engine tried to +allocate addresses from different subnets belonging to this shared network +and having a matching client class. This message is logged for each such +subnet. It is not logged for the subnets from which the engine did not try +to assign an address because of the non-matching client classes. +The log message includes the client identification information and a subnet +identifier. + % ALLOC_ENGINE_V4_DECLINED_RECOVERED IPv4 address %1 was recovered after %2 seconds of probation-period This informational message indicates that the specified address was reported as duplicate (client sent DECLINE) and the server marked this address as