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.
This commit is contained in:
1 parent
8261633c9f
commit
46041130b6
8 files changed
+313
-24
No files matched your search
@@ -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**
|
||||
@@ -229,6 +229,10 @@ public:
|
||||
bridge.end();
|
||||
bridge.begin();
|
||||
}
|
||||
|
||||
int getQueueSize() override {
|
||||
return bridge.getQueueSize();
|
||||
}
|
||||
#endif
|
||||
|
||||
// To check if there is pending work
|
||||
|
||||
@@ -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");
|
||||
|
||||
@@ -153,6 +153,10 @@ public:
|
||||
virtual void restartBridge() {
|
||||
// no op by default
|
||||
};
|
||||
|
||||
virtual int getQueueSize() {
|
||||
return 0; // no op by default
|
||||
};
|
||||
};
|
||||
|
||||
class CommonCLI {
|
||||
|
||||
@@ -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
|
||||
@@ -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
|
||||
@@ -51,6 +51,9 @@ build_flags =
|
||||
build_src_filter = ${Heltec_lora32_v3.build_src_filter}
|
||||
+<helpers/ui/SSD1306Display.cpp>
|
||||
+<../examples/simple_repeater>
|
||||
-<helpers/bridges/MQTTBridge.cpp>
|
||||
-<helpers/MQTTMessageBuilder.cpp>
|
||||
-<helpers/JWTHelper.cpp>
|
||||
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>
|
||||
-<helpers/bridges/MQTTBridge.cpp>
|
||||
-<helpers/MQTTMessageBuilder.cpp>
|
||||
-<helpers/JWTHelper.cpp>
|
||||
lib_deps =
|
||||
${Heltec_lora32_v3.lib_deps}
|
||||
${esp32_ota.lib_deps}
|
||||
|
||||
@@ -54,6 +54,9 @@ build_flags =
|
||||
; -D MESH_DEBUG=1
|
||||
build_src_filter = ${Station_G2.build_src_filter}
|
||||
+<../examples/simple_repeater>
|
||||
-<helpers/bridges/MQTTBridge.cpp>
|
||||
-<helpers/MQTTMessageBuilder.cpp>
|
||||
-<helpers/JWTHelper.cpp>
|
||||
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>
|
||||
-<helpers/bridges/MQTTBridge.cpp>
|
||||
-<helpers/MQTTMessageBuilder.cpp>
|
||||
-<helpers/JWTHelper.cpp>
|
||||
lib_deps =
|
||||
${Station_G2.lib_deps}
|
||||
${esp32_ota.lib_deps}
|
||||
|
||||
Reference in new issue
Block a user