diff --git a/cmd/cairn-server/main.go b/cmd/cairn-server/main.go index 06faebd..a02a939 100644 --- a/cmd/cairn-server/main.go +++ b/cmd/cairn-server/main.go @@ -2,13 +2,15 @@ package main import ( "context" - "log" "net/http" "os" "os/signal" "syscall" "time" + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" + "github.com/mattnite/cairn/internal/blob" "github.com/mattnite/cairn/internal/config" "github.com/mattnite/cairn/internal/database" @@ -17,9 +19,11 @@ import ( ) func main() { + zerolog.TimeFieldFormat = zerolog.TimeFormatUnix + cfg, err := config.Load() if err != nil { - log.Fatalf("Loading config: %v", err) + log.Fatal().Err(err).Msg("Loading config") } ctx, cancel := context.WithCancel(context.Background()) @@ -27,27 +31,27 @@ func main() { pool, err := database.Connect(ctx, cfg.DatabaseURL) if err != nil { - log.Fatalf("Connecting to database: %v", err) + log.Fatal().Err(err).Msg("Connecting to database") } defer pool.Close() if err := database.Migrate(ctx, pool); err != nil { - log.Fatalf("Running migrations: %v", err) + log.Fatal().Err(err).Msg("Running migrations") } store, err := blob.NewS3Store(cfg.S3Endpoint, cfg.S3AccessKey, cfg.S3SecretKey, cfg.S3Bucket, cfg.S3UseSSL) if err != nil { - log.Fatalf("Creating blob store: %v", err) + log.Fatal().Err(err).Msg("Creating blob store") } if err := store.EnsureBucket(ctx); err != nil { - log.Fatalf("Ensuring bucket: %v", err) + log.Fatal().Err(err).Msg("Ensuring bucket") } var forgejoClient *forgejo.Client if cfg.ForgejoURL != "" && cfg.ForgejoToken != "" { forgejoClient = forgejo.NewClient(cfg.ForgejoURL, cfg.ForgejoToken) - log.Printf("Forgejo integration enabled: %s", cfg.ForgejoURL) + log.Info().Str("url", cfg.ForgejoURL).Msg("Forgejo integration enabled") } router, err := web.NewRouter(web.RouterConfig{ @@ -57,7 +61,7 @@ func main() { WebhookSecret: cfg.ForgejoWebhookSecret, }) if err != nil { - log.Fatalf("Creating router: %v", err) + log.Fatal().Err(err).Msg("Creating router") } srv := &http.Server{ @@ -72,16 +76,16 @@ func main() { sigCh := make(chan os.Signal, 1) signal.Notify(sigCh, syscall.SIGINT, syscall.SIGTERM) <-sigCh - log.Println("Shutting down...") + log.Info().Msg("Shutting down...") shutdownCtx, shutdownCancel := context.WithTimeout(context.Background(), 10*time.Second) defer shutdownCancel() if err := srv.Shutdown(shutdownCtx); err != nil { - log.Printf("Shutdown error: %v", err) + log.Error().Err(err).Msg("Shutdown error") } }() - log.Printf("Cairn server listening on %s", cfg.ListenAddr) + log.Info().Str("addr", cfg.ListenAddr).Msg("Cairn server listening") if err := srv.ListenAndServe(); err != http.ErrServerClosed { - log.Fatalf("Server error: %v", err) + log.Fatal().Err(err).Msg("Server error") } } diff --git a/go.mod b/go.mod index b8a7975..8938091 100644 --- a/go.mod +++ b/go.mod @@ -6,6 +6,7 @@ require ( github.com/gin-gonic/gin v1.12.0 github.com/jackc/pgx/v5 v5.8.0 github.com/minio/minio-go/v7 v7.0.98 + github.com/rs/zerolog v1.34.0 ) require ( @@ -31,6 +32,7 @@ require ( github.com/klauspost/cpuid/v2 v2.3.0 // indirect github.com/klauspost/crc32 v1.3.0 // indirect github.com/leodido/go-urn v1.4.0 // indirect + github.com/mattn/go-colorable v0.1.13 // indirect github.com/mattn/go-isatty v0.0.20 // indirect github.com/minio/crc64nvme v1.1.1 // indirect github.com/minio/md5-simd v1.1.2 // indirect diff --git a/go.sum b/go.sum index af5a7b8..0cba481 100644 --- a/go.sum +++ b/go.sum @@ -6,6 +6,7 @@ github.com/bytedance/sonic/loader v0.5.0 h1:gXH3KVnatgY7loH5/TkeVyXPfESoqSBSBEiD github.com/bytedance/sonic/loader v0.5.0/go.mod h1:AR4NYCk5DdzZizZ5djGqQ92eEhCCcdf5x77udYiSJRo= github.com/cloudwego/base64x v0.1.6 h1:t11wG9AECkCDk5fMSoxmufanudBtJ+/HemLstXDLI2M= github.com/cloudwego/base64x v0.1.6/go.mod h1:OFcloc187FXDaYHvrNIjxSe8ncn0OOM8gEHfghB2IPU= +github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= @@ -31,6 +32,7 @@ github.com/goccy/go-json v0.10.5 h1:Fq85nIqj+gXn/S5ahsiTlK3TmC85qgirsdTP/+DeaC4= github.com/goccy/go-json v0.10.5/go.mod h1:oq7eo15ShAhp70Anwd5lgX2pLfOS3QCiwU/PULtXL6M= github.com/goccy/go-yaml v1.19.2 h1:PmFC1S6h8ljIz6gMRBopkjP1TVT7xuwrButHID66PoM= github.com/goccy/go-yaml v1.19.2/go.mod h1:XBurs7gK8ATbW4ZPGKgcbrY1Br56PdM69F7LkFRi1kA= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= github.com/google/go-cmp v0.7.0 h1:wk8382ETsv4JYUZwIsn6YpYiWiBsYLSJiTsyBybVuN8= github.com/google/go-cmp v0.7.0/go.mod h1:pXiqmnSA92OHEEa9HXL2W4E7lf9JzCmGVUdgjX3N/iU= github.com/google/gofuzz v1.0.0/go.mod h1:dBl0BpW6vV/+mYPU4Po3pmUjxk6FQPldtuIdl/M65Eg= @@ -59,6 +61,10 @@ github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/leodido/go-urn v1.4.0 h1:WT9HwE9SGECu3lg4d/dIA+jxlljEa1/ffXKmRjqdmIQ= github.com/leodido/go-urn v1.4.0/go.mod h1:bvxc+MVxLKB4z00jd1z+Dvzr47oO32F/QSNjSBOlFxI= +github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= +github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= +github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= +github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY= github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/minio/crc64nvme v1.1.1 h1:8dwx/Pz49suywbO+auHCBpCtlW1OfpcLN7wYgVR6wAI= @@ -76,6 +82,7 @@ github.com/pelletier/go-toml/v2 v2.2.4 h1:mye9XuhQ6gvn5h28+VilKrrPoQVanw5PMw/TB0 github.com/pelletier/go-toml/v2 v2.2.4/go.mod h1:2gIqNv+qfxSVS7cM2xJQKtLSTLUE9V8t9Stt+h56mCY= github.com/philhofer/fwd v1.2.0 h1:e6DnBTl7vGY+Gz322/ASL4Gyp1FspeMvx1RNDoToZuM= github.com/philhofer/fwd v1.2.0/go.mod h1:RqIHx9QI14HlwKwm98g9Re5prTQ6LdeRQn+gXJFxsJM= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/quic-go/qpack v0.6.0 h1:g7W+BMYynC1LbYLSqRt8PBg5Tgwxn214ZZR34VIOjz8= @@ -86,6 +93,8 @@ github.com/rogpeppe/go-internal v1.14.1 h1:UQB4HGPB6osV0SQTLymcB4TgvyWu6ZyliaW0t github.com/rogpeppe/go-internal v1.14.1/go.mod h1:MaRKkUm5W0goXpeCfT7UZI6fk/L7L7so1lCWt35ZSgc= github.com/rs/xid v1.6.0 h1:fV591PaemRlL6JfRxGDEPl69wICngIQ3shQtzfy2gxU= github.com/rs/xid v1.6.0/go.mod h1:7XoLgs4eV+QndskICGsho+ADou8ySMSjJKDIan90Nz0= +github.com/rs/zerolog v1.34.0 h1:k43nTLIwcTVQAncfCw4KZ2VY6ukYoZaBPNOE8txlOeY= +github.com/rs/zerolog v1.34.0/go.mod h1:bJsvje4Z08ROH4Nhs5iH600c3IkWhwp44iRc54W6wYQ= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw= github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo= @@ -118,7 +127,9 @@ golang.org/x/net v0.51.0 h1:94R/GTO7mt3/4wIKpcR5gkGmRLOuE/2hNGeWq/GBIFo= golang.org/x/net v0.51.0/go.mod h1:aamm+2QF5ogm02fjy5Bb7CQ0WMt1/WVM7FtyaTLlA9Y= golang.org/x/sync v0.19.0 h1:vV+1eWNmZ5geRlYjzm2adRgW2/mcpevXNg50YZtPCE4= golang.org/x/sync v0.19.0/go.mod h1:9KTHXmSnoGruLpwFjVSX0lNNA75CykiMECbovNTZqGI= +golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.41.0 h1:Ivj+2Cp/ylzLiEU89QhWblYnOE9zerudt9Ftecq2C6k= golang.org/x/sys v0.41.0/go.mod h1:OgkHotnGiDImocRcuBABYBEXf8A9a87e/uXjp9XT3ks= golang.org/x/text v0.34.0 h1:oL/Qq0Kdaqxa1KbNeMKwQq0reLCCaFtqu2eNuSeNHbk= diff --git a/internal/database/migrate.go b/internal/database/migrate.go index 5b64852..6dbb60d 100644 --- a/internal/database/migrate.go +++ b/internal/database/migrate.go @@ -5,11 +5,11 @@ import ( "embed" "fmt" "io/fs" - "log" "sort" "strings" "github.com/jackc/pgx/v5/pgxpool" + "github.com/rs/zerolog/log" ) //go:embed migrations/*.sql @@ -76,7 +76,7 @@ func Migrate(ctx context.Context, pool *pgxpool.Pool) error { return fmt.Errorf("committing migration %s: %w", version, err) } - log.Printf("Applied migration: %s", version) + log.Info().Str("version", version).Msg("Applied migration") } return nil diff --git a/internal/forgejo/sync.go b/internal/forgejo/sync.go index 014c573..0171402 100644 --- a/internal/forgejo/sync.go +++ b/internal/forgejo/sync.go @@ -3,10 +3,11 @@ package forgejo import ( "context" "fmt" - "log" "strings" "github.com/jackc/pgx/v5/pgxpool" + "github.com/rs/zerolog/log" + "github.com/mattnite/cairn/internal/models" ) @@ -80,5 +81,5 @@ func (s *Sync) HandlePushEvent(ctx context.Context, event *WebhookEvent) { if event.Repo == nil || event.After == "" { return } - log.Printf("Push event: %s -> %s", event.Repo.FullName, event.After[:8]) + log.Info().Str("repo", event.Repo.FullName).Str("sha", event.After[:8]).Msg("Push event") } diff --git a/internal/handler/webhooks.go b/internal/handler/webhooks.go index 4d57245..5477628 100644 --- a/internal/handler/webhooks.go +++ b/internal/handler/webhooks.go @@ -1,10 +1,11 @@ package handler import ( - "log" "net/http" "github.com/gin-gonic/gin" + "github.com/rs/zerolog/log" + "github.com/mattnite/cairn/internal/forgejo" ) @@ -16,7 +17,7 @@ type WebhookHandler struct { func (h *WebhookHandler) Handle(c *gin.Context) { event, eventType, err := forgejo.VerifyAndParse(c.Request, h.Secret) if err != nil { - log.Printf("Webhook error: %v", err) + log.Warn().Err(err).Msg("Webhook verification failed") c.JSON(http.StatusUnauthorized, gin.H{"error": err.Error()}) return } @@ -26,7 +27,7 @@ func (h *WebhookHandler) Handle(c *gin.Context) { switch eventType { case "issues": if err := h.Sync.HandleIssueEvent(ctx, event); err != nil { - log.Printf("Issue event error: %v", err) + log.Error().Err(err).Msg("Issue event error") } case "push": h.Sync.HandlePushEvent(ctx, event) diff --git a/internal/web/middleware.go b/internal/web/middleware.go index d4e2b37..0487a1c 100644 --- a/internal/web/middleware.go +++ b/internal/web/middleware.go @@ -1,16 +1,45 @@ package web import ( - "log" + "net" + "net/http" + "strings" "time" "github.com/gin-gonic/gin" + "github.com/rs/zerolog/log" ) func LoggingMiddleware() gin.HandlerFunc { return func(c *gin.Context) { start := time.Now() c.Next() - log.Printf("%s %s %d %s", c.Request.Method, c.Request.URL.Path, c.Writer.Status(), time.Since(start)) + log.Info(). + Str("method", c.Request.Method). + Str("path", c.Request.URL.Path). + Int("status", c.Writer.Status()). + Dur("latency", time.Since(start)). + Msg("Request") + } +} + +func RecoveryMiddleware() gin.HandlerFunc { + return func(c *gin.Context) { + defer func() { + if r := recover(); r != nil { + // Don't log broken pipe errors — client disconnected. + if err, ok := r.(error); ok { + if ne, ok := err.(*net.OpError); ok && ne.Op == "write" { + if strings.Contains(ne.Err.Error(), "broken pipe") || strings.Contains(ne.Err.Error(), "connection reset") { + c.Abort() + return + } + } + } + log.Error().Interface("panic", r).Str("path", c.Request.URL.Path).Msg("Recovery from panic") + c.AbortWithStatus(http.StatusInternalServerError) + } + }() + c.Next() } } diff --git a/internal/web/routes.go b/internal/web/routes.go index 970bc40..f6150a7 100644 --- a/internal/web/routes.go +++ b/internal/web/routes.go @@ -38,7 +38,9 @@ func NewRouter(cfg RouterConfig) (*gin.Engine, error) { dashboardAPI := &handler.DashboardHandler{Pool: cfg.Pool} webhookH := &handler.WebhookHandler{Sync: forgejoSync, Secret: cfg.WebhookSecret} - r := gin.Default() + gin.SetMode(gin.ReleaseMode) + r := gin.New() + r.Use(LoggingMiddleware(), RecoveryMiddleware()) // Static files staticFS, err := fs.Sub(assets.Assets, "static")