Files
mev-beta/docs/WATCH_SCRIPT_DUPLICATE_STATS_FIX.md

252 lines
7.9 KiB
Markdown

# Watch Script Duplicate Stats Fix
**Date**: November 2, 2025
**Issue**: Duplicate stats output in watch-live.sh
**Severity**: MEDIUM (UX issue, not functional)
**Status**: ✅ FIXED
---
## Problem Description
The watch scripts were printing duplicate stats repeatedly when the opportunity count reached multiples of 20 (20, 40, 60, etc.):
```
────────────────────────────────────────────────────────────
📊 Stats:
Opportunities: 60 | Executable: 0 | Executions: 0
Errors: 15 (Parsing: 0 | RPC: 0 | Zero Addr: 0)
────────────────────────────────────────────────────────────
────────────────────────────────────────────────────────────
📊 Stats:
Opportunities: 60 | Executable: 0 | Executions: 0
Errors: 15 (Parsing: 0 | RPC: 0 | Zero Addr: 0)
────────────────────────────────────────────────────────────
[... repeated many times ...]
```
---
## Root Cause Analysis
### Original Logic (BUGGY)
**File**: `scripts/watch-live.sh:141`
```bash
# Show periodic stats every 20 opportunities
if [ $((OPPORTUNITIES % 20)) -eq 0 ] && [ $OPPORTUNITIES -gt 0 ]; then
display_stats
fi
```
### Why This Failed
The script processes the log file **line by line** in a `while read` loop:
```bash
tail -f logs/mev_bot.log | while read line; do
# Process each line
# ... detect opportunities, errors, etc ...
# Check if we should display stats (line 141)
if [ $((OPPORTUNITIES % 20)) -eq 0 ] && [ $OPPORTUNITIES -gt 0 ]; then
display_stats # BUG: This triggers on EVERY line!
fi
done
```
**Example Timeline**:
| Event | OPPORTUNITIES | Condition Check | Result |
|-------|---------------|-----------------|--------|
| Opportunity #60 detected | 60 | `60 % 20 == 0` ✅ | Stats displayed ✅ |
| Warning line read | 60 | `60 % 20 == 0` ✅ | Stats displayed again ❌ |
| Another warning | 60 | `60 % 20 == 0` ✅ | Stats displayed again ❌ |
| Another warning | 60 | `60 % 20 == 0` ✅ | Stats displayed again ❌ |
| ... continues for every line read ... | 60 | `60 % 20 == 0` ✅ | Stats displayed repeatedly ❌ |
**Key Insight**: Once `OPPORTUNITIES` reaches 60, the condition `60 % 20 == 0` **remains true forever** until opportunity #61 is detected. Every non-opportunity line (warnings, errors, performance logs) still triggers the stats display!
---
## Solution
### New Logic (FIXED)
Add a **state variable** to track the last opportunity count when stats were displayed:
```bash
LAST_STATS_DISPLAY=0 # Initialize at start
# Show periodic stats every 20 opportunities (only when count changes)
if [ $((OPPORTUNITIES % 20)) -eq 0 ] &&
[ $OPPORTUNITIES -gt 0 ] &&
[ $OPPORTUNITIES -ne $LAST_STATS_DISPLAY ]; then
display_stats
LAST_STATS_DISPLAY=$OPPORTUNITIES # Update last display count
fi
```
### Three-Part Condition
1. **`$((OPPORTUNITIES % 20)) -eq 0`**: Is count a multiple of 20?
2. **`$OPPORTUNITIES -gt 0`**: Is count positive? (avoid displaying at startup)
3. **`$OPPORTUNITIES -ne $LAST_STATS_DISPLAY`**: Is this a NEW multiple of 20? ← **KEY FIX**
### How It Works Now
| Event | OPPORTUNITIES | LAST_STATS_DISPLAY | New Condition | Result |
|-------|---------------|-------------------|---------------|--------|
| Opportunity #60 detected | 60 | 0 | `60 != 0` ✅ | Stats displayed ✅ |
| (Update LAST_STATS_DISPLAY) | 60 | **60** | - | - |
| Warning line read | 60 | 60 | `60 != 60` ❌ | No display ✅ |
| Another warning | 60 | 60 | `60 != 60` ❌ | No display ✅ |
| Another warning | 60 | 60 | `60 != 60` ❌ | No display ✅ |
| Opportunity #61 detected | 61 | 60 | `61 % 20 != 0` ❌ | No display ✅ |
| Opportunity #80 detected | 80 | 60 | `80 != 60` ✅ | Stats displayed ✅ |
---
## Changes Made
### 1. scripts/watch-live.sh
**Lines 40, 142, 149** - Added state tracking:
```bash
# Line 40: Initialize tracker
LAST_STATS_DISPLAY=0 # Track last opportunity count when stats were displayed
# Line 142: Enhanced condition
if [ $((OPPORTUNITIES % 20)) -eq 0 ] && [ $OPPORTUNITIES -gt 0 ] && [ $OPPORTUNITIES -ne $LAST_STATS_DISPLAY ]; then
# Display stats...
# Line 149: Update tracker
LAST_STATS_DISPLAY=$OPPORTUNITIES # Update last display count
fi
```
### 2. scripts/watch-live-enhanced.sh
**Lines 384-388** - Same fix with associative array:
```bash
# Update stats display periodically (only when count actually changes)
local current_count=${STATS["opportunities_total"]}
if [[ $((current_count % UPDATE_INTERVAL)) -eq 0 ]] &&
[[ $current_count -gt 0 ]] &&
[[ $current_count -ne $last_stats_update ]]; then
last_stats_update=$current_count
display_stats
fi
```
---
## Verification
### Test Case 1: Basic Functionality ✅
```bash
$ ./scripts/watch-live.sh
# Stats appear at opportunities: 20, 40, 60, 80, 100...
# No duplicates between opportunity detections
```
### Test Case 2: Warning Messages ✅
```bash
# When OPPORTUNITIES = 60:
# Process 100 warning lines
# Expected: 1 stats display (at opportunity #60)
# Actual: 1 stats display ✅
```
### Test Case 3: Edge Cases ✅
| Case | Expected Behavior | Result |
|------|------------------|--------|
| Startup (0 opportunities) | No stats | ✅ Pass |
| First 19 opportunities | No stats | ✅ Pass |
| Opportunity #20 | Stats displayed once | ✅ Pass |
| 1000 log lines at count 20 | Stats only once | ✅ Pass |
| Opportunity #40 | Stats displayed once | ✅ Pass |
---
## Performance Impact
### Before Fix
- **CPU Usage**: Higher (unnecessary string formatting on every line)
- **Terminal Output**: Flooded with duplicate stats
- **User Experience**: Confusing and difficult to read
### After Fix
- **CPU Usage**: Minimal (condition check only)
- **Terminal Output**: Clean, stats appear exactly once per milestone
- **User Experience**: Clear and professional
---
## Related Files
### Modified
- `scripts/watch-live.sh` (lines 40, 142, 149)
- `scripts/watch-live-enhanced.sh` (lines 384-388)
### Documentation
- `docs/LOGGING_AUDIT_REPORT_20251102.md` - Comprehensive logging audit
- `docs/WATCH_SCRIPT_DUPLICATE_STATS_FIX.md` - This document
---
## Lessons Learned
### Shell Script State Management
- **Issue**: Shell variables in `while read` loops maintain state across iterations
- **Mistake**: Checking only the current count without tracking previous state
- **Solution**: Always track "last action state" for periodic operations
### Common Pattern
This is a common bug pattern in monitoring scripts:
```bash
# ❌ BAD: Triggers on every line when count is a multiple
if [ $((COUNT % INTERVAL)) -eq 0 ]; then
perform_action
fi
# ✅ GOOD: Triggers only when count changes to a new multiple
if [ $((COUNT % INTERVAL)) -eq 0 ] && [ $COUNT -ne $LAST_ACTION ]; then
perform_action
LAST_ACTION=$COUNT
fi
```
### Debugging Tip
When debugging duplicate outputs in log processors:
1. Add debug output showing `$COUNT` and `$LAST_ACTION` values
2. Trace which lines trigger the condition
3. Look for missing state updates
---
## Conclusion
The duplicate stats issue was caused by a **state management bug** in the periodic display logic. The condition checked if the count was a multiple of 20, but didn't verify if stats had already been displayed for that count.
**Fix**: Added `LAST_STATS_DISPLAY` tracker to ensure stats display only once per milestone.
**Impact**: Clean, professional output with stats appearing exactly when expected (every 20 opportunities).
**Status**: ✅ **RESOLVED** - Both watch scripts now work correctly.
---
**Fixed By**: Claude Code
**Date**: November 2, 2025
**Verified**: ✅ Both scripts tested and working