Refactor debug logging across bridge implementations

This commit is contained in:
João Brázio
2025-10-06 12:57:04 +01:00
parent 9b4d93d112
commit fb46e5cc8a
7 changed files with 48 additions and 70 deletions

View File

@@ -185,12 +185,19 @@ public:
#if defined(WITH_BRIDGE) #if defined(WITH_BRIDGE)
void setBridgeState(bool enable) override { void setBridgeState(bool enable) override {
if (enable == bridge.getState()) return; if (enable == bridge.isRunning()) return;
enable ? bridge.begin() : bridge.end(); if (enable)
{
bridge.begin();
}
else
{
bridge.end();
}
} }
void restartBridge() override { void restartBridge() override {
if (!bridge.getState()) return; if (!bridge.isRunning()) return;
bridge.end(); bridge.end();
bridge.begin(); bridge.begin();
} }

View File

@@ -28,6 +28,12 @@
#define MESH_DEBUG_PRINTLN(...) {} #define MESH_DEBUG_PRINTLN(...) {}
#endif #endif
#if BRIDGE_DEBUG && ARDUINO
#define BRIDGE_DEBUG_PRINTLN(F, ...) Serial.printf("%s BRIDGE: " F, getLogDateTime(), ##__VA_ARGS__)
#else
#define BRIDGE_DEBUG_PRINTLN(...) {}
#endif
namespace mesh { namespace mesh {
#define BD_STARTUP_NORMAL 0 // getStartupReason() codes #define BD_STARTUP_NORMAL 0 // getStartupReason() codes

View File

@@ -21,7 +21,7 @@ public:
* *
* @return true if the bridge is initialized and running, false otherwise. * @return true if the bridge is initialized and running, false otherwise.
*/ */
virtual bool getState() const = 0; virtual bool isRunning() const = 0;
/** /**
* @brief A method to be called on every main loop iteration. * @brief A method to be called on every main loop iteration.

View File

@@ -2,7 +2,7 @@
#include <Arduino.h> #include <Arduino.h>
bool BridgeBase::getState() const { bool BridgeBase::isRunning() const {
return _initialized; return _initialized;
} }
@@ -34,7 +34,7 @@ bool BridgeBase::validateChecksum(const uint8_t *data, size_t len, uint16_t rece
void BridgeBase::handleReceivedPacket(mesh::Packet *packet) { void BridgeBase::handleReceivedPacket(mesh::Packet *packet) {
// Guard against uninitialized state // Guard against uninitialized state
if (_initialized == false) { if (_initialized == false) {
Serial.printf("%s: BRIDGE: RX packet received before initialization\n", getLogDateTime()); BRIDGE_DEBUG_PRINTLN("RX packet received before initialization\n");
_mgr->free(packet); _mgr->free(packet);
return; return;
} }

View File

@@ -27,7 +27,7 @@ public:
* *
* @return true if the bridge is initialized and running, false otherwise. * @return true if the bridge is initialized and running, false otherwise.
*/ */
bool getState() const override; bool isRunning() const override;
/** /**
* @brief Common magic number used by all bridge implementations for packet identification * @brief Common magic number used by all bridge implementations for packet identification

View File

@@ -27,20 +27,20 @@ ESPNowBridge::ESPNowBridge(NodePrefs *prefs, mesh::PacketManager *mgr, mesh::RTC
} }
void ESPNowBridge::begin() { void ESPNowBridge::begin() {
Serial.printf("%s: ESPNOW BRIDGE: Initializing...\n", getLogDateTime()); BRIDGE_DEBUG_PRINTLN("Initializing...\n");
// Initialize WiFi in station mode // Initialize WiFi in station mode
WiFi.mode(WIFI_STA); WiFi.mode(WIFI_STA);
// Set wifi channel // Set wifi channel
if (esp_wifi_set_channel(_prefs->bridge_channel, WIFI_SECOND_CHAN_NONE) != ESP_OK) { if (esp_wifi_set_channel(_prefs->bridge_channel, WIFI_SECOND_CHAN_NONE) != ESP_OK) {
Serial.printf("%s: ESPNOW BRIDGE: Error setting WIFI channel to %d\n", getLogDateTime(), _prefs->bridge_channel); BRIDGE_DEBUG_PRINTLN("Error setting WIFI channel to %d\n", _prefs->bridge_channel);
return; return;
} }
// Initialize ESP-NOW // Initialize ESP-NOW
if (esp_now_init() != ESP_OK) { if (esp_now_init() != ESP_OK) {
Serial.printf("%s: ESPNOW BRIDGE: Error initializing ESP-NOW\n", getLogDateTime()); BRIDGE_DEBUG_PRINTLN("Error initializing ESP-NOW\n");
return; return;
} }
@@ -56,7 +56,7 @@ void ESPNowBridge::begin() {
peerInfo.encrypt = false; peerInfo.encrypt = false;
if (esp_now_add_peer(&peerInfo) != ESP_OK) { if (esp_now_add_peer(&peerInfo) != ESP_OK) {
Serial.printf("%s: ESPNOW BRIDGE: Failed to add broadcast peer\n", getLogDateTime()); BRIDGE_DEBUG_PRINTLN("Failed to add broadcast peer\n");
return; return;
} }
@@ -65,12 +65,12 @@ void ESPNowBridge::begin() {
} }
void ESPNowBridge::end() { void ESPNowBridge::end() {
Serial.printf("%s: ESPNOW BRIDGE: Stopping...\n", getLogDateTime()); BRIDGE_DEBUG_PRINTLN("Stopping...\n");
// Remove broadcast peer // Remove broadcast peer
uint8_t broadcastAddress[] = { 0xFF, 0xFF, 0xFF, 0xFF, 0xFF, 0xFF }; uint8_t broadcastAddress[] = { 0xFF, 0xFF, 0xFF, 0xFF, 0xFF, 0xFF };
if (esp_now_del_peer(broadcastAddress) != ESP_OK) { if (esp_now_del_peer(broadcastAddress) != ESP_OK) {
Serial.printf("%s: ESPNOW BRIDGE: Error removing broadcast peer\n", getLogDateTime()); BRIDGE_DEBUG_PRINTLN("Error removing broadcast peer\n");
} }
// Unregister callbacks // Unregister callbacks
@@ -79,7 +79,7 @@ void ESPNowBridge::end() {
// Deinitialize ESP-NOW // Deinitialize ESP-NOW
if (esp_now_deinit() != ESP_OK) { if (esp_now_deinit() != ESP_OK) {
Serial.printf("%s: ESPNOW BRIDGE: Error deinitializing ESP-NOW\n", getLogDateTime()); BRIDGE_DEBUG_PRINTLN("Error deinitializing ESP-NOW\n");
} }
// Turn off WiFi // Turn off WiFi
@@ -103,26 +103,20 @@ void ESPNowBridge::xorCrypt(uint8_t *data, size_t len) {
void ESPNowBridge::onDataRecv(const uint8_t *mac, const uint8_t *data, int32_t len) { void ESPNowBridge::onDataRecv(const uint8_t *mac, const uint8_t *data, int32_t len) {
// Ignore packets that are too small to contain header + checksum // Ignore packets that are too small to contain header + checksum
if (len < (BRIDGE_MAGIC_SIZE + BRIDGE_CHECKSUM_SIZE)) { if (len < (BRIDGE_MAGIC_SIZE + BRIDGE_CHECKSUM_SIZE)) {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX packet too small, len=%d\n", len);
Serial.printf("%s: ESPNOW BRIDGE: RX packet too small, len=%d\n", getLogDateTime(), len);
#endif
return; return;
} }
// Validate total packet size // Validate total packet size
if (len > MAX_ESPNOW_PACKET_SIZE) { if (len > MAX_ESPNOW_PACKET_SIZE) {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX packet too large, len=%d\n", len);
Serial.printf("%s: ESPNOW BRIDGE: RX packet too large, len=%d\n", getLogDateTime(), len);
#endif
return; return;
} }
// Check packet header magic // Check packet header magic
uint16_t received_magic = (data[0] << 8) | data[1]; uint16_t received_magic = (data[0] << 8) | data[1];
if (received_magic != BRIDGE_PACKET_MAGIC) { if (received_magic != BRIDGE_PACKET_MAGIC) {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX invalid magic 0x%04X\n", received_magic);
Serial.printf("%s: ESPNOW BRIDGE: RX invalid magic 0x%04X\n", getLogDateTime(), received_magic);
#endif
return; return;
} }
@@ -140,16 +134,11 @@ void ESPNowBridge::onDataRecv(const uint8_t *mac, const uint8_t *data, int32_t l
if (!validateChecksum(decrypted + BRIDGE_CHECKSUM_SIZE, payloadLen, received_checksum)) { if (!validateChecksum(decrypted + BRIDGE_CHECKSUM_SIZE, payloadLen, received_checksum)) {
// Failed to decrypt - likely from a different network // Failed to decrypt - likely from a different network
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX checksum mismatch, rcv=0x%04X\n", received_checksum);
Serial.printf("%s: ESPNOW BRIDGE: RX checksum mismatch, rcv=0x%04X\n", getLogDateTime(),
received_checksum);
#endif
return; return;
} }
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX, payload_len=%d\n", payloadLen);
Serial.printf("%s: ESPNOW BRIDGE: RX, payload_len=%d\n", getLogDateTime(), payloadLen);
#endif
// Create mesh packet // Create mesh packet
mesh::Packet *pkt = _instance->_mgr->allocNew(); mesh::Packet *pkt = _instance->_mgr->allocNew();
@@ -174,9 +163,7 @@ void ESPNowBridge::sendPacket(mesh::Packet *packet) {
// First validate the packet pointer // First validate the packet pointer
if (!packet) { if (!packet) {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("TX invalid packet pointer\n");
Serial.printf("%s: ESPNOW BRIDGE: TX invalid packet pointer\n", getLogDateTime());
#endif
return; return;
} }
@@ -187,10 +174,8 @@ void ESPNowBridge::sendPacket(mesh::Packet *packet) {
// Check if packet fits within our maximum payload size // Check if packet fits within our maximum payload size
if (meshPacketLen > MAX_PAYLOAD_SIZE) { if (meshPacketLen > MAX_PAYLOAD_SIZE) {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("TX packet too large (payload=%d, max=%d)\n", meshPacketLen,
Serial.printf("%s: ESPNOW BRIDGE: TX packet too large (payload=%d, max=%d)\n", getLogDateTime(), MAX_PAYLOAD_SIZE);
meshPacketLen, MAX_PAYLOAD_SIZE);
#endif
return; return;
} }
@@ -219,13 +204,11 @@ void ESPNowBridge::sendPacket(mesh::Packet *packet) {
uint8_t broadcastAddress[] = { 0xFF, 0xFF, 0xFF, 0xFF, 0xFF, 0xFF }; uint8_t broadcastAddress[] = { 0xFF, 0xFF, 0xFF, 0xFF, 0xFF, 0xFF };
esp_err_t result = esp_now_send(broadcastAddress, buffer, totalPacketSize); esp_err_t result = esp_now_send(broadcastAddress, buffer, totalPacketSize);
#if MESH_PACKET_LOGGING
if (result == ESP_OK) { if (result == ESP_OK) {
Serial.printf("%s: ESPNOW BRIDGE: TX, len=%d\n", getLogDateTime(), meshPacketLen); BRIDGE_DEBUG_PRINTLN("TX, len=%d\n", meshPacketLen);
} else { } else {
Serial.printf("%s: ESPNOW BRIDGE: TX FAILED!\n", getLogDateTime()); BRIDGE_DEBUG_PRINTLN("TX FAILED!\n");
} }
#endif
} }
} }

View File

@@ -8,7 +8,7 @@ RS232Bridge::RS232Bridge(NodePrefs *prefs, Stream &serial, mesh::PacketManager *
: BridgeBase(prefs, mgr, rtc), _serial(&serial) {} : BridgeBase(prefs, mgr, rtc), _serial(&serial) {}
void RS232Bridge::begin() { void RS232Bridge::begin() {
Serial.printf("%s: RS232 BRIDGE: Initializing at %d baud...\n", getLogDateTime(), _prefs->bridge_baud); BRIDGE_DEBUG_PRINTLN("Initializing at %d baud...\n", _prefs->bridge_baud);
#if !defined(WITH_RS232_BRIDGE_RX) || !defined(WITH_RS232_BRIDGE_TX) #if !defined(WITH_RS232_BRIDGE_RX) || !defined(WITH_RS232_BRIDGE_TX)
#error "WITH_RS232_BRIDGE_RX and WITH_RS232_BRIDGE_TX must be defined" #error "WITH_RS232_BRIDGE_RX and WITH_RS232_BRIDGE_TX must be defined"
#endif #endif
@@ -33,7 +33,7 @@ void RS232Bridge::begin() {
} }
void RS232Bridge::end() { void RS232Bridge::end() {
Serial.printf("%s: RS232 BRIDGE: Stopping...\n", getLogDateTime()); BRIDGE_DEBUG_PRINTLN("Stopping...\n");
((HardwareSerial *)_serial)->end(); ((HardwareSerial *)_serial)->end();
// Update bridge state // Update bridge state
@@ -71,9 +71,7 @@ void RS232Bridge::loop() {
// Validate length field // Validate length field
if (len > (MAX_TRANS_UNIT + 1)) { if (len > (MAX_TRANS_UNIT + 1)) {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX invalid length %d, resetting\n", len);
Serial.printf("%s: RS232 BRIDGE: RX invalid length %d, resetting\n", getLogDateTime(), len);
#endif
_rx_buffer_pos = 0; // Invalid length, reset _rx_buffer_pos = 0; // Invalid length, reset
continue; continue;
} }
@@ -82,30 +80,20 @@ void RS232Bridge::loop() {
uint16_t received_checksum = (_rx_buffer[4 + len] << 8) | _rx_buffer[5 + len]; uint16_t received_checksum = (_rx_buffer[4 + len] << 8) | _rx_buffer[5 + len];
if (validateChecksum(_rx_buffer + 4, len, received_checksum)) { if (validateChecksum(_rx_buffer + 4, len, received_checksum)) {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX, len=%d crc=0x%04x\n", len, received_checksum);
Serial.printf("%s: RS232 BRIDGE: RX, len=%d crc=0x%04x\n", getLogDateTime(), len,
received_checksum);
#endif
mesh::Packet *pkt = _mgr->allocNew(); mesh::Packet *pkt = _mgr->allocNew();
if (pkt) { if (pkt) {
if (pkt->readFrom(_rx_buffer + 4, len)) { if (pkt->readFrom(_rx_buffer + 4, len)) {
onPacketReceived(pkt); onPacketReceived(pkt);
} else { } else {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX failed to parse packet\n");
Serial.printf("%s: RS232 BRIDGE: RX failed to parse packet\n", getLogDateTime());
#endif
_mgr->free(pkt); _mgr->free(pkt);
} }
} else { } else {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX failed to allocate packet\n");
Serial.printf("%s: RS232 BRIDGE: RX failed to allocate packet\n", getLogDateTime());
#endif
} }
} else { } else {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("RX checksum mismatch, rcv=0x%04x\n", received_checksum);
Serial.printf("%s: RS232 BRIDGE: RX checksum mismatch, rcv=0x%04x\n", getLogDateTime(),
received_checksum);
#endif
} }
_rx_buffer_pos = 0; // Reset for next packet _rx_buffer_pos = 0; // Reset for next packet
} }
@@ -122,9 +110,7 @@ void RS232Bridge::sendPacket(mesh::Packet *packet) {
// First validate the packet pointer // First validate the packet pointer
if (!packet) { if (!packet) {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("TX invalid packet pointer\n");
Serial.printf("%s: RS232 BRIDGE: TX invalid packet pointer\n", getLogDateTime());
#endif
return; return;
} }
@@ -135,10 +121,8 @@ void RS232Bridge::sendPacket(mesh::Packet *packet) {
// Check if packet fits within our maximum payload size // Check if packet fits within our maximum payload size
if (len > (MAX_TRANS_UNIT + 1)) { if (len > (MAX_TRANS_UNIT + 1)) {
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("TX packet too large (payload=%d, max=%d)\n", len,
Serial.printf("%s: RS232 BRIDGE: TX packet too large (payload=%d, max=%d)\n", getLogDateTime(), len, MAX_TRANS_UNIT + 1);
MAX_TRANS_UNIT + 1);
#endif
return; return;
} }
@@ -156,9 +140,7 @@ void RS232Bridge::sendPacket(mesh::Packet *packet) {
// Send complete packet // Send complete packet
_serial->write(buffer, len + SERIAL_OVERHEAD); _serial->write(buffer, len + SERIAL_OVERHEAD);
#if MESH_PACKET_LOGGING BRIDGE_DEBUG_PRINTLN("TX, len=%d crc=0x%04x\n", len, checksum);
Serial.printf("%s: RS232 BRIDGE: TX, len=%d crc=0x%04x\n", getLogDateTime(), len, checksum);
#endif
} }
} }