From: Francis Dupont Date: Tue, 30 Dec 2025 08:36:16 +0000 (+0100) Subject: [#4282] Added logs error responses X-Git-Tag: Kea-3.1.5~39 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=c98b21f1a96792eef9e003e306ef94880f3c3631;p=thirdparty%2Fkea.git [#4282] Added logs error responses --- diff --git a/src/hooks/dhcp/radius/radius_messages.cc b/src/hooks/dhcp/radius/radius_messages.cc index e89e9d9dc0..2cc22567e5 100644 --- a/src/hooks/dhcp/radius/radius_messages.cc +++ b/src/hooks/dhcp/radius/radius_messages.cc @@ -29,6 +29,7 @@ extern const isc::log::MessageID RADIUS_ACCOUNTING_ERROR = "RADIUS_ACCOUNTING_ER extern const isc::log::MessageID RADIUS_ACCOUNTING_HISTORY_UPDATE_FAILED = "RADIUS_ACCOUNTING_HISTORY_UPDATE_FAILED"; extern const isc::log::MessageID RADIUS_ACCOUNTING_NO_HISTORY = "RADIUS_ACCOUNTING_NO_HISTORY"; extern const isc::log::MessageID RADIUS_ACCOUNTING_STATUS = "RADIUS_ACCOUNTING_STATUS"; +extern const isc::log::MessageID RADIUS_ACCOUNTING_STATUS_ERROR = "RADIUS_ACCOUNTING_STATUS_ERROR"; extern const isc::log::MessageID RADIUS_ACCOUNTING_STATUS_FAILED = "RADIUS_ACCOUNTING_STATUS_FAILED"; extern const isc::log::MessageID RADIUS_ACCOUNTING_STATUS_SUCCEED = "RADIUS_ACCOUNTING_STATUS_SUCCEED"; extern const isc::log::MessageID RADIUS_ACCOUNTING_SYNC = "RADIUS_ACCOUNTING_SYNC"; @@ -39,6 +40,7 @@ extern const isc::log::MessageID RADIUS_AUTHENTICATION_ASYNC_ACCEPTED = "RADIUS_ extern const isc::log::MessageID RADIUS_AUTHENTICATION_ASYNC_FAILED = "RADIUS_AUTHENTICATION_ASYNC_FAILED"; extern const isc::log::MessageID RADIUS_AUTHENTICATION_ASYNC_REJECTED = "RADIUS_AUTHENTICATION_ASYNC_REJECTED"; extern const isc::log::MessageID RADIUS_AUTHENTICATION_STATUS = "RADIUS_AUTHENTICATION_STATUS"; +extern const isc::log::MessageID RADIUS_AUTHENTICATION_STATUS_ERROR = "RADIUS_AUTHENTICATION_STATUS_ERROR"; extern const isc::log::MessageID RADIUS_AUTHENTICATION_STATUS_FAILED = "RADIUS_AUTHENTICATION_STATUS_FAILED"; extern const isc::log::MessageID RADIUS_AUTHENTICATION_STATUS_SUCCEED = "RADIUS_AUTHENTICATION_STATUS_SUCCEED"; extern const isc::log::MessageID RADIUS_AUTHENTICATION_SYNC = "RADIUS_AUTHENTICATION_SYNC"; @@ -124,6 +126,7 @@ const char* values[] = { "RADIUS_ACCOUNTING_HISTORY_UPDATE_FAILED", "failed to insert a record for %1 in the history container", "RADIUS_ACCOUNTING_NO_HISTORY", "failed to find the date the lease for %1 was created", "RADIUS_ACCOUNTING_STATUS", "send Status-Server with %1", + "RADIUS_ACCOUNTING_STATUS_ERROR", "received error response to Status-Server: %1 (%2) with %3", "RADIUS_ACCOUNTING_STATUS_FAILED", "Status-Server failed: return code %1 (%2)", "RADIUS_ACCOUNTING_STATUS_SUCCEED", "received valid response to Status-Server", "RADIUS_ACCOUNTING_SYNC", "Synchronous send Accounting-Request for NAS port %1 with %2", @@ -134,6 +137,7 @@ const char* values[] = { "RADIUS_AUTHENTICATION_ASYNC_FAILED", "Access-Request failed: return code %1 (%2)", "RADIUS_AUTHENTICATION_ASYNC_REJECTED", "received valid Access-Reject with %1", "RADIUS_AUTHENTICATION_STATUS", "send Status-Server with %1", + "RADIUS_AUTHENTICATION_STATUS_ERROR", "received error response to Status-Server: %1 (%2) with %3", "RADIUS_AUTHENTICATION_STATUS_FAILED", "Status-Server failed: return code %1 (%2)", "RADIUS_AUTHENTICATION_STATUS_SUCCEED", "received valid response to Status-Server", "RADIUS_AUTHENTICATION_SYNC", "send Access-Request for NAS port %1 with %2", diff --git a/src/hooks/dhcp/radius/radius_messages.h b/src/hooks/dhcp/radius/radius_messages.h index c520fc2b61..98c66422a3 100644 --- a/src/hooks/dhcp/radius/radius_messages.h +++ b/src/hooks/dhcp/radius/radius_messages.h @@ -30,6 +30,7 @@ extern const isc::log::MessageID RADIUS_ACCOUNTING_ERROR; extern const isc::log::MessageID RADIUS_ACCOUNTING_HISTORY_UPDATE_FAILED; extern const isc::log::MessageID RADIUS_ACCOUNTING_NO_HISTORY; extern const isc::log::MessageID RADIUS_ACCOUNTING_STATUS; +extern const isc::log::MessageID RADIUS_ACCOUNTING_STATUS_ERROR; extern const isc::log::MessageID RADIUS_ACCOUNTING_STATUS_FAILED; extern const isc::log::MessageID RADIUS_ACCOUNTING_STATUS_SUCCEED; extern const isc::log::MessageID RADIUS_ACCOUNTING_SYNC; @@ -40,6 +41,7 @@ extern const isc::log::MessageID RADIUS_AUTHENTICATION_ASYNC_ACCEPTED; extern const isc::log::MessageID RADIUS_AUTHENTICATION_ASYNC_FAILED; extern const isc::log::MessageID RADIUS_AUTHENTICATION_ASYNC_REJECTED; extern const isc::log::MessageID RADIUS_AUTHENTICATION_STATUS; +extern const isc::log::MessageID RADIUS_AUTHENTICATION_STATUS_ERROR; extern const isc::log::MessageID RADIUS_AUTHENTICATION_STATUS_FAILED; extern const isc::log::MessageID RADIUS_AUTHENTICATION_STATUS_SUCCEED; extern const isc::log::MessageID RADIUS_AUTHENTICATION_SYNC; diff --git a/src/hooks/dhcp/radius/radius_messages.mes b/src/hooks/dhcp/radius/radius_messages.mes index d99c3442d5..42874cb529 100644 --- a/src/hooks/dhcp/radius/radius_messages.mes +++ b/src/hooks/dhcp/radius/radius_messages.mes @@ -110,6 +110,11 @@ Logged at debug log level 40. This debug message is issued when starting to send a Status-Server message to accounting servers. The message attributes are logged. +% RADIUS_ACCOUNTING_STATUS_ERROR received error response to Status-Server: %1 (%2) with %3 +This error message indicates that a valid response to Status-Server message +was received from accounting servers but with an unexpected code or +an Error-Cause attribute. The response details are logged. + % RADIUS_ACCOUNTING_STATUS_FAILED Status-Server failed: return code %1 (%2) Logged at debug log level 40. This debug message is issued when no valid response to Status-Server message @@ -161,6 +166,11 @@ Logged at debug log level 40. This debug message is issued when starting to send a Status-Server message to access servers. The message attributes are logged. +% RADIUS_AUTHENTICATION_STATUS_ERROR received error response to Status-Server: %1 (%2) with %3 +This error message indicates that a valid response to Status-Server message +was received from access servers but with an unexpected code or an +Error-Cause attribute. The response details are logged. + % RADIUS_AUTHENTICATION_STATUS_FAILED Status-Server failed: return code %1 (%2) Logged at debug log level 40. This debug message is issued when no valid response to Status-Server message diff --git a/src/hooks/dhcp/radius/radius_status.cc b/src/hooks/dhcp/radius/radius_status.cc index fa29594837..adaa1c6c39 100644 --- a/src/hooks/dhcp/radius/radius_status.cc +++ b/src/hooks/dhcp/radius/radius_status.cc @@ -65,6 +65,21 @@ RadiusAuthStatus::invokeCallback(const CallbackAcct& callback, LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_AUTHENTICATION_STATUS_SUCCEED); RadiusImpl::instance().auth_->setIdleTimer(); + + MessagePtr response = exchange->getResponse(); + AttributesPtr resp_attrs; + uint8_t code = 0; + if (response) { + resp_attrs = response->getAttributes(); + code = response->getCode(); + } + if (((code != 0) && (code != PW_ACCESS_ACCEPT)) || + (resp_attrs && (resp_attrs->count(PW_ERROR_CAUSE) > 0))) { + LOG_ERROR(radius_logger, RADIUS_AUTHENTICATION_STATUS_ERROR) + .arg(msgCodeToText(code)) + .arg(static_cast(code)) + .arg(resp_attrs ? resp_attrs->toText() : "no attributes"); + } } else { LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_AUTHENTICATION_STATUS_FAILED) @@ -126,6 +141,21 @@ RadiusAcctStatus::invokeCallback(const CallbackAcct& callback, LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_ACCOUNTING_STATUS_SUCCEED); RadiusImpl::instance().acct_->setIdleTimer(); + + MessagePtr response = exchange->getResponse(); + AttributesPtr resp_attrs; + uint8_t code = 0; + if (response) { + resp_attrs = response->getAttributes(); + code = response->getCode(); + } + if (((code != 0) && (code != PW_ACCOUNTING_RESPONSE)) || + (resp_attrs && (resp_attrs->count(PW_ERROR_CAUSE) > 0))) { + LOG_ERROR(radius_logger, RADIUS_ACCOUNTING_STATUS_ERROR) + .arg(msgCodeToText(code)) + .arg(static_cast(code)) + .arg(resp_attrs ? resp_attrs->toText() : "no attributes"); + } } else { LOG_DEBUG(radius_logger, RADIUS_DBG_TRACE, RADIUS_ACCOUNTING_STATUS_FAILED) diff --git a/src/hooks/dhcp/radius/tests/status_unittests.cc b/src/hooks/dhcp/radius/tests/status_unittests.cc index 789ed8721c..d2351459e2 100644 --- a/src/hooks/dhcp/radius/tests/status_unittests.cc +++ b/src/hooks/dhcp/radius/tests/status_unittests.cc @@ -751,6 +751,99 @@ TEST_F(StatusTest, response) { EXPECT_EQ(OK_RC, result_); } +/// Verify what happens with error Accounting-Response response. +/// Should log a RADIUS_ACCOUNTING_STATUS_ERROR with +/// Accounting-Response (5) with Error-Cause=Unsupported-Extension +TEST_F(StatusTest, errorResponse) { + // Use CONFIGS[0]. + ElementPtr json; + ASSERT_NO_THROW(json = Element::fromJSON(CONFIGS[0])); + ASSERT_NO_THROW(impl_.init(json)); + + // Build request parameters. + which_ = "accounting"; + + // Open server socket. + open(SERVER_ACCT_PORT); + + // Push a receiver on it. + boost::asio::ip::udp::endpoint client; + size_t size = 0; + Callback receive_callback(receive_error_code_, size, received_); + server_socket_.async_receive_from( + boost::asio::buffer(&receive_buffer_[0], receive_buffer_.size()), + client, receive_callback); + + // Launch request handler i.e. the client code to test. + run(); + + // Start timer for 1.5s timeout. + start(1500); + + // Busy loop. + while (!received_ && !timeout_) { + poll(); + } + + ASSERT_TRUE(received_); + ASSERT_FALSE(timeout_); + + // Sanity checks on the request. + receive_buffer_.resize(size); + ASSERT_LE(20, size); + + // Build the response. + size = AUTH_HDR_LEN + 2 + 4; // header + Error-Cause attribute. + send_buffer_.resize(size); + send_buffer_[0] = PW_ACCOUNTING_RESPONSE; // Access-Accept. + send_buffer_[1] = receive_buffer_[1]; // Copy id. + send_buffer_[2] = size >> 8; // Length. + send_buffer_[3] = size & 0xff; + // Copy the authenticator. + memmove(&send_buffer_[4], &receive_buffer_[4], AUTH_VECTOR_LEN); + // Error-Cause attribute. + send_buffer_[AUTH_HDR_LEN] = 0x65; // Error-Cause (101) + send_buffer_[AUTH_HDR_LEN + 1] = 0x06; // Length. + send_buffer_[AUTH_HDR_LEN + 2] = 0x00; + send_buffer_[AUTH_HDR_LEN + 3] = 0x00; + send_buffer_[AUTH_HDR_LEN + 4] = 0x01; + send_buffer_[AUTH_HDR_LEN + 5] = 0x96; // Unsupported Extension (406). + + // Compute the authenticator. + vector auth_input(size + 3); + memmove(&auth_input[0], &send_buffer_[0], size); + auth_input[size] = 'b'; + auth_input[size + 1] = 'a'; + auth_input[size + 2] = 'r'; + OutputBuffer auth_output(AUTH_VECTOR_LEN); + digest(&auth_input[0], size + 3, isc::cryptolink::MD5, + auth_output, AUTH_VECTOR_LEN); + memmove(&send_buffer_[4], auth_output.getData(), AUTH_VECTOR_LEN); + + // Push a sender on the socket. + size_t sent_size = 0; + Callback send_callback(send_error_code_, sent_size, sent_); + server_socket_.async_send_to(boost::asio::buffer(&send_buffer_[0], size), + client, send_callback); + + // Second busy loop. + while ((!sent_ || !finished_) && !timeout_) { + poll(); + } + + EXPECT_TRUE(finished_); + EXPECT_TRUE(sent_); + EXPECT_FALSE(timeout_); + EXPECT_EQ(size, sent_size); + + // Done. + stop(); + service_->stopWork(); + + // Check result. + EXPECT_EQ(OK_RC, result_); +} + /// Verify what happens with bad Access-Accept response. TEST_F(StatusTest, badAccept) { // Use CONFIGS[0].