[3669] Improved error handling when triggering LFC.

Introduced a couple of new log messages and improved unit tests.

src/lib/dhcpsrv/Makefile.am

@@ -3,9 +3,12 @@ AUTOMAKE_OPTIONS = subdir-objects
 SUBDIRS = . testutils tests
 
 dhcp_data_dir = @localstatedir@/@PACKAGE@
+kea_lfc_location = @prefix@/sbin/kea-lfc
 
 AM_CPPFLAGS = -I$(top_builddir)/src/lib -I$(top_srcdir)/src/lib -DDHCP_DATA_DIR="\"$(dhcp_data_dir)\""
 AM_CPPFLAGS += -DTOP_BUILDDIR="\"$(top_builddir)\""
+# Set location of the kea-lfc binary.
+AM_CPPFLAGS += -DKEA_LFC_EXECUTABLE="\"$(kea_lfc_location)\""
 AM_CPPFLAGS += $(BOOST_INCLUDES)
 if HAVE_MYSQL
 AM_CPPFLAGS += $(MYSQL_CPPFLAGS)

src/lib/dhcpsrv/dhcpsrv_messages.mes

@@ -292,15 +292,39 @@ replaced by those read from the file.
 % DHCPSRV_MEMFILE_LEASE_LOAD loading lease %1
 A debug message issued when DHCP lease is being loaded from the file to memory.
 
+% DHCPSRV_MEMFILE_LFC_LEASE_FILE_REOPEN_FAIL failed to reopen lease file %1 after preparing input file for lease file cleanup: new leases will not be persisted!
+An error message logged when the Memfile lease database backend
+failed to re-open or re-create the lease file after moving the
+lease file to an input file for lease file cleanup. The server
+will continue to operate but leases will not be persisted to
+disk.
+
 % DHCPSRV_MEMFILE_LFC_SETUP setting up the Lease File Cleanup interval to %1 sec
 An informational message logged when the Memfile lease database backend
 configures the LFC to be executed periodically. The argument holds the
 interval in seconds in which the LFC will be executed.
 
+% DHCPSRV_MEMFILE_LFC_ROTATION_FAIL failed to rotate the current lease file %1 to %2
+An error message logged when the Memfile lease database backend fails to
+move the current lease file to a new file on which the cleanup should
+be performed. This effectively means that the lease file cleanup
+will be abandoned.
+
+% DHCPSRV_MEMFILE_LFC_SPAWN_FAIL lease file cleanup failed to run because kea-lfc process couldn't be spawned
+An error message logged when spawning kea-lfc application, which performs
+a lease file cleanup, failed. The server will try at the time at which
+the next lease file cleanup is scheduled.
+
 % DHCPSRV_MEMFILE_LFC_START starting Lease File Cleanup
 An informational message issued when the Memfile lease database backend
 starts the periodic Lease File Cleanup.
 
+% DHCPSRV_MEMFILE_LFC_EXECUTE executing Lease File Cleanup using: %1
+An informational message issued when the Memfile lease database backend
+starts the new process to perform Lease File Cleanup. Since the cleanup
+is performed in background, it is not guaranteed that the cleanup will
+be successful.
+
 % DHCPSRV_MEMFILE_NO_STORAGE running in non-persistent mode, leases will be lost after restart
 A warning message issued when writes of leases to disk have been disabled
 in the configuration. This mode is useful for some kinds of performance

src/lib/dhcpsrv/memfile_lease_mgr.cc

@@ -27,6 +27,13 @@ namespace {
 /// @brief Maximum number of errors to read the leases from the lease file.
 const uint32_t MAX_LEASE_ERRORS = 100;
 
+/// @brief A name of the environmental variable specifying the kea-lfc
+/// program location.
+///
+/// This variable can be set by tests to point to the location of the
+/// kea-lfc program within a build directory. If this variable is not
+/// set, the backend will use the location of the kea-lfc in the
+/// Kea installation directory.
 const char* KEA_LFC_EXECUTABLE_ENV_NAME = "KEA_LFC_EXECUTABLE";
 
 } // end of anonymous namespace
