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/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! " 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; }