Skip to content

[duplicate-code] Duplicate Code Pattern: Dual Logging Calls in Server #437

@github-actions

Description

@github-actions

🔍 Duplicate Code Pattern: Dual Logging Calls in Server

Part of duplicate code analysis: #435

Summary

The routed.go file contains numerous instances where the same log message is written to both the debug logger (logRouted.Printf) and the file logger (log.Printf). This pattern appears 19+ times in routed.go alone, creating visual noise and maintenance burden.

Duplication Details

Pattern: Dual Logging Statements

  • Severity: High
  • Occurrences: 19+ instances in routed.go, similar pattern likely in other files
  • Locations:
    • internal/server/routed.go (lines 40-41, 52-53, 58-59, 110-113, and many more)

Code Examples:

Example 1: Cache operations (lines 40-41)

logRouted.Printf("Reusing cached filtered server: backend=%s, session=%s", backendID, sessionID)
log.Printf("[CACHE] Reusing cached filtered server: backend=%s, session=%s", backendID, sessionID)

Example 2: Server creation (lines 58-59)

logRouted.Printf("Creating new filtered server: backend=%s, session=%s", backendID, sessionID)
log.Printf("[CACHE] Creating new filtered server: backend=%s, session=%s", backendID, sessionID)

Example 3: Request logging (lines 110-113)

log.Printf("=== NEW STREAMABLE HTTP CONNECTION (ROUTED) ===")
log.Printf("[%s] %s %s", r.RemoteAddr, r.Method, r.URL.Path)
log.Printf("Backend: %s", backendID)
log.Printf("Authorization (Session ID): %s", sessionID)

Note: Some log statements also appear in unified.go where both logUnified.Printf() and log.Printf() are used.

Pattern Analysis:

The dual logging appears to serve two purposes:

  1. Debug logger (logRouted.Printf/logUnified.Printf): Controlled by DEBUG environment variable, outputs to stderr with colors and timestamps
  2. File logger (log.Printf): Writes to operational log file for production troubleshooting

However, according to the logger package documentation, debug loggers created with logger.New() already write to both stderr AND the file logger, making the dual calls redundant.

Impact Analysis

Maintainability

  • Code clutter: Every important event requires 2 lines instead of 1
  • Inconsistency risk: Easy to update one log call but forget the other
  • Readability: Harder to scan code when log statements are duplicated

Bug Risk

  • Message drift: Over time, the two messages may diverge (already seen with [CACHE] prefix appearing only in file logger calls)
  • Missing logs: If one call is commented out during debugging, logs become incomplete

Code Bloat

  • ~40+ lines of unnecessary code in routed.go alone
  • Potential 100+ duplicate lines across all server files

Performance

  • Minor impact: Each log statement involves string formatting and I/O, effectively doubling the cost
  • Not critical: But contributes to overall overhead in high-traffic scenarios

Refactoring Recommendations

Option 1: Use Debug Logger Only (Recommended)

According to internal/logger/logger.go documentation:

Debug loggers created with logger.New() now write to both stderr (with colors/time diffs) and the file logger (text-only).

Solution: Remove all log.Printf() calls and use only the debug logger:

// Before:
logRouted.Printf("Reusing cached filtered server: backend=%s, session=%s", backendID, sessionID)
log.Printf("[CACHE] Reusing cached filtered server: backend=%s, session=%s", backendID, sessionID)

// After:
logRouted.Printf("[CACHE] Reusing cached filtered server: backend=%s, session=%s", backendID, sessionID)

Benefits:

  • Eliminates all duplication
  • Logs automatically go to both destinations
  • Cleaner, more readable code
  • No helper functions needed

Verification needed: Confirm that debug loggers do write to file logger as documented

Estimated effort: 1-2 hours

  • Find and remove redundant log.Printf calls: 45 minutes
  • Test logging behavior: 30 minutes
  • Update any related documentation: 15 minutes

Option 2: Create Unified Logging Helper

If debug loggers don't write to file logger as expected, create a helper:

// In internal/logger/logger.go
func (l *Logger) PrintfWithFile(format string, args ...any) {
    // Write to debug logger (stderr + file)
    l.Printf(format, args...)
    // Also ensure it goes to file logger
    logger.LogDebug(l.namespace, format, args...)
}

Usage:

// Before: 2 lines
logRouted.Printf("Message: %s", msg)
log.Printf("Message: %s", msg)

// After: 1 line
logRouted.PrintfWithFile("Message: %s", msg)

Benefits:

  • Reduces duplication significantly
  • Makes dual logging intentional and controlled
  • Single point of change if logging strategy changes

Drawbacks:

  • Adds a new function to the logger API
  • Still more complex than Option 1

Estimated effort: 2-3 hours

  • Implement helper function: 1 hour
  • Migrate all call sites: 1 hour
  • Testing: 1 hour

Option 3: Use Operational Logger Functions

Replace generic log.Printf() with specific operational logging functions:

// Before:
logRouted.Printf("...")
log.Printf("[CACHE] ...")

// After:
logRouted.Printf("...")
logger.LogDebug("server:cache", "...")

Benefits:

  • Uses structured logging categories
  • Better log organization

Drawbacks:

  • Still requires two calls
  • Doesn't solve the duplication problem

Not recommended - doesn't address the core issue

Investigation Required

Before implementing the solution, verify:

  1. Do debug loggers write to file logger?

    • Check internal/logger/logger.go:100-130 implementation
    • Test with DEBUG=server:* ./awmg and check file logs
  2. Why were dual logging calls added?

    • Check git history: git log -p --all -S "logRouted.Printf" -- internal/server/routed.go
    • Was there a specific reason or oversight?
  3. Are there other files with this pattern?

    • Search: grep -r "log.Printf.*\nlog.Printf" internal/ --include="*.go"

Implementation Checklist

  • Investigate: Verify debug loggers write to file logger as documented
  • Review: Check git history for context on dual logging introduction
  • Audit: Search for similar patterns in unified.go and other files
  • Choose: Select refactoring approach based on investigation findings
  • Implement: Apply chosen solution (recommend Option 1 if verification passes)
  • Test: Verify logs appear in both DEBUG output and file logger
  • Update: Fix all instances in routed.go
  • Expand: Apply same fix to unified.go if needed
  • Verify: Run integration tests to ensure no log loss
  • Document: Update AGENTS.md if logging patterns change

Parent Issue

See parent analysis report: #435
Related to #435

AI generated by Duplicate Code Detector

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions