From fb5726bd202e40a3de9e113d290e8ffb7100396a Mon Sep 17 00:00:00 2001 From: 6543 <6543@obermui.de> Date: Sun, 5 Dec 2021 14:43:51 +0100 Subject: [PATCH] use zerolog instead of own logger --- debug-stepper/stepper.go | 68 ---------------------------------------- go.mod | 1 + go.sum | 10 ++++++ handler.go | 67 +++++++++++++++++++-------------------- 4 files changed, 44 insertions(+), 102 deletions(-) delete mode 100644 debug-stepper/stepper.go diff --git a/debug-stepper/stepper.go b/debug-stepper/stepper.go deleted file mode 100644 index 05506b6..0000000 --- a/debug-stepper/stepper.go +++ /dev/null @@ -1,68 +0,0 @@ -package debug_stepper - -import ( - "fmt" - "os" - "strings" - "time" -) - -var Enabled = strings.HasSuffix(os.Args[0], ".test") || os.Getenv("DEBUG") == "1" - -var Logger = func(s string, i ...interface{}) { - fmt.Printf(s, i...) -} - -type Stepper struct { - Name string - Start time.Time - LastStep time.Time - Completion time.Time -} - -func Start(name string) *Stepper { - if !Enabled { - return nil - } - t := time.Now() - Logger("%s: started at %s\n", name, t.Format(time.RFC3339)) - return &Stepper{ - Name: name, - Start: t, - LastStep: t, - } -} - -func (s *Stepper) Debug(text string) { - if !Enabled { - return - } - t := time.Now() - Logger("%s: %s (at %s, %s since last step, %s since start)\n", s.Name, text, t.Format(time.RFC3339), t.Sub(s.LastStep).String(), t.Sub(s.Start).String()) -} - -func (s *Stepper) Step(description string) { - if !Enabled { - return - } - if s.Completion != (time.Time{}) { - Logger("%s: already completed all tasks.\n") - return - } - t := time.Now() - Logger("%s: completed %s at %s (%s)\n", s.Name, description, t.Format(time.RFC3339), t.Sub(s.LastStep).String()) - s.LastStep = t -} - -func (s *Stepper) Complete() { - if !Enabled { - return - } - if s.Completion != (time.Time{}) { - Logger("%s: already completed all tasks.\n") - return - } - t := time.Now() - Logger("%s: completed all tasks at %s (%s since last step; total time: %s)\n", s.Name, t.Format(time.RFC3339), t.Sub(s.LastStep).String(), t.Sub(s.Start).String()) - s.Completion = t -} diff --git a/go.mod b/go.mod index fd52ef1..7a64921 100644 --- a/go.mod +++ b/go.mod @@ -7,6 +7,7 @@ require ( github.com/akrylysov/pogreb v0.10.1 github.com/go-acme/lego/v4 v4.5.3 github.com/reugn/equalizer v0.0.0-20210216135016-a959c509d7ad + github.com/rs/zerolog v1.26.0 // indirect github.com/valyala/fasthttp v1.31.0 github.com/valyala/fastjson v1.6.3 ) diff --git a/go.sum b/go.sum index c93f985..8561c5c 100644 --- a/go.sum +++ b/go.sum @@ -95,6 +95,7 @@ github.com/coreos/bbolt v1.3.2/go.mod h1:iRUV2dpdMOn7Bo10OQBFzIJO9kkE559Wcmn+qkE github.com/coreos/etcd v3.3.13+incompatible/go.mod h1:uF7uidLiAD3TWHmW31ZFd/JWoc32PjwdhPthX9715RE= github.com/coreos/go-semver v0.3.0/go.mod h1:nnelYz7RCh+5ahJtPPxZlU+153eP4D4r3EedlOD2RNk= github.com/coreos/go-systemd v0.0.0-20190321100706-95778dfbb74e/go.mod h1:F5haX7vjVVG0kc13fIWeqUViNPyEJxv/OmvnBo0Yme4= +github.com/coreos/go-systemd/v22 v22.3.2/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/coreos/pkg v0.0.0-20180928190104-399ea9e2e55f/go.mod h1:E3G3o1h8I7cfcXa63jLwjI0eiQQMgzzUDFVpN/nH/eA= github.com/cpu/goacmedns v0.1.1 h1:DM3H2NiN2oam7QljgGY5ygy4yDXhK5Z4JUnqaugs2C4= github.com/cpu/goacmedns v0.1.1/go.mod h1:MuaouqEhPAHxsbqjgnck5zeghuwBP1dLnPoobeGqugQ= @@ -148,6 +149,7 @@ github.com/go-stack/stack v1.8.0/go.mod h1:v0f6uXyyMGvRgIKkXu+yp6POWl0qKG85gN/me github.com/go-task/slim-sprig v0.0.0-20210107165309-348f09dbbbc0/go.mod h1:fyg7847qk6SyHyPtNmDHnmrv/HOrqktSC+C9fM+CJOE= github.com/gobs/pretty v0.0.0-20180724170744-09732c25a95b h1:/vQ+oYKu+JoyaMPDsv5FzwuL2wwWBgBbtj/YLCi4LuA= github.com/gobs/pretty v0.0.0-20180724170744-09732c25a95b/go.mod h1:Xo4aNUOrJnVruqWQJBtW6+bTBDTniY8yZum5rF3b5jw= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= github.com/gofrs/uuid v3.2.0+incompatible h1:y12jRkkFxsd7GpqdSZ+/KCs/fJbqpEXSGd4+jfEaewE= github.com/gofrs/uuid v3.2.0+incompatible/go.mod h1:b2aQJv3Z4Fp6yNu3cdSllBxTCLRxnplIgP/c0N/04lM= github.com/gogo/protobuf v1.1.1/go.mod h1:r8qH/GZQm5c6nD/R0oafs1akxWv10x8SbQlK7atdtwQ= @@ -422,6 +424,9 @@ github.com/reugn/equalizer v0.0.0-20210216135016-a959c509d7ad h1:WtSUHi5zthjudjI github.com/reugn/equalizer v0.0.0-20210216135016-a959c509d7ad/go.mod h1:h0+DiDRe2Y+6iHTjIq/9HzUq7NII/Nffp0HkFrsAKq4= github.com/rogpeppe/fastuuid v0.0.0-20150106093220-6724a57986af/go.mod h1:XWv6SoW27p1b0cqNHllgS5HIMJraePCO15w5zCzIWYg= github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4= +github.com/rs/xid v1.3.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.26.0 h1:ORM4ibhEZeTeQlCojCK2kPz1ogAY4bGs4tD+SaAdGaE= +github.com/rs/zerolog v1.26.0/go.mod h1:yBiM87lvSqX8h0Ww4sdzNSkVYZ8dL2xjZJG1lAuGZEo= github.com/russross/blackfriday/v2 v2.0.1/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= github.com/ryanuber/columnize v0.0.0-20160712163229-9b3edd62028f/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts= github.com/sacloud/libsacloud v1.36.2 h1:aosI7clbQ9IU0Hj+3rpk3SKJop5nLPpLThnWCivPqjI= @@ -499,6 +504,7 @@ github.com/xeipuuv/gojsonschema v1.2.0/go.mod h1:anYRn/JVcOK2ZgGU+IjEV4nwlhoK5sQ github.com/xiang90/probing v0.0.0-20190116061207-43a291ad63a2/go.mod h1:UETIi67q53MR2AWcXfiuqkDkRtnGDLqkBTpCHuJHxtU= github.com/yuin/goldmark v1.1.27/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= github.com/yuin/goldmark v1.2.1/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74= +github.com/yuin/goldmark v1.4.0/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k= go.etcd.io/bbolt v1.3.2/go.mod h1:IbVyRI1SCnLcuJnV2u8VeU0CEYM7e686BmAb1XKL+uU= go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU= go.opencensus.io v0.22.0/go.mod h1:+kGneAE2xo2IficOXnaByMWTGM9T73dGwxeWcUqIpI8= @@ -557,6 +563,7 @@ golang.org/x/mod v0.1.1-0.20191105210325-c90efee705ee/go.mod h1:QqPTAvyqsEbceGzB golang.org/x/mod v0.1.1-0.20191107180719-034126e5016b/go.mod h1:QqPTAvyqsEbceGzBzNggFXnrqF1CaUcvgkdR5Ot7KZg= golang.org/x/mod v0.2.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= golang.org/x/mod v0.3.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= +golang.org/x/mod v0.4.2/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= golang.org/x/net v0.0.0-20180724234803-3673e40ba225/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20180826012351-8a410e7b638d/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20180906233101-161cd47e91fd/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= @@ -591,6 +598,7 @@ golang.org/x/net v0.0.0-20210428140749-89ef3d95e781/go.mod h1:OJAsFXCWl8Ukc7SiCT golang.org/x/net v0.0.0-20210510120150-4163338589ed/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y= golang.org/x/net v0.0.0-20210614182718-04defd469f4e h1:XpT3nA5TvE525Ne3hInMh6+GETgn27Zfm9dxsThnX2Q= golang.org/x/net v0.0.0-20210614182718-04defd469f4e/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y= +golang.org/x/net v0.0.0-20210805182204-aaa1db679c0d/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y= golang.org/x/oauth2 v0.0.0-20180821212333-d2e6202438be/go.mod h1:N/0e6XlmueqKjAGxoOufVs8QHGRruUQn6yWY3a++T0U= golang.org/x/oauth2 v0.0.0-20190226205417-e64efc72b421/go.mod h1:gOpvHmFTYa4IltrdGE7lF6nIHvwfUNPOp7c8zoXwtLw= golang.org/x/oauth2 v0.0.0-20190604053449-0f29369cfe45/go.mod h1:gOpvHmFTYa4IltrdGE7lF6nIHvwfUNPOp7c8zoXwtLw= @@ -655,6 +663,7 @@ golang.org/x/sys v0.0.0-20210423082822-04245dca01da/go.mod h1:h1NjWce9XRLGQEsW7w golang.org/x/sys v0.0.0-20210514084401-e8d321eab015/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1 h1:SrN+KX8Art/Sf4HNj6Zcz06G7VEz+7w9tdXTPOZ7+l4= golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210809222454-d867a43fc93e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/term v0.0.0-20201117132131-f5c789dd3221/go.mod h1:Nr5EML6q2oocZ2LXRh80K7BxOlk5/8JxuGnuhpl+muw= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= golang.org/x/text v0.0.0-20170915032832-14c0d48ead0c/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= @@ -708,6 +717,7 @@ golang.org/x/tools v0.0.0-20200224181240-023911ca70b2/go.mod h1:TB2adYChydJhpapK golang.org/x/tools v0.0.0-20200304193943-95d2e580d8eb/go.mod h1:o4KQGtdN14AW+yjsvvwRTJJuXz8XRtIHtEnmAXLyFUw= golang.org/x/tools v0.0.0-20200410194907-79a7a3126eef/go.mod h1:EkVYQZoAsY45+roYkvgYkIh4xh/qjgUK9TdY2XT94GE= golang.org/x/tools v0.0.0-20201224043029-2b0845dc783e/go.mod h1:emZCQorbCU4vsT4fOWvOPXz4eW1wZW4PmDk9uLelYpA= +golang.org/x/tools v0.1.7/go.mod h1:LGqMHiF4EqQNHR1JncWGqT5BVaXmza+X+BDGol+dOxo= golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= diff --git a/handler.go b/handler.go index 4e9efbf..55ae36d 100644 --- a/handler.go +++ b/handler.go @@ -2,23 +2,23 @@ package main import ( "bytes" - debug_stepper "codeberg.org/codeberg/pages/debug-stepper" "fmt" - "github.com/OrlovEvgeny/go-mcache" - "github.com/valyala/fasthttp" - "github.com/valyala/fastjson" "io" "mime" "path" "strconv" "strings" "time" + + "github.com/OrlovEvgeny/go-mcache" + "github.com/rs/zerolog/log" + "github.com/valyala/fasthttp" + "github.com/valyala/fastjson" ) // handler handles a single HTTP request to the web server. func handler(ctx *fasthttp.RequestCtx) { - s := debug_stepper.Start("handler") - defer s.Complete() + log := log.With().Str("handler", string(ctx.Request.Header.RequestURI())).Logger() ctx.Response.Header.Set("Server", "Codeberg Pages") @@ -129,11 +129,11 @@ func handler(ctx *fasthttp.RequestCtx) { } } - s.Step("preparations") + log.Debug().Msg("preparations") if RawDomain != nil && bytes.Equal(trimmedHost, RawDomain) { // Serve raw content from RawDomain - s.Debug("raw domain") + log.Debug().Msg("raw domain") targetOptions.TryIndexPages = false targetOptions.ForbiddenMimeTypes["text/html"] = struct{}{} @@ -150,30 +150,30 @@ func handler(ctx *fasthttp.RequestCtx) { // raw.codeberg.org/example/myrepo/@main/index.html if len(pathElements) > 2 && strings.HasPrefix(pathElements[2], "@") { - s.Step("raw domain preparations, now trying with specified branch") + log.Debug().Msg("raw domain preparations, now trying with specified branch") if tryBranch(targetRepo, pathElements[2][1:], pathElements[3:], string(GiteaRoot)+"/"+targetOwner+"/"+targetRepo+"/src/branch/%b/%p", ) { - s.Step("tryBranch, now trying upstream") + log.Debug().Msg("tryBranch, now trying upstream") tryUpstream() return } - s.Debug("missing branch") + log.Debug().Msg("missing branch") returnErrorPage(ctx, fasthttp.StatusFailedDependency) return } else { - s.Step("raw domain preparations, now trying with default branch") + log.Debug().Msg("raw domain preparations, now trying with default branch") tryBranch(targetRepo, "", pathElements[2:], string(GiteaRoot)+"/"+targetOwner+"/"+targetRepo+"/src/branch/%b/%p", ) - s.Step("tryBranch, now trying upstream") + log.Debug().Msg("tryBranch, now trying upstream") tryUpstream() return } } else if bytes.HasSuffix(trimmedHost, MainDomainSuffix) { // Serve pages from subdomains of MainDomainSuffix - s.Debug("main domain suffix") + log.Debug().Msg("main domain suffix") pathElements := strings.Split(string(bytes.Trim(ctx.Request.URI().Path(), "/")), "/") targetOwner = string(bytes.TrimSuffix(trimmedHost, MainDomainSuffix)) @@ -182,7 +182,7 @@ func handler(ctx *fasthttp.RequestCtx) { if targetOwner == "www" { // www.codeberg.page redirects to codeberg.page - ctx.Redirect("https://" + string(MainDomainSuffix[1:]) + string(ctx.Path()), fasthttp.StatusPermanentRedirect) + ctx.Redirect("https://"+string(MainDomainSuffix[1:])+string(ctx.Path()), fasthttp.StatusPermanentRedirect) return } @@ -195,11 +195,11 @@ func handler(ctx *fasthttp.RequestCtx) { return } - s.Step("main domain preparations, now trying with specified repo & branch") + log.Debug().Msg("main domain preparations, now trying with specified repo & branch") if tryBranch(pathElements[0], pathElements[1][1:], pathElements[2:], "/"+pathElements[0]+"/%p", ) { - s.Step("tryBranch, now trying upstream") + log.Debug().Msg("tryBranch, now trying upstream") tryUpstream() } else { returnErrorPage(ctx, fasthttp.StatusFailedDependency) @@ -210,9 +210,9 @@ func handler(ctx *fasthttp.RequestCtx) { // Check if the first directory is a branch for the "pages" repo // example.codeberg.page/@main/index.html if strings.HasPrefix(pathElements[0], "@") { - s.Step("main domain preparations, now trying with specified branch") + log.Debug().Msg("main domain preparations, now trying with specified branch") if tryBranch("pages", pathElements[0][1:], pathElements[1:], "/%p") { - s.Step("tryBranch, now trying upstream") + log.Debug().Msg("tryBranch, now trying upstream") tryUpstream() } else { returnErrorPage(ctx, fasthttp.StatusFailedDependency) @@ -223,18 +223,18 @@ func handler(ctx *fasthttp.RequestCtx) { // Check if the first directory is a repo with a "pages" branch // example.codeberg.page/myrepo/index.html // example.codeberg.page/pages/... is not allowed here. - s.Step("main domain preparations, now trying with specified repo") + log.Debug().Msg("main domain preparations, now trying with specified repo") if pathElements[0] != "pages" && tryBranch(pathElements[0], "pages", pathElements[1:], "") { - s.Step("tryBranch, now trying upstream") + log.Debug().Msg("tryBranch, now trying upstream") tryUpstream() return } // Try to use the "pages" repo on its default branch // example.codeberg.page/index.html - s.Step("main domain preparations, now trying with default repo/branch") + log.Debug().Msg("main domain preparations, now trying with default repo/branch") if tryBranch("pages", "", pathElements, "") { - s.Step("tryBranch, now trying upstream") + log.Debug().Msg("tryBranch, now trying upstream") tryUpstream() return } @@ -261,7 +261,7 @@ func handler(ctx *fasthttp.RequestCtx) { } // Try to use the given repo on the given branch or the default branch - s.Step("custom domain preparations, now trying with details from DNS") + log.Debug().Msg("custom domain preparations, now trying with details from DNS") if tryBranch(targetRepo, targetBranch, pathElements, canonicalLink) { canonicalDomain, valid := checkCanonicalDomain(targetOwner, targetRepo, targetBranch, trimmedHostStr) if !valid { @@ -279,7 +279,7 @@ func handler(ctx *fasthttp.RequestCtx) { } } - s.Step("tryBranch, now trying upstream") + log.Debug().Msg("tryBranch, now trying upstream") tryUpstream() return } else { @@ -380,9 +380,8 @@ var upstreamClient = fasthttp.Client{ } // upstream requests a file from the Gitea API at GiteaRoot and writes it to the request context. -func upstream(ctx *fasthttp.RequestCtx, targetOwner string, targetRepo string, targetBranch string, targetPath string, options *upstreamOptions) (final bool) { - s := debug_stepper.Start("upstream") - defer s.Complete() +func upstream(ctx *fasthttp.RequestCtx, targetOwner, targetRepo, targetBranch, targetPath string, options *upstreamOptions) (final bool) { + log := log.With().Strs("upstream", []string{targetOwner, targetRepo, targetBranch, targetPath}).Logger() if options.ForbiddenMimeTypes == nil { options.ForbiddenMimeTypes = map[string]struct{}{} @@ -412,7 +411,7 @@ func upstream(ctx *fasthttp.RequestCtx, targetOwner string, targetRepo string, t return true } } - s.Step("preparations") + log.Debug().Msg("preparations") // Make a GET request to the upstream URL uri := targetOwner + "/" + targetRepo + "/raw/" + targetBranch + "/" + targetPath @@ -429,7 +428,7 @@ func upstream(ctx *fasthttp.RequestCtx, targetOwner string, targetRepo string, t res.SetBodyStream(&strings.Reader{}, -1) err = upstreamClient.Do(req, res) } - s.Step("acquisition") + log.Debug().Msg("acquisition") // Handle errors if (res == nil && !cachedResponse.exists) || (res != nil && res.StatusCode() == fasthttp.StatusNotFound) { @@ -449,7 +448,7 @@ func upstream(ctx *fasthttp.RequestCtx, targetOwner string, targetRepo string, t // compatibility fix for GitHub Pages (/example → /example.html) optionsForIndexPages.AppendTrailingSlash = false optionsForIndexPages.RedirectIfExists = string(ctx.Request.URI().Path()) + ".html" - if upstream(ctx, targetOwner, targetRepo, targetBranch, targetPath + ".html", &optionsForIndexPages) { + if upstream(ctx, targetOwner, targetRepo, targetBranch, targetPath+".html", &optionsForIndexPages) { _ = fileResponseCache.Set(uri+"?timestamp="+strconv.FormatInt(options.BranchTimestamp.Unix(), 10), fileResponse{ exists: false, }, FileCacheTimeout) @@ -485,7 +484,7 @@ func upstream(ctx *fasthttp.RequestCtx, targetOwner string, targetRepo string, t ctx.Redirect(options.RedirectIfExists, fasthttp.StatusTemporaryRedirect) return true } - s.Step("error handling") + log.Debug().Msg("error handling") // Set the MIME type mimeType := mime.TypeByExtension(path.Ext(targetPath)) @@ -503,7 +502,7 @@ func upstream(ctx *fasthttp.RequestCtx, targetOwner string, targetRepo string, t ctx.Response.SetStatusCode(fasthttp.StatusOK) ctx.Response.Header.SetLastModified(options.BranchTimestamp) - s.Step("response preparations") + log.Debug().Msg("response preparations") // Write the response body to the original request var cacheBodyWriter bytes.Buffer @@ -522,7 +521,7 @@ func upstream(ctx *fasthttp.RequestCtx, targetOwner string, targetRepo string, t returnErrorPage(ctx, fasthttp.StatusInternalServerError) return true } - s.Step("response") + log.Debug().Msg("response") if res != nil && ctx.Err() == nil { cachedResponse.exists = true