@@ -538,7 +545,14 @@ Memfile_LeaseMgr::lfcSetup() {
     // If LFC is enabled, we have to setup the interval timer and prepare for
     // executing the kea-lfc process.
     if (lfc_interval > 0) {
+        std::string executable;
         char* c_executable = getenv(KEA_LFC_EXECUTABLE_ENV_NAME);
+        if (c_executable == NULL) {
+            executable = KEA_LFC_EXECUTABLE;
+
+        } else {
+            executable = c_executable;
+        }
 
         // Set the timer to call callback function periodically.
         asiolink::IntervalTimer::Callback cb =
@@ -597,8 +611,8 @@ Memfile_LeaseMgr::lfcCallback() {
 }
 
 template<typename LeaseFileType>
-void Memfile_LeaseMgr::
-leaseFileCleanup(boost::shared_ptr<LeaseFileType>& lease_file) {
+void Memfile_LeaseMgr::leaseFileCleanup(boost::shared_ptr<LeaseFileType>& lease_file) {
+    bool do_lfc = true;
     // Check if the copy of the lease file exists already. If it does, it
     // is an indication that another LFC instance may be in progress, in
     // which case we don't want to rotate the current lease file to avoid
@@ -607,24 +621,60 @@ leaseFileCleanup(boost::shared_ptr<LeaseFileType>& lease_file) {
     if (!lease_file_copy.exists()) {
         // Close the current file so as we can move it to the copy file.
         lease_file->close();
-        // Move the current file to the copy file.
-        rename(lease_file->getFilename().c_str(),
-               lease_file_copy.getFilename().c_str());
-        // Now that we moved the current file, we need to create a new one.
-        lease_file.reset(new LeaseFileType(lease_file->getFilename()));
-        // Leave the new file open for writing.
-        lease_file->open();
+        // Move the current file to the copy file. Remember the result
+        // because we don't want to run LFC if the rename failed.
+        do_lfc = (rename(lease_file->getFilename().c_str(),
+                         lease_file_copy.getFilename().c_str()) == 0);
+
+        // Regardless if we successfully moved the current file or not,
+        // we need to re-open the current file for the server to write
+        // new lease updates. If the file has been successfully moved,
+        // this will result in creation of the new file. Otherwise,
+        // an existing file will be opened.
+        try {
+            lease_file->open(true);
+
+        } catch (const CSVFileError& ex) {
+            // If we're unable to open the lease file this is a serious
+            // error because the server will not be able to persist
+            // leases.
+            /// @todo We need to better address this error. It should
+            /// trigger an alarm (once we have a monitoring system in
+            /// place) so as an administrator can correct it. In
+            /// practice it should be very rare that this happens and
+            /// is most likely related to a human error, e.g. changing
+            /// file permissions.
+            LOG_ERROR(dhcpsrv_logger, DHCPSRV_MEMFILE_LFC_LEASE_FILE_REOPEN_FAIL)
+                .arg(lease_file->getFilename());
+            // Reset the pointer to the file so as the backend doesn't
+            // try to write leases to disk.
+            lease_file.reset();
+            do_lfc = false;
+        }
     }
     // Once we have rotated files as needed, start the new kea-lfc process
     // to perform a cleanup.
-    lfc_process_->spawn();
+    if (do_lfc) {
+        try {
+            lfc_process_->spawn();
+            LOG_INFO(dhcpsrv_logger, DHCPSRV_MEMFILE_LFC_EXECUTE)
+                .arg(lfc_process_->getCommandLine());
+
+        } catch (const ProcessSpawnError& ex) {
+            LOG_ERROR(dhcpsrv_logger, DHCPSRV_MEMFILE_LFC_SPAWN_FAIL);
+        }
+
+    } else {
+        LOG_ERROR(dhcpsrv_logger, DHCPSRV_MEMFILE_LFC_ROTATION_FAIL)
+            .arg(lease_file->getFilename())
+            .arg(lease_file_copy.getFilename());
+    }
 }
 
 template<typename LeaseObjectType, typename LeaseFileType, typename StorageType>
-void Memfile_LeaseMgr::
-loadLeasesFromFiles(const std::string& filename,
-                    boost::shared_ptr<LeaseFileType>& lease_file,
-                    StorageType& storage) {
+void Memfile_LeaseMgr::loadLeasesFromFiles(const std::string& filename,
+                                           boost::shared_ptr<LeaseFileType>& lease_file,
+                                           StorageType& storage) {
     storage.clear();
 
     // Load the leasefile.completed, if exists.

src/lib/dhcpsrv/memfile_lease_mgr.h

@@ -414,7 +414,12 @@ private:
     /// is set to a non-zero value and sets up the interval timer to
     /// perform the Lease File Cleanup periodically. It also prepares the
     /// path and arguments for the @c kea-lfc application which will be
-    /// executed to perform the cleanup.
+    /// executed to perform the cleanup. By default the backend will use
+    /// the path to the kea-lfc in the Kea installation directory. If
+    /// the unit tests need to override this path (with the path in the
+    /// Kea build directory, the @c KEA_LFC_EXECUTABLE environmental
+    /// variable should be set to hold an absolute path to the kea-lfc
+    /// excutable.
     void lfcSetup();
 
     /// @brief Initialize the location of the lease file.
@@ -494,6 +499,13 @@ private:
 
 protected:
 
+    /// @brief An object representing the kea-lfc process.
+    ///
+    /// This object is created when the LFC is configured to be executed
+    /// periodically. It holds the path to kea-lfc program and the
+    /// arguments. When the LFC timer kicks the lease file cleanup
+    /// this object is used to spawn the kea-lfc as a background
+    /// process.
     boost::scoped_ptr<util::ProcessSpawn> lfc_process_;
 
 };

src/lib/dhcpsrv/tests/memfile_lease_mgr_unittest.cc

@@ -27,6 +27,7 @@
 
 #include <boost/bind.hpp>
 
+#include <cstdlib>
 #include <iostream>
 #include <fstream>
 #include <queue>
@@ -394,39 +395,167 @@ TEST_F(MemfileLeaseMgrTest, lfcTimerDisabled) {
     EXPECT_EQ(0, lease_mgr->getLFCCount());
 }
 
-// This test that the callback function performing a Lease File Cleanup
-// works as expected.
-TEST_F(MemfileLeaseMgrTest, leaseFileCleanup) {
+// This test that the callback function executing the cleanup of the
+// DHCPv4 lease file works as expected.
+TEST_F(MemfileLeaseMgrTest, leaseFileCleanup4) {
+    // This string contains the lease file header, which matches
+    // the contents of the new file in which no leases have been
+    // stored.
     std::string new_file_contents =
         "address,hwaddr,client_id,valid_lifetime,expire,"
         "subnet_id,fqdn_fwd,fqdn_rev,hostname\n";
 
+    // This string contains the contents of the lease file with exactly
+    // one lease, but two entries. One of the entries should be removed
+    // as a result of lease file cleanup.
     std::string current_file_contents = new_file_contents +
-        "192.0.2.2,02:02:02:02:02:02,,200,200,8,1,1,,\n";
+        "192.0.2.2,02:02:02:02:02:02,,200,200,8,1,1,,\n"
+        "192.0.2.2,02:02:02:02:02:02,,200,800,8,1,1,,\n";
     LeaseFileIO current_file(getLeaseFilePath("leasefile4_0.csv"));
     current_file.writeFile(current_file_contents);
 
+    std::string previous_file_contents = new_file_contents +
+        "192.0.2.3,03:03:03:03:03:03,,200,200,8,1,1,,\n"
+        "192.0.2.3,03:03:03:03:03:03,,200,800,8,1,1,,\n";
+    LeaseFileIO previous_file(getLeaseFilePath("leasefile4_0.csv.2"));
+    previous_file.writeFile(previous_file_contents);
+
+    // Create the backend.
     LeaseMgr::ParameterMap pmap;
     pmap["type"] = "memfile";
     pmap["universe"] = "4";
     pmap["name"] = getLeaseFilePath("leasefile4_0.csv");
     pmap["lfc-interval"] = "1";
+    boost::scoped_ptr<NakedMemfileLeaseMgr> lease_mgr(new NakedMemfileLeaseMgr(pmap));
 
-    boost::scoped_ptr<NakedMemfileLeaseMgr>
-        lease_mgr(new NakedMemfileLeaseMgr(pmap));
-
+    // Try to run the lease file cleanup.
     ASSERT_NO_THROW(lease_mgr->lfcCallback());
 
+    // The new lease file should have been created and it should contain
+    // no leases.
+    ASSERT_TRUE(current_file.exists());
+    EXPECT_EQ(new_file_contents, current_file.readFile());
+
+    // Wait for the LFC process to complete.
+    ASSERT_TRUE(waitForProcess(*lease_mgr->lfc_process_, 2));
+
+    // And make sure it has returned an exit status of 0.
+    EXPECT_EQ(0, lease_mgr->lfc_process_->getExitStatus());
+
+    /// @todo Replace the following with the checks that the LFC has
+    /// completed successfully, i.e. the leasefile4_0.csv.2 exists
+    /// and it holds the cleaned up lease information.
+
+    // Until the kea-lfc is implemented and performs the cleanup, we can
+    // only check that the backend has moved the lease file to a lease
+    // file with suffix ".1".
     LeaseFileIO input_file(getLeaseFilePath("leasefile4_0.csv.1"), false);
     ASSERT_TRUE(input_file.exists());
+    // And this file should contain the contents of the original file.
     EXPECT_EQ(current_file_contents, input_file.readFile());
+}
+
+// This test that the callback function executing the cleanup of the
+// DHCPv6 lease file works as expected.
+TEST_F(MemfileLeaseMgrTest, leaseFileCleanup6) {
+    // This string contains the lease file header, which matches
+    // the contents of the new file in which no leases have been
+    // stored.
+    std::string new_file_contents =
+        "address,duid,valid_lifetime,expire,subnet_id,"
+        "pref_lifetime,lease_type,iaid,prefix_len,fqdn_fwd,"
+        "fqdn_rev,hostname,hwaddr\n";
+
+    // This string contains the contents of the lease file with exactly
+    // one lease, but two entries. One of the entries should be removed
+    // as a result of lease file cleanup.
+    std::string current_file_contents = new_file_contents +
+        "2001:db8:1::1,00:01:02:03:04:05:06:0a:0b:0c:0d:0e:0f,200,200,"
+        "8,100,0,7,0,1,1,,\n"
+        "2001:db8:1::1,00:01:02:03:04:05:06:0a:0b:0c:0d:0e:0f,200,800,"
+        "8,100,0,7,0,1,1,,\n";
+    LeaseFileIO current_file(getLeaseFilePath("leasefile6_0.csv"));
+    current_file.writeFile(current_file_contents);
 
+    std::string previous_file_contents = new_file_contents +
+        "2001:db8:1::2,01:01:01:01:01:01:01:01:01:01:01:01:01,200,200,"
+        "8,100,0,7,0,1,1,,\n"
+        "2001:db8:1::2,01:01:01:01:01:01:01:01:01:01:01:01:01,200,800,"
+        "8,100,0,7,0,1,1,,\n";
+    LeaseFileIO previous_file(getLeaseFilePath("leasefile6_0.csv.2"));
+    previous_file.writeFile(previous_file_contents);
+
+    // Create the backend.
+    LeaseMgr::ParameterMap pmap;
+    pmap["type"] = "memfile";
+    pmap["universe"] = "6";
+    pmap["name"] = getLeaseFilePath("leasefile6_0.csv");
+    pmap["lfc-interval"] = "1";
+    boost::scoped_ptr<NakedMemfileLeaseMgr> lease_mgr(new NakedMemfileLeaseMgr(pmap));
+
+    // Try to run the lease file cleanup.
+    ASSERT_NO_THROW(lease_mgr->lfcCallback());
+
+    // The new lease file should have been created and it should contain
+    // no leases.
     ASSERT_TRUE(current_file.exists());
     EXPECT_EQ(new_file_contents, current_file.readFile());
 
+    // Wait for the LFC process to complete.
     ASSERT_TRUE(waitForProcess(*lease_mgr->lfc_process_, 2));
 
+    // And make sure it has returned an exit status of 0.
     EXPECT_EQ(0, lease_mgr->lfc_process_->getExitStatus());
+
+    /// @todo Replace the following with the checks that the LFC has
+    /// completed successfully, i.e. the leasefile6_0.csv.2 exists
+    /// and it holds the cleaned up lease information.
+
+    // Until the kea-lfc is implemented and performs the cleanup, we can
+    // only check that the backend has moved the lease file to a lease
+    // file with suffix ".1".
+    LeaseFileIO input_file(getLeaseFilePath("leasefile6_0.csv.1"), false);
+    ASSERT_TRUE(input_file.exists());
+    // And this file should contain the contents of the original file.
+    EXPECT_EQ(current_file_contents, input_file.readFile());
+}
+
+// This test verifies that EXIT_FAILURE status code is returned when
+// the LFC process fails to start.
+TEST_F(MemfileLeaseMgrTest, leaseFileCleanupStartFail) {
+    // This string contains the lease file header, which matches
+    // the contents of the new file in which no leases have been
+    // stored.
+    std::string new_file_contents =
+        "address,hwaddr,client_id,valid_lifetime,expire,"
+        "subnet_id,fqdn_fwd,fqdn_rev,hostname\n";
+
+    // Create the lease file to be used by the backend.
+    std::string current_file_contents = new_file_contents +
+        "192.0.2.2,02:02:02:02:02:02,,200,200,8,1,1,,\n";
+    LeaseFileIO current_file(getLeaseFilePath("leasefile4_0.csv"));
+    current_file.writeFile(current_file_contents);
+
+    // Specify invalid path to the kea-lfc executable. This should result
+    // in failure status code returned by the child process.
+    setenv("KEA_LFC_EXECUTABLE", "foobar", 1);
+
+    // Create the backend.
+    LeaseMgr::ParameterMap pmap;
+    pmap["type"] = "memfile";
+    pmap["universe"] = "4";
+    pmap["name"] = getLeaseFilePath("leasefile4_0.csv");
+    pmap["lfc-interval"] = "1";
+    boost::scoped_ptr<NakedMemfileLeaseMgr> lease_mgr(new NakedMemfileLeaseMgr(pmap));
+
+    // Try to run the lease file cleanup.
+    ASSERT_NO_THROW(lease_mgr->lfcCallback());
+
+    // Wait for the LFC process to complete.
+    ASSERT_TRUE(waitForProcess(*lease_mgr->lfc_process_, 2));
+
+    // And make sure it has returned an error.
+    EXPECT_EQ(EXIT_FAILURE, lease_mgr->lfc_process_->getExitStatus());
 }
 
 // Test that the backend returns a correct value of the interval

src/lib/util/process_spawn.cc

@@ -42,6 +42,9 @@ public:
     /// @brief Destructor.
     ~ProcessSpawnImpl();
 
+    /// @brief Returns full command line, including arguments, for the process.
+    std::string getCommandLine() const;
+
     /// @brief Spawn the new process.
     ///
     /// This method forks the current process and execues the specified
@@ -140,6 +143,21 @@ ProcessSpawnImpl::~ProcessSpawnImpl() {
     delete[] args_;
 }
 
+std::string
+ProcessSpawnImpl::getCommandLine() const {
+    std::ostringstream s;
+    s << executable_;
+    // Start with index 1, because the first argument duplicates the
+    // path to the executable. Note, that even if there are no parameters
+    // the minimum size of the table is 2.
+    int i = 1;
+    while (args_[i] != NULL) {
+        s << " " << args_[i];
+        ++i;
+    }
+    return (s.str());
+}
+
 void
 ProcessSpawnImpl::spawn() {
     pid_ = fork();
@@ -204,6 +222,11 @@ ProcessSpawn::~ProcessSpawn() {
     delete impl_;
 }
 
+std::string
+ProcessSpawn::getCommandLine() const {
+    return (impl_->getCommandLine());
+}
+
 void
 ProcessSpawn::spawn() {
     impl_->spawn();

src/lib/util/process_spawn.h

@@ -66,6 +66,9 @@ public:
     /// @brief Destructor.
     ~ProcessSpawn();
 
+    /// @brief Returns full command line, including arguments, for the process.
+    std::string getCommandLine() const;
+
     /// @brief Spawn the new process.
     ///
     /// This method forks the current process and execues the specified

src/lib/util/tests/process_spawn_unittest.cc

@@ -85,7 +85,32 @@ TEST(ProcessSpawn, invalidExecutable) {
     ASSERT_TRUE(waitForProcess(process, 2));
 
     EXPECT_EQ(EXIT_FAILURE, process.getExitStatus());
+}
+
+// This test verifies that the full command line for the process is
+// returned.
+TEST(ProcessSpawn, getCommandLine) {
+    // Note that cases below are enclosed in separate scopes to make
+    // sure that the ProcessSpawn object is destructed before a new
+    // object is created. Current implementation doesn't allow for
+    // having two ProcessSpawn objects simulatneously as they will
+    // both try to allocate a signal handler for SIGCHLD.
+    {
+        // Case 1: arguments present.
+        ProcessArgs args;
+        args.push_back("-x");
+        args.push_back("-y");
+        args.push_back("foo");
+        args.push_back("bar");
+        ProcessSpawn process("myapp", args);
+        EXPECT_EQ("myapp -x -y foo bar", process.getCommandLine());
+    }
 
+    {
+        // Case 2: no arguments.
+        ProcessSpawn process("myapp");
+        EXPECT_EQ("myapp", process.getCommandLine());
+    }
 }
 
 } // end of anonymous namespace