Skip to content

Conversation

Copy link
Contributor

Copilot AI commented Jan 24, 2026

Debug loggers created with logger.New() automatically write to both stderr and the file logger. The routed server was duplicating these writes with explicit log.Printf() calls.

Changes

Removed 3 redundant log.Printf() calls in internal/server/routed.go:

  • Cache reuse logging (line 57)
  • Concurrent server creation logging (line 69)
  • New server creation logging (line 75)

Added [CACHE] prefix to debug logger calls to preserve categorization.

Example

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)

The debug logger's Printf() method (logger.go:120) already calls LogDebug() to write to the file logger, making the second call redundant.

Warning

Firewall rules blocked me from connecting to one or more addresses (expand for details)

I tried to connect to the following addresses, but was blocked by firewall rules:

  • nonexistent.local
    • Triggering command: /tmp/go-build3904863373/b269/launcher.test /tmp/go-build3904863373/b269/launcher.test -test.testlogfile=/tmp/go-build3904863373/b269/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true go ternal/fips140cache/cache.go 64/pkg/tool/linux_amd64/compile (dns block)
  • this-host-does-not-exist-12345.com
    • Triggering command: /tmp/go-build3904863373/b278/mcp.test /tmp/go-build3904863373/b278/mcp.test -test.testlogfile=/tmp/go-build3904863373/b278/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true go1.25.6 -c=4 -nolocalimports -importcfg /tmp/go-build2239539067/b188/importcfg -pack /opt/hostedtoolcache/go/1.25.6/x64/src/net/http/httptrace/trace.go conf�� g_.a go x_amd64/vet user.name (dns block)

If you need me to access, download, or install something from one of these locations, you can either:

Original prompt

This section details on the original issue you should resolve

<issue_title>[duplicate-code] Duplicate Code Pattern: Dual Logging Calls in Server</issue_title>
<issue_description># 🔍 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...

💬 We'd love your input! Share your thoughts on Copilot coding agent in our 2 minute survey.

Co-authored-by: lpcox <15877973+lpcox@users.noreply.github.com>
Copilot AI changed the title [WIP] Fix duplicate logging calls in routed.go Remove redundant logging calls in routed.go Jan 24, 2026
Copilot AI requested a review from lpcox January 24, 2026 15:54
@lpcox lpcox marked this pull request as ready for review January 24, 2026 15:57
@lpcox lpcox merged commit 5850aa2 into main Jan 24, 2026
3 checks passed
@lpcox lpcox deleted the copilot/remove-duplicate-logging-calls branch January 24, 2026 15:57
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

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

2 participants