From d2be2276ec4ac6d3c9e1363ee1520e97b39631d4 Mon Sep 17 00:00:00 2001 From: Daniel Legt Date: Fri, 17 Apr 2026 13:25:48 +0300 Subject: [PATCH] Better logging --- lib/web/app.go | 200 ++++++++++++++++++++++++++++++++++++++++++++++--- main.go | 10 ++- 2 files changed, 200 insertions(+), 10 deletions(-) diff --git a/lib/web/app.go b/lib/web/app.go index 98049b9..3089249 100644 --- a/lib/web/app.go +++ b/lib/web/app.go @@ -5,11 +5,15 @@ import ( "fmt" "html/template" "io" + "log" "mime" "net/http" "net/url" + "os" + "path/filepath" "strconv" "strings" + "sync" "time" "cpu-benchmark-server/lib/model" @@ -25,6 +29,7 @@ type App struct { store *store.Store templates *template.Template pageSize int + errorLog *dailyErrorLogger } type indexPageData struct { @@ -46,11 +51,11 @@ type indexPageData struct { } type jsonSubmissionEnvelope struct { - Submitter string `json:"submitter"` - Platform string `json:"platform"` - Benchmark *model.BenchmarkResult `json:"benchmark"` - Result *model.BenchmarkResult `json:"result"` - Data *model.BenchmarkResult `json:"data"` + Submitter string `json:"submitter"` + Platform string `json:"platform"` + Benchmark json.RawMessage `json:"benchmark"` + Result json.RawMessage `json:"result"` + Data json.RawMessage `json:"data"` } type flatSubmissionEnvelope struct { @@ -63,7 +68,7 @@ type errorResponse struct { Error string `json:"error"` } -func New(store *store.Store, pageSize int) (*App, error) { +func New(store *store.Store, pageSize int, errorLogDir string) (*App, error) { funcs := template.FuncMap{ "formatInt64": formatInt64, "formatFloat": formatFloat, @@ -76,10 +81,16 @@ func New(store *store.Store, pageSize int) (*App, error) { return nil, err } + errorLog, err := newDailyErrorLogger(errorLogDir) + if err != nil { + return nil, err + } + return &App{ store: store, templates: templates, pageSize: pageSize, + errorLog: errorLog, }, nil } @@ -87,6 +98,7 @@ func (a *App) Routes() http.Handler { router := chi.NewRouter() router.Use(middleware.RequestID) router.Use(middleware.RealIP) + router.Use(a.errorLoggingMiddleware) router.Use(middleware.Logger) router.Use(middleware.Recoverer) router.Use(middleware.Timeout(30 * time.Second)) @@ -99,6 +111,162 @@ func (a *App) Routes() http.Handler { return router } +func (a *App) Close() error { + if a == nil || a.errorLog == nil { + return nil + } + + return a.errorLog.Close() +} + +type dailyErrorLogger struct { + dir string + mu sync.Mutex + date string + file *os.File + logger *log.Logger +} + +const maxLoggedResponseBodyBytes = 2048 + +func newDailyErrorLogger(dir string) (*dailyErrorLogger, error) { + l := &dailyErrorLogger{dir: dir} + if err := l.rotateIfNeeded(time.Now()); err != nil { + return nil, err + } + + return l, nil +} + +func (l *dailyErrorLogger) rotateIfNeeded(now time.Time) error { + date := now.Format("2006-01-02") + if l.file != nil && l.date == date { + return nil + } + + if err := os.MkdirAll(l.dir, 0o755); err != nil { + return err + } + + path := filepath.Join(l.dir, date+".error.log") + file, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o644) + if err != nil { + return err + } + + if l.file != nil { + _ = l.file.Close() + } + + l.date = date + l.file = file + l.logger = log.New(file, "", log.LstdFlags) + return nil +} + +func (l *dailyErrorLogger) LogRequest(r *http.Request, status int, duration time.Duration, responseBody string) { + l.mu.Lock() + defer l.mu.Unlock() + + now := time.Now() + if err := l.rotateIfNeeded(now); err != nil { + log.Printf("error log rotation failed: %v", err) + return + } + + l.logger.Printf( + `status=%d method=%s path=%q query=%q ip=%q request_id=%q duration=%s content_type=%q content_length=%d user_agent=%q response_body=%q`, + status, + r.Method, + r.URL.Path, + r.URL.RawQuery, + r.RemoteAddr, + middleware.GetReqID(r.Context()), + duration, + r.Header.Get("Content-Type"), + r.ContentLength, + r.UserAgent(), + responseBody, + ) +} + +func (l *dailyErrorLogger) Close() error { + l.mu.Lock() + defer l.mu.Unlock() + + if l.file == nil { + return nil + } + + err := l.file.Close() + l.file = nil + l.logger = nil + l.date = "" + return err +} + +type statusCapturingResponseWriter struct { + http.ResponseWriter + status int + body strings.Builder + bodyTruncated bool +} + +func (w *statusCapturingResponseWriter) WriteHeader(status int) { + w.status = status + w.ResponseWriter.WriteHeader(status) +} + +func (w *statusCapturingResponseWriter) Write(b []byte) (int, error) { + if w.status == 0 { + w.status = http.StatusOK + } + + if w.body.Len() < maxLoggedResponseBodyBytes { + remaining := maxLoggedResponseBodyBytes - w.body.Len() + if len(b) > remaining { + _, _ = w.body.Write(b[:remaining]) + w.bodyTruncated = true + } else { + _, _ = w.body.Write(b) + } + } else { + w.bodyTruncated = true + } + + return w.ResponseWriter.Write(b) +} + +func (w *statusCapturingResponseWriter) LoggedBody() string { + body := strings.TrimSpace(w.body.String()) + if body == "" { + return "" + } + + if w.bodyTruncated { + return body + "... [truncated]" + } + + return body +} + +func (a *App) errorLoggingMiddleware(next http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + startedAt := time.Now() + ww := &statusCapturingResponseWriter{ResponseWriter: w} + next.ServeHTTP(ww, r) + + status := ww.status + if status == 0 { + status = http.StatusOK + } + + if status >= http.StatusBadRequest { + a.errorLog.LogRequest(r, status, time.Since(startedAt), ww.LoggedBody()) + } + }) +} + func (a *App) handleIndex(w http.ResponseWriter, r *http.Request) { page := parsePositiveInt(r.URL.Query().Get("page"), 1) text := strings.TrimSpace(r.URL.Query().Get("text")) @@ -244,10 +412,24 @@ func parseJSONSubmission(r *http.Request) (model.BenchmarkResult, string, string if err := json.Unmarshal(body, &nested); err == nil { submitter = firstNonEmpty(nested.Submitter, submitter) platform = firstNonEmpty(nested.Platform, platform) - for _, candidate := range []*model.BenchmarkResult{nested.Benchmark, nested.Result, nested.Data} { - if candidate != nil { - return *candidate, submitter, platform, nil + for _, candidate := range []struct { + name string + payload json.RawMessage + }{ + {name: "benchmark", payload: nested.Benchmark}, + {name: "result", payload: nested.Result}, + {name: "data", payload: nested.Data}, + } { + if len(candidate.payload) == 0 || string(candidate.payload) == "null" { + continue } + + var result model.BenchmarkResult + if err := json.Unmarshal(candidate.payload, &result); err != nil { + return model.BenchmarkResult{}, "", "", fmt.Errorf("decode %s JSON: %w", candidate.name, err) + } + + return result, submitter, platform, nil } } diff --git a/main.go b/main.go index 0f0e568..f5e860b 100644 --- a/main.go +++ b/main.go @@ -29,6 +29,9 @@ func run(logger *log.Logger) error { if err := os.MkdirAll(cfg.BadgerDir, 0o755); err != nil { return err } + if err := os.MkdirAll("data/logs", 0o755); err != nil { + return err + } benchmarkStore, err := store.Open(cfg.BadgerDir) if err != nil { @@ -43,10 +46,15 @@ func run(logger *log.Logger) error { } defer closeOnce.Do(closeStore) - app, err := web.New(benchmarkStore, cfg.PageSize) + app, err := web.New(benchmarkStore, cfg.PageSize, "data/logs") if err != nil { return err } + defer func() { + if err := app.Close(); err != nil { + logger.Printf("close error log: %v", err) + } + }() server := &http.Server{ Addr: cfg.Addr,