diff --git a/Dockerfile b/Dockerfile index 51511347..f6a908e1 100644 --- a/Dockerfile +++ b/Dockerfile @@ -30,7 +30,7 @@ RUN VERSION=$(cat /build/.version) \ -tags "${BUILD_TAGS}" \ -ldflags="-X github.com/pocket-id/pocket-id/backend/internal/common.Version=${VERSION} -buildid=${VERSION}" \ -trimpath \ - -o /build/pocket-id-backend \ + -o /build/pocket-id \ . # Stage 3: Production Image @@ -39,7 +39,7 @@ WORKDIR /app RUN apk add --no-cache curl su-exec -COPY --from=backend-builder /build/pocket-id-backend /app/pocket-id +COPY --from=backend-builder /build/pocket-id /app/pocket-id COPY ./scripts/docker /app/docker RUN chmod +x /app/pocket-id && \ diff --git a/backend/go.mod b/backend/go.mod index 419e62ad..92cf4a1a 100644 --- a/backend/go.mod +++ b/backend/go.mod @@ -24,18 +24,25 @@ require ( github.com/joho/godotenv v1.5.1 github.com/lestrrat-go/httprc/v3 v3.0.0-beta2 github.com/lestrrat-go/jwx/v3 v3.0.1 + github.com/lmittmann/tint v1.1.2 + github.com/mattn/go-isatty v0.0.20 github.com/mileusna/useragent v1.3.5 + github.com/orandin/slog-gorm v1.4.0 github.com/oschwald/maxminddb-golang/v2 v2.0.0-beta.2 + github.com/samber/slog-gin v1.15.1 github.com/spf13/cobra v1.9.1 github.com/stretchr/testify v1.10.0 + go.opentelemetry.io/contrib/bridges/otelslog v0.12.0 go.opentelemetry.io/contrib/exporters/autoexport v0.59.0 go.opentelemetry.io/contrib/instrumentation/github.com/gin-gonic/gin/otelgin v0.60.0 go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.54.0 - go.opentelemetry.io/otel v1.35.0 - go.opentelemetry.io/otel/metric v1.35.0 + go.opentelemetry.io/otel v1.37.0 + go.opentelemetry.io/otel/log v0.13.0 + go.opentelemetry.io/otel/metric v1.37.0 go.opentelemetry.io/otel/sdk v1.35.0 + go.opentelemetry.io/otel/sdk/log v0.10.0 go.opentelemetry.io/otel/sdk/metric v1.35.0 - go.opentelemetry.io/otel/trace v1.35.0 + go.opentelemetry.io/otel/trace v1.37.0 golang.org/x/crypto v0.39.0 golang.org/x/image v0.24.0 golang.org/x/text v0.26.0 @@ -60,7 +67,7 @@ require ( github.com/gabriel-vasile/mimetype v1.4.8 // indirect github.com/gin-contrib/sse v1.0.0 // indirect github.com/go-asn1-ber/asn1-ber v1.5.7 // indirect - github.com/go-logr/logr v1.4.2 // indirect + github.com/go-logr/logr v1.4.3 // indirect github.com/go-logr/stdr v1.2.2 // indirect github.com/go-playground/locales v0.14.1 // indirect github.com/go-playground/universal-translator v0.18.1 // indirect @@ -86,7 +93,6 @@ require ( github.com/lestrrat-go/httpcc v1.0.1 // indirect github.com/lestrrat-go/option v1.0.1 // indirect github.com/lib/pq v1.10.9 // indirect - github.com/mattn/go-isatty v0.0.20 // indirect github.com/mattn/go-sqlite3 v1.14.24 // indirect github.com/mitchellh/mapstructure v1.5.0 // indirect github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect @@ -119,8 +125,6 @@ require ( go.opentelemetry.io/otel/exporters/stdout/stdoutlog v0.10.0 // indirect go.opentelemetry.io/otel/exporters/stdout/stdoutmetric v1.35.0 // indirect go.opentelemetry.io/otel/exporters/stdout/stdouttrace v1.35.0 // indirect - go.opentelemetry.io/otel/log v0.10.0 // indirect - go.opentelemetry.io/otel/sdk/log v0.10.0 // indirect go.opentelemetry.io/proto/otlp v1.5.0 // indirect go.uber.org/atomic v1.11.0 // indirect golang.org/x/arch v0.14.0 // indirect diff --git a/backend/go.sum b/backend/go.sum index 70f021e9..79b01019 100644 --- a/backend/go.sum +++ b/backend/go.sum @@ -73,8 +73,8 @@ github.com/go-co-op/gocron/v2 v2.15.0/go.mod h1:ZF70ZwEqz0OO4RBXE1sNxnANy/zvwLca github.com/go-ldap/ldap/v3 v3.4.10 h1:ot/iwPOhfpNVgB1o+AVXljizWZ9JTp7YF5oeyONmcJU= github.com/go-ldap/ldap/v3 v3.4.10/go.mod h1:JXh4Uxgi40P6E9rdsYqpUtbW46D9UTjJ9QSwGRznplY= github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= -github.com/go-logr/logr v1.4.2 h1:6pFjapn8bFcIbiKo3XT4j/BhANplGihG6tvd+8rYgrY= -github.com/go-logr/logr v1.4.2/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= +github.com/go-logr/logr v1.4.3 h1:CjnDlHq8ikf6E492q6eKboGOC0T8CDaOvkHCIg8idEI= +github.com/go-logr/logr v1.4.3/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= github.com/go-playground/assert/v2 v2.2.0 h1:JvknZsQTYeFEAhQwI4qEt9cyV5ONwRHC+lYKSsYSR8s= @@ -181,6 +181,8 @@ github.com/lestrrat-go/option v1.0.1 h1:oAzP2fvZGQKWkvHa1/SAcFolBEca1oN+mQ7eooNB github.com/lestrrat-go/option v1.0.1/go.mod h1:5ZHFbivi4xwXxhxY9XHDe2FHo6/Z7WWmtT7T5nBBp3I= github.com/lib/pq v1.10.9 h1:YXG7RB+JIjhP29X+OtkiDnYaXQwpS4JEWq7dtCCRUEw= github.com/lib/pq v1.10.9/go.mod h1:AlVN5x4E4T544tWzH6hKfbfQvm3HdbOxrmggDNAPY9o= +github.com/lmittmann/tint v1.1.2 h1:2CQzrL6rslrsyjqLDwD11bZ5OpLBPU+g3G/r5LSfS8w= +github.com/lmittmann/tint v1.1.2/go.mod h1:HIS3gSy7qNwGCj+5oRjAutErFBl4BzdQP6cJZ0NfMwE= github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY= github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/mattn/go-sqlite3 v1.14.24 h1:tpSp2G2KyMnnQu99ngJ47EIkWVmliIizyZBfPrBWDRM= @@ -208,6 +210,8 @@ github.com/opencontainers/go-digest v1.0.0 h1:apOUWs51W5PlhuyGyz9FCeeBIOUDA/6nW8 github.com/opencontainers/go-digest v1.0.0/go.mod h1:0JzlMkj0TRzQZfJkVvzbP0HBR3IKzErnv2BNG4W4MAM= github.com/opencontainers/image-spec v1.1.0 h1:8SG7/vwALn54lVB/0yZ/MMwhFrPYtpEHQb2IpWsCzug= github.com/opencontainers/image-spec v1.1.0/go.mod h1:W4s4sFTMaBeK1BQLXbG4AdM2szdn85PY75RI83NrTrM= +github.com/orandin/slog-gorm v1.4.0 h1:FgA8hJufF9/jeNSYoEXmHPPBwET2gwlF3B85JdpsTUU= +github.com/orandin/slog-gorm v1.4.0/go.mod h1:MoZ51+b7xE9lwGNPYEhxcUtRNrYzjdcKvA8QXQQGEPA= github.com/oschwald/maxminddb-golang/v2 v2.0.0-beta.2 h1:jG+FaCBv3h6GD5F+oenTfe3+0NmX8sCKjni5k3A5Dek= github.com/oschwald/maxminddb-golang/v2 v2.0.0-beta.2/go.mod h1:rHaQJ5SjfCdL4sqCKa3FhklRcaXga2/qyvmQuA+ZJ6M= github.com/pelletier/go-toml/v2 v2.2.3 h1:YmeHyLY8mFWbdkNWwpr+qIL2bEqT0o95WSdkNHvL12M= @@ -231,6 +235,8 @@ github.com/robfig/cron/v3 v3.0.1/go.mod h1:eQICP3HwyT7UooqI/z+Ov+PtYAWygg1TEWWzG github.com/rogpeppe/go-internal v1.13.1 h1:KvO1DLK/DRN07sQ1LQKScxyZJuNnedQ5/wKSR38lUII= github.com/rogpeppe/go-internal v1.13.1/go.mod h1:uMEvuHeurkdAXX61udpOXGD/AzZDWNMNyH2VO9fmH0o= github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= +github.com/samber/slog-gin v1.15.1 h1:jsnfr+S5HQPlz9pFPA3tOmKW7wN/znyZiE6hncucrTM= +github.com/samber/slog-gin v1.15.1/go.mod h1:mPAEinK/g2jPLauuWO11m3Q0Ca7aG4k9XjXjXY8IhMQ= github.com/segmentio/asm v1.2.0 h1:9BQrFxC+YOHJlTlHGkTrFWf59nbL3XnCoFLTwDCI7ys= github.com/segmentio/asm v1.2.0/go.mod h1:BqMnlJP91P8d+4ibuonYZw9mfnzI9HfxselHZr5aAcs= github.com/spf13/cobra v1.9.1 h1:CXSaggrXdbHK9CF+8ywj8Amf7PBRmPCOJugH954Nnlo= @@ -260,6 +266,8 @@ github.com/x448/float16 v0.8.4/go.mod h1:14CWIYCyZA/cWjXOioeEpHeN/83MdbZDRQHoFcY github.com/yuin/goldmark v1.4.13/go.mod h1:6yULJ656Px+3vBD8DxQVa3kxgyrAnzto9xy5taEt/CY= go.opentelemetry.io/auto/sdk v1.1.0 h1:cH53jehLUN6UFLY71z+NDOiNJqDdPRaXzTel0sJySYA= go.opentelemetry.io/auto/sdk v1.1.0/go.mod h1:3wSPjt5PWp2RhlCcmmOial7AvC4DQqZb7a7wCow3W8A= +go.opentelemetry.io/contrib/bridges/otelslog v0.12.0 h1:lFM7SZo8Ce01RzRfnUFQZEYeWRf/MtOA3A5MobOqk2g= +go.opentelemetry.io/contrib/bridges/otelslog v0.12.0/go.mod h1:Dw05mhFtrKAYu72Tkb3YBYeQpRUJ4quDgo2DQw3No5A= go.opentelemetry.io/contrib/bridges/prometheus v0.59.0 h1:HY2hJ7yn3KuEBBBsKxvF3ViSmzLwsgeNvD+0utRMgzc= go.opentelemetry.io/contrib/bridges/prometheus v0.59.0/go.mod h1:H4H7vs8766kwFnOZVEGMJFVF+phpBSmTckvvNRdJeDI= go.opentelemetry.io/contrib/exporters/autoexport v0.59.0 h1:dKhAFwh7SSoOw+gwMtSv+XLkUGTFAwAGMT3X3XSE4FA= @@ -268,8 +276,8 @@ go.opentelemetry.io/contrib/instrumentation/github.com/gin-gonic/gin/otelgin v0. go.opentelemetry.io/contrib/instrumentation/github.com/gin-gonic/gin/otelgin v0.60.0/go.mod h1:ZvRTVaYYGypytG0zRp2A60lpj//cMq3ZnxYdZaljVBM= go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.54.0 h1:TT4fX+nBOA/+LUkobKGW1ydGcn+G3vRw9+g5HwCphpk= go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.54.0/go.mod h1:L7UH0GbB0p47T4Rri3uHjbpCFYrVrwc1I25QhNPiGK8= -go.opentelemetry.io/otel v1.35.0 h1:xKWKPxrxB6OtMCbmMY021CqC45J+3Onta9MqjhnusiQ= -go.opentelemetry.io/otel v1.35.0/go.mod h1:UEqy8Zp11hpkUrL73gSlELM0DupHoiq72dR+Zqel/+Y= +go.opentelemetry.io/otel v1.37.0 h1:9zhNfelUvx0KBfu/gb+ZgeAfAgtWrfHJZcAqFC228wQ= +go.opentelemetry.io/otel v1.37.0/go.mod h1:ehE/umFRLnuLa/vSccNq9oS1ErUlkkK71gMcN34UG8I= go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploggrpc v0.10.0 h1:5dTKu4I5Dn4P2hxyW3l3jTaZx9ACgg0ECos1eAVrheY= go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploggrpc v0.10.0/go.mod h1:P5HcUI8obLrCCmM3sbVBohZFH34iszk/+CPWuakZWL8= go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploghttp v0.10.0 h1:q/heq5Zh8xV1+7GoMGJpTxM2Lhq5+bFxB29tshuRuw0= @@ -292,18 +300,18 @@ go.opentelemetry.io/otel/exporters/stdout/stdoutmetric v1.35.0 h1:PB3Zrjs1sG1GBX go.opentelemetry.io/otel/exporters/stdout/stdoutmetric v1.35.0/go.mod h1:U2R3XyVPzn0WX7wOIypPuptulsMcPDPs/oiSVOMVnHY= go.opentelemetry.io/otel/exporters/stdout/stdouttrace v1.35.0 h1:T0Ec2E+3YZf5bgTNQVet8iTDW7oIk03tXHq+wkwIDnE= go.opentelemetry.io/otel/exporters/stdout/stdouttrace v1.35.0/go.mod h1:30v2gqH+vYGJsesLWFov8u47EpYTcIQcBjKpI6pJThg= -go.opentelemetry.io/otel/log v0.10.0 h1:1CXmspaRITvFcjA4kyVszuG4HjA61fPDxMb7q3BuyF0= -go.opentelemetry.io/otel/log v0.10.0/go.mod h1:PbVdm9bXKku/gL0oFfUF4wwsQsOPlpo4VEqjvxih+FM= -go.opentelemetry.io/otel/metric v1.35.0 h1:0znxYu2SNyuMSQT4Y9WDWej0VpcsxkuklLa4/siN90M= -go.opentelemetry.io/otel/metric v1.35.0/go.mod h1:nKVFgxBZ2fReX6IlyW28MgZojkoAkJGaE8CpgeAU3oE= +go.opentelemetry.io/otel/log v0.13.0 h1:yoxRoIZcohB6Xf0lNv9QIyCzQvrtGZklVbdCoyb7dls= +go.opentelemetry.io/otel/log v0.13.0/go.mod h1:INKfG4k1O9CL25BaM1qLe0zIedOpvlS5Z7XgSbmN83E= +go.opentelemetry.io/otel/metric v1.37.0 h1:mvwbQS5m0tbmqML4NqK+e3aDiO02vsf/WgbsdpcPoZE= +go.opentelemetry.io/otel/metric v1.37.0/go.mod h1:04wGrZurHYKOc+RKeye86GwKiTb9FKm1WHtO+4EVr2E= go.opentelemetry.io/otel/sdk v1.35.0 h1:iPctf8iprVySXSKJffSS79eOjl9pvxV9ZqOWT0QejKY= go.opentelemetry.io/otel/sdk v1.35.0/go.mod h1:+ga1bZliga3DxJ3CQGg3updiaAJoNECOgJREo9KHGQg= go.opentelemetry.io/otel/sdk/log v0.10.0 h1:lR4teQGWfeDVGoute6l0Ou+RpFqQ9vaPdrNJlST0bvw= go.opentelemetry.io/otel/sdk/log v0.10.0/go.mod h1:A+V1UTWREhWAittaQEG4bYm4gAZa6xnvVu+xKrIRkzo= go.opentelemetry.io/otel/sdk/metric v1.35.0 h1:1RriWBmCKgkeHEhM7a2uMjMUfP7MsOF5JpUCaEqEI9o= go.opentelemetry.io/otel/sdk/metric v1.35.0/go.mod h1:is6XYCUMpcKi+ZsOvfluY5YstFnhW0BidkR+gL+qN+w= -go.opentelemetry.io/otel/trace v1.35.0 h1:dPpEfJu1sDIqruz7BHFG3c7528f6ddfSWfFDVt/xgMs= -go.opentelemetry.io/otel/trace v1.35.0/go.mod h1:WUk7DtFp1Aw2MkvqGdwiXYDZZNvA/1J8o6xRXLrIkyc= +go.opentelemetry.io/otel/trace v1.37.0 h1:HLdcFNbRQBE2imdSEgm/kwqmQj1Or1l/7bW6mxVK7z4= +go.opentelemetry.io/otel/trace v1.37.0/go.mod h1:TlgrlQ+PtQO5XFerSPUYG0JSgGyryXewPGyayAWSBS0= go.opentelemetry.io/proto/otlp v1.5.0 h1:xJvq7gMzB31/d406fB8U5CBdyQGw4P399D1aQWU/3i4= go.opentelemetry.io/proto/otlp v1.5.0/go.mod h1:keN8WnHxOy8PG0rQZjJJ5A2ebUoafqWp0eVQ4yIXvJ4= go.uber.org/atomic v1.11.0 h1:ZvwS0R+56ePWxUNi+Atn9dWONBPp/AUETXlHW0DxSjE= diff --git a/backend/internal/bootstrap/application_images_bootstrap.go b/backend/internal/bootstrap/application_images_bootstrap.go index 65cb3128..f9ccd23b 100644 --- a/backend/internal/bootstrap/application_images_bootstrap.go +++ b/backend/internal/bootstrap/application_images_bootstrap.go @@ -1,7 +1,7 @@ package bootstrap import ( - "log" + "fmt" "os" "path" "strings" @@ -12,17 +12,17 @@ import ( ) // initApplicationImages copies the images from the images directory to the application-images directory -func initApplicationImages() { +func initApplicationImages() error { dirPath := common.EnvConfig.UploadPath + "/application-images" sourceFiles, err := resources.FS.ReadDir("images") if err != nil && !os.IsNotExist(err) { - log.Fatalf("Error reading directory: %v", err) + return fmt.Errorf("failed to read directory: %w", err) } destinationFiles, err := os.ReadDir(dirPath) if err != nil && !os.IsNotExist(err) { - log.Fatalf("Error reading directory: %v", err) + return fmt.Errorf("failed to read directory: %w", err) } // Copy images from the images directory to the application-images directory if they don't already exist @@ -35,9 +35,11 @@ func initApplicationImages() { err := utils.CopyEmbeddedFileToDisk(srcFilePath, destFilePath) if err != nil { - log.Fatalf("Error copying file: %v", err) + return fmt.Errorf("failed to copy file: %w", err) } } + + return nil } func imageAlreadyExists(fileName string, destinationFiles []os.DirEntry) bool { diff --git a/backend/internal/bootstrap/bootstrap.go b/backend/internal/bootstrap/bootstrap.go index 9fa4ab5e..7fb4a8a9 100644 --- a/backend/internal/bootstrap/bootstrap.go +++ b/backend/internal/bootstrap/bootstrap.go @@ -3,7 +3,7 @@ package bootstrap import ( "context" "fmt" - "log" + "log/slog" "time" _ "github.com/golang-migrate/migrate/v4/source/file" @@ -14,13 +14,17 @@ import ( ) func Bootstrap(ctx context.Context) error { - initApplicationImages() - - // Initialize the tracer and metrics exporter - shutdownFns, httpClient, err := initOtel(ctx, common.EnvConfig.MetricsEnabled, common.EnvConfig.TracingEnabled) + // Initialize the observability stack, including the logger, distributed tracing, and metrics + shutdownFns, httpClient, err := initObservability(ctx, common.EnvConfig.MetricsEnabled, common.EnvConfig.TracingEnabled) if err != nil { return fmt.Errorf("failed to initialize OpenTelemetry: %w", err) } + slog.InfoContext(ctx, "Pocket ID is starting") + + err = initApplicationImages() + if err != nil { + return fmt.Errorf("failed to initialize application images: %w", err) + } // Connect to the database db := NewDatabase() @@ -62,7 +66,7 @@ func Bootstrap(ctx context.Context) error { NewServiceRunner(shutdownFns...). Run(shutdownCtx) //nolint:contextcheck if err != nil { - log.Printf("Error shutting down services: %v", err) + slog.Error("Error shutting down services", slog.Any("error", err)) } return nil diff --git a/backend/internal/bootstrap/db_bootstrap.go b/backend/internal/bootstrap/db_bootstrap.go index 5624199c..a3d08cfc 100644 --- a/backend/internal/bootstrap/db_bootstrap.go +++ b/backend/internal/bootstrap/db_bootstrap.go @@ -4,8 +4,8 @@ import ( "errors" "fmt" "log" + "log/slog" "net/url" - "os" "strings" "time" @@ -15,9 +15,10 @@ import ( postgresMigrate "github.com/golang-migrate/migrate/v4/database/postgres" sqliteMigrate "github.com/golang-migrate/migrate/v4/database/sqlite3" "github.com/golang-migrate/migrate/v4/source/iofs" + slogGorm "github.com/orandin/slog-gorm" "gorm.io/driver/postgres" "gorm.io/gorm" - "gorm.io/gorm/logger" + gormLogger "gorm.io/gorm/logger" "github.com/pocket-id/pocket-id/backend/internal/common" sqliteutil "github.com/pocket-id/pocket-id/backend/internal/utils/sqlite" @@ -107,13 +108,13 @@ func connectDatabase() (db *gorm.DB, err error) { for i := 1; i <= 3; i++ { db, err = gorm.Open(dialector, &gorm.Config{ TranslateError: true, - Logger: getLogger(), + Logger: getGormLogger(), }) if err == nil { return db, nil } - log.Printf("Attempt %d: Failed to initialize database. Retrying...", i) + slog.Info("Failed to initialize database", slog.Int("attempt", i)) time.Sleep(3 * time.Second) } @@ -164,24 +165,25 @@ func parseSqliteConnectionString(connString string) (string, error) { return connStringUrl.String(), nil } -func getLogger() logger.Interface { - isProduction := common.EnvConfig.AppEnv == "production" +func getGormLogger() gormLogger.Interface { + loggerOpts := make([]slogGorm.Option, 0, 5) + loggerOpts = append(loggerOpts, + slogGorm.WithSlowThreshold(200*time.Millisecond), + slogGorm.WithErrorField("error"), + ) - var logLevel logger.LogLevel - if isProduction { - logLevel = logger.Error + if common.EnvConfig.AppEnv == "production" { + loggerOpts = append(loggerOpts, + slogGorm.SetLogLevel(slogGorm.DefaultLogType, slog.LevelWarn), + slogGorm.WithIgnoreTrace(), + ) } else { - logLevel = logger.Info + loggerOpts = append(loggerOpts, + slogGorm.SetLogLevel(slogGorm.DefaultLogType, slog.LevelDebug), + slogGorm.WithRecordNotFoundError(), + slogGorm.WithTraceAll(), + ) } - return logger.New( - log.New(os.Stdout, "\r\n", log.LstdFlags), - logger.Config{ - SlowThreshold: 200 * time.Millisecond, - LogLevel: logLevel, - IgnoreRecordNotFoundError: isProduction, - ParameterizedQueries: isProduction, - Colorful: !isProduction, - }, - ) + return slogGorm.New(loggerOpts...) } diff --git a/backend/internal/bootstrap/observability_boostrap.go b/backend/internal/bootstrap/observability_boostrap.go new file mode 100644 index 00000000..d335567d --- /dev/null +++ b/backend/internal/bootstrap/observability_boostrap.go @@ -0,0 +1,210 @@ +package bootstrap + +import ( + "context" + "fmt" + "log/slog" + "net/http" + "os" + "time" + + "github.com/lmittmann/tint" + "github.com/mattn/go-isatty" + "go.opentelemetry.io/contrib/bridges/otelslog" + "go.opentelemetry.io/contrib/exporters/autoexport" + "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp" + "go.opentelemetry.io/otel" + globallog "go.opentelemetry.io/otel/log/global" + metricnoop "go.opentelemetry.io/otel/metric/noop" + "go.opentelemetry.io/otel/propagation" + sdklog "go.opentelemetry.io/otel/sdk/log" + "go.opentelemetry.io/otel/sdk/metric" + "go.opentelemetry.io/otel/sdk/resource" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + semconv "go.opentelemetry.io/otel/semconv/v1.30.0" + tracenoop "go.opentelemetry.io/otel/trace/noop" + + "github.com/pocket-id/pocket-id/backend/internal/common" + "github.com/pocket-id/pocket-id/backend/internal/utils" +) + +func defaultResource() (*resource.Resource, error) { + return resource.Merge( + resource.Default(), + resource.NewSchemaless( + semconv.ServiceName(common.Name), + semconv.ServiceVersion(common.Version), + ), + ) +} + +func initObservability(ctx context.Context, metrics, traces bool) (shutdownFns []utils.Service, httpClient *http.Client, err error) { + resource, err := defaultResource() + if err != nil { + return nil, nil, fmt.Errorf("failed to create OpenTelemetry resource: %w", err) + } + + shutdownFns = make([]utils.Service, 0, 2) + + httpClient = &http.Client{} + defaultTransport, ok := http.DefaultTransport.(*http.Transport) + if !ok { + // Indicates a development-time error + panic("Default transport is not of type *http.Transport") + } + httpClient.Transport = defaultTransport.Clone() + + // Logging + err = initOtelLogging(ctx, resource) + if err != nil { + return nil, nil, err + } + + // Tracing + tracingShutdownFn, err := initOtelTracing(ctx, traces, resource, httpClient) + if err != nil { + return nil, nil, err + } else if tracingShutdownFn != nil { + shutdownFns = append(shutdownFns, tracingShutdownFn) + } + + // Metrics + metricsShutdownFn, err := initOtelMetrics(ctx, metrics, resource) + if err != nil { + return nil, nil, err + } else if metricsShutdownFn != nil { + shutdownFns = append(shutdownFns, metricsShutdownFn) + } + + return shutdownFns, httpClient, nil +} + +func initOtelLogging(ctx context.Context, resource *resource.Resource) error { + // If the env var OTEL_LOGS_EXPORTER is empty, we set it to "none", for autoexport to work + if os.Getenv("OTEL_LOGS_EXPORTER") == "" { + os.Setenv("OTEL_LOGS_EXPORTER", "none") + } + exp, err := autoexport.NewLogExporter(ctx) + if err != nil { + return fmt.Errorf("failed to initialize OpenTelemetry log exporter: %w", err) + } + + level := slog.LevelDebug + if common.EnvConfig.AppEnv == "production" { + level = slog.LevelInfo + } + + // Create the handler + var handler slog.Handler + switch { + case common.EnvConfig.LogJSON: + // Log as JSON if configured + handler = slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{ + Level: level, + }) + case isatty.IsTerminal(os.Stdout.Fd()): + // Enable colors if we have a TTY + handler = tint.NewHandler(os.Stdout, &tint.Options{ + TimeFormat: time.StampMilli, + Level: level, + }) + default: + handler = slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{ + Level: level, + }) + } + + // Create the logger provider + provider := sdklog.NewLoggerProvider( + sdklog.WithProcessor( + sdklog.NewBatchProcessor(exp), + ), + sdklog.WithResource(resource), + ) + + // Set the logger provider globally + globallog.SetLoggerProvider(provider) + + // Wrap the handler in a "fanout" one + handler = utils.LogFanoutHandler{ + handler, + otelslog.NewHandler(common.Name, otelslog.WithLoggerProvider(provider)), + } + + // Set the default slog to send logs to OTel and add the app name + log := slog.New(handler). + With(slog.String("app", common.Name)). + With(slog.String("version", common.Version)) + slog.SetDefault(log) + + return nil +} + +func initOtelTracing(ctx context.Context, traces bool, resource *resource.Resource, httpClient *http.Client) (shutdownFn utils.Service, err error) { + if !traces { + otel.SetTracerProvider(tracenoop.NewTracerProvider()) + return nil, nil + } + + tr, err := autoexport.NewSpanExporter(ctx) + if err != nil { + return nil, fmt.Errorf("failed to initialize OpenTelemetry span exporter: %w", err) + } + tp := sdktrace.NewTracerProvider( + sdktrace.WithResource(resource), + sdktrace.WithBatcher(tr), + ) + + otel.SetTracerProvider(tp) + otel.SetTextMapPropagator( + propagation.NewCompositeTextMapPropagator( + propagation.TraceContext{}, + propagation.Baggage{}, + ), + ) + + shutdownFn = func(shutdownCtx context.Context) error { //nolint:contextcheck + tpCtx, tpCancel := context.WithTimeout(shutdownCtx, 10*time.Second) + defer tpCancel() + shutdownErr := tp.Shutdown(tpCtx) + if shutdownErr != nil { + return fmt.Errorf("failed to gracefully shut down traces exporter: %w", shutdownErr) + } + return nil + } + + // Add tracing to the HTTP client + httpClient.Transport = otelhttp.NewTransport(httpClient.Transport) + + return shutdownFn, nil +} + +func initOtelMetrics(ctx context.Context, metrics bool, resource *resource.Resource) (shutdownFn utils.Service, err error) { + if !metrics { + otel.SetMeterProvider(metricnoop.NewMeterProvider()) + return nil, nil + } + + mr, err := autoexport.NewMetricReader(ctx) + if err != nil { + return nil, fmt.Errorf("failed to initialize OpenTelemetry metric reader: %w", err) + } + + mp := metric.NewMeterProvider( + metric.WithResource(resource), + metric.WithReader(mr), + ) + otel.SetMeterProvider(mp) + + shutdownFn = func(shutdownCtx context.Context) error { //nolint:contextcheck + mpCtx, mpCancel := context.WithTimeout(shutdownCtx, 10*time.Second) + defer mpCancel() + shutdownErr := mp.Shutdown(mpCtx) + if shutdownErr != nil { + return fmt.Errorf("failed to gracefully shut down metrics exporter: %w", shutdownErr) + } + return nil + } + + return shutdownFn, nil +} diff --git a/backend/internal/bootstrap/otel_boostrap.go b/backend/internal/bootstrap/otel_boostrap.go deleted file mode 100644 index 754e0a14..00000000 --- a/backend/internal/bootstrap/otel_boostrap.go +++ /dev/null @@ -1,107 +0,0 @@ -package bootstrap - -import ( - "context" - "fmt" - "net/http" - "time" - - "github.com/pocket-id/pocket-id/backend/internal/common" - "github.com/pocket-id/pocket-id/backend/internal/utils" - "go.opentelemetry.io/contrib/exporters/autoexport" - "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp" - "go.opentelemetry.io/otel" - metricnoop "go.opentelemetry.io/otel/metric/noop" - "go.opentelemetry.io/otel/propagation" - "go.opentelemetry.io/otel/sdk/metric" - "go.opentelemetry.io/otel/sdk/resource" - sdktrace "go.opentelemetry.io/otel/sdk/trace" - semconv "go.opentelemetry.io/otel/semconv/v1.30.0" - tracenoop "go.opentelemetry.io/otel/trace/noop" -) - -func defaultResource() (*resource.Resource, error) { - return resource.Merge( - resource.Default(), - resource.NewSchemaless( - semconv.ServiceName("pocket-id-backend"), - semconv.ServiceVersion(common.Version), - ), - ) -} - -func initOtel(ctx context.Context, metrics, traces bool) (shutdownFns []utils.Service, httpClient *http.Client, err error) { - resource, err := defaultResource() - if err != nil { - return nil, nil, fmt.Errorf("failed to create OpenTelemetry resource: %w", err) - } - - shutdownFns = make([]utils.Service, 0, 2) - - httpClient = &http.Client{} - defaultTransport, ok := http.DefaultTransport.(*http.Transport) - if !ok { - // Indicates a development-time error - panic("Default transport is not of type *http.Transport") - } - httpClient.Transport = defaultTransport.Clone() - - if traces { - tr, err := autoexport.NewSpanExporter(ctx) - if err != nil { - return nil, nil, fmt.Errorf("failed to initialize OpenTelemetry span exporter: %w", err) - } - tp := sdktrace.NewTracerProvider( - sdktrace.WithResource(resource), - sdktrace.WithBatcher(tr), - ) - - otel.SetTracerProvider(tp) - otel.SetTextMapPropagator( - propagation.NewCompositeTextMapPropagator( - propagation.TraceContext{}, - propagation.Baggage{}, - ), - ) - - shutdownFns = append(shutdownFns, func(shutdownCtx context.Context) error { //nolint:contextcheck - tpCtx, tpCancel := context.WithTimeout(shutdownCtx, 10*time.Second) - defer tpCancel() - shutdownErr := tp.Shutdown(tpCtx) - if shutdownErr != nil { - return fmt.Errorf("failed to gracefully shut down traces exporter: %w", shutdownErr) - } - return nil - }) - - httpClient.Transport = otelhttp.NewTransport(httpClient.Transport) - } else { - otel.SetTracerProvider(tracenoop.NewTracerProvider()) - } - - if metrics { - mr, err := autoexport.NewMetricReader(ctx) - if err != nil { - return nil, nil, fmt.Errorf("failed to initialize OpenTelemetry metric reader: %w", err) - } - mp := metric.NewMeterProvider( - metric.WithResource(resource), - metric.WithReader(mr), - ) - - otel.SetMeterProvider(mp) - shutdownFns = append(shutdownFns, func(shutdownCtx context.Context) error { //nolint:contextcheck - mpCtx, mpCancel := context.WithTimeout(shutdownCtx, 10*time.Second) - defer mpCancel() - shutdownErr := mp.Shutdown(mpCtx) - if shutdownErr != nil { - return fmt.Errorf("failed to gracefully shut down metrics exporter: %w", shutdownErr) - } - return nil - }) - } else { - otel.SetMeterProvider(metricnoop.NewMeterProvider()) - } - - return shutdownFns, httpClient, nil -} diff --git a/backend/internal/bootstrap/router_bootstrap.go b/backend/internal/bootstrap/router_bootstrap.go index 76693709..6f57b430 100644 --- a/backend/internal/bootstrap/router_bootstrap.go +++ b/backend/internal/bootstrap/router_bootstrap.go @@ -4,7 +4,7 @@ import ( "context" "errors" "fmt" - "log" + "log/slog" "net" "net/http" "os" @@ -12,13 +12,13 @@ import ( "strings" "time" - "github.com/pocket-id/pocket-id/backend/frontend" - "github.com/gin-gonic/gin" + sloggin "github.com/samber/slog-gin" "go.opentelemetry.io/contrib/instrumentation/github.com/gin-gonic/gin/otelgin" "golang.org/x/time/rate" "gorm.io/gorm" + "github.com/pocket-id/pocket-id/backend/frontend" "github.com/pocket-id/pocket-id/backend/internal/common" "github.com/pocket-id/pocket-id/backend/internal/controller" "github.com/pocket-id/pocket-id/backend/internal/middleware" @@ -32,7 +32,8 @@ var registerTestControllers []func(apiGroup *gin.RouterGroup, db *gorm.DB, svc * func initRouter(db *gorm.DB, svc *services) utils.Service { runner, err := initRouterInternal(db, svc) if err != nil { - log.Fatalf("failed to init router: %v", err) + slog.Error("Failed to init router", "error", err) + os.Exit(1) } return runner } @@ -60,21 +61,25 @@ func initRouterInternal(db *gorm.DB, svc *services) (utils.Service, error) { } r := gin.New() - r.Use(gin.LoggerWithConfig(gin.LoggerConfig{Skip: func(c *gin.Context) bool { - for _, prefix := range loggerSkipPathsPrefix { - if strings.HasPrefix(c.Request.Method+" "+c.Request.URL.String(), prefix) { + r.Use(sloggin.NewWithConfig(slog.Default(), sloggin.Config{ + Filters: []sloggin.Filter{ + func(c *gin.Context) bool { + for _, prefix := range loggerSkipPathsPrefix { + if strings.HasPrefix(c.Request.Method+" "+c.Request.URL.String(), prefix) { + return false + } + } return true - } - } - return false - }})) + }, + }, + })) if !common.EnvConfig.TrustProxy { _ = r.SetTrustedProxies(nil) } if common.EnvConfig.TracingEnabled { - r.Use(otelgin.Middleware("pocket-id-backend")) + r.Use(otelgin.Middleware(common.Name)) } rateLimitMiddleware := middleware.NewRateLimitMiddleware().Add(rate.Every(time.Second), 60) @@ -85,7 +90,7 @@ func initRouterInternal(db *gorm.DB, svc *services) (utils.Service, error) { err := frontend.RegisterFrontend(r) if errors.Is(err, frontend.ErrFrontendNotIncluded) { - log.Println("Frontend is not included in the build. Skipping frontend registration.") + slog.Warn("Frontend is not included in the build. Skipping frontend registration.") } else if err != nil { return nil, fmt.Errorf("failed to register frontend: %w", err) } @@ -154,7 +159,7 @@ func initRouterInternal(db *gorm.DB, svc *services) (utils.Service, error) { // Service runner function runFn := func(ctx context.Context) error { - log.Printf("Server listening on %s", addr) + slog.Info("Server listening", slog.String("addr", addr)) // Start the server in a background goroutine go func() { @@ -163,7 +168,8 @@ func initRouterInternal(db *gorm.DB, svc *services) (utils.Service, error) { // Next call blocks until the server is shut down srvErr := srv.Serve(listener) if srvErr != http.ErrServerClosed { - log.Fatalf("Error starting app server: %v", srvErr) + slog.Error("Error starting app server", "error", srvErr) + os.Exit(1) } }() @@ -171,7 +177,7 @@ func initRouterInternal(db *gorm.DB, svc *services) (utils.Service, error) { err = systemd.SdNotifyReady() if err != nil { // Log the error only - log.Printf("[WARN] Unable to notify systemd that the service is ready: %v", err) + slog.Warn("Unable to notify systemd that the service is ready", "error", err) } // Block until the context is canceled @@ -184,7 +190,7 @@ func initRouterInternal(db *gorm.DB, svc *services) (utils.Service, error) { shutdownCancel() if shutdownErr != nil { // Log the error only (could be context canceled) - log.Printf("[WARN] App server shutdown error: %v", shutdownErr) + slog.Warn("App server shutdown error", "error", shutdownErr) } return nil diff --git a/backend/internal/bootstrap/services_bootstrap.go b/backend/internal/bootstrap/services_bootstrap.go index 3ab04da5..8502b9bf 100644 --- a/backend/internal/bootstrap/services_bootstrap.go +++ b/backend/internal/bootstrap/services_bootstrap.go @@ -38,7 +38,11 @@ func initServices(ctx context.Context, db *gorm.DB, httpClient *http.Client) (sv svc.geoLiteService = service.NewGeoLiteService(httpClient) svc.auditLogService = service.NewAuditLogService(db, svc.appConfigService, svc.emailService, svc.geoLiteService) - svc.jwtService = service.NewJwtService(db, svc.appConfigService) + svc.jwtService, err = service.NewJwtService(db, svc.appConfigService) + if err != nil { + return nil, fmt.Errorf("failed to create JWT service: %w", err) + } + svc.userService = service.NewUserService(db, svc.jwtService, svc.auditLogService, svc.emailService, svc.appConfigService) svc.customClaimService = service.NewCustomClaimService(db) diff --git a/backend/internal/common/env_config.go b/backend/internal/common/env_config.go index 2902d8dc..1ec0eb3d 100644 --- a/backend/internal/common/env_config.go +++ b/backend/internal/common/env_config.go @@ -47,6 +47,7 @@ type EnvConfigSchema struct { UiConfigDisabled bool `env:"UI_CONFIG_DISABLED"` MetricsEnabled bool `env:"METRICS_ENABLED"` TracingEnabled bool `env:"TRACING_ENABLED"` + LogJSON bool `env:"LOG_JSON"` TrustProxy bool `env:"TRUST_PROXY"` AnalyticsDisabled bool `env:"ANALYTICS_DISABLED"` } diff --git a/backend/internal/common/version.go b/backend/internal/common/version.go index 29d62508..59d43746 100644 --- a/backend/internal/common/version.go +++ b/backend/internal/common/version.go @@ -1,5 +1,8 @@ package common +// Name is the name of the application +const Name = "pocket-id" + // Version contains the Pocket ID version. // // It can be set at build time using -ldflags. diff --git a/backend/internal/controller/oidc_controller.go b/backend/internal/controller/oidc_controller.go index c2a51ba7..2c580ee8 100644 --- a/backend/internal/controller/oidc_controller.go +++ b/backend/internal/controller/oidc_controller.go @@ -2,7 +2,7 @@ package controller import ( "errors" - "log" + "log/slog" "net/http" "net/url" "strings" @@ -257,7 +257,7 @@ func (oc *OidcController) EndSessionHandler(c *gin.Context) { callbackURL, err := oc.oidcService.ValidateEndSession(c.Request.Context(), input, c.GetString("userID")) if err != nil { // If the validation fails, the user has to confirm the logout manually and doesn't get redirected - log.Printf("Error getting logout callback URL, the user has to confirm the logout manually: %v", err) + slog.WarnContext(c.Request.Context(), "Error getting logout callback URL, the user has to confirm the logout manually", "error", err) c.Redirect(http.StatusFound, common.EnvConfig.AppURL+"/logout") return } diff --git a/backend/internal/service/app_config_service.go b/backend/internal/service/app_config_service.go index 00b00af5..7df3c9bc 100644 --- a/backend/internal/service/app_config_service.go +++ b/backend/internal/service/app_config_service.go @@ -14,7 +14,6 @@ import ( "time" "github.com/hashicorp/go-uuid" - "gorm.io/gorm" "gorm.io/gorm/clause" diff --git a/backend/internal/service/audit_log_service.go b/backend/internal/service/audit_log_service.go index 0bced9ec..3f31d5ca 100644 --- a/backend/internal/service/audit_log_service.go +++ b/backend/internal/service/audit_log_service.go @@ -3,7 +3,6 @@ package service import ( "context" "fmt" - "log" "log/slog" userAgentParser "github.com/mileusna/useragent" @@ -11,6 +10,7 @@ import ( "github.com/pocket-id/pocket-id/backend/internal/model" "github.com/pocket-id/pocket-id/backend/internal/utils" "github.com/pocket-id/pocket-id/backend/internal/utils/email" + "go.opentelemetry.io/otel/trace" "gorm.io/gorm" ) @@ -82,7 +82,7 @@ func (s *AuditLogService) CreateNewSignInWithEmail(ctx context.Context, ipAddres } err := stmt.Count(&count).Error if err != nil { - log.Printf("Failed to count audit logs: %v", err) + slog.ErrorContext(ctx, "Failed to count audit logs", slog.Any("error", err)) return createdAuditLog } @@ -91,7 +91,8 @@ func (s *AuditLogService) CreateNewSignInWithEmail(ctx context.Context, ipAddres // We use a background context here as this is running in a goroutine //nolint:contextcheck go func() { - innerCtx := context.Background() + span := trace.SpanFromContext(ctx) + innerCtx := trace.ContextWithSpan(context.Background(), span) // Note we don't use the transaction here because this is running in background var user model.User @@ -101,7 +102,8 @@ func (s *AuditLogService) CreateNewSignInWithEmail(ctx context.Context, ipAddres First(&user). Error if innerErr != nil { - log.Printf("Failed to load user: %v", innerErr) + slog.ErrorContext(innerCtx, "Failed to load user from database to send notification email", slog.Any("error", innerErr)) + return } innerErr = SendEmail(innerCtx, s.emailService, email.Address{ @@ -115,7 +117,8 @@ func (s *AuditLogService) CreateNewSignInWithEmail(ctx context.Context, ipAddres DateTime: createdAuditLog.CreatedAt.UTC(), }) if innerErr != nil { - log.Printf("Failed to send email to '%s': %v", user.Email, innerErr) + slog.ErrorContext(innerCtx, "Failed to send notification email", slog.Any("error", innerErr), slog.String("address", user.Email)) + return } }() } diff --git a/backend/internal/service/geolite_service.go b/backend/internal/service/geolite_service.go index c260040b..fdc87c0a 100644 --- a/backend/internal/service/geolite_service.go +++ b/backend/internal/service/geolite_service.go @@ -7,7 +7,7 @@ import ( "errors" "fmt" "io" - "log" + "log/slog" "net" "net/http" "net/netip" @@ -52,13 +52,13 @@ func NewGeoLiteService(httpClient *http.Client) *GeoLiteService { if common.EnvConfig.MaxMindLicenseKey == "" && common.EnvConfig.GeoLiteDBUrl == common.MaxMindGeoLiteCityUrl { // Warn the user, and disable the periodic updater - log.Println("MAXMIND_LICENSE_KEY environment variable is empty. The GeoLite2 City database won't be updated.") + slog.Warn("MAXMIND_LICENSE_KEY environment variable is empty: the GeoLite2 City database won't be updated") service.disableUpdater = true } // Initialize IPv6 local ranges if err := service.initializeIPv6LocalRanges(); err != nil { - log.Printf("Warning: Failed to initialize IPv6 local ranges: %v", err) + slog.Warn("Failed to initialize IPv6 local ranges", slog.Any("error", err)) } return service @@ -96,7 +96,7 @@ func (s *GeoLiteService) initializeIPv6LocalRanges() error { s.localIPv6Ranges = localRanges if len(localRanges) > 0 { - log.Printf("Initialized %d IPv6 local ranges", len(localRanges)) + slog.Info("Initialized IPv6 local ranges", slog.Int("count", len(localRanges))) } return nil } @@ -186,11 +186,11 @@ func (s *GeoLiteService) GetLocationByIP(ipAddress string) (country, city string // UpdateDatabase checks the age of the database and updates it if it's older than 14 days. func (s *GeoLiteService) UpdateDatabase(parentCtx context.Context) error { if s.isDatabaseUpToDate() { - log.Println("GeoLite2 City database is up-to-date") + slog.Info("GeoLite2 City database is up-to-date") return nil } - log.Println("Updating GeoLite2 City database") + slog.Info("Updating GeoLite2 City database") downloadUrl := fmt.Sprintf(common.EnvConfig.GeoLiteDBUrl, common.EnvConfig.MaxMindLicenseKey) ctx, cancel := context.WithTimeout(parentCtx, 10*time.Minute) @@ -217,7 +217,7 @@ func (s *GeoLiteService) UpdateDatabase(parentCtx context.Context) error { return fmt.Errorf("failed to extract database: %w", err) } - log.Println("GeoLite2 City database successfully updated.") + slog.Info("GeoLite2 City database successfully updated.") return nil } diff --git a/backend/internal/service/jwt_service.go b/backend/internal/service/jwt_service.go index 5c36533b..b156a27f 100644 --- a/backend/internal/service/jwt_service.go +++ b/backend/internal/service/jwt_service.go @@ -5,7 +5,6 @@ import ( "encoding/json" "errors" "fmt" - "log" "time" "github.com/lestrrat-go/jwx/v3/jwa" @@ -64,16 +63,16 @@ type JwtService struct { jwksEncoded []byte } -func NewJwtService(db *gorm.DB, appConfigService *AppConfigService) *JwtService { +func NewJwtService(db *gorm.DB, appConfigService *AppConfigService) (*JwtService, error) { service := &JwtService{} // Ensure keys are generated or loaded err := service.init(db, appConfigService, &common.EnvConfig) if err != nil { - log.Fatalf("Failed to initialize jwt service: %v", err) + return nil, err } - return service + return service, nil } func (s *JwtService) init(db *gorm.DB, appConfigService *AppConfigService, envConfig *common.EnvConfigSchema) (err error) { diff --git a/backend/internal/service/ldap_service.go b/backend/internal/service/ldap_service.go index 90f9ff77..52ff9ffd 100644 --- a/backend/internal/service/ldap_service.go +++ b/backend/internal/service/ldap_service.go @@ -9,6 +9,7 @@ import ( "fmt" "io" "log" + "log/slog" "net/http" "net/url" "strings" @@ -130,7 +131,7 @@ func (s *LdapService) SyncGroups(ctx context.Context, tx *gorm.DB, client *ldap. // Skip groups without a valid LDAP ID if ldapId == "" { - log.Printf("Skipping LDAP group without a valid unique identifier (attribute: %s)", dbConfig.LdapAttributeGroupUniqueIdentifier.Value) + slog.Warn("Skipping LDAP group without a valid unique identifier", slog.String("attribute", dbConfig.LdapAttributeGroupUniqueIdentifier.Value)) continue } @@ -250,7 +251,7 @@ func (s *LdapService) SyncGroups(ctx context.Context, tx *gorm.DB, client *ldap. return fmt.Errorf("failed to delete group '%s': %w", group.Name, err) } - log.Printf("Deleted group '%s'", group.Name) + slog.Info("Deleted group", slog.String("group", group.Name)) } return nil @@ -295,7 +296,7 @@ func (s *LdapService) SyncUsers(ctx context.Context, tx *gorm.DB, client *ldap.C // Skip users without a valid LDAP ID if ldapId == "" { - log.Printf("Skipping LDAP user without a valid unique identifier (attribute: %s)", dbConfig.LdapAttributeUserUniqueIdentifier.Value) + slog.Warn("Skipping LDAP user without a valid unique identifier", slog.String("attribute", dbConfig.LdapAttributeUserUniqueIdentifier.Value)) continue } @@ -350,7 +351,7 @@ func (s *LdapService) SyncUsers(ctx context.Context, tx *gorm.DB, client *ldap.C if databaseUser.ID == "" { _, err = s.userService.createUserInternal(ctx, newUser, true, tx) if errors.Is(err, &common.AlreadyInUseError{}) { - log.Printf("Skipping creating LDAP user '%s': %v", newUser.Username, err) + slog.Warn("Skipping creating LDAP user", slog.String("username", newUser.Username), slog.Any("error", err)) continue } else if err != nil { return fmt.Errorf("error creating user '%s': %w", newUser.Username, err) @@ -358,7 +359,7 @@ func (s *LdapService) SyncUsers(ctx context.Context, tx *gorm.DB, client *ldap.C } else { _, err = s.userService.updateUserInternal(ctx, databaseUser.ID, newUser, false, true, tx) if errors.Is(err, &common.AlreadyInUseError{}) { - log.Printf("Skipping updating LDAP user '%s': %v", newUser.Username, err) + slog.Warn("Skipping updating LDAP user", slog.String("username", newUser.Username), slog.Any("error", err)) continue } else if err != nil { return fmt.Errorf("error updating user '%s': %w", newUser.Username, err) @@ -371,7 +372,7 @@ func (s *LdapService) SyncUsers(ctx context.Context, tx *gorm.DB, client *ldap.C err = s.saveProfilePicture(ctx, databaseUser.ID, pictureString) if err != nil { // This is not a fatal error - log.Printf("Error saving profile picture for user %s: %v", newUser.Username, err) + slog.Warn("Error saving profile picture for user", slog.String("username", newUser.Username), slog.Any("error", err)) } } } @@ -400,7 +401,7 @@ func (s *LdapService) SyncUsers(ctx context.Context, tx *gorm.DB, client *ldap.C return fmt.Errorf("failed to disable user %s: %w", user.Username, err) } - log.Printf("Disabled user '%s'", user.Username) + slog.Info("Disabled user", slog.String("username", user.Username)) } else { err = s.userService.deleteUserInternal(ctx, user.ID, true, tx) target := &common.LdapUserUpdateError{} @@ -410,7 +411,7 @@ func (s *LdapService) SyncUsers(ctx context.Context, tx *gorm.DB, client *ldap.C return fmt.Errorf("failed to delete user %s: %w", user.Username, err) } - log.Printf("Deleted user '%s'", user.Username) + slog.Info("Deleted user", slog.String("username", user.Username)) } } diff --git a/backend/internal/service/user_service.go b/backend/internal/service/user_service.go index cf8beab6..30527fd8 100644 --- a/backend/internal/service/user_service.go +++ b/backend/internal/service/user_service.go @@ -7,12 +7,14 @@ import ( "fmt" "io" "log" + "log/slog" "net/url" "os" "strings" "time" "github.com/google/uuid" + "go.opentelemetry.io/otel/trace" "gorm.io/gorm" "github.com/pocket-id/pocket-id/backend/internal/common" @@ -393,7 +395,8 @@ func (s *UserService) requestOneTimeAccessEmailInternal(ctx context.Context, use // We use a background context here as this is running in a goroutine //nolint:contextcheck go func() { - innerCtx := context.Background() + span := trace.SpanFromContext(ctx) + innerCtx := trace.ContextWithSpan(context.Background(), span) link := common.EnvConfig.AppURL + "/lc" linkWithCode := link + "/" + oneTimeAccessToken @@ -414,7 +417,8 @@ func (s *UserService) requestOneTimeAccessEmailInternal(ctx context.Context, use ExpirationString: utils.DurationToString(time.Until(expiration).Round(time.Second)), }) if errInternal != nil { - log.Printf("Failed to send email to '%s': %v\n", user.Email, errInternal) + slog.ErrorContext(innerCtx, "Failed to send one-time access token email", slog.Any("error", errInternal), slog.String("address", user.Email)) + return } }() diff --git a/backend/internal/utils/slogfanout.go b/backend/internal/utils/slogfanout.go new file mode 100644 index 00000000..ac6777d7 --- /dev/null +++ b/backend/internal/utils/slogfanout.go @@ -0,0 +1,85 @@ +package utils + +import ( + "context" + "errors" + "fmt" + "log/slog" + "slices" +) + +// This file contains code adapted from https://github.com/samber/slog-multi +// Source: https://github.com/samber/slog-multi/blob/ced84707f45ec9848138349ed58de178eedaa6f2/pipe.go +// Copyright (C) 2023 Samuel Berthe +// License: MIT (https://github.com/samber/slog-multi/blob/ced84707f45ec9848138349ed58de178eedaa6f2/LICENSE) + +// LogFanoutHandler is a slog.Handler that sends logs to multiple destinations +type LogFanoutHandler []slog.Handler + +// Implements slog.Handler +func (h LogFanoutHandler) Enabled(ctx context.Context, l slog.Level) bool { + for i := range h { + if h[i].Enabled(ctx, l) { + return true + } + } + + return false +} + +// Implements slog.Handler +func (h LogFanoutHandler) Handle(ctx context.Context, r slog.Record) error { + errs := make([]error, 0) + for i := range h { + if h[i].Enabled(ctx, r.Level) { + err := try(func() error { + return h[i].Handle(ctx, r.Clone()) + }) + if err != nil { + errs = append(errs, err) + } + } + } + + return errors.Join(errs...) +} + +// Implements slog.Handler +func (h LogFanoutHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + res := make(LogFanoutHandler, len(h)) + for i, v := range h { + res[i] = v.WithAttrs(slices.Clone(attrs)) + } + return res +} + +// Implements slog.Handler +func (h LogFanoutHandler) WithGroup(name string) slog.Handler { + // https://cs.opensource.google/go/x/exp/+/46b07846:slog/handler.go;l=247 + if name == "" { + return h + } + + res := make(LogFanoutHandler, len(h)) + for i, v := range h { + res[i] = v.WithGroup(name) + } + return res +} + +func try(callback func() error) (err error) { + defer func() { + r := recover() + if r != nil { + if e, ok := r.(error); ok { + err = e + } else { + err = fmt.Errorf("unexpected error: %+v", r) + } + } + }() + + err = callback() + + return +}