diff --git a/.gitignore b/.gitignore index 3035107..66e7084 100644 --- a/.gitignore +++ b/.gitignore @@ -8,3 +8,4 @@ vendor/ pages certs.sqlite .bash_history +pkg/ diff --git a/flake.lock b/flake.lock index 1062fa4..1fdb364 100644 --- a/flake.lock +++ b/flake.lock @@ -20,8 +20,8 @@ "nixpkgs": { "locked": { "lastModified": 0, - "narHash": "sha256-UA56kDQSztRWbpsG9bK+jIGyZ0YZAcIsYAhXDHIr8zs=", - "path": "/nix/store/np3i3qi6hq6d1p5xr36cjmr0xwd2j289-source", + "narHash": "sha256-zUfNgGopg1+/xYRnFaI6PAhlF2JofdEG789CsKclYSw=", + "path": "/nix/store/0ijldwygklvrzinxx7scsxsvqhx0hqgz-source", "type": "path" }, "original": { diff --git a/go.mod b/go.mod index 4f1666f..1bc1de6 100644 --- a/go.mod +++ b/go.mod @@ -72,6 +72,7 @@ require ( github.com/gorilla/css v1.0.0 // indirect github.com/hashicorp/go-cleanhttp v0.5.1 // indirect github.com/hashicorp/go-retryablehttp v0.7.0 // indirect + github.com/hashicorp/go-uuid v1.0.3 // indirect github.com/hashicorp/go-version v1.6.0 // indirect github.com/iij/doapi v0.0.0-20190504054126-0bbf12d6d7df // indirect github.com/infobloxopen/infoblox-go-client v1.1.1 // indirect diff --git a/go.sum b/go.sum index 7c4b251..6aef8a6 100644 --- a/go.sum +++ b/go.sum @@ -317,6 +317,8 @@ github.com/hashicorp/go-syslog v1.0.0/go.mod h1:qPfqrKkXGihmCqbJM2mZgkZGvKG1dFdv github.com/hashicorp/go-uuid v1.0.0/go.mod h1:6SBZvOh/SIDV7/2o3Jml5SYk/TvGqwFJ/bN7x4byOro= github.com/hashicorp/go-uuid v1.0.1/go.mod h1:6SBZvOh/SIDV7/2o3Jml5SYk/TvGqwFJ/bN7x4byOro= github.com/hashicorp/go-uuid v1.0.2/go.mod h1:6SBZvOh/SIDV7/2o3Jml5SYk/TvGqwFJ/bN7x4byOro= +github.com/hashicorp/go-uuid v1.0.3 h1:2gKiV6YVmrJ1i2CKKa9obLvRieoRGviZFL26PcT/Co8= +github.com/hashicorp/go-uuid v1.0.3/go.mod h1:6SBZvOh/SIDV7/2o3Jml5SYk/TvGqwFJ/bN7x4byOro= github.com/hashicorp/go-version v1.2.0/go.mod h1:fltr4n8CU8Ke44wwGCBoEymUuxUHl09ZGVZPK5anwXA= github.com/hashicorp/go-version v1.6.0 h1:feTTfFNnjP967rlCxM/I9g701jU+RN74YKx2mOkIeek= github.com/hashicorp/go-version v1.6.0/go.mod h1:fltr4n8CU8Ke44wwGCBoEymUuxUHl09ZGVZPK5anwXA= diff --git a/server/certificates/certificates.go b/server/certificates/certificates.go index 062f721..aeb619f 100644 --- a/server/certificates/certificates.go +++ b/server/certificates/certificates.go @@ -16,9 +16,11 @@ import ( "github.com/go-acme/lego/v4/lego" "github.com/hashicorp/golang-lru/v2/expirable" "github.com/reugn/equalizer" + "github.com/rs/zerolog" "github.com/rs/zerolog/log" "codeberg.org/codeberg/pages/server/cache" + psContext "codeberg.org/codeberg/pages/server/context" "codeberg.org/codeberg/pages/server/database" dnsutils "codeberg.org/codeberg/pages/server/dns" "codeberg.org/codeberg/pages/server/gitea" @@ -43,7 +45,11 @@ func TLSConfig(mainDomainSuffix string, return &tls.Config{ // check DNS name & get certificate from Let's Encrypt GetCertificate: func(info *tls.ClientHelloInfo) (*tls.Certificate, error) { + ctx := psContext.New(nil, nil) + log := log.With().Str("ReqId", ctx.ReqId).Logger() + domain := strings.ToLower(strings.TrimSpace(info.ServerName)) + log.Debug().Str("domain", domain).Msg("start: get tls certificate") if len(domain) < 1 { return nil, errors.New("missing domain info via SNI (RFC 4366, Section 3.1)") } @@ -100,7 +106,7 @@ func TLSConfig(mainDomainSuffix string, TargetRepo: targetRepo, TargetBranch: targetBranch, } - _, valid := targetOpt.CheckCanonicalDomain(giteaClient, domain, mainDomainSuffix, canonicalDomainCache) + _, valid := targetOpt.CheckCanonicalDomain(ctx, giteaClient, domain, mainDomainSuffix, canonicalDomainCache) if !valid { // We shouldn't obtain a certificate when we cannot check if the // repository has specified this domain in the `.domains` file. @@ -116,7 +122,7 @@ func TLSConfig(mainDomainSuffix string, var tlsCertificate *tls.Certificate var err error - if tlsCertificate, err = acmeClient.retrieveCertFromDB(domain, mainDomainSuffix, false, certDB); err != nil { + if tlsCertificate, err = acmeClient.retrieveCertFromDB(log, domain, mainDomainSuffix, false, certDB); err != nil { if !errors.Is(err, database.ErrNotFound) { return nil, err } @@ -130,7 +136,7 @@ func TLSConfig(mainDomainSuffix string, return nil, fmt.Errorf("won't request certificate for %q", domain) } - tlsCertificate, err = acmeClient.obtainCert(acmeClient.legoClient, []string{domain}, nil, targetOwner, false, mainDomainSuffix, certDB) + tlsCertificate, err = acmeClient.obtainCert(log, acmeClient.legoClient, []string{domain}, nil, targetOwner, false, mainDomainSuffix, certDB) if err != nil { return nil, err } @@ -173,7 +179,7 @@ func (c *AcmeClient) checkUserLimit(user string) error { return nil } -func (c *AcmeClient) retrieveCertFromDB(sni, mainDomainSuffix string, useDnsProvider bool, certDB database.CertDB) (*tls.Certificate, error) { +func (c *AcmeClient) retrieveCertFromDB(log zerolog.Logger, sni, mainDomainSuffix string, useDnsProvider bool, certDB database.CertDB) (*tls.Certificate, error) { // parse certificate from database res, err := certDB.Get(sni) if err != nil { @@ -206,7 +212,7 @@ func (c *AcmeClient) retrieveCertFromDB(sni, mainDomainSuffix string, useDnsProv // TODO: make a queue ? go (func() { res.CSR = nil // acme client doesn't like CSR to be set - if _, err := c.obtainCert(c.legoClient, []string{sni}, res, "", useDnsProvider, mainDomainSuffix, certDB); err != nil { + if _, err := c.obtainCert(log, c.legoClient, []string{sni}, res, "", useDnsProvider, mainDomainSuffix, certDB); err != nil { log.Error().Msgf("Couldn't renew certificate for %s: %v", sni, err) } })() @@ -216,7 +222,7 @@ func (c *AcmeClient) retrieveCertFromDB(sni, mainDomainSuffix string, useDnsProv return &tlsCertificate, nil } -func (c *AcmeClient) obtainCert(acmeClient *lego.Client, domains []string, renew *certificate.Resource, user string, useDnsProvider bool, mainDomainSuffix string, keyDatabase database.CertDB) (*tls.Certificate, error) { +func (c *AcmeClient) obtainCert(log zerolog.Logger, acmeClient *lego.Client, domains []string, renew *certificate.Resource, user string, useDnsProvider bool, mainDomainSuffix string, keyDatabase database.CertDB) (*tls.Certificate, error) { name := strings.TrimPrefix(domains[0], "*") // lock to avoid simultaneous requests @@ -226,7 +232,7 @@ func (c *AcmeClient) obtainCert(acmeClient *lego.Client, domains []string, renew time.Sleep(100 * time.Millisecond) _, working = c.obtainLocks.Load(name) } - cert, err := c.retrieveCertFromDB(name, mainDomainSuffix, useDnsProvider, keyDatabase) + cert, err := c.retrieveCertFromDB(log, name, mainDomainSuffix, useDnsProvider, keyDatabase) if err != nil { return nil, fmt.Errorf("certificate failed in synchronous request: %w", err) } @@ -320,7 +326,7 @@ func (c *AcmeClient) obtainCert(acmeClient *lego.Client, domains []string, renew return &tlsCertificate, nil } -func SetupMainDomainCertificates(mainDomainSuffix string, acmeClient *AcmeClient, certDB database.CertDB) error { +func SetupMainDomainCertificates(log zerolog.Logger, mainDomainSuffix string, acmeClient *AcmeClient, certDB database.CertDB) error { // getting main cert before ACME account so that we can fail here without hitting rate limits mainCertBytes, err := certDB.Get(mainDomainSuffix) if err != nil && !errors.Is(err, database.ErrNotFound) { @@ -328,7 +334,7 @@ func SetupMainDomainCertificates(mainDomainSuffix string, acmeClient *AcmeClient } if mainCertBytes == nil { - _, err = acmeClient.obtainCert(acmeClient.dnsChallengerLegoClient, []string{"*" + mainDomainSuffix, mainDomainSuffix[1:]}, nil, "", true, mainDomainSuffix, certDB) + _, err = acmeClient.obtainCert(log, acmeClient.dnsChallengerLegoClient, []string{"*" + mainDomainSuffix, mainDomainSuffix[1:]}, nil, "", true, mainDomainSuffix, certDB) if err != nil { log.Error().Err(err).Msg("Couldn't renew main domain certificate, continuing with mock certs only") } @@ -337,7 +343,7 @@ func SetupMainDomainCertificates(mainDomainSuffix string, acmeClient *AcmeClient return nil } -func MaintainCertDB(ctx context.Context, interval time.Duration, acmeClient *AcmeClient, mainDomainSuffix string, certDB database.CertDB) { +func MaintainCertDB(log zerolog.Logger, ctx context.Context, interval time.Duration, acmeClient *AcmeClient, mainDomainSuffix string, certDB database.CertDB) { for { // delete expired certs that will be invalid until next clean up threshold := time.Now().Add(interval) @@ -375,7 +381,7 @@ func MaintainCertDB(ctx context.Context, interval time.Duration, acmeClient *Acm } else if tlsCertificates[0].NotAfter.Before(time.Now().Add(30 * 24 * time.Hour)) { // renew main certificate 30 days before it expires go (func() { - _, err = acmeClient.obtainCert(acmeClient.dnsChallengerLegoClient, []string{"*" + mainDomainSuffix, mainDomainSuffix[1:]}, res, "", true, mainDomainSuffix, certDB) + _, err = acmeClient.obtainCert(log, acmeClient.dnsChallengerLegoClient, []string{"*" + mainDomainSuffix, mainDomainSuffix[1:]}, res, "", true, mainDomainSuffix, certDB) if err != nil { log.Error().Err(err).Msg("Couldn't renew certificate for main domain") } diff --git a/server/context/context.go b/server/context/context.go index 6650164..e695ab7 100644 --- a/server/context/context.go +++ b/server/context/context.go @@ -5,19 +5,29 @@ import ( "net/http" "codeberg.org/codeberg/pages/server/utils" + "github.com/hashicorp/go-uuid" + "github.com/rs/zerolog/log" ) type Context struct { RespWriter http.ResponseWriter Req *http.Request StatusCode int + ReqId string } func New(w http.ResponseWriter, r *http.Request) *Context { + req_uuid, err := uuid.GenerateUUID() + if err != nil { + log.Error().Err(err).Msg("Failed to generate request id, assigning error value") + req_uuid = "ERROR" + } + return &Context{ RespWriter: w, Req: r, StatusCode: http.StatusOK, + ReqId: req_uuid, } } diff --git a/server/gitea/cache.go b/server/gitea/cache.go index 276358c..03f40a9 100644 --- a/server/gitea/cache.go +++ b/server/gitea/cache.go @@ -8,9 +8,11 @@ import ( "net/http" "time" + "github.com/rs/zerolog" "github.com/rs/zerolog/log" "codeberg.org/codeberg/pages/server/cache" + "codeberg.org/codeberg/pages/server/context" ) const ( @@ -89,16 +91,17 @@ type writeCacheReader struct { hasError bool doNotCache bool complete bool + log zerolog.Logger } func (t *writeCacheReader) Read(p []byte) (n int, err error) { - log.Trace().Msgf("[cache] read %q", t.cacheKey) + t.log.Trace().Msgf("[cache] read %q", t.cacheKey) n, err = t.originalReader.Read(p) if err == io.EOF { t.complete = true } if err != nil && err != io.EOF { - log.Trace().Err(err).Msgf("[cache] original reader for %q has returned an error", t.cacheKey) + t.log.Trace().Err(err).Msgf("[cache] original reader for %q has returned an error", t.cacheKey) t.hasError = true } else if n > 0 { if t.buffer.Len()+n > int(fileCacheSizeLimit) { @@ -118,22 +121,23 @@ func (t *writeCacheReader) Close() error { if doWrite { jsonToCache, err := json.Marshal(fc) if err != nil { - log.Trace().Err(err).Msgf("[cache] marshaling json for %q has returned an error", t.cacheKey+"|Metadata") + t.log.Trace().Err(err).Msgf("[cache] marshaling json for %q has returned an error", t.cacheKey+"|Metadata") } err = t.cache.Set(t.cacheKey+"|Metadata", jsonToCache, fileCacheTimeout) if err != nil { - log.Trace().Err(err).Msgf("[cache] writer for %q has returned an error", t.cacheKey+"|Metadata") + t.log.Trace().Err(err).Msgf("[cache] writer for %q has returned an error", t.cacheKey+"|Metadata") } err = t.cache.Set(t.cacheKey+"|Body", fc.Body, fileCacheTimeout) if err != nil { - log.Trace().Err(err).Msgf("[cache] writer for %q has returned an error", t.cacheKey+"|Body") + t.log.Trace().Err(err).Msgf("[cache] writer for %q has returned an error", t.cacheKey+"|Body") } } - log.Trace().Msgf("cacheReader for %q saved=%t closed", t.cacheKey, doWrite) + t.log.Trace().Msgf("cacheReader for %q saved=%t closed", t.cacheKey, doWrite) return t.originalReader.Close() } -func (f FileResponse) CreateCacheReader(r io.ReadCloser, cache cache.ICache, cacheKey string) io.ReadCloser { +func (f FileResponse) CreateCacheReader(ctx *context.Context, r io.ReadCloser, cache cache.ICache, cacheKey string) io.ReadCloser { + log := log.With().Str("ReqId", ctx.ReqId).Logger() if r == nil || cache == nil || cacheKey == "" { log.Error().Msg("could not create CacheReader") return nil @@ -145,5 +149,6 @@ func (f FileResponse) CreateCacheReader(r io.ReadCloser, cache cache.ICache, cac fileResponse: &f, cache: cache, cacheKey: cacheKey, + log: log, } } diff --git a/server/gitea/client.go b/server/gitea/client.go index 5a12111..0cf6e6c 100644 --- a/server/gitea/client.go +++ b/server/gitea/client.go @@ -19,6 +19,7 @@ import ( "codeberg.org/codeberg/pages/config" "codeberg.org/codeberg/pages/server/cache" + "codeberg.org/codeberg/pages/server/context" "codeberg.org/codeberg/pages/server/version" ) @@ -104,8 +105,8 @@ func (client *Client) ContentWebLink(targetOwner, targetRepo, branch, resource s return path.Join(client.giteaRoot, targetOwner, targetRepo, "src/branch", branch, resource) } -func (client *Client) GiteaRawContent(targetOwner, targetRepo, ref, resource string) ([]byte, error) { - reader, _, _, err := client.ServeRawContent(targetOwner, targetRepo, ref, resource, false) +func (client *Client) GiteaRawContent(ctx *context.Context, targetOwner, targetRepo, ref, resource string) ([]byte, error) { + reader, _, _, err := client.ServeRawContent(ctx, targetOwner, targetRepo, ref, resource, false) if err != nil { return nil, err } @@ -113,9 +114,9 @@ func (client *Client) GiteaRawContent(targetOwner, targetRepo, ref, resource str return io.ReadAll(reader) } -func (client *Client) ServeRawContent(targetOwner, targetRepo, ref, resource string, decompress bool) (io.ReadCloser, http.Header, int, error) { +func (client *Client) ServeRawContent(ctx *context.Context, targetOwner, targetRepo, ref, resource string, decompress bool) (io.ReadCloser, http.Header, int, error) { cacheKey := fmt.Sprintf("%s/%s/%s|%s|%s", rawContentCacheKeyPrefix, targetOwner, targetRepo, ref, resource) - log := log.With().Str("cache_key", cacheKey).Logger() + log := log.With().Str("ReqId", ctx.ReqId).Str("cache_key", cacheKey).Logger() log.Trace().Msg("try file in cache") // handle if cache entry exist if cacheMetadata, ok := client.responseCache.Get(cacheKey + "|Metadata"); ok { @@ -142,7 +143,7 @@ func (client *Client) ServeRawContent(targetOwner, targetRepo, ref, resource str if cache.IsSymlink { linkDest := string(cache.Body) log.Debug().Msgf("[cache] follow symlink from %q to %q", resource, linkDest) - return client.ServeRawContent(targetOwner, targetRepo, ref, linkDest, decompress) + return client.ServeRawContent(ctx, targetOwner, targetRepo, ref, linkDest, decompress) } else { log.Debug().Msgf("[cache] return %d bytes", len(cache.Body)) return io.NopCloser(bytes.NewReader(cache.Body)), cachedHeader, cachedStatusCode, nil @@ -194,7 +195,7 @@ func (client *Client) ServeRawContent(targetOwner, targetRepo, ref, resource str } log.Debug().Msgf("follow symlink from %q to %q", resource, linkDest) - return client.ServeRawContent(targetOwner, targetRepo, ref, linkDest, decompress) + return client.ServeRawContent(ctx, targetOwner, targetRepo, ref, linkDest, decompress) } } @@ -214,7 +215,7 @@ func (client *Client) ServeRawContent(targetOwner, targetRepo, ref, resource str MimeType: mimeType, RawMime: rawType, } - return fileResp.CreateCacheReader(reader, client.responseCache, cacheKey), resp.Response.Header, resp.StatusCode, nil + return fileResp.CreateCacheReader(ctx, reader, client.responseCache, cacheKey), resp.Response.Header, resp.StatusCode, nil case http.StatusNotFound: jsonToCache, err := json.Marshal(FileResponse{ETag: resp.Header.Get(ETagHeader)}) diff --git a/server/handler/handler.go b/server/handler/handler.go index c038c2d..437697a 100644 --- a/server/handler/handler.go +++ b/server/handler/handler.go @@ -26,9 +26,9 @@ func Handler( canonicalDomainCache, redirectsCache cache.ICache, ) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { - log.Debug().Msg("\n----------------------------------------------------------") - log := log.With().Strs("Handler", []string{req.Host, req.RequestURI}).Logger() ctx := context.New(w, req) + log := log.With().Str("ReqId", ctx.ReqId).Strs("Handler", []string{req.Host, req.RequestURI}).Logger() + log.Debug().Msg("\n----------------------------------------------------------") ctx.RespWriter.Header().Set("Server", "pages-server") diff --git a/server/handler/handler_custom_domain.go b/server/handler/handler_custom_domain.go index 852001a..8a5f9d7 100644 --- a/server/handler/handler_custom_domain.go +++ b/server/handler/handler_custom_domain.go @@ -47,7 +47,7 @@ func handleCustomDomain(log zerolog.Logger, ctx *context.Context, giteaClient *g TargetBranch: targetBranch, TargetPath: path.Join(pathParts...), }, canonicalLink); works { - canonicalDomain, valid := targetOpt.CheckCanonicalDomain(giteaClient, trimmedHost, mainDomainSuffix, canonicalDomainCache) + canonicalDomain, valid := targetOpt.CheckCanonicalDomain(ctx, giteaClient, trimmedHost, mainDomainSuffix, canonicalDomainCache) if !valid { html.ReturnErrorPage(ctx, "domain not specified in .domains file", http.StatusMisdirectedRequest) return @@ -63,8 +63,8 @@ func handleCustomDomain(log zerolog.Logger, ctx *context.Context, giteaClient *g return } - log.Debug().Msg("tryBranch, now trying upstream 7") - tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) + log.Debug().Str("url", trimmedHost).Msg("tryBranch, now trying upstream") + tryUpstream(log, ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) return } diff --git a/server/handler/handler_raw_domain.go b/server/handler/handler_raw_domain.go index f48e8e4..bbbf7da 100644 --- a/server/handler/handler_raw_domain.go +++ b/server/handler/handler_raw_domain.go @@ -45,7 +45,7 @@ func handleRaw(log zerolog.Logger, ctx *context.Context, giteaClient *gitea.Clie TargetPath: path.Join(pathElements[3:]...), }, true); works { log.Trace().Msg("tryUpstream: serve raw domain with specified branch") - tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) + tryUpstream(log, ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) return } log.Debug().Msg("missing branch info") @@ -62,7 +62,7 @@ func handleRaw(log zerolog.Logger, ctx *context.Context, giteaClient *gitea.Clie TargetPath: path.Join(pathElements[2:]...), }, true); works { log.Trace().Msg("tryUpstream: serve raw domain with default branch") - tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) + tryUpstream(log, ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) } else { html.ReturnErrorPage(ctx, fmt.Sprintf("raw domain could not find repo %s/%s or repo is empty", targetOpt.TargetOwner, targetOpt.TargetRepo), diff --git a/server/handler/handler_sub_domain.go b/server/handler/handler_sub_domain.go index 806fe7f..e335019 100644 --- a/server/handler/handler_sub_domain.go +++ b/server/handler/handler_sub_domain.go @@ -53,7 +53,7 @@ func handleSubDomain(log zerolog.Logger, ctx *context.Context, giteaClient *gite TargetPath: path.Join(pathElements[2:]...), }, true); works { log.Trace().Msg("tryUpstream: serve with specified repo and branch") - tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) + tryUpstream(log, ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) } else { html.ReturnErrorPage( ctx, @@ -85,7 +85,7 @@ func handleSubDomain(log zerolog.Logger, ctx *context.Context, giteaClient *gite TargetPath: path.Join(pathElements[1:]...), }, true); works { log.Trace().Msg("tryUpstream: serve default pages repo with specified branch") - tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) + tryUpstream(log, ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) } else { html.ReturnErrorPage( ctx, @@ -110,7 +110,7 @@ func handleSubDomain(log zerolog.Logger, ctx *context.Context, giteaClient *gite TargetPath: path.Join(pathElements[1:]...), }, false); works { log.Debug().Msg("tryBranch, now trying upstream 5") - tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) + tryUpstream(log, ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) return } } @@ -126,7 +126,7 @@ func handleSubDomain(log zerolog.Logger, ctx *context.Context, giteaClient *gite TargetPath: path.Join(pathElements...), }, false); works { log.Debug().Msg("tryBranch, now trying upstream 6") - tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) + tryUpstream(log, ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) return } } @@ -141,7 +141,7 @@ func handleSubDomain(log zerolog.Logger, ctx *context.Context, giteaClient *gite TargetPath: path.Join(pathElements...), }, false); works { log.Debug().Msg("tryBranch, now trying upstream 6") - tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) + tryUpstream(log, ctx, giteaClient, mainDomainSuffix, trimmedHost, targetOpt, canonicalDomainCache, redirectsCache) return } diff --git a/server/handler/try.go b/server/handler/try.go index e76891d..e5fc49b 100644 --- a/server/handler/try.go +++ b/server/handler/try.go @@ -15,7 +15,7 @@ import ( ) // tryUpstream forwards the target request to the Gitea API, and shows an error page on failure. -func tryUpstream(ctx *context.Context, giteaClient *gitea.Client, +func tryUpstream(log zerolog.Logger, ctx *context.Context, giteaClient *gitea.Client, mainDomainSuffix, trimmedHost string, options *upstream.Options, canonicalDomainCache cache.ICache, @@ -23,7 +23,7 @@ func tryUpstream(ctx *context.Context, giteaClient *gitea.Client, ) { // check if a canonical domain exists on a request on MainDomain if strings.HasSuffix(trimmedHost, mainDomainSuffix) && !options.ServeRaw { - canonicalDomain, _ := options.CheckCanonicalDomain(giteaClient, "", mainDomainSuffix, canonicalDomainCache) + canonicalDomain, _ := options.CheckCanonicalDomain(ctx, giteaClient, "", mainDomainSuffix, canonicalDomainCache) if !strings.HasSuffix(strings.SplitN(canonicalDomain, "/", 2)[0], mainDomainSuffix) { canonicalPath := ctx.Req.RequestURI if options.TargetRepo != defaultPagesRepo { @@ -32,7 +32,12 @@ func tryUpstream(ctx *context.Context, giteaClient *gitea.Client, canonicalPath = "/" + path[2] } } - ctx.Redirect("https://"+canonicalDomain+canonicalPath, http.StatusTemporaryRedirect) + + redirect_to := "https://" + canonicalDomain + canonicalPath + + log.Debug().Str("to", redirect_to).Msg("redirecting") + + ctx.Redirect(redirect_to, http.StatusTemporaryRedirect) return } } @@ -41,6 +46,7 @@ func tryUpstream(ctx *context.Context, giteaClient *gitea.Client, options.Host = trimmedHost // Try to request the file from the Gitea API + log.Debug().Msg("requesting from upstream") if !options.Upstream(ctx, giteaClient, redirectsCache) { html.ReturnErrorPage(ctx, fmt.Sprintf("Forge returned %d %s", ctx.StatusCode, http.StatusText(ctx.StatusCode)), ctx.StatusCode) } diff --git a/server/startup.go b/server/startup.go index 14c37aa..4ae26c1 100644 --- a/server/startup.go +++ b/server/startup.go @@ -27,7 +27,7 @@ import ( // Serve sets up and starts the web server. func Serve(ctx *cli.Context) error { // initialize logger with Trace, overridden later with actual level - log.Logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).With().Timestamp().Logger().Level(zerolog.TraceLevel) + log.Logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).With().Timestamp().Caller().Logger().Level(zerolog.TraceLevel) cfg, err := config.ReadConfig(ctx) if err != nil { @@ -41,7 +41,8 @@ func Serve(ctx *cli.Context) error { if err != nil { return err } - log.Logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).With().Timestamp().Logger().Level(logLevel) + fmt.Printf("Setting log level to: %s\n", logLevel) + log.Logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).With().Timestamp().Caller().Logger().Level(logLevel) listeningSSLAddress := fmt.Sprintf("%s:%d", cfg.Server.Host, cfg.Server.Port) listeningHTTPAddress := fmt.Sprintf("%s:%d", cfg.Server.Host, cfg.Server.HttpPort) @@ -85,7 +86,7 @@ func Serve(ctx *cli.Context) error { return err } - if err := certificates.SetupMainDomainCertificates(cfg.Server.MainDomain, acmeClient, certDB); err != nil { + if err := certificates.SetupMainDomainCertificates(log.Logger, cfg.Server.MainDomain, acmeClient, certDB); err != nil { return err } @@ -114,7 +115,7 @@ func Serve(ctx *cli.Context) error { interval := 12 * time.Hour certMaintainCtx, cancelCertMaintain := context.WithCancel(context.Background()) defer cancelCertMaintain() - go certificates.MaintainCertDB(certMaintainCtx, interval, acmeClient, cfg.Server.MainDomain, certDB) + go certificates.MaintainCertDB(log.Logger, certMaintainCtx, interval, acmeClient, cfg.Server.MainDomain, certDB) if cfg.Server.HttpServerEnabled { // Create handler for http->https redirect and http acme challenges diff --git a/server/upstream/domains.go b/server/upstream/domains.go index d53d586..f68a02b 100644 --- a/server/upstream/domains.go +++ b/server/upstream/domains.go @@ -8,6 +8,7 @@ import ( "github.com/rs/zerolog/log" "codeberg.org/codeberg/pages/server/cache" + "codeberg.org/codeberg/pages/server/context" "codeberg.org/codeberg/pages/server/gitea" ) @@ -17,7 +18,7 @@ var canonicalDomainCacheTimeout = 15 * time.Minute const canonicalDomainConfig = ".domains" // CheckCanonicalDomain returns the canonical domain specified in the repo (using the `.domains` file). -func (o *Options) CheckCanonicalDomain(giteaClient *gitea.Client, actualDomain, mainDomainSuffix string, canonicalDomainCache cache.ICache) (domain string, valid bool) { +func (o *Options) CheckCanonicalDomain(ctx *context.Context, giteaClient *gitea.Client, actualDomain, mainDomainSuffix string, canonicalDomainCache cache.ICache) (domain string, valid bool) { // Check if this request is cached. if cachedValue, ok := canonicalDomainCache.Get(o.TargetOwner + "/" + o.TargetRepo + "/" + o.TargetBranch); ok { domains := cachedValue.([]string) @@ -30,7 +31,7 @@ func (o *Options) CheckCanonicalDomain(giteaClient *gitea.Client, actualDomain, return domains[0], valid } - body, err := giteaClient.GiteaRawContent(o.TargetOwner, o.TargetRepo, o.TargetBranch, canonicalDomainConfig) + body, err := giteaClient.GiteaRawContent(ctx, o.TargetOwner, o.TargetRepo, o.TargetBranch, canonicalDomainConfig) if err != nil && !errors.Is(err, gitea.ErrorNotFound) { log.Error().Err(err).Msgf("could not read %s of %s/%s", canonicalDomainConfig, o.TargetOwner, o.TargetRepo) } diff --git a/server/upstream/redirects.go b/server/upstream/redirects.go index ddde375..3ed5010 100644 --- a/server/upstream/redirects.go +++ b/server/upstream/redirects.go @@ -44,7 +44,7 @@ var redirectsCacheTimeout = 10 * time.Minute const redirectsConfig = "_redirects" // getRedirects returns redirects specified in the _redirects file. -func (o *Options) getRedirects(giteaClient *gitea.Client, redirectsCache cache.ICache) []Redirect { +func (o *Options) getRedirects(ctx *context.Context, giteaClient *gitea.Client, redirectsCache cache.ICache) []Redirect { var redirects []Redirect cacheKey := o.TargetOwner + "/" + o.TargetRepo + "/" + o.TargetBranch @@ -53,7 +53,7 @@ func (o *Options) getRedirects(giteaClient *gitea.Client, redirectsCache cache.I redirects = cachedValue.([]Redirect) } else { // Get _redirects file and parse - body, err := giteaClient.GiteaRawContent(o.TargetOwner, o.TargetRepo, o.TargetBranch, redirectsConfig) + body, err := giteaClient.GiteaRawContent(ctx, o.TargetOwner, o.TargetRepo, o.TargetBranch, redirectsConfig) if err == nil { for _, line := range strings.Split(string(body), "\n") { redirectArr := strings.Fields(line) diff --git a/server/upstream/upstream.go b/server/upstream/upstream.go index 2abd0b9..9aac271 100644 --- a/server/upstream/upstream.go +++ b/server/upstream/upstream.go @@ -125,7 +125,7 @@ func AcceptEncodings(header string) []string { // Upstream requests a file from the Gitea API at GiteaRoot and writes it to the request context. func (o *Options) Upstream(ctx *context.Context, giteaClient *gitea.Client, redirectsCache cache.ICache) bool { - log := log.With().Strs("upstream", []string{o.TargetOwner, o.TargetRepo, o.TargetBranch, o.TargetPath}).Logger() + log := log.With().Str("ReqId", ctx.ReqId).Strs("upstream", []string{o.TargetOwner, o.TargetRepo, o.TargetBranch, o.TargetPath}).Logger() log.Debug().Msg("Start") @@ -182,7 +182,7 @@ func (o *Options) Upstream(ctx *context.Context, giteaClient *gitea.Client, redi // add extension for encoding path := o.TargetPath + allowedEncodings[encoding] - reader, header, statusCode, err = giteaClient.ServeRawContent(o.TargetOwner, o.TargetRepo, o.TargetBranch, path, true) + reader, header, statusCode, err = giteaClient.ServeRawContent(ctx, o.TargetOwner, o.TargetRepo, o.TargetBranch, path, true) if statusCode == http.StatusNotFound { continue } @@ -206,7 +206,7 @@ func (o *Options) Upstream(ctx *context.Context, giteaClient *gitea.Client, redi if err != nil && errors.Is(err, gitea.ErrorNotFound) { log.Debug().Msg("Handling not found error") // Get and match redirects - redirects := o.getRedirects(giteaClient, redirectsCache) + redirects := o.getRedirects(ctx, giteaClient, redirectsCache) if o.matchRedirects(ctx, giteaClient, redirects, redirectsCache) { log.Trace().Msg("redirect") return true @@ -234,7 +234,7 @@ func (o *Options) Upstream(ctx *context.Context, giteaClient *gitea.Client, redi } } - log.Trace().Msg("not found") + log.Debug().Msg("not found") ctx.StatusCode = http.StatusNotFound if o.TryIndexPages {