Skip to content

Commit f99b95c

Browse files
erayderayd
committed
Add routing stats module
1 parent 13c4c20 commit f99b95c

File tree

5 files changed

+165
-0
lines changed

5 files changed

+165
-0
lines changed

‎src/mesh/MeshPacketQueue.cpp‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
#include "MeshPacketQueue.h"
22
#include "NodeDB.h"
33
#include "configuration.h"
4+
#include "modules/RoutingStatsModule.h"
45
#include <assert.h>
56

67
#include <algorithm>
@@ -76,6 +77,7 @@ bool MeshPacketQueue::enqueue(meshtastic_MeshPacket *p, bool *dropped)
7677
if (dropped) {
7778
*dropped = true;
7879
}
80+
routingStats->logEvent(RoutingEvent::TX_DROP);
7981
return replaced;
8082
}
8183

@@ -86,6 +88,7 @@ bool MeshPacketQueue::enqueue(meshtastic_MeshPacket *p, bool *dropped)
8688
// Find the correct position using upper_bound to maintain a stable order
8789
auto it = std::upper_bound(queue.begin(), queue.end(), p, CompareMeshPacketFunc);
8890
queue.insert(it, p); // Insert packet at the found position
91+
routingStats->logEvent(RoutingEvent::TX_HWM, NULL, queue.size());
8992
return true;
9093
}
9194

‎src/mesh/RadioLibInterface.cpp‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
#include "error.h"
99
#include "main.h"
1010
#include "mesh-pb-constants.h"
11+
#include "modules/RoutingStatsModule.h"
1112
#include <pb_decode.h>
1213
#include <pb_encode.h>
1314

@@ -362,6 +363,7 @@ void RadioLibInterface::clampToLateRebroadcastWindow(NodeNum from, PacketId id)
362363
bool dropped = false;
363364
if (txQueue.enqueue(p, &dropped)) {
364365
LOG_DEBUG("Move existing queued packet to the late rebroadcast window %dms from now", p->tx_after - millis());
366+
routingStats->logEvent(RoutingEvent::TX_DEFER);
365367
} else {
366368
packetPool.release(p);
367369
}
@@ -417,6 +419,8 @@ void RadioLibInterface::completeSending()
417419
txRelay++;
418420
printPacket("Completed sending", p);
419421

422+
routingStats->logEvent(RoutingEvent::TX_OK, p, xmitMsec);
423+
420424
// We are done sending that packet, release it
421425
packetPool.release(p);
422426
}
@@ -458,6 +462,7 @@ void RadioLibInterface::handleReceiveInterrupt()
458462
rxBad++;
459463

460464
airTime->logAirtime(RX_ALL_LOG, rxMsec);
465+
routingStats->logEvent(RoutingEvent::RX_BAD, NULL, rxMsec);
461466

462467
} else {
463468
// Skip the 4 headers that are at the beginning of the rxBuf
@@ -468,6 +473,7 @@ void RadioLibInterface::handleReceiveInterrupt()
468473
LOG_WARN("Ignore received packet too short");
469474
rxBad++;
470475
airTime->logAirtime(RX_ALL_LOG, rxMsec);
476+
routingStats->logEvent(RoutingEvent::RX_BAD, NULL, rxMsec);
471477
} else {
472478
rxGood++;
473479
// altered packet with "from == 0" can do Remote Node Administration without permission
@@ -506,6 +512,7 @@ void RadioLibInterface::handleReceiveInterrupt()
506512
printPacket("Lora RX", mp);
507513

508514
airTime->logAirtime(RX_LOG, rxMsec);
515+
routingStats->logEvent(RoutingEvent::RX_OK, mp, rxMsec);
509516

510517
deliverToReceiver(mp);
511518
}

