From: Thomas Markwalder Date: Sun, 28 Jun 2026 18:45:32 +0000 (-0400) Subject: [#4563] Catch legal log eval errors X-Git-Tag: Kea-3.3.0~131 X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=22c8b07bfc329b44b54cb1fd7c2ae66e8a4fb50d;p=thirdparty%2Fkea.git [#4563] Catch legal log eval errors /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 --- 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 index 0000000000..e4804125d1 --- /dev/null +++ b/changelog_unreleased/4563-f-151-forensic_log-lease4_callouts-cc-250-request-parser-format-eval-throw-lease-granted-with @@ -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) diff --git a/src/hooks/dhcp/forensic_log/lease4_callouts.cc b/src/hooks/dhcp/forensic_log/lease4_callouts.cc index eb95232ba7..180ef6e9fb 100644 --- a/src/hooks/dhcp/forensic_log/lease4_callouts.cc +++ b/src/hooks/dhcp/forensic_log/lease4_callouts.cc @@ -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() : "") + .arg(lease && lease->hwaddr_ ? lease->hwaddr_->toText() : "") + .arg(ex.what()); + value.clear(); + return (false); } return (using_custom_format); diff --git a/src/hooks/dhcp/forensic_log/lease6_callouts.cc b/src/hooks/dhcp/forensic_log/lease6_callouts.cc index ba4986e14e..343424f7b0 100644 --- a/src/hooks/dhcp/forensic_log/lease6_callouts.cc +++ b/src/hooks/dhcp/forensic_log/lease6_callouts.cc @@ -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() : "") + .arg(lease && lease->duid_ ? lease->duid_->toText() : "") + .arg(ex.what()); + value.clear(); + return (false); } return (using_custom_format); diff --git a/src/hooks/dhcp/forensic_log/legal_log_messages.cc b/src/hooks/dhcp/forensic_log/legal_log_messages.cc index 5a79dfe4d0..f869c166c6 100644 --- a/src/hooks/dhcp/forensic_log/legal_log_messages.cc +++ b/src/hooks/dhcp/forensic_log/legal_log_messages.cc @@ -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", diff --git a/src/hooks/dhcp/forensic_log/legal_log_messages.h b/src/hooks/dhcp/forensic_log/legal_log_messages.h index 530a70b057..3bca0760d1 100644 --- a/src/hooks/dhcp/forensic_log/legal_log_messages.h +++ b/src/hooks/dhcp/forensic_log/legal_log_messages.h @@ -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; diff --git a/src/hooks/dhcp/forensic_log/legal_log_messages.mes b/src/hooks/dhcp/forensic_log/legal_log_messages.mes index 0227117d30..6629b8835f 100644 --- a/src/hooks/dhcp/forensic_log/legal_log_messages.mes +++ b/src/hooks/dhcp/forensic_log/legal_log_messages.mes @@ -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. diff --git a/src/hooks/dhcp/forensic_log/tests/legal_log4_unittests.cc b/src/hooks/dhcp/forensic_log/tests/legal_log4_unittests.cc index 01069097e9..18d43cd0ea 100644 --- a/src/hooks/dhcp/forensic_log/tests/legal_log4_unittests.cc +++ b/src/hooks/dhcp/forensic_log/tests/legal_log4_unittests.cc @@ -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::vectorlines; + 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 diff --git a/src/hooks/dhcp/forensic_log/tests/legal_log6_unittests.cc b/src/hooks/dhcp/forensic_log/tests/legal_log6_unittests.cc index 746181e7ae..930435bffd 100644 --- a/src/hooks/dhcp/forensic_log/tests/legal_log6_unittests.cc +++ b/src/hooks/dhcp/forensic_log/tests/legal_log6_unittests.cc @@ -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::vectorlines; + 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 diff --git a/src/hooks/dhcp/forensic_log/tests/test_utils.h b/src/hooks/dhcp/forensic_log/tests/test_utils.h index 8e380bd43e..01517a6f13 100644 --- a/src/hooks/dhcp/forensic_log/tests/test_utils.h +++ b/src/hooks/dhcp/forensic_log/tests/test_utils.h @@ -14,6 +14,7 @@ #include #include #include +#include #include @@ -143,7 +144,9 @@ typedef boost::shared_ptr 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