Commit 9c0444c0 authored by Stephen Morris's avatar Stephen Morris
Browse files

[1545] Add logging to the DHCPv6 server code

parent 6f7afc7d
......@@ -13,7 +13,7 @@ endif
pkglibexecdir = $(libexecdir)/@PACKAGE@
CLEANFILES = spec_config.h
CLEANFILES = spec_config.h dhcp6_messages.h dhcp6_messages.cc
man_MANS = b10-dhcp6.8
DISTCLEANFILES = $(man_MANS)
......@@ -37,11 +37,20 @@ endif
spec_config.h: spec_config.h.pre
$(SED) -e "s|@@LOCALSTATEDIR@@|$(localstatedir)|" spec_config.h.pre >$@
BUILT_SOURCES = spec_config.h
dhcp6_messages.h dhcp6_messages.cc: dhcp6_messages.mes
$(top_builddir)/src/lib/log/compiler/message $(top_srcdir)/src/bin/dhcp6/dhcp6_messages.mes
BUILT_SOURCES = spec_config.h dhcp6_messages.h dhcp6_messages.cc
pkglibexec_PROGRAMS = b10-dhcp6
b10_dhcp6_SOURCES = main.cc dhcp6_srv.cc dhcp6_srv.h
b10_dhcp6_SOURCES = main.cc
b10_dhcp6_SOURCES += ctrl_dhcp6_srv.cc ctrl_dhcp6_srv.h
b10_dhcp6_SOURCES += dhcp6_log.cc dhcp6_log.h
b10_dhcp6_SOURCES += dhcp6_srv.cc dhcp6_srv.h
nodist_b10_dhcp6_SOURCES = dhcp6_messages.h dhcp6_messages.cc
EXTRA_DIST += dhcp6_messages.mes
if USE_CLANGPP
# Disable unused parameter warning caused by some of the
......@@ -49,7 +58,7 @@ if USE_CLANGPP
b10_dhcp6_CXXFLAGS = -Wno-unused-parameter
endif
b10_dhcp6_LDADD = $(top_builddir)/src/lib/exceptions/libb10-exceptions.la
b10_dhcp6_LDADD = $(top_builddir)/src/lib/exceptions/libb10-exceptions.la
b10_dhcp6_LDADD += $(top_builddir)/src/lib/asiolink/libb10-asiolink.la
b10_dhcp6_LDADD += $(top_builddir)/src/lib/log/libb10-log.la
b10_dhcp6_LDADD += $(top_builddir)/src/lib/dhcp/libb10-dhcp++.la
......
......@@ -13,28 +13,30 @@
// PERFORMANCE OF THIS SOFTWARE.
#include <config.h>
#include <cassert>
#include <iostream>
#include <cc/session.h>
#include <asiolink/asiolink.h>
#include <cc/data.h>
#include <exceptions/exceptions.h>
#include <cc/session.h>
#include <cc/session.h>
#include <config/ccsession.h>
#include <util/buffer.h>
#include <dhcp6/spec_config.h>
#include <dhcp6/ctrl_dhcp6_srv.h>
#include <dhcp6/dhcp6_log.h>
#include <dhcp6/spec_config.h>
#include <dhcp/iface_mgr.h>
#include <asiolink/asiolink.h>
#include <exceptions/exceptions.h>
#include <util/buffer.h>
using namespace std;
using namespace isc::util;
using namespace isc::dhcp;
using namespace isc::util;
using namespace isc::data;
using namespace isc::asiolink;
using namespace isc::cc;
using namespace isc::config;
using namespace isc::asiolink;
using namespace isc::data;
using namespace isc::dhcp;
using namespace isc::log;
using namespace isc::util;
using namespace std;
namespace isc {
namespace dhcp {
......@@ -43,7 +45,8 @@ ControlledDhcpv6Srv* ControlledDhcpv6Srv::server_ = NULL;
ConstElementPtr
ControlledDhcpv6Srv::dhcp6ConfigHandler(ConstElementPtr new_config) {
cout << "b10-dhcp6: Received new config:" << new_config->str() << endl;
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_COMMAND, DHCP6_CONFIG_UPDATE)
.arg(new_config->str());
ConstElementPtr answer = isc::config::createAnswer(0,
"Thank you for sending config.");
return (answer);
......@@ -51,13 +54,14 @@ ControlledDhcpv6Srv::dhcp6ConfigHandler(ConstElementPtr new_config) {
ConstElementPtr
ControlledDhcpv6Srv::dhcp6CommandHandler(const string& command, ConstElementPtr args) {
cout << "b10-dhcp6: Received new command: [" << command << "], args="
<< args->str() << endl;
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_COMMAND, DHCP6_COMMAND_RECEIVED)
.arg(command).arg(args->str());
if (command == "shutdown") {
if (ControlledDhcpv6Srv::server_) {
ControlledDhcpv6Srv::server_->shutdown();
} else {
cout << "Server not initialized yet or already shut down." << endl;
LOG_WARN(dhcp6_logger, DHCP6_NOT_RUNNING);
ConstElementPtr answer = isc::config::createAnswer(1,
"Shutdown failure.");
return (answer);
......@@ -93,10 +97,9 @@ void ControlledDhcpv6Srv::establishSession() {
/// @todo: Check if session is not established already. Throw, if it is.
cout << "b10-dhcp6: my specfile is " << specfile << endl;
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_START, DHCP6_CCSESSION_STARTING)
.arg(specfile);
cc_session_ = new Session(io_service_.get_io_service());
config_session_ = new ModuleCCSession(specfile, *cc_session_,
dhcp6ConfigHandler,
dhcp6CommandHandler, false);
......@@ -106,8 +109,8 @@ void ControlledDhcpv6Srv::establishSession() {
/// control with the "select" model of the DHCP server. This is
/// fully explained in \ref dhcpv6Session.
int ctrl_socket = cc_session_->getSocketDesc();
cout << "b10-dhcp6: Control session started, socket="
<< ctrl_socket << endl;
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_START, DHCP6_CCSESSION_STARTED)
.arg(ctrl_socket);
IfaceMgr::instance().set_session_socket(ctrl_socket, sessionReader);
}
......
// Copyright (C) 2011 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
// copyright notice and this permission notice appear in all copies.
//
// THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
// AND FITNESS. IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
// OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
// PERFORMANCE OF THIS SOFTWARE.
/// Defines the logger used by the top-level component of b10-dhcp6.
#include "dhcp6_log.h"
namespace isc {
namespace dhcp {
isc::log::Logger dhcp6_logger("dhcp6");
} // namespace dhcp
} // namespace isc
// Copyright (C) 2011 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
// copyright notice and this permission notice appear in all copies.
//
// THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
// AND FITNESS. IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
// OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
// PERFORMANCE OF THIS SOFTWARE.
#ifndef __DHCP6_LOG__H
#define __DHCP6_LOG__H
#include <log/macros.h>
#include <log/logger_support.h>
#include <dhcp6/dhcp6_messages.h>
namespace isc {
namespace dhcp {
/// \brief DHCP6 Logging
///
/// Defines the levels used to output debug messages in the non-library part of
/// the b10-dhcp6 program. Higher numbers equate to more verbose (and detailed)
/// output.
// Debug levels used to log information during startup and shutdown.
const int DBG_DHCP6_START = DBGLVL_START_SHUT;
const int DBG_DHCP6_SHUT = DBGLVL_START_SHUT;
// Debug level used to log setting information (such as configuration changes).
const int DBG_DHCP6_COMMAND = DBGLVL_COMMAND;
// Trace basic operations within the code.
const int DBG_DHCP6_BASIC = DBGLVL_TRACE_BASIC;
// Trace detailed operations, including errors raised when processing invalid
// packets. (These are not logged at severities of WARN or higher for fear
// that a set of deliberately invalid packets set to the server could overwhelm
// the logging.)
const int DBG_DHCP6_DETAIL = DBGLVL_TRACE_DETAIL;
// This level is used to log the contents of packets received and sent.
const int DBG_DHCP6_DETAIL_DATA = DBGLVL_TRACE_DETAIL_DATA;
/// Define the logger for the "dhcp6" module part of b10-dhcp6. We could define
/// 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 isc::log::Logger dhcp6_logger;
} // namespace dhcp6
} // namespace isc
#endif // __DHCP6_LOG__H
......@@ -14,23 +14,25 @@
#include <stdlib.h>
#include <time.h>
#include <asiolink/io_address.h>
#include <dhcp6/dhcp6_log.h>
#include <dhcp6/dhcp6_srv.h>
#include <dhcp/dhcp6.h>
#include <dhcp/pkt6.h>
#include <dhcp/iface_mgr.h>
#include <dhcp6/dhcp6_srv.h>
#include <dhcp/option6_ia.h>
#include <dhcp/option6_iaaddr.h>
#include <dhcp/option6_addrlst.h>
#include <asiolink/io_address.h>
#include <dhcp/option6_iaaddr.h>
#include <dhcp/option6_ia.h>
#include <dhcp/pkt6.h>
#include <exceptions/exceptions.h>
#include <util/io_utilities.h>
#include <util/range_utilities.h>
using namespace std;
using namespace isc;
using namespace isc::dhcp;
using namespace isc::asiolink;
using namespace isc::dhcp;
using namespace isc::util;
using namespace std;
const std::string HARDCODED_LEASE = "2001:db8:1::1234:abcd";
const uint32_t HARDCODED_T1 = 1500; // in seconds
......@@ -40,14 +42,14 @@ const uint32_t HARDCODED_VALID_LIFETIME = 7200; // in seconds
const std::string HARDCODED_DNS_SERVER = "2001:db8:1::1";
Dhcpv6Srv::Dhcpv6Srv(uint16_t port) {
cout << "Initialization: opening sockets on port " << port << endl;
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_START, DHCP6_OPEN_SOCKET).arg(port);
// first call to instance() will create IfaceMgr (it's a singleton)
// First call to instance() will create IfaceMgr (it's a singleton)
// it may throw something if things go wrong
try {
if (IfaceMgr::instance().countIfaces() == 0) {
cout << "Failed to detect any network interfaces. Aborting." << endl;
LOG_ERROR(dhcp6_logger, DHCP6_NO_INTERFACES);
shutdown_ = true;
return;
}
......@@ -59,7 +61,7 @@ Dhcpv6Srv::Dhcpv6Srv(uint16_t port) {
/// @todo: instantiate LeaseMgr here once it is imlpemented.
} catch (const std::exception &e) {
cerr << "Error during DHCPv4 server startup: " << e.what() << endl;
LOG_ERROR(dhcp6_logger, DHCP6_SRV_CONSTRUCT_ERROR).arg(e.what());
shutdown_ = true;
return;
}
......@@ -68,13 +70,11 @@ Dhcpv6Srv::Dhcpv6Srv(uint16_t port) {
}
Dhcpv6Srv::~Dhcpv6Srv() {
cout << "DHCPv6 Srv shutdown." << endl;
IfaceMgr::instance().closeSockets();
}
void Dhcpv6Srv::shutdown() {
cout << "b10-dhcp6: DHCPv6 server shutdown." << endl;
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_BASIC, DHCP6_SHUTDOWN_REQUEST);
shutdown_ = true;
}
......@@ -89,42 +89,58 @@ bool Dhcpv6Srv::run() {
if (query) {
if (!query->unpack()) {
cout << "Failed to parse incoming packet" << endl;
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_DETAIL,
DHCP6_PACKET_PARSE_FAIL);
continue;
}
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_DETAIL, DHCP6_PACKET_RECEIVED)
.arg(serverReceivedPacketName(query->getType()))
.arg(query->getType());
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_DETAIL_DATA, DHCP6_QUERY_DATA)
.arg(query->getType())
.arg(query->getBuffer().getLength())
.arg(query->toText());
switch (query->getType()) {
case DHCPV6_SOLICIT:
rsp = processSolicit(query);
break;
case DHCPV6_REQUEST:
rsp = processRequest(query);
break;
case DHCPV6_RENEW:
rsp = processRenew(query);
break;
case DHCPV6_REBIND:
rsp = processRebind(query);
break;
case DHCPV6_CONFIRM:
rsp = processConfirm(query);
break;
case DHCPV6_RELEASE:
rsp = processRelease(query);
break;
case DHCPV6_DECLINE:
rsp = processDecline(query);
break;
case DHCPV6_INFORMATION_REQUEST:
rsp = processInfRequest(query);
break;
default:
cout << "Unknown pkt type received:"
<< query->getType() << endl;
// Only action is to output a message if debug is enabled,
// and that will be covered by the debug statement before
// the "switch" statement.
;
}
cout << "Received " << query->getBuffer().getLength() << " bytes packet type="
<< query->getType() << endl;
cout << query->toText();
if (rsp) {
rsp->setRemoteAddr(query->getRemoteAddr());
rsp->setLocalAddr(query->getLocalAddr());
......@@ -132,14 +148,16 @@ bool Dhcpv6Srv::run() {
rsp->setLocalPort(DHCP6_SERVER_PORT);
rsp->setIndex(query->getIndex());
rsp->setIface(query->getIface());
cout << "Replying with:" << rsp->getType() << endl;
cout << rsp->toText();
cout << "----" << endl;
if (!rsp->pack()) {
cout << "Failed to assemble response packet." << endl;
continue;
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_DETAIL_DATA,
DHCP6_RESPONSE_DATA)
.arg(rsp->getType()).arg(rsp->toText());
if (rsp->pack()) {
IfaceMgr::instance().send(rsp);
} else {
LOG_ERROR(dhcp6_logger, DHCP6_PACK_FAIL);
}
IfaceMgr::instance().send(rsp);
}
}
......@@ -350,3 +368,46 @@ Pkt6Ptr Dhcpv6Srv::processInfRequest(const Pkt6Ptr& infRequest) {
Pkt6Ptr reply(new Pkt6(DHCPV6_REPLY, infRequest->getTransid()));
return reply;
}
const char*
Dhcpv6Srv::serverReceivedPacketName(uint8_t type) {
static const char* CONFIRM = "CONFIRM";
static const char* DECLINE = "DECLINE";
static const char* INFORMATION_REQUEST = "INFORMATION_REQUEST";
static const char* REBIND = "REBIND";
static const char* RELEASE = "RELEASE";
static const char* RENEW = "RENEW";
static const char* REQUEST = "REQUEST";
static const char* SOLICIT = "SOLICIT";
static const char* UNKNOWN = "UNKNOWN";
switch (type) {
case DHCPV6_CONFIRM:
return (CONFIRM);
case DHCPV6_DECLINE:
return (DECLINE);
case DHCPV6_INFORMATION_REQUEST:
return (INFORMATION_REQUEST);
case DHCPV6_REBIND:
return (REBIND);
case DHCPV6_RELEASE:
return (RELEASE);
case DHCPV6_RENEW:
return (RENEW);
case DHCPV6_REQUEST:
return (REQUEST);
case DHCPV6_SOLICIT:
return (SOLICIT);
default:
;
}
return (UNKNOWN);
}
......@@ -69,6 +69,24 @@ public:
/// @brief Instructs the server to shut down.
void shutdown();
/// @brief Return textual type of packet received by server
///
/// Returns the name of valid packet received by the server (e.g. DISCOVER).
/// If the packet is unknown - or if it is a valid DHCP packet but not one
/// expected to be received by the server (such as an OFFER), the string
/// "UNKNOWN" is returned. This methos is used in debug messages.
///
/// As the operation of the method does not depend on any server state, it
/// is declared static.
///
/// @param type DHCPv4 packet type
///
/// @return Pointer to "const" string containing the packet name.
/// Note that this string is statically allocated and MUST NOT
/// be freed by the caller.
static const char* serverReceivedPacketName(uint8_t type);
protected:
/// @brief Processes incoming SOLICIT and returns response.
///
......
......@@ -14,13 +14,15 @@
#include <config.h>
#include <iostream>
#include <log/dummylog.h>
#include <log/logger_support.h>
#include <dhcp6/ctrl_dhcp6_srv.h>
#include <boost/lexical_cast.hpp>
using namespace std;
#include <dhcp6/ctrl_dhcp6_srv.h>
#include <dhcp6/dhcp6_log.h>
#include <log/logger_support.h>
using namespace isc::dhcp;
using namespace std;
/// This file contains entry point (main() function) for standard DHCPv6 server
/// component for BIND10 framework. It parses command-line arguments and
......@@ -37,11 +39,10 @@ const char* const DHCP6_NAME = "b10-dhcp6";
void
usage() {
cerr << "Usage: b10-dhcp6 [-v]"
<< endl;
cerr << "\t-v: verbose output" << endl;
cerr << "\t-s: stand-alone mode (don't connect to BIND10)" << endl;
cerr << "\t-p number: specify non-standard port number 1-65535 "
cerr << "Usage: " << DHCP6_NAME << " [-v] [-s] [-p number]" << endl;
cerr << " -v: verbose output" << endl;
cerr << " -s: stand-alone mode (don't connect to BIND10)" << endl;
cerr << " -p number: specify non-standard port number 1-65535 "
<< "(useful for testing only)" << endl;
exit(EXIT_FAILURE);
}
......@@ -52,18 +53,19 @@ main(int argc, char* argv[]) {
int ch;
int port_number = DHCP6_SERVER_PORT; // The default. Any other values are
// useful for testing only.
bool stand_alone = false; // Should be connect to BIND10 msgq?
bool verbose_mode = false; // Should server be verbose?
bool stand_alone = false; // should be connect to BIND10 msgq?
while ((ch = getopt(argc, argv, "vsp:")) != -1) {
switch (ch) {
case 'v':
verbose_mode = true;
isc::log::denabled = true;
break;
case 's':
stand_alone = true;
break;
case 'p':
try {
port_number = boost::lexical_cast<int>(optarg);
......@@ -78,51 +80,45 @@ main(int argc, char* argv[]) {
usage();
}
break;
case ':':
default:
usage();
}
}
// Check for extraneous parameters.
if (argc > optind) {
usage();
}
// Initialize logging. If verbose, we'll use maximum verbosity.
isc::log::initLogger(DHCP6_NAME,
(verbose_mode ? isc::log::DEBUG : isc::log::INFO),
isc::log::MAX_DEBUG_LEVEL, NULL);
cout << "b10-dhcp6: My pid=" << getpid() << ", binding to port "
<< port_number << ", verbose " << (verbose_mode?"yes":"no")
<< ", stand-alone=" << (stand_alone?"yes":"no") << endl;
if (argc - optind > 0) {
usage();
}
LOG_INFO(dhcp6_logger, DHCP6_STARTING);
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_START, DHCP6_START_INFO)
.arg(getpid()).arg(port_number).arg(verbose_mode ? "yes" : "no")
.arg(stand_alone ? "yes" : "no" );
int ret = EXIT_SUCCESS;
try {
cout << "b10-dhcp6: Initiating DHCPv6 server operation." << endl;
/// @todo: pass verbose to the actual server once logging is implemented
ControlledDhcpv6Srv server(port_number);
if (!stand_alone) {
try {
server.establishSession();
} catch (const std::exception& ex) {
cerr << "Failed to establish BIND10 session. "
"Running in stand-alone mode:" << ex.what() << endl;
LOG_ERROR(dhcp6_logger, DHCP6_SESSION_FAIL).arg(ex.what());
// Let's continue. It is useful to have the ability to run
// DHCP server in stand-alone mode, e.g. for testing
}
} else {
cout << "Skipping connection to the BIND10 msgq." << endl;
LOG_DEBUG(dhcp6_logger, DBG_DHCP6_START, DHCP6_STANDALONE);
}
server.run();
LOG_INFO(dhcp6_logger, DHCP6_SHUTDOWN);
} catch (const std::exception& ex) {
cerr << "[b10-dhcp6] Server failed: " << ex.what() << endl;
LOG_FATAL(dhcp6_logger, DHCP6_SERVER_FAILED).arg(ex.what());
ret = EXIT_FAILURE;
}
......
......@@ -42,10 +42,13 @@ if HAVE_GTEST
TESTS += dhcp6_unittests
dhcp6_unittests_SOURCES = ../dhcp6_srv.h ../dhcp6_srv.cc ../ctrl_dhcp6_srv.cc
dhcp6_unittests_SOURCES += dhcp6_unittests.cc
dhcp6_unittests_SOURCES = dhcp6_unittests.cc
dhcp6_unittests_SOURCES += dhcp6_srv_unittest.cc
dhcp6_unittests_SOURCES += ctrl_dhcp6_srv_unittest.cc
dhcp6_unittests_SOURCES += ../dhcp6_srv.h ../dhcp6_srv.cc
dhcp6_unittests_SOURCES += ../dhcp6_log.h ../dhcp6_log.cc
dhcp6_unittests_SOURCES += ../dhcp6_messages.h ../dhcp6_messages.cc
dhcp6_unittests_SOURCES += ../ctrl_dhcp6_srv.cc
if USE_CLANGPP
# Disable unused parameter warning caused by some of the
......
......@@ -223,4 +223,49 @@ TEST_F(Dhcpv6SrvTest, Solicit_basic) {
// more checks to be implemented
}
TEST_F(Dhcpv6SrvTest, serverReceivedPacketName) {
// Check all possible packet types
for (int itype = 0; itype < 256; ++itype) {
uint8_t type = itype;
switch (type) {
case DHCPV6_CONFIRM:
EXPECT_STREQ("CONFIRM", Dhcpv6Srv::serverReceivedPacketName(type));
break;
case DHCPV6_DECLINE:
EXPECT_STREQ("DECLINE", Dhcpv6Srv::serverReceivedPacketName(type));
break;
case DHCPV6_INFORMATION_REQUEST:
EXPECT_STREQ("INFORMATION_REQUEST",
Dhcpv6Srv::serverReceivedPacketName(type));
break;
case DHCPV6_REBIND:
EXPECT_STREQ("REBIND", Dhcpv6Srv::serverReceivedPacketName(type));
break;
case DHCPV6_RELEASE:
EXPECT_STREQ("RELEASE", Dhcpv6Srv::serverReceivedPacketName(type));
break;
case DHCPV6_RENEW: