diff --git a/docs/cli_commands.md b/docs/cli_commands.md index 819b613337..bb5b53bd9c 100644 --- a/docs/cli_commands.md +++ b/docs/cli_commands.md @@ -157,6 +157,20 @@ This document provides an overview of CLI commands that can be sent to MeshCore --- +### Mirror packet log to serial (live) +**Usage:** `log tail on` + +**Note:** Streams RX/TX log lines to USB serial as they are captured. Enables logging if not already active (`log start`). Serial-only (not available via remote admin). + +--- + +### Stop live serial log mirror +**Usage:** `log tail off` + +**Serial Only:** Yes + +--- + ### Erase captured log **Usage:** `log erase` diff --git a/examples/simple_repeater/MyMesh.cpp b/examples/simple_repeater/MyMesh.cpp index b66e19522a..97b402fe16 100644 --- a/examples/simple_repeater/MyMesh.cpp +++ b/examples/simple_repeater/MyMesh.cpp @@ -463,6 +463,14 @@ const char *MyMesh::getLogDateTime() { return tmp; } +namespace { +const char* packetLogTypeLabel(const mesh::Packet* pkt) { + static char label[40]; + mesh::formatPayloadType(pkt->getPayloadType(), label, sizeof label); + return label; +} +} + void MyMesh::logRxRaw(float snr, float rssi, const uint8_t raw[], int len) { #if MESH_PACKET_LOGGING Serial.print(getLogDateTime()); @@ -472,6 +480,38 @@ void MyMesh::logRxRaw(float snr, float rssi, const uint8_t raw[], int len) { #endif } +void MyMesh::mirrorPacketLogRxToSerial(mesh::Packet *pkt, int len, float score) { + Serial.print(getLogDateTime()); + Serial.printf(": RX, len=%d (type=%s, route=%s, payload_len=%d) SNR=%d RSSI=%d score=%d", len, + packetLogTypeLabel(pkt), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len, + (int)_radio->getLastSNR(), (int)_radio->getLastRSSI(), (int)(score * 1000)); + + if (pkt->getPayloadType() == PAYLOAD_TYPE_PATH || pkt->getPayloadType() == PAYLOAD_TYPE_REQ || + pkt->getPayloadType() == PAYLOAD_TYPE_RESPONSE || pkt->getPayloadType() == PAYLOAD_TYPE_TXT_MSG) { + Serial.printf(" [%02X -> %02X]", (uint32_t)pkt->payload[1], (uint32_t)pkt->payload[0]); + } + Serial.print("\r\n"); +} + +void MyMesh::mirrorPacketLogTxToSerial(mesh::Packet *pkt, int len) { + Serial.print(getLogDateTime()); + Serial.printf(": TX, len=%d (type=%s, route=%s, payload_len=%d)", len, packetLogTypeLabel(pkt), + pkt->isRouteDirect() ? "D" : "F", pkt->payload_len); + + if (pkt->getPayloadType() == PAYLOAD_TYPE_PATH || pkt->getPayloadType() == PAYLOAD_TYPE_REQ || + pkt->getPayloadType() == PAYLOAD_TYPE_RESPONSE || pkt->getPayloadType() == PAYLOAD_TYPE_TXT_MSG) { + Serial.printf(" [%02X -> %02X]", (uint32_t)pkt->payload[1], (uint32_t)pkt->payload[0]); + } + Serial.print("\r\n"); +} + +void MyMesh::mirrorPacketLogTxFailToSerial(mesh::Packet *pkt, int len) { + Serial.print(getLogDateTime()); + Serial.printf(": TX FAIL!, len=%d (type=%s, route=%s, payload_len=%d)", len, packetLogTypeLabel(pkt), + pkt->isRouteDirect() ? "D" : "F", pkt->payload_len); + Serial.print("\r\n"); +} + void MyMesh::logRx(mesh::Packet *pkt, int len, float score) { #ifdef WITH_BRIDGE if (_prefs.bridge_pkt_src == 1) { @@ -483,8 +523,8 @@ void MyMesh::logRx(mesh::Packet *pkt, int len, float score) { File f = openAppend(PACKET_LOG_FILE); if (f) { f.print(getLogDateTime()); - f.printf(": RX, len=%d (type=%d, route=%s, payload_len=%d) SNR=%d RSSI=%d score=%d", len, - pkt->getPayloadType(), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len, + f.printf(": RX, len=%d (type=%s, route=%s, payload_len=%d) SNR=%d RSSI=%d score=%d", len, + packetLogTypeLabel(pkt), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len, (int)_radio->getLastSNR(), (int)_radio->getLastRSSI(), (int)(score * 1000)); if (pkt->getPayloadType() == PAYLOAD_TYPE_PATH || pkt->getPayloadType() == PAYLOAD_TYPE_REQ || @@ -496,6 +536,9 @@ void MyMesh::logRx(mesh::Packet *pkt, int len, float score) { f.close(); } } + if (_logging && _tailing) { + mirrorPacketLogRxToSerial(pkt, len, score); + } } void MyMesh::logTx(mesh::Packet *pkt, int len) { @@ -509,7 +552,7 @@ void MyMesh::logTx(mesh::Packet *pkt, int len) { File f = openAppend(PACKET_LOG_FILE); if (f) { f.print(getLogDateTime()); - f.printf(": TX, len=%d (type=%d, route=%s, payload_len=%d)", len, pkt->getPayloadType(), + f.printf(": TX, len=%d (type=%s, route=%s, payload_len=%d)", len, packetLogTypeLabel(pkt), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len); if (pkt->getPayloadType() == PAYLOAD_TYPE_PATH || pkt->getPayloadType() == PAYLOAD_TYPE_REQ || @@ -521,6 +564,9 @@ void MyMesh::logTx(mesh::Packet *pkt, int len) { f.close(); } } + if (_logging && _tailing) { + mirrorPacketLogTxToSerial(pkt, len); + } } void MyMesh::logTxFail(mesh::Packet *pkt, int len) { @@ -528,11 +574,14 @@ void MyMesh::logTxFail(mesh::Packet *pkt, int len) { File f = openAppend(PACKET_LOG_FILE); if (f) { f.print(getLogDateTime()); - f.printf(": TX FAIL!, len=%d (type=%d, route=%s, payload_len=%d)\n", len, pkt->getPayloadType(), + f.printf(": TX FAIL!, len=%d (type=%s, route=%s, payload_len=%d)\n", len, packetLogTypeLabel(pkt), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len); f.close(); } } + if (_logging && _tailing) { + mirrorPacketLogTxFailToSerial(pkt, len); + } } int MyMesh::calcRxDelay(float score, uint32_t air_time) const { @@ -864,6 +913,7 @@ MyMesh::MyMesh(mesh::MainBoard &board, mesh::Radio &radio, mesh::MillisecondCloc dirty_contacts_expiry = 0; set_radio_at = revert_radio_at = 0; _logging = false; + _tailing = false; region_load_active = false; recv_pkt_region = NULL; diff --git a/examples/simple_repeater/MyMesh.h b/examples/simple_repeater/MyMesh.h index 0b2e7491b7..14ac2316fc 100644 --- a/examples/simple_repeater/MyMesh.h +++ b/examples/simple_repeater/MyMesh.h @@ -86,6 +86,7 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks { uint64_t uptime_millis; unsigned long next_local_advert, next_flood_advert; bool _logging; + bool _tailing; NodePrefs _prefs; ClientACL acl; CommonCLI _cli; @@ -129,6 +130,9 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks { File openAppend(const char* fname); bool isLooped(const mesh::Packet* packet, const uint8_t max_counters[]); + void mirrorPacketLogRxToSerial(mesh::Packet* pkt, int len, float score); + void mirrorPacketLogTxToSerial(mesh::Packet* pkt, int len); + void mirrorPacketLogTxFailToSerial(mesh::Packet* pkt, int len); protected: float getAirtimeBudgetFactor() const override { @@ -206,6 +210,8 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks { void setLoggingOn(bool enable) override { _logging = enable; } + void setTailOn(bool enable) override { _tailing = enable; } + void eraseLogFile() override { _fs->remove(PACKET_LOG_FILE); } diff --git a/examples/simple_repeater/main.cpp b/examples/simple_repeater/main.cpp index a714db68ec..95895d1952 100644 --- a/examples/simple_repeater/main.cpp +++ b/examples/simple_repeater/main.cpp @@ -127,6 +127,11 @@ void loop() { int len = strlen(command); while (Serial.available() && len < sizeof(command)-1) { char c = Serial.read(); + if (c == 3) { // Ctrl+C — stop live log tail + the_mesh.setTailOn(false); + Serial.print("\r\n -> tail off\r\n"); + continue; + } if (c != '\n') { command[len++] = c; command[len] = 0; diff --git a/examples/simple_room_server/MyMesh.cpp b/examples/simple_room_server/MyMesh.cpp index 36978e808f..61927d0368 100644 --- a/examples/simple_room_server/MyMesh.cpp +++ b/examples/simple_room_server/MyMesh.cpp @@ -199,6 +199,14 @@ int MyMesh::handleRequest(ClientInfo *sender, uint32_t sender_timestamp, uint8_t return 0; // unknown command } +namespace { +const char* packetLogTypeLabel(const mesh::Packet* pkt) { + static char label[40]; + mesh::formatPayloadType(pkt->getPayloadType(), label, sizeof label); + return label; +} +} + void MyMesh::logRxRaw(float snr, float rssi, const uint8_t raw[], int len) { #if MESH_PACKET_LOGGING Serial.print(getLogDateTime()); @@ -208,13 +216,45 @@ void MyMesh::logRxRaw(float snr, float rssi, const uint8_t raw[], int len) { #endif } +void MyMesh::mirrorPacketLogRxToSerial(mesh::Packet *pkt, int len, float score) { + Serial.print(getLogDateTime()); + Serial.printf(": RX, len=%d (type=%s, route=%s, payload_len=%d) SNR=%d RSSI=%d score=%d", len, + packetLogTypeLabel(pkt), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len, + (int)_radio->getLastSNR(), (int)_radio->getLastRSSI(), (int)(score * 1000)); + + if (pkt->getPayloadType() == PAYLOAD_TYPE_PATH || pkt->getPayloadType() == PAYLOAD_TYPE_REQ || + pkt->getPayloadType() == PAYLOAD_TYPE_RESPONSE || pkt->getPayloadType() == PAYLOAD_TYPE_TXT_MSG) { + Serial.printf(" [%02X -> %02X]", (uint32_t)pkt->payload[1], (uint32_t)pkt->payload[0]); + } + Serial.print("\r\n"); +} + +void MyMesh::mirrorPacketLogTxToSerial(mesh::Packet *pkt, int len) { + Serial.print(getLogDateTime()); + Serial.printf(": TX, len=%d (type=%s, route=%s, payload_len=%d)", len, packetLogTypeLabel(pkt), + pkt->isRouteDirect() ? "D" : "F", pkt->payload_len); + + if (pkt->getPayloadType() == PAYLOAD_TYPE_PATH || pkt->getPayloadType() == PAYLOAD_TYPE_REQ || + pkt->getPayloadType() == PAYLOAD_TYPE_RESPONSE || pkt->getPayloadType() == PAYLOAD_TYPE_TXT_MSG) { + Serial.printf(" [%02X -> %02X]", (uint32_t)pkt->payload[1], (uint32_t)pkt->payload[0]); + } + Serial.print("\r\n"); +} + +void MyMesh::mirrorPacketLogTxFailToSerial(mesh::Packet *pkt, int len) { + Serial.print(getLogDateTime()); + Serial.printf(": TX FAIL!, len=%d (type=%s, route=%s, payload_len=%d)", len, packetLogTypeLabel(pkt), + pkt->isRouteDirect() ? "D" : "F", pkt->payload_len); + Serial.print("\r\n"); +} + void MyMesh::logRx(mesh::Packet *pkt, int len, float score) { if (_logging) { File f = openAppend(PACKET_LOG_FILE); if (f) { f.print(getLogDateTime()); - f.printf(": RX, len=%d (type=%d, route=%s, payload_len=%d) SNR=%d RSSI=%d score=%d", len, - pkt->getPayloadType(), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len, + f.printf(": RX, len=%d (type=%s, route=%s, payload_len=%d) SNR=%d RSSI=%d score=%d", len, + packetLogTypeLabel(pkt), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len, (int)_radio->getLastSNR(), (int)_radio->getLastRSSI(), (int)(score * 1000)); if (pkt->getPayloadType() == PAYLOAD_TYPE_PATH || pkt->getPayloadType() == PAYLOAD_TYPE_REQ || @@ -226,13 +266,16 @@ void MyMesh::logRx(mesh::Packet *pkt, int len, float score) { f.close(); } } + if (_logging && _tailing) { + mirrorPacketLogRxToSerial(pkt, len, score); + } } void MyMesh::logTx(mesh::Packet *pkt, int len) { if (_logging) { File f = openAppend(PACKET_LOG_FILE); if (f) { f.print(getLogDateTime()); - f.printf(": TX, len=%d (type=%d, route=%s, payload_len=%d)", len, pkt->getPayloadType(), + f.printf(": TX, len=%d (type=%s, route=%s, payload_len=%d)", len, packetLogTypeLabel(pkt), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len); if (pkt->getPayloadType() == PAYLOAD_TYPE_PATH || pkt->getPayloadType() == PAYLOAD_TYPE_REQ || @@ -244,17 +287,23 @@ void MyMesh::logTx(mesh::Packet *pkt, int len) { f.close(); } } + if (_logging && _tailing) { + mirrorPacketLogTxToSerial(pkt, len); + } } void MyMesh::logTxFail(mesh::Packet *pkt, int len) { if (_logging) { File f = openAppend(PACKET_LOG_FILE); if (f) { f.print(getLogDateTime()); - f.printf(": TX FAIL!, len=%d (type=%d, route=%s, payload_len=%d)\n", len, pkt->getPayloadType(), + f.printf(": TX FAIL!, len=%d (type=%s, route=%s, payload_len=%d)\n", len, packetLogTypeLabel(pkt), pkt->isRouteDirect() ? "D" : "F", pkt->payload_len); f.close(); } } + if (_logging && _tailing) { + mirrorPacketLogTxFailToSerial(pkt, len); + } } int MyMesh::calcRxDelay(float score, uint32_t air_time) const { @@ -623,6 +672,7 @@ MyMesh::MyMesh(mesh::MainBoard &board, mesh::Radio &radio, mesh::MillisecondCloc next_local_advert = next_flood_advert = 0; dirty_contacts_expiry = 0; _logging = false; + _tailing = false; region_load_active = false; set_radio_at = revert_radio_at = 0; recv_pkt_region = NULL; diff --git a/examples/simple_room_server/MyMesh.h b/examples/simple_room_server/MyMesh.h index 6bab9dc2d0..a0342cb7c1 100644 --- a/examples/simple_room_server/MyMesh.h +++ b/examples/simple_room_server/MyMesh.h @@ -94,6 +94,7 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks { uint64_t uptime_millis; unsigned long next_local_advert, next_flood_advert; bool _logging; + bool _tailing; bool region_load_active; NodePrefs _prefs; TransportKeyStore key_store; @@ -124,6 +125,9 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks { bool processAck(const uint8_t *data); mesh::Packet* createSelfAdvert(); File openAppend(const char* fname); + void mirrorPacketLogRxToSerial(mesh::Packet* pkt, int len, float score); + void mirrorPacketLogTxToSerial(mesh::Packet* pkt, int len); + void mirrorPacketLogTxFailToSerial(mesh::Packet* pkt, int len); int handleRequest(ClientInfo* sender, uint32_t sender_timestamp, uint8_t* payload, size_t payload_len); protected: @@ -200,6 +204,8 @@ class MyMesh : public mesh::Mesh, public CommonCLICallbacks { void setLoggingOn(bool enable) override { _logging = enable; } + void setTailOn(bool enable) override { _tailing = enable; } + void eraseLogFile() override { _fs->remove(PACKET_LOG_FILE); } diff --git a/examples/simple_room_server/main.cpp b/examples/simple_room_server/main.cpp index d833fff39e..1349bc2695 100644 --- a/examples/simple_room_server/main.cpp +++ b/examples/simple_room_server/main.cpp @@ -107,6 +107,11 @@ void loop() { int len = strlen(command); while (Serial.available() && len < sizeof(command)-1) { char c = Serial.read(); + if (c == 3) { // Ctrl+C — stop live log tail + the_mesh.setTailOn(false); + Serial.print("\r\n -> tail off\r\n"); + continue; + } if (c != '\n') { command[len++] = c; command[len] = 0; diff --git a/examples/simple_sensor/SensorMesh.h b/examples/simple_sensor/SensorMesh.h index 1d65b8772b..b850cf2d30 100644 --- a/examples/simple_sensor/SensorMesh.h +++ b/examples/simple_sensor/SensorMesh.h @@ -65,6 +65,7 @@ class SensorMesh : public mesh::Mesh, public CommonCLICallbacks { void updateAdvertTimer() override; void updateFloodAdvertTimer() override; void setLoggingOn(bool enable) override { } + void setTailOn(bool enable) override { } void eraseLogFile() override { } void dumpLogFile() override { } void setTxPower(int8_t power_dbm) override; diff --git a/src/Packet.cpp b/src/Packet.cpp index aad3e2f48e..f55af06f7b 100644 --- a/src/Packet.cpp +++ b/src/Packet.cpp @@ -1,9 +1,49 @@ #include "Packet.h" +#include #include #include namespace mesh { +namespace { + +struct PayloadTypeName { uint8_t type; const char* name; }; + +static const PayloadTypeName PAYLOAD_TYPE_NAMES[] = { + { PAYLOAD_TYPE_REQ, "PAYLOAD_TYPE_REQ" }, + { PAYLOAD_TYPE_RESPONSE, "PAYLOAD_TYPE_RESPONSE" }, + { PAYLOAD_TYPE_TXT_MSG, "PAYLOAD_TYPE_TXT_MSG" }, + { PAYLOAD_TYPE_ACK, "PAYLOAD_TYPE_ACK" }, + { PAYLOAD_TYPE_ADVERT, "PAYLOAD_TYPE_ADVERT" }, + { PAYLOAD_TYPE_GRP_TXT, "PAYLOAD_TYPE_GRP_TXT" }, + { PAYLOAD_TYPE_GRP_DATA, "PAYLOAD_TYPE_GRP_DATA" }, + { PAYLOAD_TYPE_ANON_REQ, "PAYLOAD_TYPE_ANON_REQ" }, + { PAYLOAD_TYPE_PATH, "PAYLOAD_TYPE_PATH" }, + { PAYLOAD_TYPE_TRACE, "PAYLOAD_TYPE_TRACE" }, + { PAYLOAD_TYPE_MULTIPART, "PAYLOAD_TYPE_MULTIPART" }, + { PAYLOAD_TYPE_CONTROL, "PAYLOAD_TYPE_CONTROL" }, + { PAYLOAD_TYPE_OTA, "PAYLOAD_TYPE_OTA" }, + { PAYLOAD_TYPE_RAW_CUSTOM, "PAYLOAD_TYPE_RAW_CUSTOM" }, +}; + +} // namespace + +const char* payloadTypeName(uint8_t type) { + for (unsigned i = 0; i < sizeof(PAYLOAD_TYPE_NAMES) / sizeof(PAYLOAD_TYPE_NAMES[0]); i++) { + if (PAYLOAD_TYPE_NAMES[i].type == type) return PAYLOAD_TYPE_NAMES[i].name; + } + return nullptr; +} + +void formatPayloadType(uint8_t type, char* buf, size_t cap) { + const char* name = payloadTypeName(type); + if (name) { + snprintf(buf, cap, "%s (0x%02X)", name, type); + } else { + snprintf(buf, cap, "UNKNOWN (0x%02X)", type); + } +} + Packet::Packet() { header = 0; path_len = 0; diff --git a/src/Packet.h b/src/Packet.h index c19d9e9d8f..b5c976c9f1 100644 --- a/src/Packet.h +++ b/src/Packet.h @@ -111,4 +111,7 @@ class Packet { bool readFrom(const uint8_t src[], uint8_t len); }; +const char* payloadTypeName(uint8_t type); +void formatPayloadType(uint8_t type, char* buf, size_t cap); + } diff --git a/src/helpers/CommonCLI.cpp b/src/helpers/CommonCLI.cpp index c95e3e34b0..f767ceae98 100644 --- a/src/helpers/CommonCLI.cpp +++ b/src/helpers/CommonCLI.cpp @@ -461,6 +461,15 @@ void CommonCLI::handleCommand(uint32_t sender_timestamp, char* command, char* re } else { strcpy(reply, "off"); } + } else if (sender_timestamp == 0 && memcmp(command, "log tail on", 11) == 0 + && (command[11] == 0 || command[11] == ' ')) { + _callbacks->setLoggingOn(true); + _callbacks->setTailOn(true); + strcpy(reply, " tail on"); + } else if (sender_timestamp == 0 && memcmp(command, "log tail off", 12) == 0 + && (command[12] == 0 || command[12] == ' ')) { + _callbacks->setTailOn(false); + strcpy(reply, " tail off"); } else if (memcmp(command, "log start", 9) == 0) { _callbacks->setLoggingOn(true); strcpy(reply, " logging on"); diff --git a/src/helpers/CommonCLI.h b/src/helpers/CommonCLI.h index f3abcf4772..bbec37d41b 100644 --- a/src/helpers/CommonCLI.h +++ b/src/helpers/CommonCLI.h @@ -78,6 +78,7 @@ class CommonCLICallbacks { virtual void updateAdvertTimer() = 0; virtual void updateFloodAdvertTimer() = 0; virtual void setLoggingOn(bool enable) = 0; + virtual void setTailOn(bool enable) = 0; virtual void eraseLogFile() = 0; virtual void dumpLogFile() = 0; virtual void setTxPower(int8_t power_dbm) = 0;