Skip to content

GitLab

Commit 135ffa24 authored by Thomas Markwalder's avatar Thomas Markwalder
Browse files

[master] Merge branch 'trac3743' 

    Adds bad-packet logger to DHCPv4 server
parents 4aff6048 cb91ca85
Hide whitespace changes
Inline Side-by-side
Showing with 209 additions and 86 deletions
doc/guide/logging.xml
View file @ 135ffa24
......@@ -154,6 +154,13 @@
the settings from this logger if there is no specialized logger
provided.</simpara>
</listitem>
<listitem>
<simpara><command>kea-dhcp4.bad_packet</command> - this is the
logger used by the DHCPv4 server deamon for logging inbound client
packets that were dropped or to which the server responded with a
NAK. The allows adminstrators to configure a separate log
output that contains only packet drop and reject entries.</simpara>
</listitem>
<listitem>
<simpara><command>kea-dhcp4.dhcp4</command> - this is the logger
used solely by the DHCPv4 server deamon. This logger does not
......@@ -374,7 +381,7 @@ TODO; there's a ticket to determine these levels, see #1074
</para>
<!-- configuration of flush is not supported yet.
<!-- configuration of flush is not supported yet.
<section>
<title>flush (true of false)</title>
......@@ -454,7 +461,7 @@ TODO; there's a ticket to determine these levels, see #1074
{
"output": "stdout"
}
],
],
"severity": "WARN"
}
]
......@@ -479,7 +486,7 @@ file be created.</para>
"maxsize": 204800,
"destination": "file"
}
],
],
"severity": "DEBUG",
"debuglevel": 99
}
......
src/bin/dhcp4/dhcp4_log.cc
View file @ 135ffa24
// Copyright (C) 2012, 2014 Internet Systems Consortium, Inc. ("ISC")
// Copyright (C) 2012, 2014-2015 Internet Systems Consortium, Inc. ("ISC")
//
// Permission to use, copy, modify, and/or distribute this software for any
// purpose with or without fee is hereby granted, provided that the above
......@@ -19,7 +19,12 @@
namespace isc {
namespace dhcp {
isc::log::Logger dhcp4_logger("dhcp4");
const char* DHCP4_ROOT_LOGGER_NAME = "kea-dhcp4";
const char* DHCP4_APP_LOGGER_NAME = "dhcp4";
const char* DHCP4_BAD_PACKET_LOGGER_NAME = "bad-packet";
isc::log::Logger dhcp4_logger(DHCP4_APP_LOGGER_NAME);
isc::log::Logger bad_packet_logger(DHCP4_BAD_PACKET_LOGGER_NAME);
} // namespace dhcp
} // namespace isc
......
src/bin/dhcp4/dhcp4_log.h
View file @ 135ffa24
// Copyright (C) 2012, 2014 Internet Systems Consortium, Inc. ("ISC")
// Copyright (C) 2012, 2014-2015 Internet Systems Consortium, Inc. ("ISC")
//
// Permission to use, copy, modify, and/or distribute this software for any
// purpose with or without fee is hereby granted, provided that the above
......@@ -22,6 +22,9 @@
namespace isc {
namespace dhcp {
/// Defines the name of the root level "default" logger for kea dhcp4 server.
extern const char* DHCP4_ROOT_LOGGER_NAME;
/// \brief DHCP4 Logging
///
/// Defines the levels used to output debug messages in the non-library part of
......@@ -54,8 +57,17 @@ const int DBG_DHCP4_DETAIL_DATA = DBGLVL_TRACE_DETAIL_DATA;
/// a logger in each file, but we would want to define a common name to avoid
/// spelling mistakes, so it is just one small step from there to define a
/// module-common logger.
extern const char* DHCP4_APP_LOGGER_NAME;
extern isc::log::Logger dhcp4_logger;
/// Define a separate logger to which bad packets are logged. This allows
/// users to segregate them into a separate log destination for easy monitoring
/// and diagnostics. Here "bad packet" are packets that are either dropped
/// (i.e malformed, unsupported types) or packets that are rejected and NAKed
/// for logical reasons.
extern const char* DHCP4_BAD_PACKET_LOGGER_NAME;
extern isc::log::Logger bad_packet_logger;
} // namespace dhcp4
} // namespace isc
......
src/bin/dhcp4/dhcp4_messages.mes
View file @ 135ffa24
......@@ -157,33 +157,17 @@ The server has failed to initialize. This may be because the configuration
was not successful, or it encountered any other critical error on startup.
Attached error message provides more details about the issue.
% DHCP4_INVALID_ADDRESS_INIT_REBOOT invalid address %1 requested by INIT-REBOOT client (id: %2, hwaddr: %3)
This debug message is issued when the client being in the INIT-REBOOT state
requested an address which is not assigned to him. The server will respond
to this client with DHCPNAK.
% DHCP4_LEASE_ADVERT lease %1 advertised (client client-id %2, hwaddr %3)
This debug message indicates that the server successfully advertised
a lease. It is up to the client to choose one server out of other advertised
and continue allocation with that server. This is a normal behavior and
indicates successful operation.
% DHCP4_LEASE_ADVERT_FAIL failed to advertise a lease for client-id %1, hwaddr %2, client sent ciaddr %3, requested-ip-address %4
This message indicates that the server has failed to offer a lease to
the specified client after receiving a DISCOVER message from it. There are
many possible reasons for such a failure.
% DHCP4_LEASE_ALLOC lease %1 has been allocated for client-id %2, hwaddr %3
This debug message indicates that the server successfully granted a lease
in response to client's REQUEST message. This is a normal behavior and
indicates successful operation.
% DHCP4_LEASE_ALLOC_FAIL failed to grant a lease for client-id %1, hwaddr %2, client sent ciaddr %3, requested-ip-address %4
This message indicates that the server failed to grant a lease to the
specified client after receiving a REQUEST message from it. There are many
possible reasons for such a failure. Additional messages will indicate the
reason.
% DHCP4_LEASE_DATABASE_TIMERS_EXEC_FAIL failed to execute timer-based functions for lease database: %1
A warning message executed when a server process is unable to execute
the periodic actions for the lease database. An example of the periodic
......@@ -217,13 +201,6 @@ This warning message is issued when current server configuration specifies
no interfaces that server should listen on, or specified interfaces are not
configured to receive the traffic.
% DHCP4_NO_SUBNET_FOR_DIRECT_CLIENT no suitable subnet configured for a direct client sending packet with transaction id %1, on interface %2, received message is dropped
This info message is logged when received a message from a directly connected
client but there is no suitable subnet configured for the interface on
which this message has been received. The IPv4 address assigned on this
interface must belong to one of the configured subnets. Otherwise
received message is dropped.
% DHCP4_OPEN_SOCKET opening sockets on port %1
A debug message issued during startup, this indicates that the DHCPv4
server is about to open sockets on the specified port.
......@@ -232,26 +209,66 @@ server is about to open sockets on the specified port.
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_NO_TYPE packet received on interface %1 dropped, because of missing msg-type option
This is a debug message informing that incoming DHCPv4 packet did not
have mandatory DHCP message type option and thus was dropped.
% DHCP4_PACKET_DROP_0001 %1: failed to parse incoming packet - %2
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.
% DHCP4_PACKET_DROP_0002 %1, from interface %2: no suitable subnet configured for a direct client
This info message is logged when received a message from a directly connected
client but there is no suitable subnet configured for the interface on
which this message has been received. The IPv4 address assigned on this
interface must belong to one of the configured subnets. Otherwise
received message is dropped.
% DHCP4_PACKET_NOT_FOR_US received DHCPv4 message (transid=%1, iface=%2) dropped because it contains foreign server identifier
% DHCP4_PACKET_DROP_0003 %1, from interface %2: it contains a foreign server identifier
This debug message is issued when received DHCPv4 message is dropped because
it is addressed to a different server, i.e. a server identifier held by
this message doesn't match the identifier used by our server. The arguments
of this message hold the name of the transaction id and interface on which
the message has been received.
% DHCP4_PACKET_PARSE_FAIL failed to parse incoming packet: %1
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.
% DHCP4_PACKET_DROP_0004 %1, from interface %2: missing msg-type option
This is a debug message informing that incoming DHCPv4 packet did not
have mandatory DHCP message type option and thus was dropped.
% DHCP4_PACKET_DROP_0005 %1: unrecognized type %2 in option 53
This debug message indicates that the message type carried in DHCPv4 option
53 is unrecognized by the server. The valid message types are listed
on the IANA website: http://www.iana.org/assignments/bootp-dhcp-parameters/bootp-dhcp-parameters.xhtml#message-type-53.
The message will not be processed by the server.
% DHCP4_PACKET_PROCESS_FAIL failed to process packet received from %1: %2
% DHCP4_PACKET_DROP_0006 %1: unsupported DHCPv4 message type %2
This debug message indicates that the message type carried in DHCPv4 option
53 is valid but the message will not be processed by the server. This includes
messages being normally sent by the server to the client, such as Offer, ACK,
NAK etc.
% DHCP4_PACKET_DROP_0007 %1: failed to process packet - %2
This is a general catch-all message indicating that the processing of a
received packet failed. The reason is given in the message. The server
will not send a response but will instead ignore the packet.
% DHCP4_PACKET_NAK_0001 %1: failed to select a subnet for incoming packet, src %2, type %3
This error message is output when a packet was received from a subnet
for which the DHCPv4 server has not been configured. The most probable
cause is a misconfiguration of the server.
% DHCP4_PACKET_NAK_0002 %1: invalid address %2 requested by INIT-REBOOT
This debug message is issued when the client being in the INIT-REBOOT state
requested an address which is not assigned to him. The server will respond
to this client with DHCPNAK.
% DHCP4_PACKET_NAK_0003 %1: failed to advertise a lease, client sent ciaddr %2, requested-ip-address %3
This message indicates that the server has failed to offer a lease to
the specified client after receiving a DISCOVER message from it. There are
many possible reasons for such a failure.
% DHCP4_PACKET_NAK_0004 %1: failed to grant a lease, client sent ciaddr %2, requested-ip-address %3
This message indicates that the server failed to grant a lease to the
specified client after receiving a REQUEST message from it. There are many
possible reasons for such a failure. Additional messages will indicate the
reason.
% DHCP4_PACKET_RECEIVED %1 (type %2) packet received on interface %3
A debug message noting that the server has received the specified type of
packet on the specified interface. Note that a packet marked as UNKNOWN
......@@ -390,20 +407,3 @@ is running.
This is a debug message noting the selection of a subnet to be used for
address and option assignment. Subnet selection is one of the early
steps in the processing of incoming client message.
% DHCP4_SUBNET_SELECTION_FAILED failed to select a subnet for incoming packet, src: %1, type: %2
This warning message is output when a packet was received from a subnet
for which the DHCPv4 server has not been configured. The most probable
cause is a misconfiguration of the server.
% DHCP4_UNRECOGNIZED_RCVD_PACKET_TYPE received message (transaction id %1) has unrecognized type %2 in option 53
This debug message indicates that the message type carried in DHCPv4 option
53 is unrecognized by the server. The valid message types are listed
on the IANA website: http://www.iana.org/assignments/bootp-dhcp-parameters/bootp-dhcp-parameters.xhtml#message-type-53.
The message will not be processed by the server.
% DHCP4_UNSUPPORTED_RCVD_PACKET_TYPE received message (transaction id %1), having type %2 is not supported
This debug message indicates that the message type carried in DHCPv4 option
53 is valid but the message will not be processed by the server. This includes
messages being normally sent by the server to the client, such as Offer, ACK,
NAK etc.
src/bin/dhcp4/dhcp4_srv.cc
View file @ 135ffa24
......@@ -403,8 +403,10 @@ Dhcpv4Srv::run() {
query->unpack();
} catch (const std::exception& e) {
// Failed to parse the packet.
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL,
DHCP4_PACKET_PARSE_FAIL).arg(e.what());
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_DETAIL,
DHCP4_PACKET_DROP_0001)
.arg(query->getLabel())
.arg(e.what());
continue;
}
}
......@@ -501,9 +503,10 @@ Dhcpv4Srv::run() {
if (hwptr) {
source = hwptr->toText();
}
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_BASIC,
DHCP4_PACKET_PROCESS_FAIL)
.arg(source).arg(e.what());
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_BASIC,
DHCP4_PACKET_DROP_0007)
.arg(query->getLabel())
.arg(e.what());
}
}
......@@ -1059,7 +1062,8 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
// perhaps this should be logged on some higher level? This is most
// likely configuration bug.
LOG_ERROR(dhcp4_logger, DHCP4_SUBNET_SELECTION_FAILED)
LOG_ERROR(bad_packet_logger, DHCP4_PACKET_NAK_0001)
.arg(query->getLabel())
.arg(query->getRemoteAddr().toText())
.arg(serverReceivedPacketName(query->getType()));
resp->setType(DHCPNAK);
......@@ -1124,11 +1128,10 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
}
// Got a lease so we can check the address.
if (lease && (lease->addr_ != hint)) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL,
DHCP4_INVALID_ADDRESS_INIT_REBOOT)
.arg(hint.toText())
.arg(client_id ? client_id->toText():"(no client-id)")
.arg(hwaddr ? hwaddr->toText():"(no hwaddr info)");
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_DETAIL,
DHCP4_PACKET_NAK_0002)
.arg(query->getLabel())
.arg(hint.toText());
resp->setType(DHCPNAK);
resp->setYiaddr(IOAddress::IPV4_ZERO_ADDRESS());
......@@ -1289,10 +1292,9 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
// cause of that failure. The only thing left is to insert
// status code to pass the sad news to the client.
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL, fake_allocation?
DHCP4_LEASE_ADVERT_FAIL:DHCP4_LEASE_ALLOC_FAIL)
.arg(client_id?client_id->toText():"(no client-id)")
.arg(hwaddr?hwaddr->toText():"(no hwaddr info)")
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL, fake_allocation ?
DHCP4_PACKET_NAK_0003 : DHCP4_PACKET_NAK_0004)
.arg(query->getLabel())
.arg(query->getCiaddr().toText())
.arg(opt_requested_address ?
opt_requested_address->readAddress().toText() : "(no address)");
......@@ -1753,8 +1755,8 @@ Dhcpv4Srv::accept(const Pkt4Ptr& query) const {
// Check if the message from directly connected client (if directly
// connected) should be dropped or processed.
if (!acceptDirectRequest(query)) {
LOG_INFO(dhcp4_logger, DHCP4_NO_SUBNET_FOR_DIRECT_CLIENT)
.arg(query->getTransid())
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_DROP_0002)
.arg(query->getLabel())
.arg(query->getIface());
return (false);
}
......@@ -1762,8 +1764,8 @@ Dhcpv4Srv::accept(const Pkt4Ptr& query) const {
// Check if the DHCPv4 packet has been sent to us or to someone else.
// If it hasn't been sent to us, drop it!
if (!acceptServerId(query)) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_NOT_FOR_US)
.arg(query->getTransid())
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_DROP_0003)
.arg(query->getLabel())
.arg(query->getIface());
return (false);
}
......@@ -1806,17 +1808,17 @@ Dhcpv4Srv::acceptMessageType(const Pkt4Ptr& query) const {
type = query->getType();
} catch (...) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_DROP_NO_TYPE)
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_DROP_0004)
.arg(query->getLabel())
.arg(query->getIface());
return (false);
}
// If we receive a message with a non-existing type, we are logging it.
if (type > DHCPLEASEQUERYDONE) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL,
DHCP4_UNRECOGNIZED_RCVD_PACKET_TYPE)
.arg(type)
.arg(query->getTransid());
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_DROP_0005)
.arg(query->getLabel())
.arg(type);
return (false);
}
......@@ -1831,10 +1833,9 @@ Dhcpv4Srv::acceptMessageType(const Pkt4Ptr& query) const {
if ((type != DHCPDISCOVER) && (type != DHCPREQUEST) &&
(type != DHCPRELEASE) && (type != DHCPDECLINE) &&
(type != DHCPINFORM)) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL,
DHCP4_UNSUPPORTED_RCVD_PACKET_TYPE)
.arg(type)
.arg(query->getTransid());
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_DROP_0006)
.arg(query->getLabel())
.arg(type);
return (false);
}
......
src/bin/dhcp4/main.cc
View file @ 135ffa24
......@@ -40,8 +40,6 @@ namespace {
const char* const DHCP4_NAME = "kea-dhcp4";
const char* const DHCP4_LOGGER_NAME = "kea-dhcp4";
/// @brief Prints Kea Usage and exits
///
/// Note: This function never returns. It terminates the process.
......@@ -126,10 +124,10 @@ main(int argc, char* argv[]) {
// It is important that we set a default logger name because this name
// will be used when the user doesn't provide the logging configuration
// in the Kea configuration file.
CfgMgr::instance().setDefaultLoggerName(DHCP4_LOGGER_NAME);
CfgMgr::instance().setDefaultLoggerName(DHCP4_ROOT_LOGGER_NAME);
// Initialize logging. If verbose, we'll use maximum verbosity.
Daemon::loggerInit(DHCP4_LOGGER_NAME, verbose_mode);
Daemon::loggerInit(DHCP4_ROOT_LOGGER_NAME, verbose_mode);
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_START, DHCP4_START_INFO)
.arg(getpid()).arg(port_number).arg(verbose_mode ? "yes" : "no");
......
src/lib/dhcp/pkt.h
View file @ 135ffa24
......@@ -141,6 +141,17 @@ public:
/// @return true if option was deleted, false if no such option existed
bool delOption(uint16_t type);
/// @brief Returns text representation primary packet identifiers
///
/// This method is intended to be used to provide as a consistent way to
/// identify packets within log statements. Derivations should supply
/// there own implementation.
///
/// @return string with text representation
virtual std::string getLabel() const {
isc_throw(NotImplemented, "Pkt::getLabel()");
}
/// @brief Returns text representation of the packet.
///
/// This function is useful mainly for debugging.
......
src/lib/dhcp/pkt4.cc
View file @ 135ffa24
......@@ -282,6 +282,33 @@ void Pkt4::setType(uint8_t dhcp_type) {
}
}
std::string
Pkt4::getLabel() const {
/// @todo If and when client id is extracted into Pkt4, this method should
/// the instance member rather than fetch it every time.
ClientIdPtr client_id;
OptionPtr client_opt = getOption(DHO_DHCP_CLIENT_IDENTIFIER);
if (client_opt ) {
client_id = ClientIdPtr(new ClientId(client_opt->getData()));
}
return makeLabel(hwaddr_, client_id, transid_);
}
std::string
Pkt4::makeLabel(const HWAddrPtr& hwaddr, const ClientIdPtr& client_id,
const uint32_t transid) {
stringstream label;
label << "hwaddr=[" << (hwaddr ? hwaddr->toText() : "no info")
<< "], client-id=[" << (client_id ? client_id->toText() : "no info")
<< "], transid=0x" << hex << transid << dec;
return label.str();
}
std::string
Pkt4::toText() {
stringstream tmp;
......
src/lib/dhcp/pkt4.h
View file @ 135ffa24
......@@ -17,6 +17,7 @@
#include <asiolink/io_address.h>
#include <dhcp/option.h>
#include <dhcp/duid.h>
#include <util/buffer.h>
#include <dhcp/option.h>
#include <dhcp/classify.h>
......@@ -108,6 +109,29 @@ public:
/// Method will throw exception if anomaly is found.
void check();
/// @brief Returns text representation of the primary packet identifiers
///
/// This method is intended to be used to provide a consistent way to
/// identify packets within log statements. It is an instance-level
/// wrapper around static makeLabel(). See this method for string
/// content.
///
/// @return string with text representation
std::string getLabel() const;
/// @brief Returns text representation of the given packet identifiers
///
/// @param hwaddr - hardware address to include in the string, it may be
/// NULL.
/// @param client_id - client id to include in the string, it may be NULL.
/// to include in the string
/// @param transid - numeric transaction id to include in the string
///
/// @return string with text representation
static std::string makeLabel(const HWAddrPtr& hwaddr,
const ClientIdPtr& client_id,
const uint32_t transid);
/// @brief Returns text representation of the packet.
///
/// This function is useful mainly for debugging.
......
src/lib/dhcp/tests/pkt4_unittest.cc
View file @ 135ffa24
......@@ -878,4 +878,42 @@ TEST_F(Pkt4Test, getMAC) {
ASSERT_TRUE(*dummy_hwaddr == *pkt.getMAC(HWAddr::HWADDR_SOURCE_RAW));
}
// Tests that getLabel/makeLabel methods produces the expected strings based on
// packet content.
TEST_F(Pkt4Test, getLabel) {
Pkt4 pkt(DHCPOFFER, 1234);
// Verify makeLabel() handles empty values
EXPECT_EQ ("hwaddr=[no info], client-id=[no info], transid=0x0",
Pkt4::makeLabel(HWAddrPtr(), ClientIdPtr(), 0));
// Verify an "empty" packet label is as we expect
EXPECT_EQ ("hwaddr=[hwtype=1 ], client-id=[no info], transid=0x4d2",
pkt.getLabel());
// 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=[hwtype=123 02:04:06:08:0a:0c],"
" client-id=[no info], transid=0x4d2", pkt.getLabel());
// Add a client id to the packet then verify getLabel
OptionBuffer clnt_id(4);
for (int i = 0; i < 4; i++) {
clnt_id[i] = 100 + i;
}
OptionPtr opt(new Option(Option::V4, DHO_DHCP_CLIENT_IDENTIFIER,
clnt_id.begin(), clnt_id.begin() + 4));
pkt.addOption(opt);
EXPECT_EQ ("hwaddr=[hwtype=123 02:04:06:08:0a:0c],"
" client-id=[64:65:66:67], transid=0x4d2",
pkt.getLabel());
}
} // end of anonymous namespace
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment