Commit 7f36e034 authored by Shawn Routhier's avatar Shawn Routhier
Browse files

[master] Merge in log support for LFC

Add log support for LFC

Add statistics support in lease files used
by LFC to report stats for leases.

Update memfile tests to check that LFC
did the right thing.

Merge branch 'trac3667'

Conflicts:
	ChangeLog
	src/lib/util/csv_file.h
parents 4d4d074e 59e1089f
XXX. [func] sar
A class, LeaseFileStats, has been added to provide simple
statistics for use with lease files. Also added logging
to the kea-lfc process per the design.
See http://kea.isc.org/wiki/LFCDesign for the design.
(Trac #3667, git )
891. [func] tomek
libdhcpsrv: Allocation Engine now uses statically assigned
addresses when processing DHCPv6 renewals.
......
......@@ -47,8 +47,8 @@ BUILT_SOURCES = lfc_messages.h lfc_messages.cc
noinst_LTLIBRARIES = liblfc.la
liblfc_la_SOURCES =
liblfc_la_SOURCES += lfc_controller.h
liblfc_la_SOURCES += lfc_controller.cc
liblfc_la_SOURCES += lfc_controller.h lfc_controller.cc
liblfc_la_SOURCES += lfc_log.h lfc_log.cc
nodist_liblfc_la_SOURCES = lfc_messages.h lfc_messages.cc
EXTRA_DIST += lfc_messages.mes
......
......@@ -13,6 +13,7 @@
// PERFORMANCE OF THIS SOFTWARE.
#include <lfc/lfc_controller.h>
#include <lfc/lfc_log.h>
#include <util/pid_file.h>
#include <exceptions/exceptions.h>
#include <dhcpsrv/csv_lease_file4.h>
......@@ -20,6 +21,8 @@
#include <dhcpsrv/memfile_lease_storage.h>
#include <dhcpsrv/lease_mgr.h>
#include <dhcpsrv/lease_file_loader.h>
#include <log/logger_manager.h>
#include <log/logger_name.h>
#include <config.h>
#include <iostream>
......@@ -31,6 +34,7 @@
using namespace std;
using namespace isc::util;
using namespace isc::dhcp;
using namespace isc::log;
namespace {
/// @brief Maximum number of errors to allow when reading leases from the file.
......@@ -56,9 +60,17 @@ LFCController::~LFCController() {
}
void
LFCController::launch(int argc, char* argv[]) {
LFCController::launch(int argc, char* argv[], const bool test_mode) {
bool do_rotate = true;
// It would be nice to set up the logger as the first step
// in the process, but we don't know where to send logging
// info until after we have parsed our arguments. As we
// don't currently log anything when trying to parse the
// arguments we do the parse before the logging setup. If
// we do decide to log something then the code will need
// to move around a bit.
try {
parseArgs(argc, argv);
} catch (const InvalidUsage& ex) {
......@@ -66,9 +78,10 @@ LFCController::launch(int argc, char* argv[]) {
throw; // rethrow it
}
if (verbose_) {
std::cerr << "Starting lease file cleanup" << std::endl;
}
// Start up the logging system.
startLogger(test_mode);
LOG_INFO(lfc_logger, LFC_START);
// verify we are the only instance
PIDFile pid_file(pid_file_);
......@@ -76,14 +89,14 @@ LFCController::launch(int argc, char* argv[]) {
try {
if (pid_file.check()) {
// Already running instance, bail out
std::cerr << "LFC instance already running" << std::endl;
LOG_FATAL(lfc_logger, LFC_RUNNING);
return;
}
// create the pid file for this instance
pid_file.write();
} catch (const PIDFileError& pid_ex) {
std::cerr << pid_ex.what() << std::endl;
LOG_FATAL(lfc_logger, LFC_FAIL_PID_CREATE).arg(pid_ex.what());
return;
}
......@@ -92,9 +105,9 @@ LFCController::launch(int argc, char* argv[]) {
// all we care about is if it exists so that's okay
CSVFile lf_finish(getFinishFile());
if (!lf_finish.exists()) {
if (verbose_) {
std::cerr << "LFC Processing files" << std::endl;
}
LOG_INFO(lfc_logger, LFC_PROCESSING)
.arg(previous_file_)
.arg(copy_file_);
try {
if (getProtocolVersion() == 4) {
......@@ -105,7 +118,7 @@ LFCController::launch(int argc, char* argv[]) {
} catch (const isc::Exception& proc_ex) {
// We don't want to do the cleanup but do want to get rid of the pid
do_rotate = false;
std::cerr << "Processing failed: " << proc_ex.what() << std::endl;
LOG_FATAL(lfc_logger, LFC_FAIL_PROCESS).arg(proc_ex.what());
}
}
......@@ -114,14 +127,12 @@ LFCController::launch(int argc, char* argv[]) {
// we don't want to return after the catch as we
// still need to cleanup the pid file
if (do_rotate) {
if (verbose_) {
std::cerr << "LFC cleaning files" << std::endl;
}
LOG_INFO(lfc_logger, LFC_ROTATING);
try {
fileRotate();
} catch (const RunTimeFail& run_ex) {
std::cerr << run_ex.what() << std::endl;
LOG_FATAL(lfc_logger, LFC_FAIL_ROTATE).arg(run_ex.what());
}
}
......@@ -129,12 +140,10 @@ LFCController::launch(int argc, char* argv[]) {
try {
pid_file.deleteFile();
} catch (const PIDFileError& pid_ex) {
std::cerr << pid_ex.what() << std::endl;
LOG_FATAL(lfc_logger, LFC_FAIL_PID_DEL).arg(pid_ex.what());
}
if (verbose_) {
std::cerr << "LFC complete" << std::endl;
}
LOG_INFO(lfc_logger, LFC_TERMINATE);
}
void
......@@ -272,7 +281,7 @@ LFCController::parseArgs(int argc, char* argv[]) {
// If verbose is set echo the input information
if (verbose_) {
std::cerr << "Protocol version: DHCPv" << protocol_version_ << std::endl
std::cout << "Protocol version: DHCPv" << protocol_version_ << std::endl
<< "Previous or ex lease file: " << previous_file_ << std::endl
<< "Copy lease file: " << copy_file_ << std::endl
<< "Output lease file: " << output_file_ << std::endl
......@@ -340,6 +349,17 @@ LFCController::processLeases() const {
LeaseFileType lf_output(getOutputFile());
LeaseFileLoader::write<LeaseObjectType>(lf_output, storage);
// If desired log the stats
LOG_INFO(lfc_logger, LFC_READ_STATS)
.arg(lf_prev.getReadLeases() + lf_copy.getReadLeases())
.arg(lf_prev.getReads() + lf_copy.getReads())
.arg(lf_prev.getReadErrs() + lf_copy.getReadErrs());
LOG_INFO(lfc_logger, LFC_WRITE_STATS)
.arg(lf_output.getWriteLeases())
.arg(lf_output.getWrites())
.arg(lf_output.getWriteErrs());
// Once we've finished the output file move it to the complete file
if (rename(getOutputFile().c_str(), getFinishFile().c_str()) != 0) {
isc_throw(RunTimeFail, "Unable to move output (" << output_file_
......@@ -371,5 +391,40 @@ LFCController::fileRotate() const {
<< ") error: " << strerror(errno));
}
}
void
LFCController::startLogger(const bool test_mode) const {
// If we are running in test mode use the environment variables
// else use our defaults
if (test_mode) {
initLogger();
}
else {
OutputOption option;
LoggerManager manager;
initLogger(lfc_app_name_, INFO, 0, NULL, false);
// Prepare the objects to define the logging specification
LoggerSpecification spec(getRootLoggerName(),
keaLoggerSeverity(INFO),
keaLoggerDbglevel(0));
// If we are running in verbose (debugging) mode
// we send the output to the console, otherwise
// by default we send it to the SYSLOG
if (verbose_) {
option.destination = OutputOption::DEST_CONSOLE;
} else {
option.destination = OutputOption::DEST_SYSLOG;
}
// ... and set the destination
spec.addOutputOption(option);
manager.process(spec);
}
}
}; // namespace isc::lfc
}; // namespace isc
......@@ -77,9 +77,13 @@ public:
///
/// @param argc Number of strings in the @c argv array.
/// @param argv Array of arguments passed in via the program's main function.
/// @param test_mode is a bool value which indicates if @c launch
/// should be run in the test mode (if true). This parameter doesn't
/// have a default value to force test implementers to enable test
/// mode explicitly.
///
/// @throw InvalidUsage if the command line parameters are invalid.
void launch(int argc, char* argv[]);
void launch(int argc, char* argv[], const bool test_mode);
/// @brief Process the command line arguments.
///
......@@ -192,6 +196,12 @@ private:
/// @throw RunTimeFail if we can't move the file.
template<typename LeaseObjectType, typename LeaseFileType, typename StorageType>
void processLeases() const;
///@brief Start up the logging system
///
/// @param test_mode indicates if we have have been started from the test
/// system (true) or are running normally (false)
void startLogger(const bool test_mode) const;
};
}; // namespace isc::lfc
......
// Copyright (C) 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
// 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 kea-lfc.
#include <lfc/lfc_log.h>
namespace isc {
namespace lfc {
/// @brief Defines the logger used within LFC.
isc::log::Logger lfc_logger("DhcpLFC");
} // namespace lfc
} // namespace isc
// Copyright (C) 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
// 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 LFC_LOG_H
#define LFC_LOG_H
#include <log/logger_support.h>
#include <log/macros.h>
#include <lfc/lfc_messages.h>
namespace isc {
namespace lfc {
/// Define the logger for the "lfc" logging.
extern isc::log::Logger lfc_logger;
} // namespace lfc
} // namespace isc
#endif // LFC_LOG_H
......@@ -13,5 +13,48 @@
# PERFORMANCE OF THIS SOFTWARE.
$NAMESPACE isc::lfc
% LFC_TEST_MESSAGE test messages
This is a test and placeholder debug message
% LFC_START Starting lease file cleanup
This message is issued as the LFC process starts.
% LFC_TERMINATE LFC finished processing
This message is issued when the LFC process completes. It does not
indicate that the process was successful only that it has finished.
% LFC_RUNNING LFC instance already running
This message is issued if LFC detects that a previous copy of LFC
may still be running via the PID check.
% LFC_PROCESSING Previous file: %1, copy file: %2
This message is issued just before LFC starts processing the
lease files.
% LFC_ROTATING LFC rotating files
This message is issued just before LFC starts rotating the
lease files - removing the old and replacing them with the new.
% LFC_FAIL_PID_CREATE : %1
This message is issued if LFC detected a failure when trying
to create the PID file. It includes a more specifc error string.
% LFC_FAIL_PROCESS : %1
This message is issued if LFC detected a failure when trying
to process the files. It includes a more specifc error string.
% LFC_FAIL_ROTATE : %1
This message is issued if LFC detected a failure when trying
to rotate the files. It includes a more specifc error string.
% LFC_FAIL_PID_DEL : %1
This message is issued if LFC detected a failure when trying
to delete the PID file. It includes a more specifc error string.
% LFC_READ_STATS Leases: %1, attempts: %2, errors: %3.
This message prints out the number of leases that were read, the
number of attempts to read leases and the number of errors
encountered while reading.
% LFC_WRITE_STATS Leases: %1, attempts: %2, errors: %3.
This message prints out the number of leases that were written, the
number of attempts to write leases and the number of errors
encountered while writing.
......@@ -19,8 +19,8 @@
#include <config.h>
#include <iostream>
using namespace isc::lfc;
using namespace std;
using namespace isc::lfc;
/// This file contains the entry point (main() function) for the
/// standard LFC process, kea-lfc, component of the Kea software suite.
......@@ -36,7 +36,7 @@ int main(int argc, char* argv[]) {
// Exit program with the controller's return code.
try {
// 'false' value disables test mode.
lfc_controller.launch(argc, argv);
lfc_controller.launch(argc, argv, false);
} catch (const isc::Exception& ex) {
std::cerr << "Service failed: " << ex.what() << std::endl;
ret = EXIT_FAILURE;
......
......@@ -75,7 +75,7 @@ public:
}
protected:
/// @brief Sets up the file names and header string and removes
/// @brief Sets up the file names and header string and removes
/// any old test files before the test
virtual void SetUp() {
// set up the test files we need
......@@ -105,6 +105,13 @@ protected:
removeTestFile();
}
/// @Wrapper to invoke the controller's launch method Please refer to
/// lfcController::launch for details. This is wrapped to provide
/// a single place to update the test_mode throughout the file.
void launch(LFCController lfc_controller, int argc, char* argv[]) {
lfc_controller.launch(argc, argv, true);
}
private:
};
......@@ -348,7 +355,7 @@ TEST_F(LFCControllerTest, fileRotate) {
writeFile(istr_, "11");
writeFile(fstr_, "12");
lfc_controller_launch.launch(argc, argv);
launch(lfc_controller_launch, argc, argv);
// verify finish is now previous and no temp files or pid remain.
EXPECT_EQ(readFile(xstr_), "12");
......@@ -426,7 +433,7 @@ TEST_F(LFCControllerTest, launch4) {
writeFile(istr_, test_str);
// Run the cleanup
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// Compare the results, we expect the last lease for each ip
// except for C which was invalid and D which has expired.
......@@ -445,7 +452,7 @@ TEST_F(LFCControllerTest, launch4) {
// No copy file
// Run the cleanup
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// Compare the results, we expect the last lease for each ip
// except for C which was invalid and D which has expired.
......@@ -464,7 +471,7 @@ TEST_F(LFCControllerTest, launch4) {
writeFile(istr_, test_str);
// Run the cleanup
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// Compare the results, we expect the last lease for each ip
// except for C which was invalid and D which has expired.
......@@ -481,7 +488,7 @@ TEST_F(LFCControllerTest, launch4) {
// No copy file
// Run the cleanup
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// Compare the results, we expect a header and no leaes.
// We also verify none of the temp or pid files remain.
......@@ -502,7 +509,7 @@ TEST_F(LFCControllerTest, launch4) {
// Run the cleanup, the file should fail but we should
// catch the error and properly cleanup.
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// And we shouldn't have deleted the previous file.
// We also verify none of the temp or pid files remain.
......@@ -563,10 +570,10 @@ TEST_F(LFCControllerTest, launch6) {
string b_3 = "2001:db8:2::10,01:01:01:01:0a:01:02:03:04:05,"
"300,1000,6,150,0,8,0,0,0,,\n";
string c_1 = "3000:1::,00:01:02:03:04:05:06:0a:0b:0c:0d:0e:0f,100,200,8,0,2,"
"16,64,0,0,,\n";
string c_2 = "3000:1::,00:01:02:03:04:05:06:0a:0b:0c:0d:0e:0f,100,400,8,0,2,"
"16,64,0,0,,\n";
string c_1 = "3000:1::,00:01:02:03:04:05:06:0a:0b:0c:0d:0e:0f,"
"100,200,8,0,2,16,64,0,0,,\n";
string c_2 = "3000:1::,00:01:02:03:04:05:06:0a:0b:0c:0d:0e:0f,"
"100,400,8,0,2,16,64,0,0,,\n";
string d_1 = "2001:db8:1::3,00:01:02:03:04:05:06:0a:0b:0c:0d:0e:0f,"
"200,600,8,100,0,7,0,1,1,host.example.com,\n";
......@@ -581,7 +588,7 @@ TEST_F(LFCControllerTest, launch6) {
writeFile(istr_, test_str);
// Run the cleanup
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// Compare the results, we expect the last lease for each ip
// except for A which has expired.
......@@ -600,7 +607,7 @@ TEST_F(LFCControllerTest, launch6) {
// No copy file
// Run the cleanup
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// Compare the results, we expect the last lease for each ip.
// We also verify none of the temp or pid files remain.
......@@ -618,7 +625,7 @@ TEST_F(LFCControllerTest, launch6) {
writeFile(istr_, test_str);
// Run the cleanup
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// Compare the results, we expect the last lease for each ip.
// We also verify none of the temp or pid files remain.
......@@ -634,7 +641,7 @@ TEST_F(LFCControllerTest, launch6) {
// No copy file
// Run the cleanup
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// Compare the results, we expect a header and no leases.
// We also verify none of the temp or pid files remain.
......@@ -655,7 +662,7 @@ TEST_F(LFCControllerTest, launch6) {
// Run the cleanup, the file should fail but we should
// catch the error and properly cleanup.
lfc_controller.launch(argc, argv);
launch(lfc_controller, argc, argv);
// And we shouldn't have deleted the previous file.
// We also verify none of the temp or pid files remain.
......
......@@ -86,6 +86,7 @@ libkea_dhcpsrv_la_SOURCES += host_mgr.cc host_mgr.h
libkea_dhcpsrv_la_SOURCES += key_from_key.h
libkea_dhcpsrv_la_SOURCES += lease.cc lease.h
libkea_dhcpsrv_la_SOURCES += lease_file_loader.h
libkea_dhcpsrv_la_SOURCES += lease_file_stats.h
libkea_dhcpsrv_la_SOURCES += lease_mgr.cc lease_mgr.h
libkea_dhcpsrv_la_SOURCES += lease_mgr_factory.cc lease_mgr_factory.h
libkea_dhcpsrv_la_SOURCES += logging.cc logging.h
......
// Copyright (C) 2014 Internet Systems Consortium, Inc. ("ISC")
// Copyright (C) 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
......@@ -26,10 +26,25 @@ CSVLeaseFile4::CSVLeaseFile4(const std::string& filename)
}
void
CSVLeaseFile4::append(const Lease4& lease) const {
CSVLeaseFile4::open(const bool seek_to_end) {
// Call the base class to open the file
CSVFile::open(seek_to_end);
// and clear any statistics we may have
clearStatistics();
}
void
CSVLeaseFile4::append(const Lease4& lease) {
// Bump the number of write attempts
++writes_;
CSVRow row(getColumnCount());
row.writeAt(getColumnIndex("address"), lease.addr_.toText());
if (!lease.hwaddr_) {
// Bump the error counter
++write_errs_;
isc_throw(BadValue, "Lease4 must have hardware address specified.");
}
row.writeAt(getColumnIndex("hwaddr"), lease.hwaddr_->toText(false));
......@@ -43,11 +58,24 @@ CSVLeaseFile4::append(const Lease4& lease) const {
row.writeAt(getColumnIndex("fqdn_fwd"), lease.fqdn_fwd_);
row.writeAt(getColumnIndex("fqdn_rev"), lease.fqdn_rev_);
row.writeAt(getColumnIndex("hostname"), lease.hostname_);
CSVFile::append(row);
try {
CSVFile::append(row);
} catch (const std::exception& ex) {
// Catch any errors so we can bump the error counter than rethrow it
++write_errs_;
throw;
}
// Bump the number of leases written
++write_leases_;
}
bool
CSVLeaseFile4::next(Lease4Ptr& lease) {
// Bump the number of read attempts
++reads_;
// Read the CSV row and try to create a lease from the values read.
// This may easily result in exception. We don't want this function
// to throw exceptions, so we catch them all and rather return the
......@@ -88,12 +116,19 @@ CSVLeaseFile4::next(Lease4Ptr& lease) {
readHostname(row)));
} catch (std::exception& ex) {
// bump the read error count
++read_errs_;
// The lease might have been created, so let's set it back to NULL to
// signal that lease hasn't been parsed.
lease.reset();
setReadMsg(ex.what());
return (false);
}
// bump the number of leases read
++read_leases_;
return (true);
}
......
// Copyright (C) 2014 Internet Systems Consortium, Inc. ("ISC")
// Copyright (C) 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,6 +19,7 @@
#include <dhcp/duid.h>
#include <dhcpsrv/lease.h>
#include <dhcpsrv/subnet.h>
#include <dhcpsrv/lease_file_stats.h>
#include <util/csv_file.h>
#include <stdint.h>
#include <string>
......@@ -38,7 +39,7 @@ namespace dhcp {
/// validation (see http://kea.isc.org/ticket/2405). However, when #2405
/// is implemented, the @c next function may need to be updated to use the
/// validation capablity of @c Lease4.
class CSVLeaseFile4 : public isc::util::CSVFile {
class CSVLeaseFile4 : public isc::util::CSVFile, public LeaseFileStats {
public:
/// @brief Constructor.
......@@ -48,6 +49,15 @@ public:
/// @param filename Name of the lease file.
CSVLeaseFile4(const std::string& filename);
/// @brief Opens a lease file.
///
/// This function calls the base class open to do the
/// work of opening a file. It is used to clear any
/// statistics associated with any previous use of the file
/// While it doesn't throw any exceptions of its own
/// the base class may do so.
virtual void open(const bool seek_to_end = false);