Commit 201fdcad authored by Marcin Siodelski's avatar Marcin Siodelski

[3806] Added traces to the Dhcpv4Srv class.

parent 59ca0413
......@@ -19,6 +19,38 @@ This message is printed when DHCPv4 server enabled an interface to be used
to receive DHCPv4 traffic. IPv4 socket on this interface will be opened once
Interface Manager starts up procedure of opening sockets.
% DHCP4_BUFFER_RECEIVE_FAIL error on attempt to receive packet: %1
The DHCPv4 server tried to receive a packet but an error
occurred during this attempt. The reason for the error is included in
the message.
% DHCP4_BUFFER_RECEIVED received buffer from %1:%2 to %3:%4 over interface %5
This debug message is logged when the server has received some packet
over the socket. When the message is logged the contents of the received
packet hasn't been parsed yet. The only available information is the
interface and the source and destination addresses/ports.
% DHCP4_BUFFER_UNPACK parsing received buffer from %1 to %2 over interface %3
This debug message is issued when the server starts parsing the received
buffer holding the DHCPv4 message.
% DHCP4_BUFFER_WAIT waiting for next DHCPv4 packet with timeout %1 ms
This debug message is issued when the server enters the state when it
waits for new packets. The argument specifies the timeout for the server
to wait for the packet. When this time elapses the server will pass
through its main loop to perform handling of any pending signals
and timers. After that it will enter the wait state again.
% DHCP4_BUFFER_WAIT_SIGNAL signal received while waiting for next packet, next waiting signal is %1
This debug message is issued when the server's waiting for the packet
is interrupted by the signal received by the process. The signal
will be handled before the server starts waiting for next packets.
% DHCP4_BUFFER_WAIT_TIMEOUT timeout %1 ms reached while waiting for the next packet
This debug message is issued when the timeout has occured while
waiting for the next packet. The server will now handle signals
received and ready timers before waiting for next packets again.
% DHCP4_CCSESSION_STARTED control channel session started on socket %1
A debug message issued during startup after the DHCPv4 server has
successfully established a session with the Kea control channel.
......@@ -31,6 +63,26 @@ to establish a session with the Kea control channel.
This debug message informs that incoming packet has been assigned to specified
class or classes. This is a normal behavior and indicates successful operation.
% DHCP4_CLIENT_FQDN_PROCESS %1: processing Client FQDN option
This debug message is issued when the server starts to process the Client
FQDN option sent in the client's query. The argument includes the
client and transaction identification information.
% DHCP4_CLIENT_FQDN_DATA %1: client FQDN option information: %2
This debug message includes the detailed information extracted from the
Client FQDN option sent in the query. The first argument includes the
client and transaction identification information.
% DHCP4_CLIENT_HOSTNAME_PROCESS %1: processing client's Hostname option
This debug message is issued when the server starts to process the Hostname
option sent in the client's query. The argument includes the client and
transaction identification information.
% DHCP4_CLIENT_HOSTNAME_DATA %1: client Hostname option information: %2
This debug message includes the detailed information extracted from the
Hostname option sent in the query. The first argument includes the
client and transaction identification information.
% DHCP4_CLIENT_NAME_PROC_FAIL failed to process the fqdn or hostname sent by a client: %1
This debug message is issued when the DHCP server was unable to process the
FQDN or Hostname option sent by a client. This is likely because the client's
......@@ -111,12 +163,12 @@ A "libreload" command was issued to reload the hooks libraries but for
some reason the reload failed. Other error messages issued from the
hooks framework will indicate the nature of the problem.
% DHCP4_HOOK_BUFFER_RCVD_SKIP received DHCPv4 buffer was dropped because a callout set the skip flag.
% DHCP4_HOOK_BUFFER_RCVD_SKIP received buffer from %1 to %2 over interface %3 was dropped because a callout set the skip flag
This debug message is printed when a callout installed on buffer4_receive
hook point set the skip flag. For this particular hook point, the
setting of the flag by a callout instructs the server to drop the packet.
% DHCP4_HOOK_BUFFER_SEND_SKIP prepared DHCPv4 response was dropped because a callout set the skip flag.
% DHCP4_HOOK_BUFFER_SEND_SKIP %1: prepared response is dropped because a callout set the skip flag.
This debug message is printed when a callout installed on buffer4_send
hook point set the skip flag. For this particular hook point, the
setting of the flag by a callout instructs the server to drop the packet.
......@@ -129,12 +181,12 @@ hook point set the skip flag. For this particular hook point, the
setting of the flag by a callout instructs the server to not release
a lease.
% DHCP4_HOOK_PACKET_RCVD_SKIP received DHCPv4 packet was dropped, because a callout set the skip flag.
% DHCP4_HOOK_PACKET_RCVD_SKIP %1: packet is dropped, because a callout set the skip flag.
This debug message is printed when a callout installed on the pkt4_receive
hook point sets the skip flag. For this particular hook point, the
setting of the flag instructs the server to drop the packet.
% DHCP4_HOOK_PACKET_SEND_SKIP prepared DHCPv6 response was not sent, because a callout set skip flag.
% DHCP4_HOOK_PACKET_SEND_SKIP %1: prepared response is not sent, because a callout set skip flag.
This debug message is printed when a callout installed on the pkt4_send
hook point sets the skip flag. For this particular hook point, the setting
of the flag instructs the server to drop the packet. This means that
......@@ -157,16 +209,21 @@ 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_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_INIT_REBOOT %1: client is in INIT-REBOOT state and requests address %2
This debug message is issued when the client is in the INIT-REBOOT state and
is requesting an address it is using to be allocated for it. The first argument
includes the client and transaction identification information. The second
argument specifies the requested IP address.
% DHCP4_LEASE_ALLOC lease %1 has been allocated for client-id %2, hwaddr %3
% DHCP4_LEASE_ADVERT %1: lease %2 will be advertised
This debug message indicates that the server has found the lease to be
offered to the client. It is up to the client to choose one server out of
those which offered leases and continue allocation with that server. This
% DHCP4_LEASE_ALLOC %1: lease %2 has been allocated
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.
in response to client's DHCPREQUEST message. The lease information will
be sent to the client in the DHCPACK message.
% 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
......@@ -181,18 +238,26 @@ options in the server's response with the hostname generated by the server
from the acquired address. The message argument indicates the reason for the
failure.
% DHCP4_NCR_CREATION_FAILED failed to generate name change requests for DNS: %1
% DHCP4_NCR_CREATE %1: DDNS updates enabled, therefore sending name change requests
This debug message message is issued when the server is starting to send
name change requests to the D2 module to update records for the client
in the DNS. This includes removal of old records and addition of the
new records as required. The argument includes the client and the
transaction identification information.
% DHCP4_NCR_CREATION_FAILED %1: failed to generate name change requests for DNS: %2
This message indicates that server was unable to generate NameChangeRequests
which should be sent to the kea-dhcp_ddns module to create
new DNS records for the lease being acquired or to update existing records
for the renewed lease. The reason for the failure is printed in the logged
message.
for the renewed lease. The first argument contains the client and transaction
identification information. The second argument includes the reason for the
failure.
% DHCP4_NOT_RUNNING DHCPv4 server is not running
A warning message is issued when an attempt is made to shut down the
DHCPv4 server but it is not running.
% DHCP4_NO_LEASE_INIT_REBOOT no lease for address %1 requested by INIT-REBOOT client (id: %2, hwaddr: %3)
% DHCP4_NO_LEASE_INIT_REBOOT %1: no lease for address %2 requested by INIT-REBOOT client
This debug message is issued when the client being in the INIT-REBOOT state
requested an address but this client is unknown. The server will not respond.
......@@ -209,7 +274,7 @@ 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_0001 %1: failed to parse incoming packet - %2
% DHCP4_PACKET_DROP_0001 failed to parse packet from %1 to %2, received over interace %3, reason: %4
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.
......@@ -269,18 +334,29 @@ 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
% DHCP4_PACKET_PACK %1: preparing on-wire format of the packet to be sent
This debug message is issued when the server starts preparing the on-wire
format of the packet to be sent back to the client. The argument specifies
the identifiers of the client: HW address and client identifier.
% DHCP4_PACKET_PACK_FAIL %1: preparing on-wire-format of the packet to be sent failed %2
This error message is issued when preparing an on-wire format of the packet
has failed. The first argument identifies the client and the DHCP transaction.
The second argument includes the error string.
% DHCP4_PACKET_RECEIVED %1: %2 (type %3) received from %4 to %5 on interface %6
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
may well be a valid DHCP packet, just a type not expected by the server
(e.g. it will report a received OFFER packet as UNKNOWN).
% DHCP4_PACKET_RECEIVE_FAIL error on attempt to receive packet: %1
The DHCPv4 server tried to receive a packet but an error
occurred during this attempt. The reason for the error is included in
the message.
% DHCP4_PACKET_SEND %1: sending packet %2 (type %3) from %4:%5 to %6:%7 on interface %8
This debug message is issued when the server is sending the response to
the client. The arguments specify the client identification information
(HW address and client identifier), DHCP message name and type, source
address and port, destination address and port and the interface name.
% DHCP4_PACKET_SEND_FAIL failed to send DHCPv4 packet: %1
% DHCP4_PACKET_SEND_FAIL %1: failed to send DHCPv4 packet: %2
This error is output if the DHCPv4 server fails to send an assembled
DHCP message to a client. The reason for the error is included in the
message.
......@@ -317,8 +393,8 @@ of the named configuration element, or the creation succeeded but the
parsing actions and committal of changes failed. The reason for the
failure is given in the message.
% DHCP4_QUERY_DATA received packet type %1, data is <%2>
A debug message listing the data received from the client.
% DHCP4_QUERY_DATA %1, packet details: [%2]
A debug message listing the details of the received from the client.
% DHCP4_QUEUE_NCR name change request to %1 DNS entry queued: %2
A debug message which is logged when the NameChangeRequest to add or remove
......@@ -363,12 +439,37 @@ a different hardware address. One possible reason for using different
hardware address is that a cloned virtual machine was not updated and
both clones use the same client-id.
% DHCP4_RESPONSE_FQDN_DATA %1: including FQDN option in the server's response: %2
This debug message is issued when the server is adding the Client FQDN
option in its response to the client. The first argument includes the
client and transaction identification information. The second argument
includes the details of the FQDN option being included. Note that the
name carried in the FQDN option may be modified by the server when
the lease is acquired for the client.
% DHCP4_RESPONSE_HOSTNAME_DATA %1: including Hostname option in the server's response: %2
This debug message is issued when the server is adding the Hostname
option in its response to the client. The first argument includes the
client and transaction identification information. The second argument
includes the details of the FQDN option being included. Note that the
name carried in the Hostname option may be modified by the server when
the lease is acquired for the client.
% DHCP4_RESPONSE_HOSTNAME_GENERATE %1: server has generated hostname %2 for the client
This debug message includes the auto-generated hostname which will be used
for the client which message is processed. Hostnames may need to be generated
when required by the server's configuration or when the client hasn't
supplied its hostname. The first argument includes the client and the
transaction identification information. The second argument holds the
generated hostname.
% DHCP4_REQUEST_CLASS_PROCESSING_FAILED client class specific processing failed for DHCPREQUEST
This debug message means that the server processing that is unique for each
client class has reported a failure. The response packet will not be sent.
% DHCP4_RESPONSE_DATA responding with packet type %1, data is <%2>
A debug message listing the data returned to the client.
% DHCP4_RESPONSE_DATA %1: responding with packet type %2, packet details: "%3"
A debug message including the detailed data about the packet being sent
to the client.
% DHCP4_SERVER_FAILED server failed: %1
The DHCPv4 server has encountered a fatal error and is terminating.
......
......@@ -194,6 +194,7 @@ Dhcpv4Srv::Dhcpv4Srv(uint16_t port, const bool use_bcast,
use_bcast_(use_bcast), hook_index_pkt4_receive_(-1),
hook_index_subnet4_select_(-1), hook_index_pkt4_send_(-1) {
// fixme: either remove or change its name.
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_START, DHCP4_OPEN_SOCKET).arg(port);
try {
// Port 0 is used for testing purposes where we don't open broadcast
......@@ -318,17 +319,39 @@ Dhcpv4Srv::run() {
if (timeout == 0) {
timeout = 1000;
}
LOG_DEBUG(packet_logger, DBG_DHCP4_DETAIL, DHCP4_BUFFER_WAIT).arg(timeout);
query = receivePacket(timeout);
// Log if packet has arrived. We can't log the detailed information
// about the DHCP message because it hasn't been unpacked/parsed
// yet, and it can't be parsed at this point because hooks will
// have to process it first. The only information available at this
// point are: the interface, source address and destination addresses
// and ports.
if (query) {
LOG_DEBUG(packet_logger, DBG_DHCP4_DETAIL, DHCP4_BUFFER_RECEIVED)
.arg(query->getRemoteAddr().toText())
.arg(query->getRemotePort())
.arg(query->getLocalAddr().toText())
.arg(query->getLocalPort())
.arg(query->getIface());
} else {
LOG_DEBUG(packet_logger, DBG_DHCP4_DETAIL, DHCP4_BUFFER_WAIT_TIMEOUT)
.arg(timeout);
}
} catch (const SignalInterruptOnSelect) {
// Packet reception interrupted because a signal has been received.
// This is not an error because we might have received a SIGTERM,
// SIGINT or SIGHUP which are handled by the server. For signals
// that are not handled by the server we rely on the default
// behavior of the system, but there is nothing we should log here.
LOG_DEBUG(packet_logger, DBG_DHCP4_DETAIL, DHCP4_BUFFER_WAIT_SIGNAL)
.arg(signal_set_->getNext());
} catch (const std::exception& e) {
// Log all other errors.
LOG_ERROR(dhcp4_logger, DHCP4_PACKET_RECEIVE_FAIL).arg(e.what());
LOG_ERROR(packet_logger, DHCP4_BUFFER_RECEIVE_FAIL).arg(e.what());
}
// Handle next signal received by the process. It must be called after
......@@ -341,10 +364,12 @@ Dhcpv4Srv::run() {
// select() function is called. If the function was called before
// receivePacket the process could wait up to the duration of timeout
// of select() to terminate.
// fixme
handleSignal();
// Execute ready timers for the lease database, e.g. Lease File Cleanup.
try {
// fixme
LeaseMgrFactory::instance().getIOService()->poll();
} catch (const std::exception& ex) {
......@@ -353,7 +378,8 @@ Dhcpv4Srv::run() {
}
// Timeout may be reached or signal received, which breaks select()
// with no reception occurred
// with no reception occurred. No need to log anything here because
// we have logged right after the call to receivePacket().
if (!query) {
continue;
}
......@@ -364,6 +390,7 @@ Dhcpv4Srv::run() {
// available in the libdhcp, so we need to supply our own implementation
// of the option parsing function here, which would rely on the
// configuration data.
// fixme
query->setCallback(boost::bind(&Dhcpv4Srv::unpackOptions, this,
_1, _2, _3));
......@@ -389,7 +416,10 @@ Dhcpv4Srv::run() {
// stage means that callouts did the parsing already, so server
// should skip parsing.
if (callout_handle->getSkip()) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_HOOKS, DHCP4_HOOK_BUFFER_RCVD_SKIP);
LOG_DEBUG(srv_hooks_logger, DBG_DHCP4_DETAIL, DHCP4_HOOK_BUFFER_RCVD_SKIP)
.arg(query->getRemoteAddr().toText())
.arg(query->getLocalAddr().toText())
.arg(query->getIface());
skip_unpack = true;
}
......@@ -400,12 +430,18 @@ Dhcpv4Srv::run() {
// indicated they did it
if (!skip_unpack) {
try {
LOG_DEBUG(options_logger, DBG_DHCP4_DETAIL, DHCP4_BUFFER_UNPACK)
.arg(query->getRemoteAddr().toText())
.arg(query->getLocalAddr().toText())
.arg(query->getIface());
query->unpack();
} catch (const std::exception& e) {
// Failed to parse the packet.
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_DETAIL,
DHCP4_PACKET_DROP_0001)
.arg(query->getLabel())
.arg(query->getRemoteAddr().toText())
.arg(query->getLocalAddr().toText())
.arg(query->getIface())
.arg(e.what());
continue;
}
......@@ -414,10 +450,12 @@ Dhcpv4Srv::run() {
// Assign this packet to one or more classes if needed. We need to do
// this before calling accept(), because getSubnet4() may need client
// class information.
// fixme
classifyPacket(query);
// Check whether the message should be further processed or discarded.
// There is no need to log anything here. This function logs by itself.
// fixme
if (!accept(query)) {
continue;
}
......@@ -425,12 +463,15 @@ Dhcpv4Srv::run() {
// We have sanity checked (in accept() that the Message Type option
// exists, so we can safely get it here.
int type = query->getType();
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_RECEIVED)
LOG_DEBUG(packet_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_RECEIVED)
.arg(query->getLabel())
.arg(serverReceivedPacketName(type))
.arg(type)
.arg(query->getRemoteAddr())
.arg(query->getLocalAddr())
.arg(query->getIface());
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL_DATA, DHCP4_QUERY_DATA)
.arg(type)
LOG_DEBUG(packet_logger, DBG_DHCP4_DETAIL_DATA, DHCP4_QUERY_DATA)
.arg(query->getLabel())
.arg(query->toText());
// Let's execute all callouts registered for pkt4_receive
......@@ -451,7 +492,8 @@ Dhcpv4Srv::run() {
// processing step would to process the packet, so skip at this
// stage means drop.
if (callout_handle->getSkip()) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_HOOKS, DHCP4_HOOK_PACKET_RCVD_SKIP);
LOG_DEBUG(srv_hooks_logger, DBG_DHCP4_HOOKS, DHCP4_HOOK_PACKET_RCVD_SKIP)
.arg(query->getLabel());
continue;
}
......@@ -539,16 +581,20 @@ Dhcpv4Srv::run() {
// processing step would to send the packet, so skip at this
// stage means "drop response".
if (callout_handle->getSkip()) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_HOOKS, DHCP4_HOOK_PACKET_SEND_SKIP);
LOG_DEBUG(srv_hooks_logger, DBG_DHCP4_HOOKS, DHCP4_HOOK_PACKET_SEND_SKIP)
.arg(query->getLabel());
skip_pack = true;
}
}
if (!skip_pack) {
try {
LOG_DEBUG(options_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_PACK)
.arg(rsp->getLabel());
rsp->pack();
} catch (const std::exception& e) {
LOG_ERROR(dhcp4_logger, DHCP4_PACKET_SEND_FAIL)
LOG_ERROR(options_logger, DHCP4_PACKET_PACK_FAIL)
.arg(rsp->getLabel())
.arg(e.what());
}
}
......@@ -575,21 +621,35 @@ Dhcpv4Srv::run() {
// processing step would to parse the packet, so skip at this
// stage means drop.
if (callout_handle->getSkip()) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_HOOKS,
DHCP4_HOOK_BUFFER_SEND_SKIP);
LOG_DEBUG(srv_hooks_logger, DBG_DHCP4_HOOKS,
DHCP4_HOOK_BUFFER_SEND_SKIP)
.arg(rsp->getLabel());
continue;
}
callout_handle->getArgument("response4", rsp);
}
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL_DATA,
LOG_DEBUG(options_logger, DBG_DHCP4_DETAIL_DATA,
DHCP4_RESPONSE_DATA)
.arg(static_cast<int>(rsp->getType())).arg(rsp->toText());
.arg(rsp->getLabel())
.arg(static_cast<int>(rsp->getType()))
.arg(rsp->toText());
LOG_DEBUG(packet_logger, DBG_DHCP4_DETAIL, DHCP4_PACKET_SEND)
.arg(rsp->getLabel())
.arg("fixme")
.arg(static_cast<int>(rsp->getType()))
.arg(rsp->getLocalAddr())
.arg(rsp->getLocalPort())
.arg(rsp->getRemoteAddr())
.arg(rsp->getRemotePort())
.arg(rsp->getIface());
sendPacket(rsp);
} catch (const std::exception& e) {
LOG_ERROR(dhcp4_logger, DHCP4_PACKET_SEND_FAIL)
LOG_ERROR(packet_logger, DHCP4_PACKET_SEND_FAIL)
.arg(rsp->getLabel())
.arg(e.what());
}
}
......@@ -818,12 +878,16 @@ Dhcpv4Srv::processClientName(Dhcpv4Exchange& ex) {
Option4ClientFqdnPtr fqdn = boost::dynamic_pointer_cast<Option4ClientFqdn>
(ex.getQuery()->getOption(DHO_FQDN));
if (fqdn) {
LOG_DEBUG(hostname_logger, DBG_DHCP4_BASIC, DHCP4_CLIENT_FQDN_PROCESS)
.arg(ex.getQuery()->getLabel());
processClientFqdnOption(ex);
} else {
OptionStringPtr hostname = boost::dynamic_pointer_cast<OptionString>
(ex.getQuery()->getOption(DHO_HOST_NAME));
if (hostname) {
LOG_DEBUG(hostname_logger, DBG_DHCP4_BASIC, DHCP4_CLIENT_HOSTNAME_PROCESS)
.arg(ex.getQuery()->getLabel());
processHostnameOption(ex);
}
}
......@@ -847,6 +911,10 @@ Dhcpv4Srv::processClientFqdnOption(Dhcpv4Exchange& ex) {
Option4ClientFqdnPtr fqdn = boost::dynamic_pointer_cast<
Option4ClientFqdn>(ex.getQuery()->getOption(DHO_FQDN));
LOG_DEBUG(hostname_logger, DBG_DHCP4_DETAIL_DATA, DHCP4_CLIENT_FQDN_DATA)
.arg(ex.getQuery()->getLabel())
.arg(fqdn->toText());
// Create the DHCPv4 Client FQDN Option to be included in the server's
// response to a client.
Option4ClientFqdnPtr fqdn_resp(new Option4ClientFqdn(*fqdn));
......@@ -883,6 +951,9 @@ Dhcpv4Srv::processClientFqdnOption(Dhcpv4Exchange& ex) {
// If we don't store the option in the response message, we will have to
// propagate it in the different way to the functions which acquire the
// lease. This would require modifications to the API of this class.
LOG_DEBUG(hostname_logger, DBG_DHCP4_DETAIL_DATA, DHCP4_RESPONSE_FQDN_DATA)
.arg(ex.getQuery()->getLabel())
.arg(fqdn_resp->toText());
ex.getResponse()->addOption(fqdn_resp);
}
......@@ -892,6 +963,10 @@ Dhcpv4Srv::processHostnameOption(Dhcpv4Exchange& ex) {
OptionStringPtr opt_hostname = boost::dynamic_pointer_cast<OptionString>
(ex.getQuery()->getOption(DHO_HOST_NAME));
LOG_DEBUG(hostname_logger, DBG_DHCP4_DETAIL_DATA, DHCP4_CLIENT_HOSTNAME_DATA)
.arg(ex.getQuery()->getLabel())
.arg(opt_hostname->getValue());
// Fetch D2 configuration.
D2ClientMgr& d2_mgr = CfgMgr::instance().getD2ClientMgr();
......@@ -950,7 +1025,10 @@ Dhcpv4Srv::processHostnameOption(Dhcpv4Exchange& ex) {
// clients do not handle the hostnames with the trailing dot.
opt_hostname_resp->setValue(d2_mgr.qualifyName(hostname, false));
}
LOG_DEBUG(hostname_logger, DBG_DHCP4_DETAIL_DATA, DHCP4_RESPONSE_HOSTNAME_DATA)
.arg(ex.getQuery()->getLabel())
.arg(opt_hostname_resp->getValue());
ex.getResponse()->addOption(opt_hostname_resp);
}
......@@ -1054,14 +1132,9 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
if (!subnet) {
// This particular client is out of luck today. We do not have
// information about the subnet he is connected to. This likely means
// misconfiguration of the server (or some relays). We will continue to
// process this message, but our response will be almost useless: no
// addresses or prefixes, no subnet specific configuration etc. The only
// thing this client can get is some global information (like DNS
// servers).
// perhaps this should be logged on some higher level? This is most
// likely configuration bug.
// misconfiguration of the server (or some relays).
// Perhaps this should be logged on some higher level?
LOG_ERROR(bad_packet_logger, DHCP4_PACKET_NAK_0001)
.arg(query->getLabel())
.arg(query->getRemoteAddr().toText())
......@@ -1093,7 +1166,7 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
// ciaddr.
OptionCustomPtr opt_requested_address = boost::dynamic_pointer_cast<
OptionCustom>(query->getOption(DHO_DHCP_REQUESTED_ADDRESS));
IOAddress hint(0);
IOAddress hint(IOAddress::IPV4_ZERO_ADDRESS());
if (opt_requested_address) {
hint = opt_requested_address->readAddress();
......@@ -1117,6 +1190,11 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
// determine whether the client's notion of the address is correct
// and whether the client is known, i.e., has a lease.
if (!fake_allocation && !opt_serverid && opt_requested_address) {
LOG_DEBUG(lease_logger, DBG_DHCP4_DETAIL, DHCP4_INIT_REBOOT)
.arg(query->getLabel())
.arg(hint.toText());
Lease4Ptr lease;
if (hwaddr) {
lease = LeaseMgrFactory::instance().getLease4(*hwaddr,
......@@ -1139,11 +1217,10 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
}
// Now check the second error case: unknown client.
if (!lease) {
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL,
LOG_DEBUG(bad_packet_logger, DBG_DHCP4_DETAIL,
DHCP4_NO_LEASE_INIT_REBOOT)
.arg(hint.toText())
.arg(client_id ? client_id->toText():"(no client-id)")
.arg(hwaddr ? hwaddr->toText():"(no hwaddr info)");
.arg(query->getLabel())
.arg(hint.toText());
ex.deleteResponse();
return;
......@@ -1167,6 +1244,7 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
} else {
opt_hostname = boost::dynamic_pointer_cast<OptionString>
(resp->getOption(DHO_HOST_NAME));
if (opt_hostname) {
hostname = opt_hostname->getValue();
// DHO_HOST_NAME is string option which cannot be blank,
......@@ -1196,11 +1274,10 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
if (lease) {
// We have a lease! Let's set it in the packet and send it back to
// the client.
LOG_DEBUG(dhcp4_logger, DBG_DHCP4_DETAIL, fake_allocation?
DHCP4_LEASE_ADVERT:DHCP4_LEASE_ALLOC)
.arg(lease->addr_.toText())
.arg(client_id?client_id->toText():"(no client-id)")
.arg(hwaddr?hwaddr->toText():"(no hwaddr info)");
LOG_DEBUG(lease_logger, DBG_DHCP4_DETAIL, fake_allocation?
DHCP4_LEASE_ADVERT : DHCP4_LEASE_ALLOC)
.arg(query->getLabel())
.arg(lease->addr_.toText());
resp->setYiaddr(lease->addr_);
......@@ -1221,6 +1298,7 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
// generating the entire hostname for the client. The example of the
// client's name, generated from the IP address is: host-192-0-2-3.
if ((fqdn || opt_hostname) && lease->hostname_.empty()) {
// Note that if we have received the hostname option, rather than
// Client FQDN the trailing dot is not appended to the generated
// hostname because some clients don't handle the trailing dot in
......@@ -1229,6 +1307,10 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
lease->hostname_ = CfgMgr::instance().getD2ClientMgr()
.generateFqdn(lease->addr_, static_cast<bool>(fqdn));
LOG_DEBUG(hostname_logger, DBG_DHCP4_DETAIL, DHCP4_RESPONSE_HOSTNAME_GENERATE)
.arg(query->getLabel())
.arg(lease->hostname_);
// The operations below are rather safe, but we want to catch
// any potential exceptions (e.g. invalid lease database backend
// implementation) and log an error.
......@@ -1280,19 +1362,21 @@ Dhcpv4Srv::assignLease(Dhcpv4Exchange& ex) {
// real allocation.
if (!fake_allocation && CfgMgr::instance().ddnsEnabled()) {
try {
LOG_DEBUG(hostname_logger, DBG_DHCP4_DETAIL, DHCP4_NCR_CREATE)
.arg(query->getLabel());
createNameChangeRequests(lease, ctx->old_lease_);
} catch (const Exception& ex) {
LOG_ERROR(dhcp4_logger, DHCP4_NCR_CREATION_FAILED)
LOG_ERROR(hostname_logger, DHCP4_NCR_CREATION_FAILED)
.arg(query->getLabel())
.arg(ex.what());
}
}
} else {
// Allocation engine did not allocate a lease. The engine logged
// 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,