diff --git a/functions/infra/logger_test.go b/functions/infra/logger_test.go new file mode 100644 index 00000000..ffd12c45 --- /dev/null +++ b/functions/infra/logger_test.go @@ -0,0 +1,312 @@ +package infra + +import ( + "bytes" + "encoding/json" + "net/http" + "net/http/httptest" + "strings" + "testing" +) + +// --- LoggerNew --- + +func TestLoggerNew(t *testing.T) { + t.Run("crea logger JSON valido", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, err := LoggerNew(LogLevelInfo, buf, "json") + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if logger == nil { + t.Fatal("expected non-nil logger") + } + if logger.Format != "json" { + t.Errorf("got format=%q, want json", logger.Format) + } + if logger.Level != LogLevelInfo { + t.Errorf("got level=%d, want LogLevelInfo", logger.Level) + } + }) + + t.Run("crea logger text valido", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, err := LoggerNew(LogLevelDebug, buf, "text") + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if logger.Format != "text" { + t.Errorf("got format=%q, want text", logger.Format) + } + }) + + t.Run("rechaza formato invalido", func(t *testing.T) { + _, err := LoggerNew(LogLevelInfo, &bytes.Buffer{}, "xml") + if err == nil { + t.Fatal("expected error for invalid format") + } + }) + + t.Run("output nil cae en os.Stderr sin panic", func(t *testing.T) { + logger, err := LoggerNew(LogLevelError, nil, "json") + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if logger.Output == nil { + t.Error("expected Output to default to os.Stderr, got nil") + } + }) + + t.Run("emite JSON valido al escribir", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, _ := LoggerNew(LogLevelInfo, buf, "json") + LogInfo(logger, "hello") + + var parsed map[string]any + if err := json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed); err != nil { + t.Fatalf("output no es JSON valido: %v\noutput: %s", err, buf.String()) + } + if parsed["msg"] != "hello" { + t.Errorf("got msg=%v, want hello", parsed["msg"]) + } + if parsed["level"] != "INFO" { + t.Errorf("got level=%v, want INFO", parsed["level"]) + } + }) + + t.Run("filtra mensajes debajo del nivel configurado", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, _ := LoggerNew(LogLevelWarn, buf, "json") + LogDebug(logger, "debug msg") + LogInfo(logger, "info msg") + LogWarn(logger, "warn msg") + LogError(logger, "error msg") + + output := buf.String() + if strings.Contains(output, "debug msg") { + t.Error("debug msg no deberia aparecer con LogLevelWarn") + } + if strings.Contains(output, "info msg") { + t.Error("info msg no deberia aparecer con LogLevelWarn") + } + if !strings.Contains(output, "warn msg") { + t.Error("warn msg deberia aparecer con LogLevelWarn") + } + if !strings.Contains(output, "error msg") { + t.Error("error msg deberia aparecer con LogLevelWarn") + } + }) +} + +// --- LoggerWith --- + +func TestLoggerWith(t *testing.T) { + t.Run("anade campos al logger", func(t *testing.T) { + buf := &bytes.Buffer{} + base, _ := LoggerNew(LogLevelInfo, buf, "json") + appLog := LoggerWith(base, map[string]any{"app": "test", "version": "1.0"}) + + LogInfo(appLog, "evento") + + var parsed map[string]any + if err := json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed); err != nil { + t.Fatalf("JSON invalido: %v", err) + } + if parsed["app"] != "test" { + t.Errorf("got app=%v, want test", parsed["app"]) + } + if parsed["version"] != "1.0" { + t.Errorf("got version=%v, want 1.0", parsed["version"]) + } + }) + + t.Run("no muta el logger original", func(t *testing.T) { + base, _ := LoggerNew(LogLevelInfo, &bytes.Buffer{}, "json") + if len(base.Fields) != 0 { + t.Fatalf("base logger deberia tener 0 fields iniciales, got %d", len(base.Fields)) + } + _ = LoggerWith(base, map[string]any{"a": 1}) + if len(base.Fields) != 0 { + t.Errorf("base logger no deberia haber mutado, got %d fields", len(base.Fields)) + } + }) + + t.Run("apila fields sobre un logger ya contextualizado", func(t *testing.T) { + buf := &bytes.Buffer{} + base, _ := LoggerNew(LogLevelInfo, buf, "json") + appLog := LoggerWith(base, map[string]any{"app": "api"}) + reqLog := LoggerWith(appLog, map[string]any{"request_id": "abc"}) + + LogInfo(reqLog, "inicio") + + var parsed map[string]any + if err := json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed); err != nil { + t.Fatalf("JSON invalido: %v", err) + } + if parsed["app"] != "api" { + t.Errorf("falta campo app heredado del padre, got %v", parsed["app"]) + } + if parsed["request_id"] != "abc" { + t.Errorf("falta campo request_id nuevo, got %v", parsed["request_id"]) + } + }) + + t.Run("retorna nil si recibe nil", func(t *testing.T) { + got := LoggerWith(nil, map[string]any{"k": "v"}) + if got != nil { + t.Errorf("expected nil, got %v", got) + } + }) +} + +// --- Log niveles --- + +func TestLogLevels(t *testing.T) { + t.Run("LogInfo emite nivel INFO", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, _ := LoggerNew(LogLevelDebug, buf, "json") + LogInfo(logger, "m") + + var parsed map[string]any + _ = json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed) + if parsed["level"] != "INFO" { + t.Errorf("got level=%v, want INFO", parsed["level"]) + } + }) + + t.Run("LogWarn emite nivel WARN", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, _ := LoggerNew(LogLevelDebug, buf, "json") + LogWarn(logger, "m") + + var parsed map[string]any + _ = json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed) + if parsed["level"] != "WARN" { + t.Errorf("got level=%v, want WARN", parsed["level"]) + } + }) + + t.Run("LogError emite nivel ERROR", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, _ := LoggerNew(LogLevelDebug, buf, "json") + LogError(logger, "m") + + var parsed map[string]any + _ = json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed) + if parsed["level"] != "ERROR" { + t.Errorf("got level=%v, want ERROR", parsed["level"]) + } + }) + + t.Run("LogDebug emite nivel DEBUG", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, _ := LoggerNew(LogLevelDebug, buf, "json") + LogDebug(logger, "m") + + var parsed map[string]any + _ = json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed) + if parsed["level"] != "DEBUG" { + t.Errorf("got level=%v, want DEBUG", parsed["level"]) + } + }) + + t.Run("campos inline en la llamada aparecen en el JSON", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, _ := LoggerNew(LogLevelInfo, buf, "json") + LogInfo(logger, "evento", "port", 8080, "user", "lucas") + + var parsed map[string]any + _ = json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed) + if parsed["port"] != float64(8080) { + t.Errorf("got port=%v, want 8080", parsed["port"]) + } + if parsed["user"] != "lucas" { + t.Errorf("got user=%v, want lucas", parsed["user"]) + } + }) + + t.Run("logger nil no hace panic en las funciones de log", func(t *testing.T) { + defer func() { + if r := recover(); r != nil { + t.Errorf("panic inesperado con logger nil: %v", r) + } + }() + LogDebug(nil, "msg") + LogInfo(nil, "msg") + LogWarn(nil, "msg") + LogError(nil, "msg") + }) +} + +// --- LoggerMiddleware --- + +func TestLoggerMiddleware(t *testing.T) { + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusCreated) + _, _ = w.Write([]byte("ok")) + }) + + t.Run("loguea method, path, status y duration_ms", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, _ := LoggerNew(LogLevelInfo, buf, "json") + mw := LoggerMiddleware(logger) + + req := httptest.NewRequest(http.MethodPost, "/api/users", nil) + rec := httptest.NewRecorder() + mw(handler).ServeHTTP(rec, req) + + var parsed map[string]any + if err := json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed); err != nil { + t.Fatalf("JSON invalido: %v\noutput: %s", err, buf.String()) + } + if parsed["method"] != "POST" { + t.Errorf("got method=%v, want POST", parsed["method"]) + } + if parsed["path"] != "/api/users" { + t.Errorf("got path=%v, want /api/users", parsed["path"]) + } + if parsed["status"] != float64(http.StatusCreated) { + t.Errorf("got status=%v, want 201", parsed["status"]) + } + if _, ok := parsed["duration_ms"]; !ok { + t.Error("falta campo duration_ms en el log") + } + }) + + t.Run("usa status 200 si el handler no llama WriteHeader", func(t *testing.T) { + buf := &bytes.Buffer{} + logger, _ := LoggerNew(LogLevelInfo, buf, "json") + mw := LoggerMiddleware(logger) + + silentHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + _, _ = w.Write([]byte("hi")) + }) + + req := httptest.NewRequest(http.MethodGet, "/health", nil) + rec := httptest.NewRecorder() + mw(silentHandler).ServeHTTP(rec, req) + + var parsed map[string]any + _ = json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed) + if parsed["status"] != float64(http.StatusOK) { + t.Errorf("got status=%v, want 200", parsed["status"]) + } + }) + + t.Run("preserva los campos contextuales del logger", func(t *testing.T) { + buf := &bytes.Buffer{} + base, _ := LoggerNew(LogLevelInfo, buf, "json") + appLog := LoggerWith(base, map[string]any{"app": "sqlite_api"}) + mw := LoggerMiddleware(appLog) + + req := httptest.NewRequest(http.MethodGet, "/", nil) + rec := httptest.NewRecorder() + mw(handler).ServeHTTP(rec, req) + + var parsed map[string]any + _ = json.Unmarshal(bytes.TrimSpace(buf.Bytes()), &parsed) + if parsed["app"] != "sqlite_api" { + t.Errorf("falta campo contextual app=sqlite_api, got %v", parsed["app"]) + } + }) +}