diff --git a/cmd/api/main.go b/cmd/api/main.go index e5241e8..9da262b 100644 --- a/cmd/api/main.go +++ b/cmd/api/main.go @@ -12,8 +12,39 @@ import ( "github.com/prabhupadasays/spsays-bff/internal/config" "github.com/prabhupadasays/spsays-bff/internal/server" "go.uber.org/zap" + "go.uber.org/zap/zapcore" ) +// newLogger builds the app logger, routing logs by level: Debug/Info/Warn go +// to stdout and only Error/Fatal/Panic go to stderr. Hosting platforms tag +// every stderr line as "error", so without this split a routine Debug/Info +// line shows up with a misleading error badge. Production uses JSON at Info+; +// development uses colored console at Debug+. +func newLogger(production bool) *zap.Logger { + var encoder zapcore.Encoder + minLevel := zapcore.DebugLevel + if production { + encoder = zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()) + minLevel = zapcore.InfoLevel + } else { + encCfg := zap.NewDevelopmentEncoderConfig() + encCfg.EncodeLevel = zapcore.CapitalColorLevelEncoder + encoder = zapcore.NewConsoleEncoder(encCfg) + } + + low := zap.LevelEnablerFunc(func(l zapcore.Level) bool { + return l >= minLevel && l < zapcore.ErrorLevel + }) + high := zap.LevelEnablerFunc(func(l zapcore.Level) bool { + return l >= zapcore.ErrorLevel + }) + core := zapcore.NewTee( + zapcore.NewCore(encoder, zapcore.Lock(os.Stdout), low), + zapcore.NewCore(encoder, zapcore.Lock(os.Stderr), high), + ) + return zap.New(core, zap.AddCaller(), zap.AddStacktrace(zapcore.ErrorLevel)) +} + func main() { // Load config cfg, err := config.Load() @@ -22,13 +53,8 @@ func main() { os.Exit(1) } - // Initialize logger - var logger *zap.Logger - if cfg.Env == "production" { - logger, _ = zap.NewProduction() - } else { - logger, _ = zap.NewDevelopment() - } + // Initialize logger — routes normal logs to stdout, errors to stderr. + logger := newLogger(cfg.Env == "production") defer logger.Sync() sugar := logger.Sugar() diff --git a/internal/service/push_sender.go b/internal/service/push_sender.go index ef7f506..aef35f1 100644 --- a/internal/service/push_sender.go +++ b/internal/service/push_sender.go @@ -3,8 +3,11 @@ package service import ( "context" "encoding/json" + "io" "net/http" + "net/url" "strconv" + "strings" "time" webpush "github.com/SherClockHolmes/webpush-go" @@ -81,10 +84,13 @@ func (p *PushSender) SendToUser(ctx context.Context, userID string, payload Push Endpoint: s.Endpoint, Keys: webpush.Keys{P256dh: s.P256dh, Auth: s.Auth}, } - status, err := p.sendWithRetry(ctx, body, sub) + status, respBody, err := p.sendWithRetry(ctx, body, sub) if err != nil { failed++ - p.logger.Warn("push: send failed", zap.String("user", userID), zap.Error(err)) + p.logger.Warn("push: send failed", + zap.String("user", userID), + zap.String("host", endpointHost(s.Endpoint)), + zap.Error(err)) continue } switch { @@ -96,7 +102,13 @@ func (p *PushSender) SendToUser(ctx context.Context, userID string, payload Push } case status >= 400: failed++ - p.logger.Warn("push: non-2xx", zap.Int("status", status), zap.String("user", userID)) + // The response body carries the real reason (e.g. a VAPID + // credential mismatch, malformed request) — log it. + p.logger.Warn("push: non-2xx", + zap.Int("status", status), + zap.String("user", userID), + zap.String("host", endpointHost(s.Endpoint)), + zap.String("body", respBody)) default: sent++ } @@ -108,8 +120,10 @@ func (p *PushSender) SendToUser(ctx context.Context, userID string, payload Push // sendWithRetry posts one notification, retrying on transient failures // (network error or 429/5xx) with a short backoff that honors Retry-After. -// Returns the final HTTP status, or an error if every attempt errored. -func (p *PushSender) sendWithRetry(ctx context.Context, body []byte, sub *webpush.Subscription) (int, error) { +// Returns the final HTTP status and, on a 4xx/5xx, a snippet of the response +// body (the push service's error reason). Returns an error if every attempt +// errored at the transport level. +func (p *PushSender) sendWithRetry(ctx context.Context, body []byte, sub *webpush.Subscription) (int, string, error) { var lastErr error for attempt := 1; attempt <= pushMaxAttempts; attempt++ { resp, err := webpush.SendNotification(body, sub, &webpush.Options{ @@ -127,18 +141,33 @@ func (p *PushSender) sendWithRetry(ctx context.Context, body []byte, sub *webpus sleepCtx(ctx, backoff(attempt)) continue } - return 0, err + return 0, "", err } status := resp.StatusCode retryAfter := resp.Header.Get("Retry-After") - _ = resp.Body.Close() if isTransientStatus(status) && attempt < pushMaxAttempts { + _ = resp.Body.Close() sleepCtx(ctx, retryDelay(retryAfter, attempt)) continue } - return status, nil + // Final attempt — capture the body on errors for diagnostics. + var snippet string + if status >= 400 { + b, _ := io.ReadAll(io.LimitReader(resp.Body, 512)) + snippet = strings.TrimSpace(string(b)) + } + _ = resp.Body.Close() + return status, snippet, nil } - return 0, lastErr + return 0, "", lastErr +} + +// endpointHost extracts the host of a push endpoint for log context. +func endpointHost(endpoint string) string { + if u, err := url.Parse(endpoint); err == nil { + return u.Host + } + return "" } func isTransientStatus(s int) bool {