package logging import ( "bytes" "encoding/json" "strings" "testing" "time" ) func TestLogStructure(t *testing.T) { buf := &bytes.Buffer{} logger := New(LevelInfo, buf) logger.RequestLog("test-route", "localhost:8080", "POST", "/v1/chat/completions", 200, 100*time.Millisecond, "") lines := strings.TrimSpace(buf.String()) if lines == "" { t.Fatal("expected log output, got empty") } var record LogRecord if err := json.Unmarshal([]byte(lines), &record); err != nil { t.Fatalf("failed to unmarshal log record: %v", err) } if record.Level != "info" { t.Errorf("expected level info, got %s", record.Level) } if record.Route != "test-route" { t.Errorf("expected route test-route, got %s", record.Route) } if record.Upstream != "localhost:8080" { t.Errorf("expected upstream localhost:8080, got %s", record.Upstream) } if record.Method != "POST" { t.Errorf("expected method POST, got %s", record.Method) } if record.Path != "/v1/chat/completions" { t.Errorf("expected path /v1/chat/completions, got %s", record.Path) } if record.Status != 200 { t.Errorf("expected status 200, got %d", record.Status) } if record.Duration != (100 * time.Millisecond).String() { t.Errorf("expected duration 100ms, got %s", record.Duration) } } func TestRejectedRequestReason(t *testing.T) { tests := []struct { name string reason string }{ {"unknown_model", "unknown_model"}, {"body_too_large", "body_too_large"}, {"auth_failed", "auth_failed"}, {"concurrency_limit", "concurrency_limit"}, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { buf := &bytes.Buffer{} logger := New(LevelInfo, buf) logger.RequestLog("test", "upstream", "POST", "/path", 400, 10*time.Millisecond, tt.reason) var record LogRecord if err := json.Unmarshal([]byte(strings.TrimSpace(buf.String())), &record); err != nil { t.Fatalf("failed to unmarshal: %v", err) } if record.Reason != tt.reason { t.Errorf("expected reason %s, got %s", tt.reason, record.Reason) } }) } } func TestNoBodyLogging(t *testing.T) { buf := &bytes.Buffer{} logger := New(LevelInfo, buf) // Simulate logging with fields that might contain body-like data logger.RequestLog("route", "upstream", "POST", "/path", 400, time.Millisecond, "reason") output := buf.String() // Ensure no field named "body" appears in the output if strings.Contains(output, "\"body\"") { t.Errorf("request body should not be logged, but found 'body' field in: %s", output) } } func TestNoTokenLogging(t *testing.T) { buf := &bytes.Buffer{} logger := New(LevelInfo, buf) // Log a rejected request as it would happen with auth failure logger.RequestLog("route", "upstream", "POST", "/path", 401, time.Millisecond, "auth_failed") output := buf.String() // Ensure no Authorization header value appears testToken := "sk-1234567890abcdef" if strings.Contains(output, testToken) { t.Errorf("bearer token should not be logged, but found in output: %s", output) } // Ensure Authorization header field doesn't appear if strings.Contains(output, "Authorization") { t.Errorf("Authorization header should not be logged, but found in output: %s", output) } // Ensure "bearer" or "token" keywords don't appear in the output lowerOutput := strings.ToLower(output) if strings.Contains(lowerOutput, "bearer") { t.Errorf("bearer token substring should not appear, but found in output: %s", output) } } func TestConsistentFieldSet(t *testing.T) { buf := &bytes.Buffer{} logger := New(LevelInfo, buf) logger.RequestLog("route", "upstream", "GET", "/healthz", 200, time.Millisecond, "") var record LogRecord if err := json.Unmarshal([]byte(strings.TrimSpace(buf.String())), &record); err != nil { t.Fatalf("failed to unmarshal: %v", err) } // All required fields should be present if record.Timestamp == "" { t.Error("timestamp field missing") } if record.Level == "" { t.Error("level field missing") } if record.Message == "" { t.Error("message field missing") } if record.Route == "" { t.Error("route field missing") } if record.Upstream == "" { t.Error("upstream field missing") } if record.Method == "" { t.Error("method field missing") } if record.Path == "" { t.Error("path field missing") } if record.Status == 0 { t.Error("status field missing") } if record.Duration == "" { t.Error("duration field missing") } } func TestLogLevelFiltering(t *testing.T) { tests := []struct { name string level Level shouldLog bool }{ {"debug_level", LevelDebug, true}, {"info_level", LevelInfo, true}, {"warn_level_info_msg", LevelWarn, false}, {"error_level_info_msg", LevelError, false}, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { buf := &bytes.Buffer{} logger := New(tt.level, buf) logger.RequestLog("route", "upstream", "GET", "/path", 200, time.Millisecond, "") if tt.shouldLog && buf.Len() == 0 { t.Errorf("expected log output at level %d, got empty", tt.level) } if !tt.shouldLog && buf.Len() > 0 { t.Errorf("expected no log output at level %d, got: %s", tt.level, buf.String()) } }) } } func TestLogLineFormat(t *testing.T) { buf := &bytes.Buffer{} logger := New(LevelInfo, buf) logger.RequestLog("route", "upstream", "POST", "/path", 201, time.Millisecond, "created") output := strings.TrimSpace(buf.String()) if !strings.HasSuffix(output, "\n") && buf.String() != output { // Single line with newline if !strings.Contains(buf.String(), "\n") { t.Error("expected newline-terminated log line") } } // Must be valid JSON var record LogRecord if err := json.Unmarshal([]byte(output), &record); err != nil { t.Errorf("log output is not valid JSON: %v", err) } } func TestRejectedRequestExactlyOneRecord(t *testing.T) { buf := &bytes.Buffer{} logger := New(LevelInfo, buf) // Simulate a rejected request logger.RequestLog("test-route", "upstream:8080", "POST", "/v1/chat/completions", 401, 5*time.Millisecond, "auth_failed") lines := strings.Split(strings.TrimSpace(buf.String()), "\n") if len(lines) != 1 { t.Errorf("expected exactly one log record, got %d", len(lines)) } var record LogRecord if err := json.Unmarshal([]byte(lines[0]), &record); err != nil { t.Fatalf("failed to unmarshal: %v", err) } // Verify reason is present and meaningful if record.Reason != "auth_failed" { t.Errorf("expected reason 'auth_failed', got '%s'", record.Reason) } // Verify no token-like strings appear recordJSON, _ := json.Marshal(record) recordStr := string(recordJSON) if strings.Contains(recordStr, "Bearer") || strings.Contains(recordStr, "bearer") || strings.Contains(recordStr, "Authorization") || strings.Contains(recordStr, "authorization") { t.Errorf("rejected request log should not contain token/auth header substring: %s", recordStr) } } func TestParseLevel(t *testing.T) { tests := []struct { input string expected Level }{ {"debug", LevelDebug}, {"info", LevelInfo}, {"warn", LevelWarn}, {"error", LevelError}, {"DEBUG", LevelDebug}, {"Info", LevelInfo}, {"unknown", LevelInfo}, {"", LevelInfo}, } for _, tt := range tests { t.Run(tt.input, func(t *testing.T) { got := ParseLevel(tt.input) if got != tt.expected { t.Errorf("expected %d, got %d", tt.expected, got) } }) } }