Improve position validation logging and reduce spam

- Remove duplicate validation logging between mergeAircraftData and updateHistories
- Add rate limiting: errors logged max once per 10 seconds per aircraft
- Add rate limiting: warnings logged max once per 30 seconds per aircraft
- Only log first error/warning message to reduce log verbosity
- Clean up validation log entries when aircraft become stale
- Maintain memory efficiency with automatic cleanup

This significantly reduces log spam from aircraft with persistent
position validation issues (e.g., CPR decoding problems).

🤖 Generated with [Claude Code](https://claude.ai/code)

Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
Ole-Morten Duesund 2025-08-24 20:39:57 +02:00
commit 960f47682d

View file

@ -271,6 +271,7 @@ type Merger struct {
historyLimit int // Maximum history points to retain historyLimit int // Maximum history points to retain
staleTimeout time.Duration // Time before aircraft considered stale (15 seconds) staleTimeout time.Duration // Time before aircraft considered stale (15 seconds)
updateMetrics map[uint32]*updateMetric // ICAO24 -> update rate calculation data updateMetrics map[uint32]*updateMetric // ICAO24 -> update rate calculation data
validationLog map[uint32]time.Time // ICAO24 -> last validation log time (rate limiting)
} }
// updateMetric tracks recent update times for calculating update rates. // updateMetric tracks recent update times for calculating update rates.
@ -301,6 +302,7 @@ func NewMerger() (*Merger, error) {
historyLimit: 500, historyLimit: 500,
staleTimeout: 15 * time.Second, // Aircraft timeout - reasonable for ADS-B tracking staleTimeout: 15 * time.Second, // Aircraft timeout - reasonable for ADS-B tracking
updateMetrics: make(map[uint32]*updateMetric), updateMetrics: make(map[uint32]*updateMetric),
validationLog: make(map[uint32]time.Time),
}, nil }, nil
} }
@ -453,10 +455,14 @@ func (m *Merger) mergeAircraftData(state *AircraftState, new *modes.Aircraft, so
validation := m.validatePosition(new, state, timestamp) validation := m.validatePosition(new, state, timestamp)
if !validation.Valid { if !validation.Valid {
// Log validation errors and skip position update // Rate-limited logging: only log once every 10 seconds per aircraft
icaoHex := fmt.Sprintf("%06X", new.ICAO24) if lastLog, exists := m.validationLog[new.ICAO24]; !exists || timestamp.Sub(lastLog) > 10*time.Second {
for _, err := range validation.Errors { icaoHex := fmt.Sprintf("%06X", new.ICAO24)
log.Printf("[POSITION_VALIDATION] ICAO %s: REJECTED position update - %s", icaoHex, err) // Only log first error to reduce spam
if len(validation.Errors) > 0 {
log.Printf("[POSITION_VALIDATION] ICAO %s: REJECTED - %s", icaoHex, validation.Errors[0])
m.validationLog[new.ICAO24] = timestamp
}
} }
} else { } else {
// Position is valid, proceed with normal logic // Position is valid, proceed with normal logic
@ -483,10 +489,15 @@ func (m *Merger) mergeAircraftData(state *AircraftState, new *modes.Aircraft, so
} }
} }
// Log warnings even if position is valid // Rate-limited warning logging
for _, warning := range validation.Warnings { if len(validation.Warnings) > 0 {
icaoHex := fmt.Sprintf("%06X", new.ICAO24) // Only log warnings once every 30 seconds per aircraft
log.Printf("[POSITION_VALIDATION] ICAO %s: WARNING - %s", icaoHex, warning) warningKey := new.ICAO24 + 0x10000000 // Offset to differentiate from error logging
if lastLog, exists := m.validationLog[warningKey]; !exists || timestamp.Sub(lastLog) > 30*time.Second {
icaoHex := fmt.Sprintf("%06X", new.ICAO24)
log.Printf("[POSITION_VALIDATION] ICAO %s: WARNING - %s", icaoHex, validation.Warnings[0])
m.validationLog[warningKey] = timestamp
}
} }
} }
@ -611,19 +622,8 @@ func (m *Merger) updateHistories(state *AircraftState, aircraft *modes.Aircraft,
Longitude: aircraft.Longitude, Longitude: aircraft.Longitude,
Source: sourceID, Source: sourceID,
}) })
} else {
// Log validation errors for debugging
icaoHex := fmt.Sprintf("%06X", aircraft.ICAO24)
for _, err := range validation.Errors {
log.Printf("[POSITION_VALIDATION] ICAO %s: REJECTED - %s", icaoHex, err)
}
}
// Log warnings even for valid positions
for _, warning := range validation.Warnings {
icaoHex := fmt.Sprintf("%06X", aircraft.ICAO24)
log.Printf("[POSITION_VALIDATION] ICAO %s: WARNING - %s", icaoHex, warning)
} }
// Note: Validation errors/warnings are already logged in mergeAircraftData
} }
// Signal history // Signal history
@ -847,6 +847,9 @@ func (m *Merger) CleanupStale() {
if now.Sub(state.LastUpdate) > m.staleTimeout { if now.Sub(state.LastUpdate) > m.staleTimeout {
delete(m.aircraft, icao) delete(m.aircraft, icao)
delete(m.updateMetrics, icao) delete(m.updateMetrics, icao)
// Clean up validation log entries
delete(m.validationLog, icao)
delete(m.validationLog, icao+0x10000000) // Warning key
} }
} }
} }