‎src/modules/Modules.cpp‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
#include "input/SerialKeyboardImpl.h"
99
#include "input/UpDownInterruptImpl1.h"
1010
#include "input/i2cButton.h"
11+
#include "modules/RoutingStatsModule.h"
1112
#include "modules/SystemCommandsModule.h"
1213
#if HAS_TRACKBALL
1314
#include "input/TrackballInterruptImpl1.h"
@@ -112,6 +113,8 @@
112113
*/
113114
void setupModules()
114115
{
116+
routingStats = new RoutingStatsModule();
117+
115118
#if (HAS_BUTTON || ARCH_PORTDUINO) && !MESHTASTIC_EXCLUDE_INPUTBROKER
116119
if (config.display.displaymode != meshtastic_Config_DisplayConfig_DisplayMode_COLOR) {
117120
inputBroker = new InputBroker();

‎src/modules/RoutingStatsModule.cpp‎

Lines changed: 120 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,120 @@
1+
#include "RoutingStatsModule.h"
2+
#include "MeshService.h"
3+
#include "NodeDB.h"
4+
#include "airtime.h"
5+
6+
RoutingStatsModule *routingStats;
7+
8+
#define PRINT_STATS_INTERVAL_MS (60 * 1000) // Print our own stats every 60 seconds
9+
10+
/**
11+
* Log a routing event
12+
*/
13+
void RoutingStatsModule::logEvent(RoutingEvent event, meshtastic_MeshPacket *p, uint32_t detail)
14+
{
15+
switch (event) {
16+
case RoutingEvent::TX_OK:
17+
stats.tx_total++;
18+
stats.tx_total_ms += detail;
19+
if (isFromUs(p)) {
20+
stats.tx_mine++;
21+
if (!p->hop_start)
22+
stats.tx_zero++;
23+
} else
24+
stats.tx_relayed++;
25+
break;
26+
case RoutingEvent::TX_DROP:
27+
stats.tx_dropped++;
28+
break;
29+
case RoutingEvent::TX_DEFER:
30+
stats.tx_deferred++;
31+
break;
32+
case RoutingEvent::TX_HWM:
33+
if (detail > stats.tx_hwm)
34+
stats.tx_hwm = detail;
35+
break;
36+
case RoutingEvent::RX_OK:
37+
stats.rx_total++;
38+
stats.rx_total_ms += detail;
39+
if (p) {
40+
if (p->hop_limit == p->hop_start) {
41+
if (!p->hop_start)
42+
stats.rx_zero++;
43+
else
44+
stats.rx_direct++;
45+
} else if (!p->hop_limit)
46+
stats.rx_eol++;
47+
}
48+
break;
49+
case RoutingEvent::RX_BAD:
50+
stats.rx_bad++;
51+
stats.rx_total_ms += detail;
52+
break;
53+
default:
54+
LOG_WARN("Unknown routing event %d", static_cast<int>(event));
55+
break;
56+
}
57+
}
58+
59+
/**
60+
* Print routing stats to the console
61+
*/
62+
void RoutingStatsModule::printStats(meshtastic_RoutingStats *stats, NodeNum src)
63+
{
64+
const meshtastic_NodeInfoLite *node = nodeDB->getMeshNode(src);
65+
const char *short_name = (node && node->has_user) ? node->user.short_name : "????";
66+
67+
LOG_INFO("Routing stats from %s (0x%08x), last %lu seconds", short_name, src, stats->window_secs);
68+
LOG_INFO(" Airtime: chutil=%lu%% duty=%lu%% rx=%lums tx=%lums", stats->channel_util_pct, stats->tx_duty_pct,
69+
stats->rx_total_ms, stats->tx_total_ms);
70+
LOG_INFO(" TX: packets=%lu relayed=%lu mine=%lu zero-hop=%lu dropped=%lu hwm=%lu", stats->tx_total, stats->tx_relayed,
71+
stats->tx_mine, stats->tx_zero, stats->tx_dropped, stats->tx_hwm);
72+
LOG_INFO(" RX: packets=%lu bad=%lu direct=%lu zero-hop=%lu eol=%lu", stats->rx_total, stats->rx_bad, stats->rx_direct,
73+
stats->rx_zero, stats->rx_eol);
74+
}
75+
76+
/**
77+
* Handle an incoming routing stats protobuf
78+
*/
79+
bool RoutingStatsModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, meshtastic_RoutingStats *decoded)
80+
{
81+
printStats(decoded, getFrom(&mp));
82+
return true;
83+
}
84+
85+
/**
86+
* Periodic thread wakeup
87+
*/
88+
int32_t RoutingStatsModule::runOnce()
89+
{
90+
unsigned long now = millis();
91+
unsigned long next_tx_millis = config.device.routing_stats_broadcast_secs
92+
? (last_tx_millis + config.device.routing_stats_broadcast_secs * 1000)
93+
: INT32_MAX;
94+
unsigned long next_print_millis = last_print_millis + PRINT_STATS_INTERVAL_MS;
95+
96+
// Update 'now' fields
97+
stats.window_secs = (now - last_tx_millis) / 1000;
98+
stats.channel_util_pct = airTime->channelUtilizationPercent();
99+
stats.tx_duty_pct = airTime->utilizationTXPercent();
100+
101+
if (now >= next_print_millis) {
102+
printStats(&stats, nodeDB->getNodeNum());
103+
last_print_millis = now;
104+
next_print_millis = last_print_millis + PRINT_STATS_INTERVAL_MS;
105+
}
106+
107+
if (next_tx_millis > now)
108+
return (next_tx_millis > next_print_millis ? next_print_millis : next_tx_millis) - now;
109+
110+
LOG_DEBUG("Broadcast routing stats for last %d seconds", stats.window_secs);
111+
meshtastic_MeshPacket *p = allocDataProtobuf(stats);
112+
p->to = NODENUM_BROADCAST;
113+
service->sendToMesh(p);
114+
115+
stats = {};
116+
last_tx_millis = now;
117+
next_tx_millis = last_tx_millis + config.device.routing_stats_broadcast_secs * 1000;
118+
119+
return (next_tx_millis > next_print_millis ? next_print_millis : next_tx_millis) - now;
120+
}

‎src/modules/RoutingStatsModule.h‎

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,32 @@
1+
#pragma once
2+
#include "ProtobufModule.h"
3+
4+
typedef enum class RoutingEvent {
5+
TX_OK = 1, // Successfully transmitted a packet. Detail = transmission time in ms
6+
TX_DROP = 2, // Packet dropped from TX queue.
7+
TX_DEFER = 3, // Packet deferred to late contention window.
8+
TX_HWM = 4, // High water mark of TX queue. Detail = current TX queue length
9+
RX_OK = 5, // Successfully received a packet. Detail = reception time in ms
10+
RX_BAD = 6, // Failed to receive a packet. Detail = reception time in ms
11+
} RoutingEvent;
12+
13+
class RoutingStatsModule : public ProtobufModule<meshtastic_RoutingStats>, public concurrency::OSThread
14+
{
15+
public:
16+
RoutingStatsModule()
17+
: ProtobufModule("RoutingStats", meshtastic_PortNum_ROUTING_STATS_APP, meshtastic_RoutingStats_fields),
18+
concurrency::OSThread("RoutingStats")
19+
{
20+
}
21+
void logEvent(RoutingEvent event, meshtastic_MeshPacket *p = NULL, uint32_t detail = 0);
22+
23+
private:
24+
unsigned long last_tx_millis = 0;
25+
unsigned long last_print_millis = 0;
26+
meshtastic_RoutingStats stats{};
27+
void printStats(meshtastic_RoutingStats *stats, NodeNum src = 0);
28+
bool handleReceivedProtobuf(const meshtastic_MeshPacket &mp, meshtastic_RoutingStats *decoded) override;
29+
int32_t runOnce() override;
30+
};
31+
32+
extern RoutingStatsModule *routingStats;

0 commit comments

Comments
 (0)