[master] Log rotation now functions and is on by default

    Merge branch 'trac5324'

doc/guide/logging.xml

@@ -628,15 +628,17 @@
         <section>
           <title>maxsize (integer)</title>
           <para>
-            Only relevant when destination is file, this is maximum file size of
-            output files in bytes. When the maximum size is reached, the file is
-            renamed and a new file opened.  (For example, a ".1" is appended to
-            the name &mdash; if a ".1" file exists, it is renamed ".2", etc.)
+            Only relevant when the destination is a file. This is maximum size
+            in bytes that a log file may reach.  When the maximum size is
+            reached, the file is renamed and a new file opened. For example,
+            a ".1" is appended to the name &mdash; if a ".1" file exists, it
+            is renamed ".2", etc. This is referred to as rotation.
           </para>
           <para>
-            If this is set to 0 or omitted, no maximum file size is used.
+            The default value is 10240000 (10MB).  The smallest value that may
+            be specified without disabling rotation is 204800. Any value less than
+            this, including 0, disables rotation.
           </para>
-
           <note>
             <simpara>
               Due to a limitation of the underlying logging library (log4cplus),
@@ -655,9 +657,13 @@
         <section>
           <title>maxver (integer)</title>
           <para>
-            Maximum number of old log files to keep around when rolling the
-            output file. Only relevant when <option>output</option> is
-            <quote>file</quote>.
+            Only relevant when the destination is file and rotation is enabled
+            (i.e. maxsize is large enough).  This is maximum number of rotated
+            versions that will be kept. Once that number of files has been
+            reached, the oldest file, "log-name.maxver", will be discarded
+            each time the log rotates. In other words, at most there will be
+            the active log file plus maxver rotated files.  The minimum and
+            default value is 1.
           </para>
         </section>
       </section>

src/lib/dhcpsrv/logging_info.cc

@@ -142,6 +142,8 @@ LoggingInfo::toSpec() const {
             // Not a recognized destination, assume a file.
             option.destination = OutputOption::DEST_FILE;
             option.filename = dest->output_;
+            option.maxsize = dest->maxsize_;
+            option.maxver = dest->maxver_;
         }
 
         // Copy the immediate flush flag

src/lib/dhcpsrv/logging_info.h

