From f3d099824a06094ce1f812bef970cf0709ecbaf9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gunics=20Bal=C3=A1zs?= Date: Mon, 28 Sep 2026 22:34:29 +0200 Subject: [PATCH 1/2] Cut log noise from bad UDP packets and global-destination RTS frames "Unknown start of message" was printed twice per packet: both UDP sockets listen on port 8888 (one on the AOG subnet address, one on all interfaces), so every broadcast arrives on both. Log it through UdpConnections::log_unknown_start(), which skips an identical report (same sender, same leading bytes) within 50 ms and includes the sender IP:port and up to 16 bytes in hex, so the source can be found. "Received a Request to Send (RTS) message with a global destination" is a stack warning without a source address, printed for every frame. The CAN stack log sink now treats it as Debug. The application counts such RTS frames per source address from the CAN frame received event and logs one summary line per minute when there were any. Co-Authored-By: Claude Opus 5.5 --- include/udp_connections.hpp | 11 +++++++++ src/app.cpp | 46 +++++++++++++++++++++++++++++++++++++ src/logging.cpp | 12 ++++++++++ src/udp_connections.cpp | 35 ++++++++++++++++++++++++++-- 4 files changed, 102 insertions(+), 2 deletions(-) diff --git a/include/udp_connections.hpp b/include/udp_connections.hpp index 2c2200a..36d2032 100644 --- a/include/udp_connections.hpp +++ b/include/udp_connections.hpp @@ -10,7 +10,9 @@ #pragma once #include +#include #include +#include #include "settings.hpp" using boost::asio::ip::udp; @@ -92,7 +94,16 @@ class UdpConnections */ std::uint8_t calculate_crc(std::span data); + /** + * @brief Log a packet that does not start with PACKET_START, once even if both sockets receive it + * @param sender The endpoint the packet came from + * @param data The bytes from the unexpected start onwards + */ + void log_unknown_start(const udp::endpoint &sender, std::span data); + PacketCallback packetCallback = nullptr; + std::string lastUnknownStartSignature; ///< Sender and leading bytes of the last logged unknown start + std::chrono::steady_clock::time_point lastUnknownStartTime; std::shared_ptr settings; udp::socket udpConnection; udp::socket udpConnectionAddressDetection; diff --git a/src/app.cpp b/src/app.cpp index 9ac8802..d413490 100644 --- a/src/app.cpp +++ b/src/app.cpp @@ -27,6 +27,8 @@ #include "logging_utils.hpp" #include +#include +#include #include #include #include @@ -44,6 +46,42 @@ static std::string format_hex_address(std::uint8_t address) return value.str(); } +// Requests to Send with a global destination are invalid and ignored by the stack. Its per-message warning +// has no source address, so count them per source here (CAN thread) and report once per minute from update(). +static std::array, 256> globalRtsCountBySource{}; + +static void count_global_rts(const isobus::CANMessageFrame &frame) +{ + constexpr std::uint8_t TP_CONNECTION_MANAGEMENT_PF = 0xEC; + constexpr std::uint8_t TP_REQUEST_TO_SEND = 16; + if (frame.isExtendedFrame && (frame.dataLength > 0) && + (((frame.identifier >> 16) & 0xFF) == TP_CONNECTION_MANAGEMENT_PF) && + (((frame.identifier >> 8) & 0xFF) == 0xFF) && + (frame.data[0] == TP_REQUEST_TO_SEND)) + { + globalRtsCountBySource[frame.identifier & 0xFF]++; + } +} + +static void report_global_rts_counts() +{ + std::ostringstream sources; + std::uint32_t total = 0; + for (std::size_t source = 0; source < globalRtsCountBySource.size(); source++) + { + const std::uint32_t count = globalRtsCountBySource[source].exchange(0); + if (count > 0) + { + sources << (total > 0 ? ", " : "") << format_hex_address(static_cast(source)) << " (" << count << ")"; + total += count; + } + } + if (total > 0) + { + log("TP") << "Ignored " << total << " Request to Send message(s) with a global destination in the last minute, from source address(es) " << sources.str() << std::endl; + } +} + // Enumerate and log all Control Functions on the bus static void enumerate_bus_control_functions(const std::string &context) { @@ -194,6 +232,7 @@ bool Application::setup_can_hardware() } isobus::CANHardwareInterface::set_number_of_can_channels(1); isobus::CANHardwareInterface::assign_can_channel_frame_handler(0, canDriver); + isobus::CANHardwareInterface::get_can_frame_received_event_dispatcher().add_listener(count_global_rts); canHardwareStarted = isobus::CANHardwareInterface::start(); if ((!canHardwareStarted) || (!canDriver->get_is_valid())) @@ -627,6 +666,13 @@ bool Application::update() lastConflictCheck = isobus::SystemTiming::get_timestamp_ms(); } + static std::uint32_t lastGlobalRtsReportMs = 0; + if (isobus::SystemTiming::time_expired_ms(lastGlobalRtsReportMs, 60000)) + { + report_global_rts_counts(); + lastGlobalRtsReportMs = isobus::SystemTiming::get_timestamp_ms(); + } + // Diff active implement clients once per second so disconnect messages retain prior metadata. static std::uint32_t lastImplementScanMs = 0; if (isobus::SystemTiming::time_expired_ms(lastImplementScanMs, 1000)) diff --git a/src/logging.cpp b/src/logging.cpp index 2534664..37c679f 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -78,6 +78,18 @@ class CustomLogger : public isobus::CANStackLogger void sink_CAN_stack_log(CANStackLogger::LoggingLevel level, const std::string &text) override { + // Some bus devices send these continuously. The stack's text has no source address; the application + // reports them per source once per minute instead (see report_global_rts_counts in app.cpp). + if ((LoggingLevel::Warning == level) && + (text == "[TP]: Received a Request to Send (RTS) message with a global destination, ignoring")) + { + level = LoggingLevel::Debug; + if (get_log_level() > LoggingLevel::Debug) + { + return; + } + } + std::ostream &out = async_log::stream(); out << "[" << get_timestamp() << "] "; switch (level) diff --git a/src/udp_connections.cpp b/src/udp_connections.cpp index a4e7540..ad85a22 100644 --- a/src/udp_connections.cpp +++ b/src/udp_connections.cpp @@ -8,8 +8,11 @@ */ #include "udp_connections.hpp" +#include #include +#include #include +#include #include "logging_utils.hpp" #if !defined(_WIN32) @@ -153,6 +156,34 @@ std::uint8_t UdpConnections::calculate_crc(std::span data) return static_cast(result & 0xFF); } +void UdpConnections::log_unknown_start(const udp::endpoint &sender, std::span data) +{ + // Both sockets listen on port 8888 (one on the AOG subnet address, one on all interfaces), so a + // broadcast packet usually arrives on both. Only log it once. + static constexpr std::size_t MAX_LOGGED_BYTES = 16; + static constexpr auto DUPLICATE_WINDOW = std::chrono::milliseconds(50); + + std::ostringstream signature; + signature << sender.address().to_string() << ":" << sender.port() << " " << std::hex << std::setfill('0'); + for (std::size_t i = 0; i < std::min(data.size(), MAX_LOGGED_BYTES); i++) + { + signature << (i ? " " : "") << std::setw(2) << static_cast(data[i]); + } + if (data.size() > MAX_LOGGED_BYTES) + { + signature << " ..."; + } + + const auto now = std::chrono::steady_clock::now(); + if ((signature.str() == lastUnknownStartSignature) && (now - lastUnknownStartTime < DUPLICATE_WINDOW)) + { + return; + } + lastUnknownStartSignature = signature.str(); + lastUnknownStartTime = now; + log() << "Unknown start of message from " << lastUnknownStartSignature << " (" << std::dec << data.size() << " bytes)" << std::endl; +} + void UdpConnections::handle_incoming_packets() { static std::array rxBuffer; @@ -200,7 +231,7 @@ void UdpConnections::handle_incoming_packets() else { // Unknown start of message, reset buffer - log() << "Unknown start of message: 0x" << std::hex << start << std::dec << std::endl; + log_unknown_start(sender_endpoint, { rxBuffer.data() + index - 2, rxIndex - (index - 2) }); rxIndex = 0; } @@ -288,7 +319,7 @@ void UdpConnections::handle_address_detection() else { // Unknown start of message, reset buffer - log() << "Unknown start of message: 0x" << std::hex << start << std::dec << std::endl; + log_unknown_start(sender_endpoint, { rxBuffer.data() + index - 2, rxIndex - (index - 2) }); rxIndex = 0; } From a11fdade70fe94b87d4578eac7cdf9faf815a484 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gunics=20Bal=C3=A1zs?= Date: Mon, 28 Sep 2026 22:35:17 +0200 Subject: [PATCH 2/2] Log DDOPs without sections as a non-section client instead of a warning A client whose DDOP has no section elements, such as a tractor ECU that only describes hitch or GNSS geometry, has nothing to section-control. It was reported with "WARNING: No supported section control method detected!", which sent people looking for a problem that is not there. Log it as info ("Non-section client") when the DDOP has zero sections; DDOPs that do have sections but no supported method still get the warning. Co-Authored-By: Claude Opus 5.5 --- src/task_controller.cpp | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/task_controller.cpp b/src/task_controller.cpp index f60afef..b13a7ef 100644 --- a/src/task_controller.cpp +++ b/src/task_controller.cpp @@ -597,6 +597,11 @@ bool MyTCServer::activate_object_pool(std::shared_ptr p log() << " Section " << static_cast(i) << " -> element " << sectionElementNumbers[i] << std::endl; } } + else if (0 == numberOfSections) + { + // e.g. a tractor ECU describing hitch or GNSS geometry: nothing to control, nothing wrong + log("TC Server") << "Non-section client: the DDOP has no section elements, section control not applicable." << std::endl; + } else { log("TC Server") << "WARNING: No supported section control method detected! "