]> git.ipfire.org Git - thirdparty/kea.git/commitdiff
[#4563] Catch legal log eval errors
authorThomas Markwalder <tmark@isc.org>
Sun, 28 Jun 2026 18:45:32 +0000 (14:45 -0400)
committerThomas Markwalder <tmark@isc.org>
Wed, 1 Jul 2026 15:49:50 +0000 (15:49 +0000)
/src/hooks/dhcp/forensic_log/lease4_callouts.cc
    getCustomEntry() - emit an error log and return false if
    a custom expression throws an evaluation error.

/src/hooks/dhcp/forensic_log/lease6_callouts.cc
    getCustomEntry() - emit an error log and return false if
    a custom expression throws an evaluation error.

/src/hooks/dhcp/forensic_log/legal_log_messages.*
    LEGAL_LOG_LEASE4_RENDER_ERROR
    LEGAL_LOG_LEASE6_RENDER_ERROR
    - new messages

/src/hooks/dhcp/forensic_log/tests/legal_log4_unittests.cc
    TEST_F(CalloutTestv4, customLogRenderError)
    - new test

/src/hooks/dhcp/forensic_log/tests/legal_log6_unittests.cc
    TEST_F(CalloutTestv6, customLogRenderError)
    - new test

/src/hooks/dhcp/forensic_log/tests/test_utils.h
    class RotatingFileTest - now derives from LogContentTest

changelog_unreleased/4563-f-151-forensic_log-lease4_callouts-cc-250-request-parser-format-eval-throw-lease-granted-with [new file with mode: 0644]
src/hooks/dhcp/forensic_log/lease4_callouts.cc
src/hooks/dhcp/forensic_log/lease6_callouts.cc
src/hooks/dhcp/forensic_log/legal_log_messages.cc
src/hooks/dhcp/forensic_log/legal_log_messages.h
src/hooks/dhcp/forensic_log/legal_log_messages.mes
src/hooks/dhcp/forensic_log/tests/legal_log4_unittests.cc
src/hooks/dhcp/forensic_log/tests/legal_log6_unittests.cc
src/hooks/dhcp/forensic_log/tests/test_utils.h

diff --git a/changelog_unreleased/4563-f-151-forensic_log-lease4_callouts-cc-250-request-parser-format-eval-throw-lease-granted-with b/changelog_unreleased/4563-f-151-forensic_log-lease4_callouts-cc-250-request-parser-format-eval-throw-lease-granted-with
new file mode 100644 (file)
index 0000000..e480412
--- /dev/null
@@ -0,0 +1,7 @@
+[func]         tmark
+       Changed legal log hook library to generate a legal
+       log entry using the default log expression when
+       a custom log expression results in an evaluation
+       error. Prior to this the library would emit an
+       error but not generate a legal log entry.
+       (Gitlab #4563)
index eb95232ba79785708bb53d2176e5fdfce8116502..180ef6e9fbf3630b0221b88bddf8d9b64aaeec94 100644 (file)
@@ -36,19 +36,28 @@ using namespace std;
 /// @param lease The current lease generating this log entry.
 /// @param [out] value The value of the custom log entry after parser execution.
 bool getCustomEntry(CalloutHandle& handle, const Pkt4Ptr& query, const Pkt4Ptr& response,
-                    const Lease4Ptr& /*lease*/, std::string& value) {
+                    const Lease4Ptr& lease, std::string& value) {
     bool using_custom_format = false;
+    auto library = LegalLogMgrFactory::instance(handle.getCurrentLibrary());
+    try {
+        auto expression = library->getRequestFormatExpression();
+        if (expression && query) {
+            value = evaluateString(*expression, *query);
+            using_custom_format = true;
+        }
 
-    auto expression = LegalLogMgrFactory::instance(handle.getCurrentLibrary())->getRequestFormatExpression();
-    if (expression && query) {
-        value = evaluateString(*expression, *query);
-        using_custom_format = true;
-    }
-
-    expression = LegalLogMgrFactory::instance(handle.getCurrentLibrary())->getResponseFormatExpression();
-    if (expression && response) {
-        value += evaluateString(*expression, *response);
-        using_custom_format = true;
+        expression = library->getResponseFormatExpression();
+        if (expression && response) {
+            value += evaluateString(*expression, *response);
+            using_custom_format = true;
+        }
+    } catch (const std::exception& ex) {
+        LOG_ERROR(legal_log_logger, LEGAL_LOG_LEASE4_RENDER_ERROR)
+                  .arg(lease ? lease->addr_.toText() : "<none>")
+                  .arg(lease && lease->hwaddr_ ? lease->hwaddr_->toText() : "<none>")
+                  .arg(ex.what());
+        value.clear();
+        return (false);
     }
 
     return (using_custom_format);
index ba4986e14e1e04cf9a12689d51b1a2223d39a06b..343424f7b02e12f31cfc968dd91f6d9489d48505 100644 (file)
@@ -483,21 +483,30 @@ void replaceTokensForLease(isc::dhcp::ExpressionPtr& expression,
 bool getCustomEntry(CalloutHandle& handle, const Pkt6Ptr& query, const Pkt6Ptr& response,
                     const Lease6Ptr& lease, std::string& value) {
     bool using_custom_format = false;
+    auto library = LegalLogMgrFactory::instance(handle.getCurrentLibrary());
+    try {
+        auto expression = library->getRequestFormatExpression();
+        if (expression && query) {
+            replaceTokensForLease(expression, lease);
 
-    auto expression = LegalLogMgrFactory::instance(handle.getCurrentLibrary())->getRequestFormatExpression();
-    if (expression && query) {
-        replaceTokensForLease(expression, lease);
-
-        value = evaluateString(*expression, *query);
-        using_custom_format = true;
-    }
+            value = evaluateString(*expression, *query);
+            using_custom_format = true;
+        }
 
-    expression = LegalLogMgrFactory::instance(handle.getCurrentLibrary())->getResponseFormatExpression();
-    if (expression && response) {
-        replaceTokensForLease(expression, lease);
+        expression = library->getResponseFormatExpression();
+        if (expression && response) {
+            replaceTokensForLease(expression, lease);
 
-        value += evaluateString(*expression, *response);
-        using_custom_format = true;
+            value += evaluateString(*expression, *response);
+            using_custom_format = true;
+        }
+    } catch (const std::exception& ex) {
+        LOG_ERROR(legal_log_logger, LEGAL_LOG_LEASE6_RENDER_ERROR)
+                  .arg(lease ? lease->addr_.toText() : "<none>")
+                  .arg(lease && lease->duid_ ? lease->duid_->toText() : "<none>")
+                  .arg(ex.what());
+        value.clear();
+        return (false);
     }
 
     return (using_custom_format);
index 5a79dfe4d0a5407479846d77a67b9d841f193356..f869c166c6921088ca464edc007f89193f360c19 100644 (file)
@@ -8,8 +8,10 @@ extern const isc::log::MessageID LEGAL_LOG_COMMAND_NO_LEGAL_STORE = "LEGAL_LOG_C
 extern const isc::log::MessageID LEGAL_LOG_COMMAND_WRITE_ERROR = "LEGAL_LOG_COMMAND_WRITE_ERROR";
 extern const isc::log::MessageID LEGAL_LOG_DB_OPEN_CONNECTION_WITH_RETRY_FAILED = "LEGAL_LOG_DB_OPEN_CONNECTION_WITH_RETRY_FAILED";
 extern const isc::log::MessageID LEGAL_LOG_LEASE4_NO_LEGAL_STORE = "LEGAL_LOG_LEASE4_NO_LEGAL_STORE";
+extern const isc::log::MessageID LEGAL_LOG_LEASE4_RENDER_ERROR = "LEGAL_LOG_LEASE4_RENDER_ERROR";
 extern const isc::log::MessageID LEGAL_LOG_LEASE4_WRITE_ERROR = "LEGAL_LOG_LEASE4_WRITE_ERROR";
 extern const isc::log::MessageID LEGAL_LOG_LEASE6_NO_LEGAL_STORE = "LEGAL_LOG_LEASE6_NO_LEGAL_STORE";
+extern const isc::log::MessageID LEGAL_LOG_LEASE6_RENDER_ERROR = "LEGAL_LOG_LEASE6_RENDER_ERROR";
 extern const isc::log::MessageID LEGAL_LOG_LEASE6_WRITE_ERROR = "LEGAL_LOG_LEASE6_WRITE_ERROR";
 extern const isc::log::MessageID LEGAL_LOG_LOAD_ERROR = "LEGAL_LOG_LOAD_ERROR";
 extern const isc::log::MessageID LEGAL_LOG_STORE_CLOSED = "LEGAL_LOG_STORE_CLOSED";
@@ -27,8 +29,10 @@ const char* values[] = {
     "LEGAL_LOG_COMMAND_WRITE_ERROR", "Could not write command entry to the legal store: %1",
     "LEGAL_LOG_DB_OPEN_CONNECTION_WITH_RETRY_FAILED", "Failed to connect to database: %1 with error: %2",
     "LEGAL_LOG_LEASE4_NO_LEGAL_STORE", "LegalStore instance is null",
+    "LEGAL_LOG_LEASE4_RENDER_ERROR", "custom request/response-parser-format failed for lease %1 hwaddr %2 (%3); falling back to default format",
     "LEGAL_LOG_LEASE4_WRITE_ERROR", "Could not write to the legal store: %1",
     "LEGAL_LOG_LEASE6_NO_LEGAL_STORE", "LegalStore instance is null",
+    "LEGAL_LOG_LEASE6_RENDER_ERROR", "custom request/response-parser-format failed for lease %1 duid %2 (%3); falling back to default format",
     "LEGAL_LOG_LEASE6_WRITE_ERROR", "Could not write to the legal store: %1",
     "LEGAL_LOG_LOAD_ERROR", "LEGAL LOGGING DISABLED! An error occurred loading the library: %1",
     "LEGAL_LOG_STORE_CLOSED", "Legal store closed: %1",
index 530a70b057c317352215f3512c330edb33708788..3bca0760d14b5fdf9bca45f731f09318c7b56224 100644 (file)
@@ -9,8 +9,10 @@ extern const isc::log::MessageID LEGAL_LOG_COMMAND_NO_LEGAL_STORE;
 extern const isc::log::MessageID LEGAL_LOG_COMMAND_WRITE_ERROR;
 extern const isc::log::MessageID LEGAL_LOG_DB_OPEN_CONNECTION_WITH_RETRY_FAILED;
 extern const isc::log::MessageID LEGAL_LOG_LEASE4_NO_LEGAL_STORE;
+extern const isc::log::MessageID LEGAL_LOG_LEASE4_RENDER_ERROR;
 extern const isc::log::MessageID LEGAL_LOG_LEASE4_WRITE_ERROR;
 extern const isc::log::MessageID LEGAL_LOG_LEASE6_NO_LEGAL_STORE;
+extern const isc::log::MessageID LEGAL_LOG_LEASE6_RENDER_ERROR;
 extern const isc::log::MessageID LEGAL_LOG_LEASE6_WRITE_ERROR;
 extern const isc::log::MessageID LEGAL_LOG_LOAD_ERROR;
 extern const isc::log::MessageID LEGAL_LOG_STORE_CLOSED;
index 0227117d3034c10f221216022c5435442eb176a6..6629b8835f8471468b8aeb86d26b8e99a87f97ad 100644 (file)
@@ -78,3 +78,19 @@ the backend are logged.
 This is an error message issued when an error occurs while unloading the
 Legal Log library.  This is unlikely to occur and normal operations of the
 library will likely resume when it is next loaded.
+
+% LEGAL_LOG_LEASE4_RENDER_ERROR custom request/response-parser-format failed for lease %1 hwaddr %2 (%3); falling back to default format
+This error message is issued when an error occurs while evaluating a custom
+legal log message expression.  When this occurs the legal log library will
+then attempt to output an entry using the default expression.  This is most
+likely caused by an invalid expression such as attempting to evaluate
+uint32totext() on an uint8 byte option. The arguments provide the lease
+address, hardware address, and a description of the error.
+
+% LEGAL_LOG_LEASE6_RENDER_ERROR custom request/response-parser-format failed for lease %1 duid %2 (%3); falling back to default format
+This error message is issued when an error occurs while evaluating a custom
+legal log message expression.  When this occurs the legal log library will
+then attempt to output an entry using the default expression.  This is most
+likely caused by an invalid expression such as attempting to evaluate
+uint32totext() on an uint8 byte option. The arguments provide the lease
+address, duid, and a description of the error.
index 01069097e9cd967d69e16e75544b7f2f721e67fd..18d43cd0ea14133a1befd3fa25ebef0475ef0e88 100644 (file)
@@ -1722,4 +1722,51 @@ TEST_F(CalloutTestv4, customRequestLoggingFormatMultipleLines) {
     checkFileLines(genName(today()), today_now_string, lines);
 }
 
+// Verifies that the custom format logs that fail to render
+// are error logged and the default format is used instead.
+TEST_F(CalloutTestv4, customLogRenderError) {
+    ASSERT_NO_THROW(LegalLogMgrFactory::instance().reset(new TestableRotatingFile(time_)));
+
+    // Make a callout handle
+    CalloutHandlePtr handle = getCalloutHandle(decline_);
+    handle->setCurrentLibrary(0);
+
+    // Set the request format to an expression that is valid syntax but
+    // will fail to evaluate. Option 53 has a defined length of 1 which
+    // will cause uint32totext() to throw.
+    std::string format = "uint32totext(option[53].hex)";
+    LegalLogMgrFactory::instance()->setRequestFormatExpression(format);
+
+    int ret;
+
+    // Make a lease and add it to the callout arguments.
+    Lease4Ptr lease4 = createLease4("192.2.1.100", 6735, hwaddr_, ClientIdPtr(), 1234);
+
+    // The callout should succeed and generate an entry for 192.2.1.100.
+    {
+        ScopedCalloutHandleState callout_handle_state(handle);
+        handle->setArgument("lease4", lease4);
+        handle->setArgument("query4", decline_);
+        ASSERT_NO_THROW(ret = lease4_decline(*handle));
+        EXPECT_EQ(0, ret);
+    }
+
+    // Close it to flush any unwritten data
+    LegalLogMgrFactory::instance()->close();
+
+    // Verify we logged the error.
+    auto err_text = "LEGAL_LOG_LEASE4_RENDER_ERROR custom request/response"
+                    "-parser-format failed for lease 192.2.1.100 hwaddr hwtype"
+                    "=1 08:00:2b:02:3f:4e (Can not convert to valid uint32.);"
+                    " falling back to default format";
+    EXPECT_EQ(1, countFile(err_text));
+
+    // Verify that the default entry was generated.
+    std::vector<std::string>lines;
+    lines.push_back("Address: 192.2.1.100 has been released from a device"
+                    " with hardware address: hwtype=1 08:00:2b:02:3f:4e");
+    std::string today_now_string = LegalLogMgrFactory::instance()->getNowString();
+    checkFileLines(genName(today()), today_now_string, lines);
+}
+
 } // end of anonymous namespace
index 746181e7ae20882905dc2f2d535375ea012f4d81..930435bffdb7e522243cf2e3395351051f0426a1 100644 (file)
@@ -2764,4 +2764,56 @@ TEST_F(CalloutTestv6, multipleAddressesAndPrefixesCustomLoggingFormatRequestAndR
     checkFileLines(genName(today()), today_now_string, lines);
 }
 
+TEST_F(CalloutTestv6, customLogRenderError) {
+    ASSERT_NO_THROW(LegalLogMgrFactory::instance().reset(new TestableRotatingFile(time_)));
+
+    CfgMgr::instance().setFamily(AF_INET6);
+
+    // Make a callout handle
+    CalloutHandlePtr handle = getCalloutHandle(decline_);
+    handle->setCurrentLibrary(0);
+
+    // Set the request format to an expression that is valid syntax but
+    // will fail to evaluate. Message type has a defined length of 2 which
+    // will cause uint32totext() to throw.
+    std::string format = "uint32totext(option[1].hex)";
+    LegalLogMgrFactory::instance()->setRequestFormatExpression(format);
+
+    int ret;
+
+    // Make a lease and add it to the callout arguments.
+    Lease6Ptr lease6 = createLease6(duid_, Lease::TYPE_NA, "2001:db8:1::", 128,
+                                    713, HWAddrPtr());
+
+    // The callout should succeed and generate an entry for 2001:db8:1::
+    {
+        ScopedCalloutHandleState callout_handle_state(handle);
+        handle->setArgument("lease6", lease6);
+        ASSERT_NO_THROW(ret = lease6_decline(*handle));
+        ASSERT_EQ(0, ret);
+    }
+
+    {
+        ScopedCalloutHandleState callout_handle_state(handle);
+        handle->setArgument("query6", decline_);
+        handle->setArgument("response6", response_);
+        ASSERT_NO_THROW(ret = pkt6_send(*handle));
+        EXPECT_EQ(0, ret);
+    }
+
+    // Verify we logged the error.
+    auto err_text = "LEGAL_LOG_LEASE6_RENDER_ERROR custom request/"
+                    "response-parser-format failed for lease 2001:db8:1::"
+                    " duid 17:34:e2:ff:09:92:54 (Can not convert to valid"
+                    " uint32.); falling back to default format";
+    EXPECT_EQ(1, countFile(err_text));
+
+    // Verify that the default entry was generated.
+    std::vector<std::string>lines;
+    lines.push_back("Address: 2001:db8:1:: has been released "
+                    "from a device with DUID: 17:34:e2:ff:09:92:54");
+    std::string today_now_string = LegalLogMgrFactory::instance()->getNowString();
+    checkFileLines(genName(today()), today_now_string, lines);
+}
+
 } // end of anonymous namespace
index 8e380bd43e242fe3076c538e189c195bbbf71af4..01517a6f1321c18f1d7e7ab502060ef4c43c3f3c 100644 (file)
@@ -14,6 +14,7 @@
 #include <dhcpsrv/legal_log_mgr.h>
 #include <rotating_file.h>
 #include <util/reconnect_ctl.h>
+#include <testutils/log_utils.h>
 
 #include <gtest/gtest.h>
 
@@ -143,7 +144,9 @@ typedef boost::shared_ptr<TestableRotatingFile> TestableRotatingFilePtr;
 /// @brief Test fixture for testing RotatingFile.
 /// It provides tools for erasing test files, altering date values,
 /// generating file names, checking file existence and content.
-class RotatingFileTest : public ::testing::Test {
+
+//class RotatingFileTest : public ::testing::Test {
+class RotatingFileTest : public test::LogContentTest {
 public:
 
     /// @brief Constructor