From 09ee2de72936ea0b0edc5d3360ce1c72803a817b Mon Sep 17 00:00:00 2001 From: Alan Pearce Date: Sun, 19 May 2024 15:42:36 +0200 Subject: log in logfmt via zap, with nicer console output in dev --- cmd/build/main.go | 24 ++++------- cmd/cspgenerator/cspgenerator.go | 4 +- cmd/dev/main.go | 86 ++++++++++++++++++++-------------------- cmd/server/main.go | 22 ++++------ 4 files changed, 60 insertions(+), 76 deletions(-) (limited to 'cmd') diff --git a/cmd/build/main.go b/cmd/build/main.go index 069f9bd..0b1cc46 100644 --- a/cmd/build/main.go +++ b/cmd/build/main.go @@ -3,11 +3,10 @@ package main import ( "fmt" "io/fs" - "log" - "log/slog" "os" "website/internal/builder" + "website/internal/log" "github.com/BurntSushi/toml" "github.com/ardanlabs/conf/v3" @@ -15,22 +14,17 @@ import ( ) func main() { - if os.Getenv("DEBUG") != "" { - slog.SetLogLoggerLevel(slog.LevelDebug) - } - log.SetFlags(log.LstdFlags | log.Lmsgprefix) - log.SetPrefix("build: ") - slog.Debug("starting build process") - ioConfig := builder.IOConfig{} if help, err := conf.Parse("", &ioConfig); err != nil { if errors.Is(err, conf.ErrHelpWanted) { fmt.Println(help) os.Exit(1) } - log.Panicf("parsing I/O configuration: %v", err) + panic("error parsing configuration: " + err.Error()) } + log.Configure(!ioConfig.Development) + log.Debug("starting build process") if ioConfig.Source != "." { err := os.Chdir(ioConfig.Source) if err != nil { @@ -41,15 +35,11 @@ func main() { if err := builder.BuildSite(ioConfig); err != nil { switch cause := errors.Cause(err).(type) { case *fs.PathError: - slog.Info("pathError") - slog.Error(fmt.Sprintf("%s", err)) + log.Error("path error", "error", err) case toml.ParseError: - slog.Info("parseError") - slog.Error(fmt.Sprintf("%s", err)) + log.Info("parse error", "error", err) default: - slog.Info("other") - slog.Error(fmt.Sprintf("cause:%+v", errors.Cause(cause))) - slog.Error(fmt.Sprintf("%+v", cause)) + log.Info("other error", "error", err, "cause", errors.Cause(cause)) } os.Exit(1) } diff --git a/cmd/cspgenerator/cspgenerator.go b/cmd/cspgenerator/cspgenerator.go index f79a591..89d2718 100644 --- a/cmd/cspgenerator/cspgenerator.go +++ b/cmd/cspgenerator/cspgenerator.go @@ -1,13 +1,13 @@ package main import ( - "log" "website/internal/config" + "website/internal/log" ) func main() { err := config.GenerateCSP() if err != nil { - log.Fatal(err) + log.Fatal("error generating csp", "error", err) } } diff --git a/cmd/dev/main.go b/cmd/dev/main.go index aa3102f..459cfaf 100644 --- a/cmd/dev/main.go +++ b/cmd/dev/main.go @@ -5,8 +5,6 @@ import ( "fmt" "io" "io/fs" - "log" - "log/slog" "net/http" "net/http/httputil" @@ -15,12 +13,12 @@ import ( "os/signal" "path" "path/filepath" - "strings" "sync" "syscall" "time" "website/internal/config" + "website/internal/log" "github.com/antage/eventsource" "github.com/ardanlabs/conf/v3" @@ -41,14 +39,14 @@ func RunCommandPiped( command string, args ...string, ) (cmd *exec.Cmd, err error) { - slog.Debug(fmt.Sprintf("running command %s %s", command, strings.Join(args, " "))) + log.Debug("running command", "command", command, "args", args) cmd = exec.CommandContext(ctx, command, args...) cmd.Env = append(os.Environ(), "DEBUG=") cmd.Cancel = func() error { - slog.Debug("signalling child") + log.Debug("signalling child") err := cmd.Process.Signal(os.Interrupt) if err != nil { - slog.Error(fmt.Sprintf("signal error: %v", err)) + log.Error("signal error:", "error", err) } return err } @@ -80,12 +78,12 @@ func NewFileWatcher(pollTime time.Duration) (*FileWatcher, error) { } func (watcher FileWatcher) WatchAllFiles(from string) error { - slog.Debug(fmt.Sprintf("watching files under %s", from)) + log.Debug("watching files under", "from", from) err := filepath.Walk(from, func(path string, info fs.FileInfo, err error) error { if err != nil { return err } - // slog.Debug(fmt.Sprintf("adding file %s to watcher", path)) + // log.Debug(fmt.Sprintf("adding file %s to watcher", path)) if err = watcher.Add(path); err != nil { return err } @@ -107,7 +105,11 @@ func build(ctx context.Context, config DevConfig) error { } err = cmd.Run() - slog.Debug(fmt.Sprintf("build command exited with code %d", cmd.ProcessState.ExitCode())) + log.Debug( + "build command exited", + "status", + cmd.ProcessState.ExitCode(), + ) if err != nil { return errors.WithMessage(err, "error running build command") } @@ -148,7 +150,7 @@ func server(ctx context.Context, devConfig DevConfig) error { for { select { case <-ctx.Done(): - slog.Debug("server context done") + log.Debug("server context done") err := cmd.Process.Signal(os.Interrupt) if err != nil { return err @@ -161,10 +163,8 @@ func server(ctx context.Context, devConfig DevConfig) error { } func main() { - if os.Getenv("DEBUG") != "" { - slog.SetLogLoggerLevel(slog.LevelDebug) - } var wg sync.WaitGroup + log.Configure(false) devConfig := DevConfig{} help, err := conf.Parse("", &devConfig) @@ -173,23 +173,23 @@ func main() { fmt.Println(help) os.Exit(1) } - log.Panicf("parsing dev configuration: %v", err) + log.Panic("parsing dev configuration", "error", err) } - slog.Debug(fmt.Sprintf("using folder %s for build output", devConfig.TempDir)) + log.Debug("running with in /tmp", "dir", devConfig.TempDir) ctx, cancel := context.WithCancel(context.Background()) defer cancel() - slog.Debug("setting interrupt handler") + log.Debug("setting interrupt handler") c := make(chan os.Signal, 1) signal.Notify(c, os.Interrupt, syscall.SIGTERM) go func() { sig := <-c - slog.Info(fmt.Sprintf("shutting down on signal %d", sig)) + log.Info("shutting down on signal", "sig", sig) cancel() sig = <-c - slog.Info(fmt.Sprintf("got second signal, dying %d", sig)) + log.Info("got second signal, dying", "sig", sig) os.Exit(1) }() @@ -205,9 +205,9 @@ func main() { go func() { defer wg.Done() defer devCancel() - slog.Debug("waiting for first server launch") + log.Debug("waiting for first server launch") <-serverChan - slog.Debug("got first server launch event") + log.Debug("got first server launch event") http.Handle("/", &httputil.ReverseProxy{ Rewrite: func(req *httputil.ProxyRequest) { @@ -220,7 +220,7 @@ func main() { go func() { err := srv.ListenAndServe() if err != nil && err != http.ErrServerClosed { - slog.Error(err.Error()) + log.Error(err.Error()) cancel() } done <- true @@ -228,29 +228,29 @@ func main() { go func() { for ready := range serverChan { if ready { - slog.Debug("sending reload message") + log.Debug("sending reload message") eventsource.SendEventMessage("reload", "", "") } else { - slog.Debug("server not ready") + log.Debug("server not ready") } } }() - slog.Info(fmt.Sprintf("dev server listening on %s", devConfig.BaseURL.Host)) + log.Info("dev server listening on", "host", devConfig.BaseURL.String()) <-done - slog.Debug("dev server closed") + log.Debug("dev server closed") }() fw, err := NewFileWatcher(500 * time.Millisecond) if err != nil { - log.Fatalf("error creating file watcher: %v", err) + log.Fatal("error creating file watcher", "error", err) } err = fw.WatchAllFiles("content") if err != nil { - log.Fatalf("could not watch files in content directory: %v", err) + log.Fatal("could not watch files in content directory", "error", err) } err = fw.WatchAllFiles("templates") if err != nil { - log.Fatalf("could not watch files in templates directory: %v", err) + log.Fatal("could not watch files in templates directory", "error", err) } var exitCode int @@ -258,14 +258,14 @@ func main() { loop: for { serverCtx, stopServer := context.WithCancel(ctx) - slog.Debug("starting build") + log.Debug("starting build") err := build(ctx, devConfig) if err != nil { - slog.Error(fmt.Sprintf("build error: %v", err)) + log.Error("build error:", "error", err) // don't set up the server until there's a FS change event } else { - slog.Debug("setting up server") + log.Debug("setting up server") wg.Add(1) go func() { defer wg.Done() @@ -276,43 +276,43 @@ loop: select { case <-ctx.Done(): - slog.Debug("main context cancelled") - slog.Debug("calling server shutdown") + log.Debug("main context cancelled") + log.Debug("calling server shutdown") err := srv.Shutdown(devCtx) if err != nil { - slog.Debug("shutdown error", "error", err) + log.Debug("shutdown error", "error", err) } exitCode = 1 break loop case event := <-fw.Events: - slog.Debug(fmt.Sprintf("event received: %v", event)) + log.Debug("event received:", "event", event) stopServer() serverChan <- false - slog.Debug("waiting for server shutdown") + log.Debug("waiting for server shutdown") <-serverErr - slog.Debug("server shutdown completed") + log.Debug("server shutdown completed") continue case err = <-serverErr: if err != nil && err != context.Canceled { var exerr *exec.ExitError - slog.Error(fmt.Sprintf("server reported error: %v", err)) + log.Error("server reported error:", "error", err) if errors.As(err, &exerr) { - slog.Debug("server exit error") + log.Debug("server exit error") } else { - slog.Debug("server other error") + log.Debug("server other error") } break } - slog.Debug("no error or server context cancelled") + log.Debug("no error or server context cancelled") continue } - slog.Debug("waiting on server") + log.Debug("waiting on server") exitCode = 0 break } - slog.Debug("waiting for wg before shutting down") + log.Debug("waiting for wg before shutting down") wg.Wait() os.Exit(exitCode) } diff --git a/cmd/server/main.go b/cmd/server/main.go index bae215a..464c438 100644 --- a/cmd/server/main.go +++ b/cmd/server/main.go @@ -2,12 +2,11 @@ package main import ( "fmt" - "log" - "log/slog" "os" "os/signal" "sync" + "website/internal/log" "website/internal/server" "github.com/ardanlabs/conf/v3" @@ -20,12 +19,6 @@ var ( ) func main() { - if os.Getenv("DEBUG") != "" { - slog.SetLogLoggerLevel(slog.LevelDebug) - } - log.SetFlags(log.LstdFlags | log.Lmsgprefix) - log.SetPrefix("server: ") - runtimeConfig := server.Config{} help, err := conf.Parse("", &runtimeConfig) if err != nil { @@ -33,23 +26,24 @@ func main() { fmt.Println(help) os.Exit(1) } - log.Panicf("parsing runtime configuration: %v", err) + panic("parsing runtime configuration" + err.Error()) } + log.Configure(runtimeConfig.Production) c := make(chan os.Signal, 2) signal.Notify(c, os.Interrupt) sv, err := server.New(&runtimeConfig) if err != nil { - log.Fatalf("error setting up server: %v", err) + log.Fatal("error setting up server", "error", err) } wg := &sync.WaitGroup{} wg.Add(1) go func() { defer wg.Done() sig := <-c - log.Printf("signal captured: %v", sig) + log.Info("signal captured", "sig", sig) <-sv.Stop() - slog.Debug("server stopped") + log.Debug("server stopped") }() sErr := make(chan error) @@ -59,13 +53,13 @@ func main() { sErr <- sv.Start() }() if !runtimeConfig.InDevServer { - log.Printf("server listening on %s", sv.Addr) + log.Info("server listening", "address", sv.Addr) } err = <-sErr if err != nil { // Error starting or closing listener: - log.Fatalf("error: %v", err) + log.Fatal("error", "error", err) } wg.Wait() } -- cgit 1.4.1