diff --git a/internal/middleware/logfmt.go b/internal/middleware/logfmt.go new file mode 100644 index 0000000..2e0c221 --- /dev/null +++ b/internal/middleware/logfmt.go @@ -0,0 +1,130 @@ +package middleware + +import ( + "io" + "log/slog" + "net/http" + "os" + "strings" + "sync/atomic" + "time" +) + +type ( + LogFmtConfig struct { + // Skipper defines a function to skip middleware. + Skipper Skipper + + // Output is a writer where logs in JSON format are written. + // Optional. Default value os.Stdout. + Output io.Writer + } + + logFmtResponse struct { + http.ResponseWriter + error error + start time.Time + end time.Time + statusCode int + responseLength int + id uint64 + } +) + +//nolint:gochecknoglobals // default configuration +var DefaultLogFmtConfig = LogFmtConfig{ + Skipper: DefaultSkipper, + Output: os.Stdout, +} + +//nolint:gochecknoglobals +var globalConnID uint64 + +func LogFmt() Interceptor { + c := DefaultLogFmtConfig + + return LogFmtWithConfig(c) +} + +func LogFmtWithConfig(config LogFmtConfig) Interceptor { + if config.Skipper == nil { + config.Skipper = DefaultLogFmtConfig.Skipper + } + + if config.Output == nil { + config.Output = DefaultLogFmtConfig.Output + } + + encoder := slog.New(slog.NewTextHandler(config.Output, nil)) + + return func(w http.ResponseWriter, r *http.Request, next http.HandlerFunc) { + tx := &logFmtResponse{ + id: nextConnID(), + responseLength: 0, + ResponseWriter: w, + start: time.Now().UTC(), + statusCode: 0, + } + + next(tx, r) + + tx.end = time.Now().UTC() + payload := []any{ + slog.Int64("bytes_in", r.ContentLength), + slog.Int("bytes_out", tx.responseLength), + slog.Any("error", tx.error), + slog.String("host", r.Host), + slog.Uint64("id", tx.id), + slog.Int64("latency", tx.end.Sub(tx.start).Nanoseconds()), + slog.String("latency_human", tx.end.Sub(tx.start).String()), + slog.String("method", r.Method), + slog.String("path", r.URL.Path), + slog.String("protocol", r.Proto), + slog.String("referer", r.Referer()), + slog.String("remote_ip", r.RemoteAddr), + slog.Int("status", tx.statusCode), + slog.String("time_rfc3339", tx.start.Format(time.RFC3339)), + slog.String("time_rfc3339_nano", tx.start.Format(time.RFC3339Nano)), + slog.Int64("time_unix", tx.start.Unix()), + slog.Int64("time_unix_nano", tx.start.UnixNano()), + slog.String("uri", r.RequestURI), + slog.String("user_agent", r.UserAgent()), + } + + for name, src := range map[string]map[string][]string{ + "form": r.PostForm, + "header": r.Header, + "query": r.URL.Query(), + } { + values := make([]any, 0) + + for k, v := range src { + values = append(values, slog.String(strings.ReplaceAll(strings.ToLower(k), " ", "_"), + strings.Join(v, " "))) + } + + payload = append(payload, slog.Group(name, values...)) + } + + encoder.Log(r.Context(), slog.LevelInfo, "" /* msg */, payload...) + } +} + +func (r *logFmtResponse) WriteHeader(status int) { + r.statusCode = status + + r.ResponseWriter.WriteHeader(status) +} + +func (r *logFmtResponse) Write(src []byte) (int, error) { + var length int + + length, r.error = r.ResponseWriter.Write(src) + r.responseLength += length + + return length, r.error +} + +func nextConnID() uint64 { + return atomic.AddUint64(&globalConnID, 1) +} diff --git a/main.go b/main.go index cfc391a..e92e784 100644 --- a/main.go +++ b/main.go @@ -28,6 +28,7 @@ import ( "source.toby3d.me/toby3d/home/internal/common" "source.toby3d.me/toby3d/home/internal/domain" + "source.toby3d.me/toby3d/home/internal/middleware" "source.toby3d.me/toby3d/home/internal/page" pagefsrepo "source.toby3d.me/toby3d/home/internal/page/repository/fs" pageucase "source.toby3d.me/toby3d/home/internal/page/usecase" @@ -81,118 +82,119 @@ func NewApp(ctx context.Context, config *domain.Config) (*App, error) { themer := themeucase.NewThemeUseCase(themes) pages := pagefsrepo.NewFileSystemPageRepository(contentDir) pager := pageucase.NewPageUseCase(pages, resources) + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + // TODO(toby3d): use exists static use case or split that on static and resource modules? + // INFO(toby3d): any static file is public and unprotected by design, so it's safe to search it + // first before deep down to any page or it's resource which might be secured by middleware or + // something else. + static, err := staticer.Do(r.Context(), strings.TrimPrefix(r.URL.Path, "/")) + if err == nil { + http.ServeContent(w, r, static.Name(), domain.ResourceModTime(static), static) + return + } + + lang := domain.LanguageUnd + + s, err := siter.Do(r.Context(), lang) + if err != nil { + http.Error(w, err.Error(), http.StatusInternalServerError) + + return + } + + if s.IsMultiLingual() { + head, tail := urlutil.ShiftPath(r.URL.Path) + + if head == "" { + supported := make([]language.Tag, len(s.Languages)) + for i := range s.Languages { + supported[i] = language.Make(s.Languages[i].Lang()) + } + + if s.DefaultLanguage != domain.LanguageUnd { + supported = append( + []language.Tag{language.Make(s.DefaultLanguage.Code())}, + supported..., + ) + } + + requested, _, err := language.ParseAcceptLanguage( + r.Header.Get(common.HeaderAcceptLanguage)) + if err != nil || len(requested) == 0 { + requested = append(requested, language.English) + } + + matched, _, _ := language.NewMatcher(supported).Match(requested...) + lang = domain.NewLanguage(matched.String()) + + http.Redirect(w, r, "/"+lang.Lang()+"/", http.StatusSeeOther) + + return + } + + lang = domain.NewLanguage(head) + r.URL.Path = tail + } + + if s, err = siter.Do(r.Context(), lang); err != nil { + http.Error(w, err.Error(), http.StatusInternalServerError) + + return + } + + p, err := pager.Do(r.Context(), lang, r.URL.Path) + if err != nil { + if !errors.Is(err, page.ErrNotExist) { + http.Error(w, err.Error(), http.StatusInternalServerError) + + return + } + + res, err := resourcer.Do(r.Context(), r.URL.Path) + if err != nil { + if errors.Is(err, fs.ErrNotExist) { + http.Error(w, err.Error(), http.StatusNotFound) + + return + } + + http.Error(w, err.Error(), http.StatusInternalServerError) + + return + } + + http.ServeContent(w, r, res.Name(), domain.ResourceModTime(res), res) + + return + } + + contentLanguage := make([]string, len(p.Translations)) + for i := range p.Translations { + contentLanguage[i] = p.Translations[i].Language.Code() + } + + w.Header().Set(common.HeaderContentLanguage, strings.Join(contentLanguage, ", ")) + + tpl, err := themer.Do(r.Context()) + if err != nil { + http.Error(w, err.Error(), http.StatusInternalServerError) + + return + } + + w.Header().Set(common.HeaderContentType, common.MIMETextHTMLCharsetUTF8) + if err = tpl.Execute(w, &Context{ + Site: s, + Page: p, + }); err != nil { + http.Error(w, err.Error(), http.StatusInternalServerError) + } + }) + chain := middleware.Chain{middleware.LogFmt()} server := &http.Server{ - Addr: config.AddrPort().String(), - Handler: http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - // TODO(toby3d): use exists static use case or split that on static and resource modules? - // INFO(toby3d): any static file is public and unprotected by design, so it's safe to search it - // first before deep down to any page or it's resource which might be secured by middleware or - // something else. - static, err := staticer.Do(r.Context(), strings.TrimPrefix(r.URL.Path, "/")) - if err == nil { - http.ServeContent(w, r, static.Name(), domain.ResourceModTime(static), static) - - return - } - - lang := domain.LanguageUnd - - s, err := siter.Do(r.Context(), lang) - if err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - - return - } - - if s.IsMultiLingual() { - head, tail := urlutil.ShiftPath(r.URL.Path) - - if head == "" { - supported := make([]language.Tag, len(s.Languages)) - for i := range s.Languages { - supported[i] = language.Make(s.Languages[i].Lang()) - } - - if s.DefaultLanguage != domain.LanguageUnd { - supported = append( - []language.Tag{language.Make(s.DefaultLanguage.Code())}, - supported..., - ) - } - - requested, _, err := language.ParseAcceptLanguage( - r.Header.Get(common.HeaderAcceptLanguage)) - if err != nil || len(requested) == 0 { - requested = append(requested, language.English) - } - - matched, _, _ := language.NewMatcher(supported).Match(requested...) - lang = domain.NewLanguage(matched.String()) - - http.Redirect(w, r, "/"+lang.Lang()+"/", http.StatusSeeOther) - - return - } - - lang = domain.NewLanguage(head) - r.URL.Path = tail - } - - if s, err = siter.Do(r.Context(), lang); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - - return - } - - p, err := pager.Do(r.Context(), lang, r.URL.Path) - if err != nil { - if !errors.Is(err, page.ErrNotExist) { - http.Error(w, err.Error(), http.StatusInternalServerError) - - return - } - - res, err := resourcer.Do(r.Context(), r.URL.Path) - if err != nil { - if errors.Is(err, fs.ErrNotExist) { - http.Error(w, err.Error(), http.StatusNotFound) - - return - } - - http.Error(w, err.Error(), http.StatusInternalServerError) - - return - } - - http.ServeContent(w, r, res.Name(), domain.ResourceModTime(res), res) - - return - } - - contentLanguage := make([]string, len(p.Translations)) - for i := range p.Translations { - contentLanguage[i] = p.Translations[i].Language.Code() - } - - w.Header().Set(common.HeaderContentLanguage, strings.Join(contentLanguage, ", ")) - - tpl, err := themer.Do(r.Context()) - if err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - - return - } - - w.Header().Set(common.HeaderContentType, common.MIMETextHTMLCharsetUTF8) - if err = tpl.Execute(w, &Context{ - Site: s, - Page: p, - }); err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - } - }), + Addr: config.AddrPort().String(), + Handler: chain.Handler(handler), ErrorLog: logger, BaseContext: func(ln net.Listener) context.Context { return ctx }, WriteTimeout: 500 * time.Millisecond,