@@ -45,7 +45,7 @@ struct LoggingDestination : public isc::data::CfgToElement {
 
     /// @brief Default constructor.
     LoggingDestination()
-        : output_("stdout"), maxver_(1), maxsize_(204800), flush_(true) {
+        : output_("stdout"), maxver_(1), maxsize_(10240000), flush_(true) {
     }
 
     /// @brief Unparse a configuration object

src/lib/dhcpsrv/tests/logging_info_unittest.cc

@@ -74,7 +74,7 @@ TEST_F(LoggingInfoTest, defaults) {
     std::string header = "{\n"
         "\"name\": \"kea\",\n"
         "\"output_options\": [ {\n"
-        " \"output\": \"stdout\",\n \"maxsize\": 204800,\n"
+        " \"output\": \"stdout\",\n \"maxsize\": 10240000,\n"
         " \"maxver\": 1,\n \"flush\": true } ],\n"
         "\"severity\": \"";
     std::string dbglvl = "\",\n\"debuglevel\": ";
@@ -91,6 +91,9 @@ TEST_F(LoggingInfoTest, defaults) {
     ASSERT_EQ(1, info_verbose.destinations_.size());
     EXPECT_EQ("stdout", info_verbose.destinations_[0].output_);
 
+    EXPECT_EQ(10240000, info_verbose.destinations_[0].maxsize_);
+    EXPECT_EQ(1, info_verbose.destinations_[0].maxver_);
+
     expected = header + "DEBUG" + dbglvl + "99" + trailer;
     runToElementTest<LoggingInfo>(expected, info_verbose);
 }

src/lib/dhcpsrv/tests/logging_unittest.cc

@@ -5,12 +5,15 @@
 // file, You can obtain one at http://mozilla.org/MPL/2.0/.
 
 #include <config.h>
-#include <exceptions/exceptions.h>
 #include <cc/data.h>
 #include <config/module_spec.h>
+#include <dhcpsrv/dhcpsrv_log.h>
 #include <dhcpsrv/logging.h>
-#include <gtest/gtest.h>
+#include <exceptions/exceptions.h>
 #include <log/logger_support.h>
+#include <testutils/io_utils.h>
+
+#include <gtest/gtest.h>
 
 using namespace isc;
 using namespace isc::dhcp;
@@ -24,7 +27,6 @@ namespace {
 /// each test.  Strictly speaking this only resets the testing root logger (which
 /// has the name "kea") but as the only other logger mentioned here ("wombat")
 /// is not used elsewhere, that is sufficient.
-
 class LoggingTest : public ::testing::Test {
     public:
         /// @brief Constructor
@@ -34,10 +36,46 @@ class LoggingTest : public ::testing::Test {
         ///
         /// Reset root logger back to defaults.
         ~LoggingTest() {
-            isc::log::setDefaultLoggingOutput();
+            isc::log::initLogger();
+            wipeFiles();
         }
+
+    /// @brief Generates a log file name suffixed with a rotation number
+    /// @param rotation number to the append to the end of the file
+    std::string logName(int rotation) {
+        std::ostringstream os;
+        os << TEST_LOG_NAME << "." << rotation;
+        return (os.str());
+    }
+
+    /// @brief Removes the base log file name and 1 rotation
+    void wipeFiles()  {
+        static_cast<void>(remove(TEST_LOG_NAME));
+        for (int i = 1; i < TEST_MAX_VERS + 1; ++i) {
+            static_cast<void>(remove(logName(i).c_str()));
+        }
+
+        // Remove the lock file
+        std::ostringstream os;
+        os << TEST_LOG_NAME << ".lock";
+        static_cast<void>(remove(os.str().c_str()));
+    }
+
+    /// @brief Name of the log file
+    static const char* TEST_LOG_NAME;
+
+    /// @brief Maximum log size
+    static const int TEST_MAX_SIZE;
+
+    /// @brief Maximum rotated log versions
+    static const int TEST_MAX_VERS;
+
 };
 
+const char* LoggingTest::TEST_LOG_NAME = "kea.test.log";
+const int LoggingTest::TEST_MAX_SIZE = 204800;  // Smallest without disabling rotation 
+const int LoggingTest::TEST_MAX_VERS = 2;       // More than the default of 1
+
 // Tests that the spec file is valid.
 TEST_F(LoggingTest, basicSpec) {
     std::string specfile = std::string(LOGGING_SPEC_FILE);
@@ -244,6 +282,69 @@ TEST_F(LoggingTest, multipleLoggingDestinations) {
     EXPECT_TRUE(storage->getLoggingInfo()[0].destinations_[1].flush_);
 }
 
+// Verifies that log rotation occurs when configured.  We do not
+// worry about contents of the log files, only that rotation occurs.
+// Such details are tested in lib/log.  This test verifies that
+// we can correcty configure logging such that rotation occurs as
+// expected.
+TEST_F(LoggingTest, logRotate) {
+    wipeFiles();
+
+    std::ostringstream os;
+    os <<
+        "{ \"loggers\": ["
+        "    {"
+        "        \"name\": \"kea\","
+        "        \"output_options\": ["
+        "            {"
+        "                \"output\": \""
+        << TEST_LOG_NAME << "\","  <<
+        "                \"flush\": true,"
+        "                \"maxsize\":"
+        << TEST_MAX_SIZE << "," <<
+        "                \"maxver\":"
+        << TEST_MAX_VERS <<
+        "            }"
+        "        ],"
+        "        \"debuglevel\": 99,"
+        "        \"severity\": \"DEBUG\""
+        "    }"
+        "]}";
+
+    // Create our server config container.
+    SrvConfigPtr server_cfg(new SrvConfig());
+
+    // LogConfigParser expects a list of loggers, so parse
+    // the JSON text and extract the "loggers" element from it
+    ConstElementPtr config = Element::fromJSON(os.str());
+    config = config->get("loggers");
+
+    // Parse the config and then apply it.
+    LogConfigParser parser(server_cfg);
+    ASSERT_NO_THROW(parser.parseConfiguration(config));
+    ASSERT_NO_THROW(server_cfg->applyLoggingCfg());
+
+    EXPECT_EQ(TEST_MAX_SIZE, server_cfg->getLoggingInfo()[0].destinations_[0].maxsize_);
+    EXPECT_EQ(TEST_MAX_VERS, server_cfg->getLoggingInfo()[0].destinations_[0].maxver_);
+
+    // Make sure we have the initial log file.
+    ASSERT_TRUE(isc::test::fileExists(TEST_LOG_NAME));
+
+    // Now generate a log we know will be large enough to force a rotation.
+    // We borrow a one argument log message for the test.
+    std::string big_arg(TEST_MAX_SIZE, 'x');
+    isc::log::Logger logger("kea");
+
+    for (int i = 1; i < TEST_MAX_VERS + 1; i++) {
+        // Output the big log and make sure we get the expected rotation file.
+        LOG_INFO(logger, DHCPSRV_CFGMGR_ADD_IFACE).arg(big_arg);
+        EXPECT_TRUE(isc::test::fileExists(logName(i).c_str()));
+    }
+
+    // Clean up.
+    wipeFiles();
+}
+
 /// @todo Add tests for malformed logging configuration
 
 /// @todo There is no easy way to test applyConfiguration() and defaultLogging().

src/lib/testutils/dhcp_test_lib.sh.in

@@ -1,4 +1,4 @@
-# Copyright (C) 2014-2015,2017 Internet Systems Consortium, Inc. ("ISC")
+# Copyright (C) 2014-2017 Internet Systems Consortium, Inc. ("ISC")
 #
 # This Source Code Form is subject to the terms of the Mozilla Public
 # License, v. 2.0. If a copy of the MPL was not distributed with this
@@ -307,6 +307,7 @@ cleanup() {
 
     # Remove temporary files.
     rm -rf ${LOG_FILE}
+    rm -rf ${LOG_FILE}.lock
     # Use asterisk to remove all files starting with the given name,
     # in case the LFC has been run. LFC creates files with postfixes
     # appended to the lease file name.