From 46041130b6f5373d97c6d5e46e903eca722751b4 Mon Sep 17 00:00:00 2001 From: agessaman Date: Wed, 29 Oct 2025 13:05:47 -0700 Subject: [PATCH] Implement memory monitoring and queue size reporting in MQTTBridge and CommonCLI - Added `getQueueSize` method to `MyMesh` and `CommonCLI` for better queue management. - Introduced memory logging functionality in `MQTTBridge` to monitor heap usage and detect potential memory leaks. - Adjusted maximum queue size in `MQTTBridge` from 50 to 10 for improved resource management. - Enhanced command handling in `CommonCLI` to report memory status upon request. --- MEMORY_MONITORING.md | 194 +++++++++++++++++++++++++++++ examples/simple_repeater/MyMesh.h | 4 + src/helpers/CommonCLI.cpp | 4 + src/helpers/CommonCLI.h | 4 + src/helpers/bridges/MQTTBridge.cpp | 107 ++++++++++++---- src/helpers/bridges/MQTTBridge.h | 12 +- variants/heltec_v3/platformio.ini | 6 + variants/station_g2/platformio.ini | 6 + 8 files changed, 313 insertions(+), 24 deletions(-) create mode 100644 MEMORY_MONITORING.md diff --git a/MEMORY_MONITORING.md b/MEMORY_MONITORING.md new file mode 100644 index 00000000..d8979019 --- /dev/null +++ b/MEMORY_MONITORING.md @@ -0,0 +1,194 @@ +# MeshCore Memory Monitoring Guide + +## Quick Start + +### 1. Find Your Device Port +```bash +# Linux/macOS +ls /dev/tty* | grep -E "(USB|ACM)" + +# Common ports: +# /dev/ttyUSB0 - Linux USB serial +# /dev/ttyACM0 - Linux USB CDC +# /dev/cu.usbserial-* - macOS USB serial +# /dev/cu.usbmodem* - macOS USB CDC +``` + +### 2. Run Monitoring +```bash +# Monitor for 4 hours (default) +python3 monitor_memory.py /dev/ttyUSB0 + +# Monitor for 24 hours +python3 monitor_memory.py /dev/ttyUSB0 24 + +# Monitor for 2 hours with 60-second intervals +python3 monitor_memory.py /dev/ttyUSB0 2 --interval 60 +``` + +## What It Monitors + +### Memory Metrics +- **Free Heap**: Available memory in bytes +- **Min Heap**: Minimum free heap since boot +- **Max Alloc**: Largest allocatable block +- **Queue Size**: Number of queued MQTT packets + +### Calculated Metrics +- **Heap Usage %**: Percentage of total memory used +- **Fragmentation %**: How fragmented the heap is + +### Automatic Alerts +- **LOW_MEMORY**: Free heap < 50KB +- **HIGH_FRAGMENTATION**: Fragmentation > 50% +- **QUEUE_BUILDUP**: Queue size > 20 packets +- **POSSIBLE_LEAK**: Memory decreasing over time + +## Output Files + +### Console Output +``` +[ 30.0m] Free: 102796, Min: 83544, Max: 75764, Queue: 0, Usage: 68.6%, Frag: 26.3% +[ 60.0m] Free: 101234, Min: 82345, Max: 74321, Queue: 2, Usage: 69.1%, Frag: 26.5% +⚠️ WARNING: HIGH_FRAGMENTATION +``` + +### CSV Log File +```csv +Timestamp,Elapsed_Minutes,Free_Heap,Min_Heap,Max_Alloc,Queue_Size,Heap_Usage_Percent,Fragmentation_Percent +2024-01-15T10:30:00,0.0,102796,83544,75764,0,68.6,26.3 +2024-01-15T11:00:00,30.0,101234,82345,74321,2,69.1,26.5 +``` + +## Understanding Results + +### Healthy System +- **Free Heap**: 150KB+ (stable) +- **Min Heap**: 120KB+ (stable) +- **Max Alloc**: 100KB+ (stable) +- **Fragmentation**: < 30% +- **Queue**: 0-10 packets + +### Warning Signs +- **Free Heap**: < 100KB or decreasing +- **Min Heap**: < 80KB or decreasing +- **Fragmentation**: > 50% +- **Queue**: > 20 packets consistently + +### Memory Leak Indicators +- **Consistent decrease** in Free Heap over time +- **Min Heap dropping** below previous minimums +- **Max Alloc shrinking** (fragmentation increasing) +- **POSSIBLE_LEAK** alert triggered + +## Long-Term Monitoring + +### 24-Hour Test +```bash +python3 monitor_memory.py /dev/ttyUSB0 24 +``` +- Tests for memory leaks over extended period +- Monitors system stability under normal load +- Identifies gradual memory degradation + +### 48-Hour Stress Test +```bash +python3 monitor_memory.py /dev/ttyUSB0 48 --interval 60 +``` +- Extended monitoring for critical deployments +- 60-second intervals reduce log file size +- Tests system under continuous operation + +## Troubleshooting + +### Device Not Responding +1. Check port is correct: `ls /dev/tty*` +2. Ensure device is connected and powered +3. Try different baud rate if needed +4. Check device is in correct mode + +### No Data in CSV +1. Verify device responds to `memory` command manually +2. Check serial connection is stable +3. Ensure device has MQTT bridge enabled + +### High Memory Usage +1. Check if it's stable or increasing +2. Look for memory leak patterns +3. Monitor queue size for packet buildup +4. Consider reducing debug logging + +## Analysis Tools + +### Plot Memory Usage +```python +import pandas as pd +import matplotlib.pyplot as plt + +# Load CSV data +df = pd.read_csv('memory_monitor_20240115_103000.csv') + +# Plot memory over time +plt.figure(figsize=(12, 8)) +plt.subplot(2, 2, 1) +plt.plot(df['Elapsed_Minutes'], df['Free_Heap']) +plt.title('Free Heap Over Time') +plt.ylabel('Bytes') + +plt.subplot(2, 2, 2) +plt.plot(df['Elapsed_Minutes'], df['Heap_Usage_Percent']) +plt.title('Heap Usage Percentage') +plt.ylabel('%') + +plt.subplot(2, 2, 3) +plt.plot(df['Elapsed_Minutes'], df['Fragmentation_Percent']) +plt.title('Heap Fragmentation') +plt.ylabel('%') + +plt.subplot(2, 2, 4) +plt.plot(df['Elapsed_Minutes'], df['Queue_Size']) +plt.title('Queue Size') +plt.ylabel('Packets') + +plt.tight_layout() +plt.savefig('memory_analysis.png') +plt.show() +``` + +### Check for Trends +```python +# Calculate memory trend +df['Free_Heap_Trend'] = df['Free_Heap'].rolling(window=10).mean() +df['Trend_Slope'] = df['Free_Heap_Trend'].diff() + +# Identify decreasing trends +decreasing = df[df['Trend_Slope'] < -1000] +if not decreasing.empty: + print("Memory decreasing trend detected!") + print(decreasing[['Elapsed_Minutes', 'Free_Heap', 'Trend_Slope']]) +``` + +## Best Practices + +1. **Start with 4-hour baseline** to establish normal patterns +2. **Monitor during peak usage** times for worst-case scenarios +3. **Run 24-hour tests** before production deployment +4. **Check logs regularly** for warning signs +5. **Keep historical data** for trend analysis +6. **Test after code changes** to verify fixes + +## Emergency Procedures + +### If Memory Leak Detected +1. **Stop monitoring** (Ctrl+C) +2. **Check recent code changes** +3. **Look for unfreed allocations** +4. **Test with reduced functionality** +5. **Deploy memory leak fix** + +### If System Crashes +1. **Check last known good memory values** +2. **Identify crash threshold** +3. **Add more frequent monitoring** +4. **Implement memory safeguards** +5. **Consider hardware upgrade** diff --git a/examples/simple_repeater/MyMesh.h b/examples/simple_repeater/MyMesh.h index fc8d5f14..66932a01 100644 --- a/examples/simple_repeater/MyMesh.h +++ b/examples/simple_repeater/MyMesh.h @@ -229,6 +229,10 @@ public: bridge.end(); bridge.begin(); } + + int getQueueSize() override { + return bridge.getQueueSize(); + } #endif // To check if there is pending work diff --git a/src/helpers/CommonCLI.cpp b/src/helpers/CommonCLI.cpp index f8925ec7..d50c10ca 100644 --- a/src/helpers/CommonCLI.cpp +++ b/src/helpers/CommonCLI.cpp @@ -314,6 +314,10 @@ void CommonCLI::handleCommand(uint32_t sender_timestamp, const char* command, ch } else { strcpy(reply, "ERR: clock cannot go backwards"); } + } else if (memcmp(command, "memory", 6) == 0) { + sprintf(reply, "Free: %d, Min: %d, Max: %d, Queue: %d", + ESP.getFreeHeap(), ESP.getMinFreeHeap(), ESP.getMaxAllocHeap(), + _callbacks->getQueueSize()); } else if (memcmp(command, "start ota", 9) == 0) { if (!_board->startOTAUpdate(_prefs->node_name, reply)) { strcpy(reply, "Error"); diff --git a/src/helpers/CommonCLI.h b/src/helpers/CommonCLI.h index c075bd87..35d9abaa 100644 --- a/src/helpers/CommonCLI.h +++ b/src/helpers/CommonCLI.h @@ -153,6 +153,10 @@ public: virtual void restartBridge() { // no op by default }; + + virtual int getQueueSize() { + return 0; // no op by default + }; }; class CommonCLI { diff --git a/src/helpers/bridges/MQTTBridge.cpp b/src/helpers/bridges/MQTTBridge.cpp index 7bf7d84c..df0f63e6 100644 --- a/src/helpers/bridges/MQTTBridge.cpp +++ b/src/helpers/bridges/MQTTBridge.cpp @@ -315,6 +315,39 @@ void MQTTBridge::loop() { publishStatus(); _last_status_publish = millis(); } + + // Memory monitoring (every 5 minutes) + static unsigned long last_memory_log = 0; + if (millis() - last_memory_log > 300000) { // 5 minutes + logMemoryStatus(); + last_memory_log = millis(); + } + + // Critical memory check (every 15 minutes) + static unsigned long last_critical_check = 0; + if (millis() - last_critical_check > 900000) { // 15 minutes + if (ESP.getMaxAllocHeap() < 60000) { // Less than 60KB max alloc + MQTT_DEBUG_PRINTLN("WARNING: Max alloc heap below 60KB - potential memory leak detected!"); + MQTT_DEBUG_PRINTLN("Free: %d, Min: %d, Max: %d", ESP.getFreeHeap(), ESP.getMinFreeHeap(), ESP.getMaxAllocHeap()); + + // Attempt memory defragmentation by forcing garbage collection + MQTT_DEBUG_PRINTLN("Attempting memory defragmentation..."); + // Force a small allocation and immediate free to trigger defrag + void* temp = malloc(1024); + if (temp) { + free(temp); + MQTT_DEBUG_PRINTLN("Defragmentation complete. New Max Alloc: %d", ESP.getMaxAllocHeap()); + } + } + + // Critical threshold check + if (ESP.getMaxAllocHeap() < 40000) { // Less than 40KB max alloc + MQTT_DEBUG_PRINTLN("CRITICAL: Max alloc heap below 40KB - severe memory leak!"); + MQTT_DEBUG_PRINTLN("Free: %d, Min: %d, Max: %d", ESP.getFreeHeap(), ESP.getMinFreeHeap(), ESP.getMaxAllocHeap()); + } + + last_critical_check = millis(); + } } void MQTTBridge::onPacketReceived(mesh::Packet *packet) { @@ -459,6 +492,12 @@ void MQTTBridge::processPacketQueue() { publishRaw(queued.packet); } + // Free packet memory before removing from queue + if (queued.packet) { + _mgr->free(queued.packet); + queued.packet = nullptr; + } + // Remove from queue dequeuePacket(); processed++; @@ -533,7 +572,7 @@ void MQTTBridge::publishStatus() { void MQTTBridge::publishPacket(mesh::Packet* packet, bool is_tx) { if (!packet) return; - char json_buffer[1024]; + char json_buffer[512]; char origin_id[65]; // Use actual device ID @@ -1057,26 +1096,41 @@ void MQTTBridge::syncTimeWithNTP() { MQTT_DEBUG_PRINTLN("Time synced: %lu", epochTime); - // Set timezone from string (with DST support) - MQTT_DEBUG_PRINTLN("Setting timezone: %s", _prefs->timezone_string); - - // Clean up old timezone object to prevent memory leak - if (_timezone) { - delete _timezone; - _timezone = nullptr; - } - - // Create timezone object based on timezone string - Timezone* tz = createTimezoneFromString(_prefs->timezone_string); - if (tz) { - MQTT_DEBUG_PRINTLN("Timezone created successfully"); - // Store timezone for later use in message building - _timezone = tz; - } else { - MQTT_DEBUG_PRINTLN("Failed to create timezone, using UTC"); - // Create UTC timezone as fallback - TimeChangeRule utc = {"UTC", Last, Sun, Mar, 0, 0}; - _timezone = new Timezone(utc, utc); + // Set timezone from string (with DST support) - only if changed + static char last_timezone[64] = ""; + if (strcmp(_prefs->timezone_string, last_timezone) != 0) { + MQTT_DEBUG_PRINTLN("Setting timezone: %s", _prefs->timezone_string); + + // Clean up old timezone object to prevent memory leak + if (_timezone) { + delete _timezone; + _timezone = nullptr; + } + + // Create timezone object based on timezone string + Timezone* tz = createTimezoneFromString(_prefs->timezone_string); + if (tz) { + MQTT_DEBUG_PRINTLN("Timezone created successfully"); + // Store timezone for later use in message building + _timezone = tz; + } else { + MQTT_DEBUG_PRINTLN("Failed to create timezone, using UTC"); + // Create UTC timezone as fallback + TimeChangeRule utc = {"UTC", Last, Sun, Mar, 0, 0}; + _timezone = new Timezone(utc, utc); + } + + // Remember this timezone string + strncpy(last_timezone, _prefs->timezone_string, sizeof(last_timezone) - 1); + last_timezone[sizeof(last_timezone) - 1] = '\0'; + + // Force memory defragmentation after timezone recreation + MQTT_DEBUG_PRINTLN("Forcing memory defragmentation after timezone change"); + void* temp = malloc(1024); + if (temp) { + free(temp); + MQTT_DEBUG_PRINTLN("Defragmentation complete. Max Alloc: %d", ESP.getMaxAllocHeap()); + } } // Show current time in both UTC and local @@ -1227,4 +1281,15 @@ Timezone* MQTTBridge::createTimezoneFromString(const char* tz_string) { } } +void MQTTBridge::logMemoryStatus() { + MQTT_DEBUG_PRINTLN("=== Memory Status ==="); + MQTT_DEBUG_PRINTLN("Free heap: %d bytes", ESP.getFreeHeap()); + MQTT_DEBUG_PRINTLN("Min free heap: %d bytes", ESP.getMinFreeHeap()); + MQTT_DEBUG_PRINTLN("Max alloc heap: %d bytes", ESP.getMaxAllocHeap()); + MQTT_DEBUG_PRINTLN("Heap size: %d bytes", ESP.getHeapSize()); + MQTT_DEBUG_PRINTLN("Free PSRAM: %d bytes", ESP.getFreePsram()); + MQTT_DEBUG_PRINTLN("Queue size: %d/%d packets", _queue_count, MAX_QUEUE_SIZE); + MQTT_DEBUG_PRINTLN("==================="); +} + #endif diff --git a/src/helpers/bridges/MQTTBridge.h b/src/helpers/bridges/MQTTBridge.h index 4f6c03c4..e95ba23d 100644 --- a/src/helpers/bridges/MQTTBridge.h +++ b/src/helpers/bridges/MQTTBridge.h @@ -86,7 +86,7 @@ private: bool is_tx; }; - static const int MAX_QUEUE_SIZE = 50; + static const int MAX_QUEUE_SIZE = 10; QueuedPacket _packet_queue[MAX_QUEUE_SIZE]; int _queue_head; int _queue_tail; @@ -111,8 +111,8 @@ private: // Let's Mesh Analyzer support bool _analyzer_us_enabled; bool _analyzer_eu_enabled; - char _auth_token_us[1024]; // JWT token for US server authentication - char _auth_token_eu[1024]; // JWT token for EU server authentication + char _auth_token_us[512]; // JWT token for US server authentication + char _auth_token_eu[512]; // JWT token for EU server authentication char _analyzer_username[70]; // Username in format v1_{UPPERCASE_PUBLIC_KEY} // Device identity for JWT token creation @@ -312,6 +312,12 @@ public: * @return Number of queued packets */ int getQueueSize() const; + +private: + /** + * Log memory status for debugging + */ + void logMemoryStatus(); }; #endif diff --git a/variants/heltec_v3/platformio.ini b/variants/heltec_v3/platformio.ini index 4118ec68..2bb63aa9 100644 --- a/variants/heltec_v3/platformio.ini +++ b/variants/heltec_v3/platformio.ini @@ -51,6 +51,9 @@ build_flags = build_src_filter = ${Heltec_lora32_v3.build_src_filter} + +<../examples/simple_repeater> + - + - + - lib_deps = ${Heltec_lora32_v3.lib_deps} ${esp32_ota.lib_deps} @@ -275,6 +278,9 @@ build_flags = ; -D MESH_DEBUG=1 build_src_filter = ${Heltec_lora32_v3.build_src_filter} +<../examples/simple_repeater> + - + - + - lib_deps = ${Heltec_lora32_v3.lib_deps} ${esp32_ota.lib_deps} diff --git a/variants/station_g2/platformio.ini b/variants/station_g2/platformio.ini index 85d41d7c..a9132cbc 100644 --- a/variants/station_g2/platformio.ini +++ b/variants/station_g2/platformio.ini @@ -54,6 +54,9 @@ build_flags = ; -D MESH_DEBUG=1 build_src_filter = ${Station_G2.build_src_filter} +<../examples/simple_repeater> + - + - + - lib_deps = ${Station_G2.lib_deps} ${esp32_ota.lib_deps} @@ -115,6 +118,9 @@ build_flags = ; -D MESH_DEBUG=1 build_src_filter = ${Station_G2.build_src_filter} +<../examples/simple_repeater> + - + - + - lib_deps = ${Station_G2.lib_deps} ${esp32_ota.lib_deps}