From 973fa31b6743a3ea84c86ab7671349cc70a69142 Mon Sep 17 00:00:00 2001 From: Alan Pearce Date: Sat, 29 Jun 2024 21:27:35 +0200 Subject: enable filtered debug logging via DEBUG="component.*" --- internal/builder/builder.go | 18 ++++++------ internal/config/config.go | 2 +- internal/content/posts.go | 16 +++++++---- internal/listenfd/listenfd.go | 11 ++++++-- internal/log/log.go | 66 +++++++++++++++++++++++++++++-------------- internal/server/dev.go | 19 +++++++------ internal/server/logging.go | 2 +- internal/server/mime.go | 6 +--- internal/server/server.go | 32 ++++++++++++--------- internal/server/tcp.go | 2 +- internal/server/tls.go | 7 +++-- internal/vcs/repository.go | 13 +++++---- internal/website/filemap.go | 2 +- internal/website/mux.go | 12 ++++---- 14 files changed, 125 insertions(+), 83 deletions(-) (limited to 'internal') diff --git a/internal/builder/builder.go b/internal/builder/builder.go index 0d4b1fc..b6da17d 100644 --- a/internal/builder/builder.go +++ b/internal/builder/builder.go @@ -93,7 +93,7 @@ func joinSourcePath(src string) func(string) string { } } -func build(ioConfig *IOConfig, config *config.Config) (*Result, error) { +func build(ioConfig *IOConfig, config *config.Config, log *log.Logger) (*Result, error) { outDir := ioConfig.Destination joinSource := joinSourcePath(ioConfig.Source) log.Debug("output", "dir", outDir) @@ -110,7 +110,11 @@ func build(ioConfig *IOConfig, config *config.Config) (*Result, error) { return nil, errors.WithMessage(err, "could not create post output directory") } log.Debug("reading posts") - posts, tags, err := content.ReadPosts(joinSource("content"), "post", outDir) + posts, tags, err := content.ReadPosts(&content.Config{ + Root: joinSource("content"), + InputDir: "post", + OutputDir: outDir, + }, log.Named("content")) if err != nil { return nil, err } @@ -254,13 +258,9 @@ func build(ioConfig *IOConfig, config *config.Config) (*Result, error) { return r, nil } -func BuildSite(ioConfig *IOConfig, cfg *config.Config) (*Result, error) { +func BuildSite(ioConfig *IOConfig, cfg *config.Config, log *log.Logger) (*Result, error) { if cfg == nil { - var err error - cfg, err = config.GetConfig(ioConfig.Source) - if err != nil { - return nil, errors.WithMessage(err, "could not get config") - } + return nil, errors.New("config is nil") } cfg.InjectLiveReload = ioConfig.Development compressFiles = !ioConfig.Development @@ -268,5 +268,5 @@ func BuildSite(ioConfig *IOConfig, cfg *config.Config) (*Result, error) { templates.Setup() loadCSS(ioConfig.Source) - return build(ioConfig, cfg) + return build(ioConfig, cfg, log) } diff --git a/internal/config/config.go b/internal/config/config.go index 5e568cd..42e36d7 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -51,7 +51,7 @@ type Config struct { Menus map[string][]MenuItem } -func GetConfig(dir string) (*Config, error) { +func GetConfig(dir string, log *log.Logger) (*Config, error) { config := Config{} filename := filepath.Join(dir, "config.toml") log.Debug("reading config", "filename", filename) diff --git a/internal/content/posts.go b/internal/content/posts.go index 000cd98..dd14d1e 100644 --- a/internal/content/posts.go +++ b/internal/content/posts.go @@ -13,11 +13,11 @@ import ( "github.com/adrg/frontmatter" mapset "github.com/deckarep/golang-set/v2" - "gitlab.com/tozd/go/errors" fences "github.com/stefanfritsch/goldmark-fences" "github.com/yuin/goldmark" "github.com/yuin/goldmark/extension" htmlrenderer "github.com/yuin/goldmark/renderer/html" + "gitlab.com/tozd/go/errors" ) type PostMatter struct { @@ -80,16 +80,22 @@ func RenderMarkdown(content []byte) (string, error) { return buf.String(), nil } -func ReadPosts(root string, inputDir string, outputDir string) ([]Post, Tags, error) { +type Config struct { + Root string + InputDir string + OutputDir string +} + +func ReadPosts(config *Config, log *log.Logger) ([]Post, Tags, error) { tags := mapset.NewSet[string]() posts := []Post{} - subdir := filepath.Join(root, inputDir) + subdir := filepath.Join(config.Root, config.InputDir) files, err := os.ReadDir(subdir) if err != nil { return nil, nil, errors.WithMessagef(err, "could not read post directory %s", subdir) } - outputReplacer := strings.NewReplacer(root, outputDir, ".md", "/index.html") - urlReplacer := strings.NewReplacer(root, "", ".md", "/") + outputReplacer := strings.NewReplacer(config.Root, config.OutputDir, ".md", "/index.html") + urlReplacer := strings.NewReplacer(config.Root, "", ".md", "/") for _, f := range files { pathFromRoot := filepath.Join(subdir, f.Name()) if !f.IsDir() && path.Ext(pathFromRoot) == ".md" { diff --git a/internal/listenfd/listenfd.go b/internal/listenfd/listenfd.go index 4e8c007..8c723eb 100644 --- a/internal/listenfd/listenfd.go +++ b/internal/listenfd/listenfd.go @@ -13,7 +13,7 @@ import ( const fdStart = 3 -func GetListener(i uint64, addr string) (l net.Listener, err error) { +func GetListener(i uint64, addr string, log *log.Logger) (l net.Listener, err error) { l, err = getFDSocket(i) if err != nil { log.Warn("could not create listener from listenfd", "error", err) @@ -30,8 +30,13 @@ func GetListener(i uint64, addr string) (l net.Listener, err error) { return } -func GetListenerTLS(i uint64, addr string, config *tls.Config) (l net.Listener, err error) { - l, err = GetListener(i, addr) +func GetListenerTLS( + i uint64, + addr string, + config *tls.Config, + log *log.Logger, +) (l net.Listener, err error) { + l, err = GetListener(i, addr, log) if err != nil { return nil, err } diff --git a/internal/log/log.go b/internal/log/log.go index a0f5ba7..f644e6b 100644 --- a/internal/log/log.go +++ b/internal/log/log.go @@ -7,30 +7,43 @@ import ( prettyconsole "github.com/thessem/zap-prettyconsole" "go.uber.org/zap" "go.uber.org/zap/zapcore" + "moul.io/zapfilter" ) -var logger *zap.SugaredLogger +type Logger struct { + logger *zap.SugaredLogger +} -func DPanic(msg string, rest ...any) { - logger.DPanicw(msg, rest...) +func (l Logger) DPanic(msg string, rest ...any) { + l.logger.DPanicw(msg, rest...) } -func Debug(msg string, rest ...any) { - logger.Debugw(msg, rest...) +func (l Logger) Debug(msg string, rest ...any) { + l.logger.Debugw(msg, rest...) } -func Info(msg string, rest ...any) { - logger.Infow(msg, rest...) +func (l Logger) Info(msg string, rest ...any) { + l.logger.Infow(msg, rest...) } -func Warn(msg string, rest ...any) { - logger.Warnw(msg, rest...) +func (l Logger) Warn(msg string, rest ...any) { + l.logger.Warnw(msg, rest...) } -func Error(msg string, rest ...any) { - logger.Errorw(msg, rest...) +func (l Logger) Error(msg string, rest ...any) { + l.logger.Errorw(msg, rest...) } -func Panic(msg string, rest ...any) { - logger.Panicw(msg, rest...) +func (l Logger) Panic(msg string, rest ...any) { + l.logger.Panicw(msg, rest...) } -func Fatal(msg string, rest ...any) { - logger.Fatalw(msg, rest...) +func (l Logger) Fatal(msg string, rest ...any) { + l.logger.Fatalw(msg, rest...) +} + +func (l Logger) Named(name string) *Logger { + return &Logger{ + logger: l.logger.Named(name), + } +} + +func (l Logger) GetLogger() *zap.Logger { + return l.logger.Desugar() } func getLevelFromEnv() (zapcore.Level, error) { @@ -43,7 +56,7 @@ func getLevelFromEnv() (zapcore.Level, error) { return zap.InfoLevel, nil } -func Configure(isProduction bool) { +func Configure(isProduction bool) *Logger { var l *zap.Logger level, err := getLevelFromEnv() if err != nil { @@ -54,10 +67,21 @@ func Configure(isProduction bool) { cfg.TimeKey = "" l = zap.New(zapcore.NewCore(zaplogfmt.NewEncoder(cfg), os.Stderr, level)) } else { - cfg := prettyconsole.NewConfig() - cfg.EncoderConfig.TimeKey = "" - cfg.Level.SetLevel(level) - l = zap.Must(cfg.Build()) + cfg := prettyconsole.NewEncoderConfig() + cfg.TimeKey = "" + var filter zapfilter.FilterFunc + if debug := os.Getenv("DEBUG"); debug != "" { + filter = zapfilter.Any(zapfilter.MinimumLevel(level), zapfilter.ByNamespaces(debug)) + } else { + filter = zapfilter.MinimumLevel(level) + } + l = zap.New(zapfilter.NewFilteringCore( + zapcore.NewCore(prettyconsole.NewEncoder(cfg), os.Stderr, zap.DebugLevel), + filter, + )) + } + + return &Logger{ + logger: l.WithOptions(zap.AddCallerSkip(1)).Sugar(), } - logger = l.WithOptions(zap.AddCallerSkip(1)).Sugar() } diff --git a/internal/server/dev.go b/internal/server/dev.go index e83201a..4db9465 100644 --- a/internal/server/dev.go +++ b/internal/server/dev.go @@ -3,7 +3,6 @@ package server import ( "fmt" "io/fs" - "log/slog" "os" "path" "path/filepath" @@ -21,6 +20,7 @@ type FileWatcher struct { } var ( + l *log.Logger ignores = []string{ "*.templ", "*.go", @@ -32,7 +32,7 @@ func matches(name string) func(string) bool { return func(pattern string) bool { matched, err := path.Match(pattern, name) if err != nil { - log.Warn("error checking watcher ignores", "error", err) + l.Warn("error checking watcher ignores", "error", err) } return matched @@ -43,23 +43,24 @@ func ignored(pathname string) bool { return slices.ContainsFunc(ignores, matches(path.Base(pathname))) } -func NewFileWatcher() (*FileWatcher, error) { +func NewFileWatcher(log *log.Logger) (*FileWatcher, error) { watcher, err := fsnotify.NewWatcher() if err != nil { return nil, errors.WithMessage(err, "could not create watcher") } + l = log return &FileWatcher{watcher}, nil } func (watcher FileWatcher) AddRecursive(from string) error { - log.Debug("walking directory tree", "root", from) + l.Debug("walking directory tree", "root", from) err := filepath.WalkDir(from, func(path string, entry fs.DirEntry, err error) error { if err != nil { return errors.WithMessagef(err, "could not walk directory %s", path) } if entry.IsDir() { - log.Debug("adding directory to watcher", "path", path) + l.Debug("adding directory to watcher", "path", path) if err = watcher.Add(path); err != nil { return errors.WithMessagef(err, "could not add directory %s to watcher", path) } @@ -77,17 +78,17 @@ func (watcher FileWatcher) Start(callback func(string)) { select { case event := <-watcher.Events: if !ignored(event.Name) { - log.Debug("watcher event", "name", event.Name, "op", event.Op.String()) + l.Debug("watcher event", "name", event.Name, "op", event.Op.String()) if event.Has(fsnotify.Create) || event.Has(fsnotify.Rename) { f, err := os.Stat(event.Name) if err != nil { - slog.Error( + l.Error( fmt.Sprintf("error handling %s event: %v", event.Op.String(), err), ) } else if f.IsDir() { err = watcher.Add(event.Name) if err != nil { - slog.Error(fmt.Sprintf("error adding new folder to watcher: %v", err)) + l.Error(fmt.Sprintf("error adding new folder to watcher: %v", err)) } } } @@ -102,7 +103,7 @@ func (watcher FileWatcher) Start(callback func(string)) { } } case err := <-watcher.Errors: - slog.Error(fmt.Sprintf("error in watcher: %v", err)) + l.Error("error in watcher", "error", err) } } } diff --git a/internal/server/logging.go b/internal/server/logging.go index 20f0a92..6393099 100644 --- a/internal/server/logging.go +++ b/internal/server/logging.go @@ -23,7 +23,7 @@ func NewLoggingResponseWriter(w http.ResponseWriter) *LoggingResponseWriter { return &LoggingResponseWriter{w, http.StatusOK} } -func wrapHandlerWithLogging(wrappedHandler http.Handler) http.Handler { +func wrapHandlerWithLogging(wrappedHandler http.Handler, log *log.Logger) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { lw := NewLoggingResponseWriter(w) wrappedHandler.ServeHTTP(lw, r) diff --git a/internal/server/mime.go b/internal/server/mime.go index 3a1ec8a..340e4c5 100644 --- a/internal/server/mime.go +++ b/internal/server/mime.go @@ -10,14 +10,10 @@ var newMIMEs = map[string]string{ ".xsl": "text/xsl", } -func fixupMIMETypes() { +func fixupMIMETypes(log *log.Logger) { for ext, newType := range newMIMEs { if err := mime.AddExtensionType(ext, newType); err != nil { log.Error("could not update mime type", "ext", ext, "mime", newType) } } } - -func init() { - fixupMIMETypes() -} diff --git a/internal/server/server.go b/internal/server/server.go index dfb0f8c..f01f939 100644 --- a/internal/server/server.go +++ b/internal/server/server.go @@ -49,6 +49,7 @@ type Server struct { redirectServer *http.Server runtimeConfig *Config config *cfg.Config + log *log.Logger } func applyDevModeOverrides(config *cfg.Config, runtimeConfig *Config) { @@ -87,8 +88,8 @@ func serverHeaderHandler(wrappedHandler http.Handler) http.Handler { }) } -func rebuild(builderConfig *builder.IOConfig, config *cfg.Config) error { - r, err := builder.BuildSite(builderConfig, config) +func rebuild(builderConfig *builder.IOConfig, config *cfg.Config, log *log.Logger) error { + r, err := builder.BuildSite(builderConfig, config, log.Named("builder")) if err != nil { return errors.WithMessage(err, "could not build site") } @@ -97,7 +98,7 @@ func rebuild(builderConfig *builder.IOConfig, config *cfg.Config) error { return nil } -func New(runtimeConfig *Config) (*Server, error) { +func New(runtimeConfig *Config, log *log.Logger) (*Server, error) { builderConfig := &builder.IOConfig{ Destination: runtimeConfig.Root, Development: runtimeConfig.Development, @@ -109,7 +110,7 @@ func New(runtimeConfig *Config) (*Server, error) { if err != nil { return nil, err } - _, err = vcs.CloneOrUpdate(vcsConfig) + _, err = vcs.CloneOrUpdate(vcsConfig, log.Named("vcs")) if err != nil { return nil, err } @@ -125,7 +126,7 @@ func New(runtimeConfig *Config) (*Server, error) { runtimeConfig.Root = publicDir } - config, err := cfg.GetConfig(builderConfig.Source) + config, err := cfg.GetConfig(builderConfig.Source, log.Named("config")) if err != nil { return nil, errors.WithMessage(err, "error parsing configuration file") } @@ -136,16 +137,18 @@ func New(runtimeConfig *Config) (*Server, error) { listenAddress := net.JoinHostPort(runtimeConfig.ListenAddress, strconv.Itoa(runtimeConfig.Port)) top := http.NewServeMux() - err = rebuild(builderConfig, config) + err = rebuild(builderConfig, config, log) if err != nil { return nil, err } + fixupMIMETypes(log) + if runtimeConfig.Development { liveReload := livereload.New() top.Handle("/_/reload", liveReload) liveReload.Start() - fw, err := NewFileWatcher() + fw, err := NewFileWatcher(log.Named("watcher")) if err != nil { return nil, errors.WithMessage(err, "could not create file watcher") } @@ -165,7 +168,7 @@ func New(runtimeConfig *Config) (*Server, error) { } go fw.Start(func(filename string) { log.Info("rebuilding site", "changed_file", filename) - err := rebuild(builderConfig, config) + err := rebuild(builderConfig, config, log) if err != nil { log.Error("error rebuilding site", "error", err) } @@ -173,7 +176,7 @@ func New(runtimeConfig *Config) (*Server, error) { } loggingMux := http.NewServeMux() - mux, err := website.NewMux(config, runtimeConfig.Root) + mux, err := website.NewMux(config, runtimeConfig.Root, log.Named("website")) if err != nil { return nil, errors.Wrap(err, "could not create website mux") } @@ -193,7 +196,7 @@ func New(runtimeConfig *Config) (*Server, error) { top.Handle("/", serverHeaderHandler( - wrapHandlerWithLogging(loggingMux), + wrapHandlerWithLogging(loggingMux, log), ), ) @@ -218,6 +221,7 @@ func New(runtimeConfig *Config) (*Server, error) { Addr: listenAddress, Handler: rMux, }, + log: log, config: config, runtimeConfig: runtimeConfig, }, nil @@ -240,19 +244,19 @@ func (s *Server) Start() error { } func (s *Server) Stop() chan struct{} { - log.Debug("stop called") + s.log.Debug("stop called") idleConnsClosed := make(chan struct{}) go func() { - log.Debug("shutting down server") + s.log.Debug("shutting down server") ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) defer cancel() err := s.Server.Shutdown(ctx) - log.Debug("server shut down") + s.log.Debug("server shut down") if err != nil { // Error from closing listeners, or context timeout: - log.Warn("HTTP server Shutdown", "error", err) + s.log.Warn("HTTP server Shutdown", "error", err) } close(idleConnsClosed) }() diff --git a/internal/server/tcp.go b/internal/server/tcp.go index 4efde7d..12fdeb2 100644 --- a/internal/server/tcp.go +++ b/internal/server/tcp.go @@ -5,7 +5,7 @@ import ( ) func (s *Server) serveTCP() error { - l, err := listenfd.GetListener(0, s.Addr) + l, err := listenfd.GetListener(0, s.Addr, s.log.Named("tcp.listenfd")) if err != nil { return err } diff --git a/internal/server/tls.go b/internal/server/tls.go index 6c48f86..655455c 100644 --- a/internal/server/tls.go +++ b/internal/server/tls.go @@ -8,7 +8,6 @@ import ( "strconv" "go.alanpearce.eu/website/internal/listenfd" - "go.alanpearce.eu/website/internal/log" "github.com/ardanlabs/conf/v3" "github.com/caddyserver/caddy/v2" @@ -27,10 +26,10 @@ type redisConfig struct { func (s *Server) serveTLS() (err error) { var issuer *certmagic.ACMEIssuer + log := s.log.Named("tls") // setting cfg.Logger is too late somehow - certmagic.Default.Logger = log.GetLogger(). - Named("certmagic") + certmagic.Default.Logger = log.GetLogger().Named("certmagic") cfg := certmagic.NewDefault() cfg.DefaultServerName = s.config.Domains[0] @@ -97,6 +96,7 @@ func (s *Server) serveTLS() (err error) { ln, err := listenfd.GetListener( 1, net.JoinHostPort(s.runtimeConfig.ListenAddress, strconv.Itoa(s.runtimeConfig.Port)), + log.Named("listenfd"), ) if err != nil { return errors.Wrap(err, "could not bind plain socket") @@ -127,6 +127,7 @@ func (s *Server) serveTLS() (err error) { 0, net.JoinHostPort(s.runtimeConfig.ListenAddress, strconv.Itoa(s.runtimeConfig.TLSPort)), tlsConfig, + log.Named("listenfd"), ) if err != nil { return errors.Wrap(err, "could not bind tls socket") diff --git a/internal/vcs/repository.go b/internal/vcs/repository.go index 1dbf783..017b3d8 100644 --- a/internal/vcs/repository.go +++ b/internal/vcs/repository.go @@ -18,9 +18,10 @@ type Config struct { type Repository struct { repo *git.Repository + log *log.Logger } -func CloneOrUpdate(cfg *Config) (*Repository, error) { +func CloneOrUpdate(cfg *Config, log *log.Logger) (*Repository, error) { gr, err := git.PlainClone(cfg.LocalPath, false, &git.CloneOptions{ URL: cfg.RemoteURL.String(), Progress: os.Stdout, @@ -35,6 +36,7 @@ func CloneOrUpdate(cfg *Config) (*Repository, error) { } repo := &Repository{ repo: gr, + log: log, } _, err := repo.Update() if err != nil { @@ -46,18 +48,19 @@ func CloneOrUpdate(cfg *Config) (*Repository, error) { return &Repository{ repo: gr, + log: log, }, nil } func (r *Repository) Update() (bool, error) { - log.Info("updating repository") + r.log.Info("updating repository") head, err := r.repo.Head() if err != nil { return false, err } - log.Info("updating from", "rev", head.Hash().String()) + r.log.Info("updating from", "rev", head.Hash().String()) wt, err := r.repo.Worktree() if err != nil { return false, err @@ -68,7 +71,7 @@ func (r *Repository) Update() (bool, error) { }) if err != nil { if errors.Is(err, git.NoErrAlreadyUpToDate) { - log.Info("already up-to-date") + r.log.Info("already up-to-date") return true, nil } @@ -80,7 +83,7 @@ func (r *Repository) Update() (bool, error) { if err != nil { return false, err } - log.Info("updated to", "rev", head.Hash().String()) + r.log.Info("updated to", "rev", head.Hash().String()) return true, r.Clean(wt) } diff --git a/internal/website/filemap.go b/internal/website/filemap.go index 21cd28a..f9ce462 100644 --- a/internal/website/filemap.go +++ b/internal/website/filemap.go @@ -79,7 +79,7 @@ func registerFile(urlpath string, fp string) error { return nil } -func registerContentFiles(root string) error { +func registerContentFiles(root string, log *log.Logger) error { err := filepath.WalkDir(root, func(filePath string, f fs.DirEntry, err error) error { if err != nil { return errors.WithMessagef(err, "failed to access path %s", filePath) diff --git a/internal/website/mux.go b/internal/website/mux.go index c6992df..ebdf2d0 100644 --- a/internal/website/mux.go +++ b/internal/website/mux.go @@ -31,12 +31,14 @@ type webHandler func(http.ResponseWriter, *http.Request) *ihttp.Error type WrappedWebHandler struct { config *config.Config handler webHandler + log *log.Logger } -func wrapHandler(cfg *config.Config, webHandler webHandler) WrappedWebHandler { +func wrapHandler(cfg *config.Config, webHandler webHandler, log *log.Logger) WrappedWebHandler { return WrappedWebHandler{ config: cfg, handler: webHandler, + log: log, } } @@ -44,7 +46,7 @@ func (fn WrappedWebHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { defer func() { if fail := recover(); fail != nil { w.WriteHeader(http.StatusInternalServerError) - log.Error("runtime panic!", "error", fail) + fn.log.Error("runtime panic!", "error", fail) } }() if err := fn.handler(w, r); err != nil { @@ -60,11 +62,11 @@ func (fn WrappedWebHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { } } -func NewMux(cfg *config.Config, root string) (mux *http.ServeMux, err error) { +func NewMux(cfg *config.Config, root string, log *log.Logger) (mux *http.ServeMux, err error) { mux = &http.ServeMux{} log.Debug("registering content files", "root", root) - err = registerContentFiles(root) + err = registerContentFiles(root, log) if err != nil { return nil, errors.WithMessagef(err, "registering content files") } @@ -99,7 +101,7 @@ func NewMux(cfg *config.Config, root string) (mux *http.ServeMux, err error) { http.ServeFile(w, r, files[urlPath].alternatives[enc]) return nil - })) + }, log)) var acctResource = "acct:" + cfg.Email me := digit.NewResource(acctResource). -- cgit 1.4.1