Use zerolog

This commit is contained in:
Gusted 2022-08-10 01:17:04 +02:00
parent bf910f4df4
commit 1d6d90f387
No known key found for this signature in database
GPG key ID: FD821B732837125F
10 changed files with 105 additions and 295 deletions

View file

@ -27,12 +27,12 @@ import (
"github.com/go-acme/lego/v4/providers/dns"
"github.com/go-acme/lego/v4/registration"
"github.com/reugn/equalizer"
"github.com/rs/zerolog/log"
"codeberg.org/codeberg/pages/server/cache"
"codeberg.org/codeberg/pages/server/database"
dnsutils "codeberg.org/codeberg/pages/server/dns"
"codeberg.org/codeberg/pages/server/gitea"
"codeberg.org/codeberg/pages/server/log"
"codeberg.org/codeberg/pages/server/upstream"
)
@ -229,7 +229,7 @@ func retrieveCertFromDB(sni, mainDomainSuffix []byte, dnsProvider string, acmeUs
res.CSR = nil // acme client doesn't like CSR to be set
tlsCertificate, err = obtainCert(acmeClient, []string{string(sni)}, res, "", dnsProvider, mainDomainSuffix, acmeUseRateLimits, certDB)
if err != nil {
log.Error("Couldn't renew certificate for %s: %v", string(sni), err)
log.Error().Msgf("Couldn't renew certificate for %s: %v", string(sni), err)
}
})()
}
@ -272,10 +272,10 @@ func obtainCert(acmeClient *lego.Client, domains []string, renew *certificate.Re
if acmeUseRateLimits {
acmeClientRequestLimit.Take()
}
log.Debug("Renewing certificate for: %v", domains)
log.Debug().Msgf("Renewing certificate for: %v", domains)
res, err = acmeClient.Certificate.Renew(*renew, true, false, "")
if err != nil {
log.Error("Couldn't renew certificate for %v, trying to request a new one: %v", domains, err)
log.Error().Err(err).Msgf("Couldn't renew certificate for %v, trying to request a new one", domains)
res = nil
}
}
@ -290,7 +290,7 @@ func obtainCert(acmeClient *lego.Client, domains []string, renew *certificate.Re
acmeClientOrderLimit.Take()
acmeClientRequestLimit.Take()
}
log.Debug("Re-requesting new certificate for %v", domains)
log.Debug().Msgf("Re-requesting new certificate for %v", domains)
res, err = acmeClient.Certificate.Obtain(certificate.ObtainRequest{
Domains: domains,
Bundle: true,
@ -298,7 +298,7 @@ func obtainCert(acmeClient *lego.Client, domains []string, renew *certificate.Re
})
}
if err != nil {
log.Error("Couldn't obtain again a certificate or %v: %v", domains, err)
log.Error().Err(err).Msgf("Couldn't obtain again a certificate or %v", domains)
if renew != nil && renew.CertURL != "" {
tlsCertificate, err := tls.X509KeyPair(renew.Certificate, renew.PrivateKey)
if err == nil && tlsCertificate.Leaf.NotAfter.After(time.Now()) {
@ -312,7 +312,7 @@ func obtainCert(acmeClient *lego.Client, domains []string, renew *certificate.Re
}
return mockCert(domains[0], err.Error(), string(mainDomainSuffix), keyDatabase), err
}
log.Debug("Obtained certificate for %v", domains)
log.Debug().Msgf("Obtained certificate for %v", domains)
if err := keyDatabase.Put(name, res); err != nil {
return tls.Certificate{}, err
@ -345,7 +345,7 @@ func SetupAcmeConfig(acmeAPI, acmeMail, acmeEabHmac, acmeEabKID string, acmeAcce
_, err := lego.NewClient(myAcmeConfig)
if err != nil {
// TODO: should we fail hard instead?
log.Error("Can't create ACME client, continuing with mock certs only: %v", err)
log.Error().Err(err).Msg("Can't create ACME client, continuing with mock certs only")
}
return myAcmeConfig, nil
} else if !os.IsNotExist(err) {
@ -366,13 +366,13 @@ func SetupAcmeConfig(acmeAPI, acmeMail, acmeEabHmac, acmeEabKID string, acmeAcce
myAcmeConfig.Certificate.KeyType = certcrypto.RSA2048
tempClient, err := lego.NewClient(myAcmeConfig)
if err != nil {
log.Error("Can't create ACME client, continuing with mock certs only: %v", err)
log.Error().Err(err).Msg("Can't create ACME client, continuing with mock certs only")
} else {
// accept terms & log in to EAB
if acmeEabKID == "" || acmeEabHmac == "" {
reg, err := tempClient.Registration.Register(registration.RegisterOptions{TermsOfServiceAgreed: acmeAcceptTerms})
if err != nil {
log.Error("Can't register ACME account, continuing with mock certs only: %v", err)
log.Error().Err(err).Msg("Can't register ACME account, continuing with mock certs only")
} else {
myAcmeAccount.Registration = reg
}
@ -383,7 +383,7 @@ func SetupAcmeConfig(acmeAPI, acmeMail, acmeEabHmac, acmeEabKID string, acmeAcce
HmacEncoded: acmeEabHmac,
})
if err != nil {
log.Error("Can't register ACME account, continuing with mock certs only: %v", err)
log.Error().Err(err).Msg("Can't register ACME account, continuing with mock certs only")
} else {
myAcmeAccount.Registration = reg
}
@ -392,12 +392,12 @@ func SetupAcmeConfig(acmeAPI, acmeMail, acmeEabHmac, acmeEabKID string, acmeAcce
if myAcmeAccount.Registration != nil {
acmeAccountJSON, err := json.Marshal(myAcmeAccount)
if err != nil {
log.Error("json.Marshalfailed, waiting for manual restart to avoid rate limits: %v", err)
log.Error().Err(err).Msg("json.Marshalfailed, waiting for manual restart to avoid rate limits")
select {}
}
err = os.WriteFile(configFile, acmeAccountJSON, 0o600)
if err != nil {
log.Error("os.WriteFile failed, waiting for manual restart to avoid rate limits: %s", err)
log.Error().Err(err).Msg("os.WriteFile failed, waiting for manual restart to avoid rate limits")
select {}
}
}
@ -415,38 +415,38 @@ func SetupCertificates(mainDomainSuffix []byte, dnsProvider string, acmeConfig *
acmeClient, err = lego.NewClient(acmeConfig)
if err != nil {
log.Error("Can't create ACME client, continuing with mock certs only: %v", err)
log.Error().Err(err).Msg("Can't create ACME client, continuing with mock certs only")
} else {
err = acmeClient.Challenge.SetTLSALPN01Provider(AcmeTLSChallengeProvider{challengeCache})
if err != nil {
log.Error("Can't create TLS-ALPN-01 provider: %v", err)
log.Error().Err(err).Msg("Can't create TLS-ALPN-01 provider")
}
if enableHTTPServer {
err = acmeClient.Challenge.SetHTTP01Provider(AcmeHTTPChallengeProvider{challengeCache})
if err != nil {
log.Error("Can't create HTTP-01 provider: %v", err)
log.Error().Err(err).Msg("Can't create HTTP-01 provider")
}
}
}
mainDomainAcmeClient, err = lego.NewClient(acmeConfig)
if err != nil {
log.Error("Can't create ACME client, continuing with mock certs only: %v", err)
log.Error().Err(err).Msg("Can't create ACME client, continuing with mock certs only")
} else {
if dnsProvider == "" {
// using mock server, don't use wildcard certs
err := mainDomainAcmeClient.Challenge.SetTLSALPN01Provider(AcmeTLSChallengeProvider{challengeCache})
if err != nil {
log.Error("Can't create TLS-ALPN-01 provider: %v", err)
log.Error().Err(err).Msg("Can't create TLS-ALPN-01 provider")
}
} else {
provider, err := dns.NewDNSChallengeProviderByName(dnsProvider)
if err != nil {
log.Error("Can't create DNS Challenge provider: %v", err)
log.Error().Err(err).Msg("Can't create DNS Challenge provider")
}
err = mainDomainAcmeClient.Challenge.SetDNS01Provider(provider)
if err != nil {
log.Error("Can't create DNS-01 provider: %v", err)
log.Error().Err(err).Msg("Can't create DNS-01 provider")
}
}
}
@ -454,7 +454,7 @@ func SetupCertificates(mainDomainSuffix []byte, dnsProvider string, acmeConfig *
if mainCertBytes == nil {
_, err = obtainCert(mainDomainAcmeClient, []string{"*" + string(mainDomainSuffix), string(mainDomainSuffix[1:])}, nil, "", dnsProvider, mainDomainSuffix, acmeUseRateLimits, certDB)
if err != nil {
log.Error("Couldn't renew main domain certificate, continuing with mock certs only: %v", err)
log.Error().Err(err).Msg("Couldn't renew main domain certificate, continuing with mock certs only")
}
}
@ -482,7 +482,7 @@ func MaintainCertDB(ctx context.Context, interval time.Duration, mainDomainSuffi
if err != nil || !tlsCertificates[0].NotAfter.After(now) {
err := certDB.Delete(string(key))
if err != nil {
log.Error("Deleting expired certificate for %q failed: %v", string(key), err)
log.Error().Err(err).Msgf("Deleting expired certificate for %q failed", string(key))
} else {
expiredCertCount++
}
@ -490,22 +490,22 @@ func MaintainCertDB(ctx context.Context, interval time.Duration, mainDomainSuffi
}
key, resBytes, err = keyDatabaseIterator.Next()
}
log.Debug("Removed %d expired certificates from the database", expiredCertCount)
log.Debug().Msgf("Removed %d expired certificates from the database", expiredCertCount)
// compact the database
msg, err := certDB.Compact()
if err != nil {
log.Error("Compacting key database failed: %v", err)
log.Error().Err(err).Msg("Compacting key database failed")
} else {
log.Debug("Compacted key database (%s)", msg)
log.Debug().Msgf("Compacted key database: %s", msg)
}
// update main cert
res, err := certDB.Get(string(mainDomainSuffix))
if err != nil {
log.Error("Couldn't get cert for domain %q", mainDomainSuffix)
log.Error().Msgf("Couldn't get cert for domain %q", mainDomainSuffix)
} else if res == nil {
log.Error("Couldn't renew certificate for main domain %q expected main domain cert to exist, but it's missing - seems like the database is corrupted", string(mainDomainSuffix))
log.Error().Msgf("Couldn't renew certificate for main domain %q expected main domain cert to exist, but it's missing - seems like the database is corrupted", string(mainDomainSuffix))
} else {
tlsCertificates, err := certcrypto.ParsePEMBundle(res.Certificate)
@ -514,7 +514,7 @@ func MaintainCertDB(ctx context.Context, interval time.Duration, mainDomainSuffi
go (func() {
_, err = obtainCert(mainDomainAcmeClient, []string{"*" + string(mainDomainSuffix), string(mainDomainSuffix[1:])}, res, "", dnsProvider, mainDomainSuffix, acmeUseRateLimits, certDB)
if err != nil {
log.Error("Couldn't renew certificate for main domain: %v", err)
log.Error().Err(err).Msg("Couldn't renew certificate for main domain")
}
})()
}

View file

@ -7,10 +7,10 @@ import (
"fmt"
"time"
"codeberg.org/codeberg/pages/server/log"
"github.com/akrylysov/pogreb"
"github.com/akrylysov/pogreb/fs"
"github.com/go-acme/lego/v4/certificate"
"github.com/rs/zerolog/log"
)
var _ CertDB = aDB{}
@ -72,7 +72,7 @@ func (p aDB) sync() {
for {
err := p.intern.Sync()
if err != nil {
log.Error("Syncing cert database failed: %v", err)
log.Error().Err(err).Msg("Syncing cert database failed")
}
select {
case <-p.ctx.Done():

View file

@ -2,16 +2,16 @@ package server
import (
"bytes"
"fmt"
"strings"
"github.com/rs/zerolog"
"github.com/rs/zerolog/log"
"github.com/valyala/fasthttp"
"codeberg.org/codeberg/pages/html"
"codeberg.org/codeberg/pages/server/cache"
"codeberg.org/codeberg/pages/server/dns"
"codeberg.org/codeberg/pages/server/gitea"
"codeberg.org/codeberg/pages/server/log"
"codeberg.org/codeberg/pages/server/upstream"
"codeberg.org/codeberg/pages/server/utils"
"codeberg.org/codeberg/pages/server/version"
@ -25,7 +25,7 @@ func Handler(mainDomainSuffix, rawDomain []byte,
dnsLookupCache, canonicalDomainCache, branchTimestampCache, fileResponseCache cache.SetGetKey,
) func(ctx *fasthttp.RequestCtx) {
return func(ctx *fasthttp.RequestCtx) {
logInfo := fmt.Sprintf("[handler=%q]", string(ctx.Request.Header.RequestURI()))
log := log.With().Str("Handler", string(ctx.Request.Header.RequestURI())).Logger()
ctx.Response.Header.Set("Server", "CodebergPages/"+version.Version)
@ -83,9 +83,9 @@ func Handler(mainDomainSuffix, rawDomain []byte,
// tryBranch checks if a branch exists and populates the target variables. If canonicalLink is non-empty, it will
// also disallow search indexing and add a Link header to the canonical URL.
tryBranch := func(logInfo, repo, branch string, path []string, canonicalLink string) bool {
tryBranch := func(log zerolog.Logger, repo, branch string, path []string, canonicalLink string) bool {
if repo == "" {
log.Debug("tryBranch%s: repo is empty", logInfo)
log.Debug().Msg("tryBranch: repo is empty")
return false
}
@ -96,7 +96,7 @@ func Handler(mainDomainSuffix, rawDomain []byte,
// Check if the branch exists, otherwise treat it as a file path
branchTimestampResult := upstream.GetBranchTimestamp(giteaClient, targetOwner, repo, branch, branchTimestampCache)
if branchTimestampResult == nil {
log.Debug("tryBranch%s: branch doesn't exist", logInfo)
log.Debug().Msg("tryBranch: branch doesn't exist")
return false
}
@ -116,14 +116,14 @@ func Handler(mainDomainSuffix, rawDomain []byte,
)
}
log.Debug("tryBranch%s: true", logInfo)
log.Debug().Msg("tryBranch: true")
return true
}
log.Debug("Preparing %s", logInfo)
log.Debug().Msg("Preparing")
if rawDomain != nil && bytes.Equal(trimmedHost, rawDomain) {
// Serve raw content from RawDomain
log.Debug("Serving raw domain %s", logInfo)
log.Debug().Msg("Serving raw domain")
targetOptions.TryIndexPages = false
if targetOptions.ForbiddenMimeTypes == nil {
@ -143,28 +143,28 @@ func Handler(mainDomainSuffix, rawDomain []byte,
// raw.codeberg.org/example/myrepo/@main/index.html
if len(pathElements) > 2 && strings.HasPrefix(pathElements[2], "@") {
log.Debug("Preparing raw domain, now trying with specified branch %s", logInfo)
if tryBranch(logInfo,
log.Debug().Msg("Preparing raw domain, now trying with specified branch")
if tryBranch(log,
targetRepo, pathElements[2][1:], pathElements[3:],
giteaRoot+"/"+targetOwner+"/"+targetRepo+"/src/branch/%b/%p",
) {
log.Info("tryBranch, now trying upstream 1 %s", logInfo)
log.Info().Msg("tryBranch, now trying upstream 1")
tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost,
targetOptions, targetOwner, targetRepo, targetBranch, targetPath,
canonicalDomainCache, branchTimestampCache, fileResponseCache)
return
}
log.Warn("Path missed a branch %s", logInfo)
log.Warn().Msg("Path missed a branch")
html.ReturnErrorPage(ctx, fasthttp.StatusFailedDependency)
return
}
log.Debug("Preparing raw domain, now trying with default branch %s", logInfo)
tryBranch(logInfo,
log.Debug().Msg("Preparing raw domain, now trying with default branch")
tryBranch(log,
targetRepo, "", pathElements[2:],
giteaRoot+"/"+targetOwner+"/"+targetRepo+"/src/branch/%b/%p",
)
log.Info("tryBranch, now trying upstream 2 %s", logInfo)
log.Info().Msg("tryBranch, now trying upstream 2")
tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost,
targetOptions, targetOwner, targetRepo, targetBranch, targetPath,
canonicalDomainCache, branchTimestampCache, fileResponseCache)
@ -172,7 +172,7 @@ func Handler(mainDomainSuffix, rawDomain []byte,
} else if bytes.HasSuffix(trimmedHost, mainDomainSuffix) {
// Serve pages from subdomains of MainDomainSuffix
log.Debug("Serve pages from main domain suffix %s", logInfo)
log.Info().Msg("Serve pages from main domain suffix")
pathElements := strings.Split(string(bytes.Trim(ctx.Request.URI().Path(), "/")), "/")
targetOwner = string(bytes.TrimSuffix(trimmedHost, mainDomainSuffix))
@ -194,17 +194,17 @@ func Handler(mainDomainSuffix, rawDomain []byte,
return
}
log.Debug("Preparing main domain, now trying with specified repo & branch, %s", logInfo)
if tryBranch(logInfo,
log.Debug().Msg("Preparing main domain, now trying with specified repo & branch")
if tryBranch(log,
pathElements[0], pathElements[1][1:], pathElements[2:],
"/"+pathElements[0]+"/%p",
) {
log.Info("tryBranch, now trying upstream 3 %s", logInfo)
log.Info().Msg("tryBranch, now trying upstream 3")
tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost,
targetOptions, targetOwner, targetRepo, targetBranch, targetPath,
canonicalDomainCache, branchTimestampCache, fileResponseCache)
} else {
log.Warn("tryBranch%s: upstream 3 failed", logInfo)
log.Warn().Msg("tryBranch: upstream 3 failed")
html.ReturnErrorPage(ctx, fasthttp.StatusFailedDependency)
}
return
@ -213,15 +213,15 @@ func Handler(mainDomainSuffix, rawDomain []byte,
// Check if the first directory is a branch for the "pages" repo
// example.codeberg.page/@main/index.html
if strings.HasPrefix(pathElements[0], "@") {
log.Debug("Preparing main domain, now trying with specified branch %s", logInfo)
if tryBranch(logInfo,
log.Debug().Msg("Preparing main domain, now trying with specified branch")
if tryBranch(log,
"pages", pathElements[0][1:], pathElements[1:], "/%p") {
log.Info("tryBranch, now trying upstream 4 %s", logInfo)
log.Info().Msg("tryBranch, now trying upstream 4")
tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost,
targetOptions, targetOwner, targetRepo, targetBranch, targetPath,
canonicalDomainCache, branchTimestampCache, fileResponseCache)
} else {
log.Warn("tryBranch%s: upstream 4 failed", logInfo)
log.Warn().Msg("tryBranch: upstream 4 failed")
html.ReturnErrorPage(ctx, fasthttp.StatusFailedDependency)
}
return
@ -230,10 +230,10 @@ func Handler(mainDomainSuffix, rawDomain []byte,
// 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.
log.Debug("main domain preparations, now trying with specified repo %s", logInfo)
if pathElements[0] != "pages" && tryBranch(logInfo,
log.Debug().Msg("main domain preparations, now trying with specified repo")
if pathElements[0] != "pages" && tryBranch(log,
pathElements[0], "pages", pathElements[1:], "") {
log.Info("tryBranch, now trying upstream 5 %s", logInfo)
log.Info().Msg("tryBranch, now trying upstream 5")
tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost,
targetOptions, targetOwner, targetRepo, targetBranch, targetPath,
canonicalDomainCache, branchTimestampCache, fileResponseCache)
@ -242,10 +242,10 @@ func Handler(mainDomainSuffix, rawDomain []byte,
// Try to use the "pages" repo on its default branch
// example.codeberg.page/index.html
log.Debug("main domain preparations, now trying with default repo/branch %s", logInfo)
if tryBranch(logInfo,
log.Debug().Msg("main domain preparations, now trying with default repo/branch")
if tryBranch(log,
"pages", "", pathElements, "") {
log.Info("tryBranch, now trying upstream 6 %s", logInfo)
log.Info().Msg("tryBranch, now trying upstream 6")
tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost,
targetOptions, targetOwner, targetRepo, targetBranch, targetPath,
canonicalDomainCache, branchTimestampCache, fileResponseCache)
@ -275,12 +275,12 @@ func Handler(mainDomainSuffix, rawDomain []byte,
}
// Try to use the given repo on the given branch or the default branch
log.Debug("Preparing custom domain, now trying with details from DNS %s", logInfo)
if tryBranch(logInfo,
log.Debug().Msg("Preparing custom domain, now trying with details from DNS")
if tryBranch(log,
targetRepo, targetBranch, pathElements, canonicalLink) {
canonicalDomain, valid := upstream.CheckCanonicalDomain(giteaClient, targetOwner, targetRepo, targetBranch, trimmedHostStr, string(mainDomainSuffix), canonicalDomainCache)
if !valid {
log.Warn("Custom domains, domain from DNS isn't valid/canonical %s", logInfo)
log.Warn().Msg("Custom domains, domain from DNS isn't valid/canonical")
html.ReturnErrorPage(ctx, fasthttp.StatusMisdirectedRequest)
return
} else if canonicalDomain != trimmedHostStr {
@ -291,19 +291,19 @@ func Handler(mainDomainSuffix, rawDomain []byte,
return
}
log.Warn("Custom domains, targetOwner from DNS is empty", logInfo)
log.Warn().Msg("Custom domains, targetOwner from DNS is empty")
html.ReturnErrorPage(ctx, fasthttp.StatusFailedDependency)
return
}
log.Info("tryBranch, now trying upstream 7 %s", logInfo)
log.Info().Msg("tryBranch, now trying upstream 7 %s")
tryUpstream(ctx, giteaClient, mainDomainSuffix, trimmedHost,
targetOptions, targetOwner, targetRepo, targetBranch, targetPath,
canonicalDomainCache, branchTimestampCache, fileResponseCache)
return
}
log.Warn("Couldn't handle request, none of the options succeed %q", logInfo)
log.Warn().Msg("Couldn't handle request, none of the options succeed")
html.ReturnErrorPage(ctx, fasthttp.StatusFailedDependency)
return
}

View file

@ -1,194 +0,0 @@
package log
import (
"errors"
"fmt"
"io"
stdLog "log"
"os"
"runtime"
"strings"
"time"
)
var (
// logger is the variable to which the code can write its output.
logger *stdLog.Logger
// The current absolute path to backend/ is stored in filePrefix; this is
// removed from the filename because the logging doesn't require any of the other junk.
filePrefix string
// logLevel is the variable that decides at which log level the logger will output
// to the logger.
logLevel LogLevel
)
type LogLevel uint8
const (
DebugLevel LogLevel = iota
InfoLevel
WarnLevel
ErrorLevel
FatalLevel
)
func init() {
// Make sure that logger is always initalized, this is to still be able to use the logger
// even when logger isn't yet initilazed with the correct values.
initializeLogger(os.Stdout)
// A quick and dirty way to get the backend/ absolute folder
_, filename, _, _ := runtime.Caller(0)
filePrefix = strings.TrimSuffix(filename, "server/log/log.go")
if filePrefix == filename {
// in case the source code file is moved, we can not trim the suffix, the code above should also be updated.
panic("unable to detect correct package prefix, please update file: " + filename)
}
}
// initializeLogger takes a input of multiple writers, which to all writers will be logged to.
func initializeLogger(w ...io.Writer) {
logger = stdLog.New(io.MultiWriter(w...), "", 0)
}
func stringToLogLevel(input string) (LogLevel, error) {
switch strings.ToLower(input) {
case "fatal":
return FatalLevel, nil
case "error":
return ErrorLevel, nil
case "warn":
return WarnLevel, nil
case "info":
return InfoLevel, nil
}
return FatalLevel, errors.New("invalid log level value")
}
// Config takes the ini config and correctly adjust the logger variable.
func Config(outputs []string, outputFile, level string) error {
newLogLevel, err := stringToLogLevel(level)
if err != nil {
return err
}
logLevel = newLogLevel
isFileLog := false
isConsoleLog := false
for _, output := range outputs {
switch output {
case "file":
isFileLog = true
case "console":
isConsoleLog = true
}
}
writers := []io.Writer{}
if isConsoleLog {
writers = append(writers, os.Stdout)
}
if isFileLog {
f, err := os.OpenFile(outputFile, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0o644)
if err != nil {
return fmt.Errorf("cannot open log output's file %q: %v", outputFile, err)
}
writers = append(writers, f)
}
initializeLogger(writers...)
return nil
}
// the Skipper struct can be passed as firt argument to adjust the skip offset.
type Skipper struct {
// SkipOffset will be added on top of the existing "2" skips.
SkipOffset int
}
func log(msg, prefix string, print bool, args ...interface{}) string {
caller := "?()"
skipOffset := 2
// Check if the first argument is Skipper and add the skipoffset accordingly.
if len(args) > 0 {
if skip, ok := args[0].(Skipper); ok {
skipOffset += skip.SkipOffset
args = args[1:]
}
}
pc, filename, line, ok := runtime.Caller(skipOffset)
if ok {
// Get caller function name.
fn := runtime.FuncForPC(pc)
if fn != nil {
caller = fn.Name() + "()"
// Remove prefix of binary's name.
lastIndex := strings.LastIndexByte(caller, '.')
if lastIndex > 0 && len(caller) > lastIndex+1 {
caller = caller[lastIndex+1:]
}
}
}
filename = strings.TrimPrefix(filename, filePrefix)
// Don't output long file names.
if len(filename) > 40 {
filename = "..." + filename[len(filename)-40:]
}
now := time.Now()
year, month, day := now.Date()
hour, min, sec := now.Clock()
// Output message:
// DATE TIME FILENAME:LINE:CALLER PREFIX: MSG
prefixedMessage := fmt.Sprintf("%d/%02d/%02d %02d:%02d:%02d %s:%d:%s %s: %s", year, month, day, hour, min, sec, filename, line, caller, prefix, msg)
// Only print the message if it has been requested.
if print {
if len(args) > 0 {
logger.Printf(prefixedMessage+"\n", args...)
} else {
logger.Println(prefixedMessage)
}
return ""
} else {
return fmt.Sprintf(prefixedMessage, args...)
}
}
// Debug logs a message with the DEBUG prefix.
func Debug(msg string, args ...interface{}) {
if logLevel > DebugLevel {
return
}
log(msg, "DEBUG", true, args...)
}
// Info logs a message with the INFO prefix.
func Info(msg string, args ...interface{}) {
if logLevel > InfoLevel {
return
}
log(msg, "INFO", true, args...)
}
// Warn logs a message with the WARN prefix.
func Warn(msg string, args ...interface{}) {
if logLevel > WarnLevel {
return
}
log(msg, "WARN", true, args...)
}
// Error logs a message with the ERROR prefix.
func Error(msg string, args ...interface{}) {
if logLevel > ErrorLevel {
return
}
log(msg, "ERROR", true, args...)
}
// Fatal logs a message with the FATAL prefix and then exit the program.
func Fatal(msg string, args ...interface{}) {
log(msg, "FATAL", true, args...)
os.Exit(1)
}

View file

@ -6,17 +6,17 @@ import (
"net/http"
"time"
"github.com/rs/zerolog/log"
"github.com/valyala/fasthttp"
"codeberg.org/codeberg/pages/server/cache"
"codeberg.org/codeberg/pages/server/log"
"codeberg.org/codeberg/pages/server/utils"
)
type fasthttpLogger struct{}
func (fasthttpLogger) Printf(format string, args ...interface{}) {
log.Info("FastHTTP: %s", fmt.Sprintf(format, args...))
log.Printf("FastHTTP: %s", fmt.Sprintf(format, args...))
}
func SetupServer(handler fasthttp.RequestHandler) *fasthttp.Server {

View file

@ -3,17 +3,16 @@ package upstream
import (
"bytes"
"errors"
"fmt"
"io"
"strings"
"time"
"github.com/rs/zerolog/log"
"github.com/valyala/fasthttp"
"codeberg.org/codeberg/pages/html"
"codeberg.org/codeberg/pages/server/cache"
"codeberg.org/codeberg/pages/server/gitea"
"codeberg.org/codeberg/pages/server/log"
)
// upstreamIndexPages lists pages that may be considered as index pages for directories.
@ -47,7 +46,7 @@ type Options struct {
// Upstream requests a file from the Gitea API at GiteaRoot and writes it to the request context.
func (o *Options) Upstream(ctx *fasthttp.RequestCtx, giteaClient *gitea.Client, branchTimestampCache, fileResponseCache cache.SetGetKey) (final bool) {
logInfo := fmt.Sprintf("[owner=%q, repo=%q, branch=%q, path=%q, host=%q]", o.TargetOwner, o.TargetRepo, o.TargetBranch, o.TargetPath, o.Host)
log := log.With().Strs("upstream", []string{o.TargetOwner, o.TargetRepo, o.TargetBranch, o.TargetPath, o.Host}).Logger()
// Check if the branch exists and when it was modified
if o.BranchTimestamp.IsZero() {
@ -74,7 +73,7 @@ func (o *Options) Upstream(ctx *fasthttp.RequestCtx, giteaClient *gitea.Client,
}
}
log.Debug("Preparing %s", logInfo)
log.Debug().Msg("Preparing")
// Make a GET request to the upstream URL
uri := o.generateUri()
@ -86,7 +85,7 @@ func (o *Options) Upstream(ctx *fasthttp.RequestCtx, giteaClient *gitea.Client,
} else {
res, err = giteaClient.ServeRawContent(uri)
}
log.Debug("Aquisting %s", logInfo)
log.Debug().Msg("Aquisting")
// Handle errors
if (err != nil && errors.Is(err, gitea.ErrorNotFound)) || (res == nil && !cachedResponse.Exists) {
@ -140,7 +139,7 @@ func (o *Options) Upstream(ctx *fasthttp.RequestCtx, giteaClient *gitea.Client,
return false
}
if res != nil && (err != nil || res.StatusCode() != fasthttp.StatusOK) {
log.Warn("Couldn't fetch contents from %q: %v (status code %d)", uri, err, res.StatusCode())
log.Warn().Msgf("Couldn't fetch contents from %q: %v (status code %d)", uri, err, res.StatusCode())
html.ReturnErrorPage(ctx, fasthttp.StatusInternalServerError)
return true
}
@ -159,7 +158,7 @@ func (o *Options) Upstream(ctx *fasthttp.RequestCtx, giteaClient *gitea.Client,
ctx.Redirect(o.redirectIfExists, fasthttp.StatusTemporaryRedirect)
return true
}
log.Debug("Handling error %s", logInfo)
log.Debug().Msg("Handling error")
// Set the MIME type
mimeType := o.getMimeTypeByExtension()
@ -179,7 +178,7 @@ func (o *Options) Upstream(ctx *fasthttp.RequestCtx, giteaClient *gitea.Client,
}
ctx.Response.Header.SetLastModified(o.BranchTimestamp)
log.Debug("Prepare response %s", logInfo)
log.Debug().Msg("Prepare response")
// Write the response body to the original request
var cacheBodyWriter bytes.Buffer
@ -197,11 +196,11 @@ func (o *Options) Upstream(ctx *fasthttp.RequestCtx, giteaClient *gitea.Client,
_, err = ctx.Write(cachedResponse.Body)
}
if err != nil {
fmt.Printf("Couldn't write body for \"%s\": %s\n", uri, err)
log.Error().Err(err).Msgf("Couldn't write body for %q", uri)
html.ReturnErrorPage(ctx, fasthttp.StatusInternalServerError)
return true
}
log.Debug("Sending response %s", logInfo)
log.Debug().Msg("Sending response")
if res != nil && res.Header.ContentLength() <= fileCacheSizeLimit && ctx.Err() == nil {
cachedResponse.Exists = true