diff --git a/db/sql.go b/db/sql.go index 838bc7e..1991e1e 100644 --- a/db/sql.go +++ b/db/sql.go @@ -2,7 +2,7 @@ package isudb import ( "database/sql" - "log" + "log/slog" "strconv" "sync/atomic" "time" @@ -37,7 +37,11 @@ func DBMetricsSetup[T interface { if fixInterpolateParams { config, err := mysql.ParseDSN(dataSourceName) if err != nil { - log.Printf("failed to parse dsn: %v\n", err) + slog.Error("failed to parse DSN", + slog.String("driver", driverName), + slog.String("dsn", dataSourceName), + slog.String("error", err.Error()), + ) goto CONNECT } diff --git a/http/echo.go b/http/echo.go index 3667d37..2d6371e 100644 --- a/http/echo.go +++ b/http/echo.go @@ -3,7 +3,7 @@ package isuhttp import ( "errors" "fmt" - "log" + "log/slog" "net/http" "os" "strconv" @@ -28,7 +28,10 @@ func init() { subEnableGoJson, err := strconv.ParseBool(strEnableGoJson) if err != nil { - log.Printf("failed to parse GO_JSON: %s\n", err) + slog.Error("failed to parse GO_JSON", + slog.String("GO_JSON", strEnableGoJson), + slog.String("error", err.Error()), + ) return } @@ -44,7 +47,9 @@ func EchoSetting(e *echo.Echo) *echo.Echo { listener, ok, err := newUnixDomainSockListener() if err != nil { - log.Printf("failed to init unix domain socket: %s\n", err) + slog.Error("failed to create unix domain socket listener", + slog.String("error", err.Error()), + ) } if ok { diff --git a/http/fiber.go b/http/fiber.go index 190bdda..dff0744 100644 --- a/http/fiber.go +++ b/http/fiber.go @@ -3,7 +3,7 @@ package isuhttp import ( "errors" "fmt" - "log" + "log/slog" "net/http" "strconv" "strings" @@ -35,13 +35,17 @@ func FiberNew(conf ...fiber.Config) *fiber.App { listener, ok, err := newUnixDomainSockListener() if err != nil { - log.Printf("failed to init unix domain socket: %s\n", err) + slog.Error("failed to create unix domain socket listener", + slog.String("error", err.Error()), + ) } if ok { err := app.Listener(listener) if err != nil { - log.Printf("failed to set listener: %s\n", err) + slog.Error("failed to set unix domain socket listener", + slog.String("error", err.Error()), + ) } } diff --git a/http/gin.go b/http/gin.go index 1817f0a..4b1f849 100644 --- a/http/gin.go +++ b/http/gin.go @@ -2,7 +2,7 @@ package isuhttp import ( "fmt" - "log" + "log/slog" "strconv" "strings" "time" @@ -21,7 +21,9 @@ func GinNew(engine *gin.Engine) *gin.Engine { func GinRun(engine *gin.Engine, addrs ...string) error { listener, ok, err := newUnixDomainSockListener() if err != nil { - log.Printf("failed to init unix domain socket: %s\n", err) + slog.Error("failed to create unix domain socket listener", + slog.String("error", err.Error()), + ) } if ok { @@ -34,7 +36,9 @@ func GinRun(engine *gin.Engine, addrs ...string) error { func GinRunTLS(engine *gin.Engine, addr, certFile, keyFile string) error { listener, ok, err := newUnixDomainSockListener() if err != nil { - log.Printf("failed to init unix domain socket: %s\n", err) + slog.Error("failed to create unix domain socket listener", + slog.String("error", err.Error()), + ) } if ok { diff --git a/internal/benchmark/status.go b/internal/benchmark/status.go index 4beac62..0c532da 100644 --- a/internal/benchmark/status.go +++ b/internal/benchmark/status.go @@ -5,7 +5,7 @@ import ( "encoding/gob" "encoding/json" "fmt" - "log" + "log/slog" "net/http" "os" "strconv" @@ -52,7 +52,10 @@ func init() { f, err := os.Open(gobFile) if err != nil { if !os.IsNotExist(err) { - log.Printf("failed to open gob file(%s): %s\n", gobFile, err) + slog.Error("failed to open gob file", + slog.String("file", gobFile), + slog.String("error", err.Error()), + ) } return @@ -61,7 +64,10 @@ func init() { err = gob.NewDecoder(f).Decode(latest) if err != nil { - log.Printf("failed to decode gob file(%s): %s\n", gobFile, err) + slog.Error("failed to decode gob file", + slog.String("file", gobFile), + slog.String("error", err.Error()), + ) } scoreGauge.Set(float64(latest.Score)) @@ -99,19 +105,30 @@ func setScore(ctx context.Context, score int64) { scoreGauge.Set(float64(score)) durationGauge.Set(latest.End.Sub(latest.Start).Seconds()) + for _, f := range endHooks { + f(ctx, latest) + } + f, err := os.Create(gobFile) if err != nil { - log.Printf("failed to create gob file(%s): %s\n", gobFile, err) - return + slog.Error("failed to create gob file", + slog.String("file", gobFile), + slog.String("error", err.Error()), + ) } + defer f.Close() err = gob.NewEncoder(f).Encode(latest) if err != nil { - log.Printf("failed to encode gob file(%s): %s\n", gobFile, err) - } - - for _, f := range endHooks { - f(ctx, latest) + slog.Error("failed to encode gob file", + slog.String("file", gobFile), + slog.Group("latest", + slog.Time("start", latest.Start), + slog.Time("end", latest.End), + slog.Int64("score", latest.Score), + ), + slog.String("error", err.Error()), + ) } } diff --git a/internal/config/config.go b/internal/config/config.go index ddfbdf1..4c9413e 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -1,7 +1,7 @@ package config import ( - "log" + "log/slog" "os" "strconv" "strings" @@ -18,7 +18,10 @@ func init() { if ok { enable, err := strconv.ParseBool(strings.TrimSpace(strEnable)) if err != nil { - log.Printf("failed to parse ISUTOOLS_ENABLE: %v", err) + slog.Error("failed to parse ISUTOOLS_ENABLE", + slog.String("ISUTOOLS_ENABLE", strEnable), + slog.String("error", err.Error()), + ) return } diff --git a/internal/log/slog.go b/internal/log/slog.go new file mode 100644 index 0000000..8b95a4c --- /dev/null +++ b/internal/log/slog.go @@ -0,0 +1,40 @@ +package log + +import ( + "context" + "log/slog" + "os" + + "github.com/mazrean/isucon-go-tools/v2/internal/config" +) + +func init() { + var logger *slog.Logger + if config.Enable { + logger = slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{ + Level: slog.LevelInfo, + })) + } else { + logger = slog.New(DiscardHandler{}) + } + + slog.SetDefault(logger) +} + +type DiscardHandler struct{} + +func (h DiscardHandler) Enabled(_ context.Context, _ slog.Level) bool { + return false +} + +func (h DiscardHandler) Handle(_ context.Context, _ slog.Record) error { + return nil +} + +func (h DiscardHandler) WithAttrs(_ []slog.Attr) slog.Handler { + return h +} + +func (h DiscardHandler) WithGroup(_ string) slog.Handler { + return h +} diff --git a/profiler/profiler.go b/profiler/profiler.go index 68d882e..6f52cf0 100644 --- a/profiler/profiler.go +++ b/profiler/profiler.go @@ -1,7 +1,7 @@ package profiler import ( - "log" + "log/slog" "net/http" "os" "runtime" @@ -21,7 +21,10 @@ func init() { if ok { blockRate, err := strconv.Atoi(strBlockRate) if err != nil { - log.Printf("failed to parse BLOCK_RATE(%s): %v", strBlockRate, err) + slog.Error("failed to parse BLOCK_RATE", + slog.String("BLOCK_RATE", strBlockRate), + slog.String("error", err.Error()), + ) } else { runtime.SetBlockProfileRate(blockRate) } @@ -31,15 +34,20 @@ func init() { if ok { mutexRate, err := strconv.Atoi(strMutexRate) if err != nil { - log.Printf("failed to parse MUTEX_RATE(%s): %v", strMutexRate, err) + slog.Error("failed to parse MUTEX_RATE", + slog.String("MUTEX_RATE", strMutexRate), + slog.String("error", err.Error()), + ) } else { runtime.SetMutexProfileFraction(mutexRate) } } - err := pyroscopeStart() + err := setupPyroscope() if err != nil { - log.Printf("failed to init pyroscope: %v", err) + slog.Error("failed to setup pyroscope", + slog.String("error", err.Error()), + ) } } diff --git a/profiler/pyroscope.go b/profiler/pyroscope.go index adeb0c8..d0db44a 100644 --- a/profiler/pyroscope.go +++ b/profiler/pyroscope.go @@ -6,9 +6,11 @@ import ( "context" "fmt" "io" - "log" + "log/slog" "net/http" "os" + "runtime" + "time" "connectrpc.com/connect" "github.com/grafana/pyroscope-go" @@ -26,11 +28,7 @@ var ( query string ) -func init() { - if !config.Enable { - return - } - +func setupPyroscope() error { var ok bool serverAddr, ok = os.LookupEnv("PYROSCOPE_SERVER") if !ok { @@ -52,7 +50,14 @@ func init() { query = "{}" } + err := pyroscopeStart() + if err != nil { + return fmt.Errorf("failed to start pyroscope: %w", err) + } + benchmark.SetEndHook(DownloadPGO) + + return nil } func pyroscopeStart() error { @@ -64,7 +69,7 @@ func pyroscopeStart() error { _, err := pyroscope.Start(pyroscope.Config{ ApplicationName: "isucon.go.app", ServerAddress: serverAddr, - Logger: pyroscope.StandardLogger, + Logger: slogLogger{}, Tags: tagMap, ProfileTypes: []pyroscope.ProfileType{ pyroscope.ProfileCPU, @@ -86,6 +91,29 @@ func pyroscopeStart() error { return nil } +type slogLogger struct{} + +func (slogLogger) Infof(format string, args ...any) { + var pcs [1]uintptr + runtime.Callers(2, pcs[:]) + r := slog.NewRecord(time.Now(), slog.LevelInfo, fmt.Sprintf(format, args...), pcs[0]) + slog.Default().Handler().Handle(context.Background(), r) +} + +func (slogLogger) Debugf(format string, args ...any) { + var pcs [1]uintptr + runtime.Callers(2, pcs[:]) + r := slog.NewRecord(time.Now(), slog.LevelDebug, fmt.Sprintf(format, args...), pcs[0]) + slog.Default().Handler().Handle(context.Background(), r) +} + +func (slogLogger) Errorf(format string, args ...any) { + var pcs [1]uintptr + runtime.Callers(2, pcs[:]) + r := slog.NewRecord(time.Now(), slog.LevelError, fmt.Sprintf(format, args...), pcs[0]) + slog.Default().Handler().Handle(context.Background(), r) +} + func DownloadPGO(ctx context.Context, b *benchmark.Benchmark) { client := querierv1connect.NewQuerierServiceClient( http.DefaultClient, @@ -103,19 +131,31 @@ func DownloadPGO(ctx context.Context, b *benchmark.Benchmark) { LabelSelector: query, })) if err != nil { - log.Printf("failed to select merge span profile: %v\n", err) + slog.Error("failed to select merge span profile", + slog.Group("benchmark", + slog.Time("start", b.Start), + slog.Time("end", b.End), + slog.Int64("score", b.Score), + ), + slog.String("error", err.Error()), + ) return } buf, err := res.Msg.MarshalVT() if err != nil { - log.Printf("failed to marshal vt: %v\n", err) + slog.Error("failed to marshal vt", + slog.String("error", err.Error()), + ) return } f, err := os.Create(pgoFile) if err != nil { - log.Printf("failed to create pgo file(%s): %s\n", pgoFile, err) + slog.Error("failed to create pgo file", + slog.String("file", pgoFile), + slog.String("error", err.Error()), + ) return } defer f.Close() @@ -124,6 +164,9 @@ func DownloadPGO(ctx context.Context, b *benchmark.Benchmark) { defer gzipWriter.Close() if _, err := io.Copy(gzipWriter, bytes.NewReader(buf)); err != nil { - log.Printf("failed to copy response: %v\n", err) + slog.Error("failed to copy buffer", + slog.String("error", err.Error()), + ) + return } } diff --git a/query/update.go b/query/update.go index 122049d..cd27b4f 100644 --- a/query/update.go +++ b/query/update.go @@ -2,7 +2,7 @@ package query import ( "errors" - "log" + "log/slog" "strings" ) @@ -39,7 +39,10 @@ func (b *BulkUpdate) Add(key any, values ...any) error { b.values[i] = append(b.values[i], values[i]) } if len(values) > len(b.values) { - log.Println("warning: too many values") + slog.Warn("too many values", + slog.Int("expected", len(b.values)), + slog.Int("actual", len(values)), + ) } return nil diff --git a/server.go b/server.go index 9f03818..1d68ecf 100644 --- a/server.go +++ b/server.go @@ -1,13 +1,14 @@ package isutools import ( - "log" + "log/slog" "net/http" _ "net/http/pprof" "github.com/mazrean/isucon-go-tools/v2/internal/benchmark" "github.com/mazrean/isucon-go-tools/v2/internal/config" + _ "github.com/mazrean/isucon-go-tools/v2/internal/log" "github.com/mazrean/isucon-go-tools/v2/profiler" ) @@ -27,7 +28,10 @@ func init() { } err := server.ListenAndServe() if err != nil { - log.Printf("failed to listen and serve(%s): %v", config.Addr, err) + slog.Error("failed to start http server", + slog.String("addr", config.Addr), + slog.String("error", err.Error()), + ) } }() }