use zitadel/logging

This commit is contained in:
Tim Möhlmann 2023-08-24 19:08:14 +03:00
parent f30f0d3ead
commit 6f8f5226d7
7 changed files with 48 additions and 138 deletions

View file

@ -4,13 +4,15 @@ import (
"crypto/sha256"
"log"
"net/http"
"os"
"strconv"
"sync/atomic"
"time"
"github.com/go-chi/chi"
"golang.org/x/exp/slog"
"golang.org/x/text/language"
"github.com/zitadel/logging"
"github.com/zitadel/oidc/v3/example/server/storage"
"github.com/zitadel/oidc/v3/pkg/op"
)
@ -33,15 +35,25 @@ type Storage interface {
deviceAuthenticate
}
// simple request id counter
var requestID atomic.Uint64
// SetupServer creates an OIDC server with Issuer=http://localhost:<port>
//
// Use one of the pre-made clients in storage/clients.go or register a new one.
func SetupServer(issuer string, storage Storage) chi.Router {
func SetupServer(issuer string, storage Storage, logger *slog.Logger) chi.Router {
// the OpenID Provider requires a 32-byte key for (token) encryption
// be sure to create a proper crypto random key and manage it securely!
key := sha256.Sum256([]byte("test"))
router := chi.NewRouter()
// Enable request logging on INFO level
router.Use(logging.Middleware(
logging.MiddlewareWithLoggerOption(logger),
logging.MiddlewareWithIDOption(func() string {
return strconv.FormatUint(requestID.Add(1), 10)
}),
))
// for simplicity, we provide a very small default page for users who have signed out
router.HandleFunc(pathLoggedOut, func(w http.ResponseWriter, req *http.Request) {
@ -50,7 +62,7 @@ func SetupServer(issuer string, storage Storage) chi.Router {
})
// creation of the OpenIDProvider with the just created in-memory Storage
provider, err := newOP(storage, issuer, key)
provider, err := newOP(storage, issuer, key, logger)
if err != nil {
log.Fatal(err)
}
@ -80,7 +92,7 @@ func SetupServer(issuer string, storage Storage) chi.Router {
// newOP will create an OpenID Provider for localhost on a specified port with a given encryption key
// and a predefined default logout uri
// it will enable all options (see descriptions)
func newOP(storage op.Storage, issuer string, key [32]byte) (op.OpenIDProvider, error) {
func newOP(storage op.Storage, issuer string, key [32]byte, logger *slog.Logger) (op.OpenIDProvider, error) {
config := &op.Config{
CryptoKey: key,
@ -117,12 +129,8 @@ func newOP(storage op.Storage, issuer string, key [32]byte) (op.OpenIDProvider,
op.WithAllowInsecure(),
// as an example on how to customize an endpoint this will change the authorization_endpoint from /authorize to /auth
op.WithCustomAuthEndpoint(op.NewEndpoint("auth")),
op.WithLogger(slog.New(
slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{
AddSource: true,
Level: slog.LevelDebug,
}),
)),
// Pass our logger to the OP
op.WithLogger(logger.WithGroup("op")),
)
if err != nil {
return nil, err

View file

@ -4,9 +4,12 @@ import (
"fmt"
"log"
"net/http"
"os"
"github.com/zitadel/logging"
"github.com/zitadel/oidc/v3/example/server/exampleop"
"github.com/zitadel/oidc/v3/example/server/storage"
"golang.org/x/exp/slog"
)
func main() {
@ -20,14 +23,24 @@ func main() {
// in this example it will be handled in-memory
storage := storage.NewStorage(storage.NewUserStore(issuer))
router := exampleop.SetupServer(issuer, storage)
// Using our wrapped logging handler,
// data set to the context gets printed
// as part of the log output.
// This helps us tie log output to requests.
logger := slog.New(logging.WrapHandler(
slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{
AddSource: true,
Level: slog.LevelDebug,
}),
logging.HandlerWithCTXGroupName("ctx"),
))
router := exampleop.SetupServer(issuer, storage, logger)
server := &http.Server{
Addr: ":" + port,
Handler: router,
}
log.Printf("server listening on http://localhost:%s/", port)
log.Println("press ctrl+c to stop")
logger.Info("server listening, press ctrl+c to stop", "addr", fmt.Sprintf("http://localhost:%s/", port))
err := server.ListenAndServe()
if err != nil {
log.Fatal(err)

5
go.mod
View file

@ -11,9 +11,9 @@ require (
github.com/jeremija/gosubmit v0.2.7
github.com/muhlemmer/gu v0.3.1
github.com/rs/cors v1.9.0
github.com/rs/xid v1.5.0
github.com/sirupsen/logrus v1.9.0
github.com/sirupsen/logrus v1.9.3
github.com/stretchr/testify v1.8.2
github.com/zitadel/logging v0.3.5-0.20230824152050-9b8a8a0bdf73
github.com/zitadel/schema v1.3.0
golang.org/x/exp v0.0.0-20230817173708-d852ddb80c63
golang.org/x/oauth2 v0.7.0
@ -22,6 +22,7 @@ require (
)
require (
github.com/benbjohnson/clock v1.3.5 // indirect
github.com/davecgh/go-spew v1.1.1 // indirect
github.com/golang/protobuf v1.5.3 // indirect
github.com/google/go-cmp v0.5.9 // indirect

11
go.sum
View file

@ -1,3 +1,5 @@
github.com/benbjohnson/clock v1.3.5 h1:VvXlSJBzZpA/zum6Sj74hxwYI2DIxRWuNIoXAzHZz5o=
github.com/benbjohnson/clock v1.3.5/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA=
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
@ -36,10 +38,8 @@ github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZb
github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
github.com/rs/cors v1.9.0 h1:l9HGsTsHJcvW14Nk7J9KFz8bzeAWXn3CG6bgt7LsrAE=
github.com/rs/cors v1.9.0/go.mod h1:XyqrcTp5zjWr1wsJ8PIRZssZ8b/WMcMf71DJnit4EMU=
github.com/rs/xid v1.5.0 h1:mKX4bl4iPYJtEIxp6CYiUuLQ/8DYMoz0PUdtGgMFRVc=
github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
github.com/sirupsen/logrus v1.9.0 h1:trlNQbNUG3OdDrDil03MCb1H2o9nJ1x4/5LYw7byDE0=
github.com/sirupsen/logrus v1.9.0/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ=
github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo=
@ -49,6 +49,8 @@ github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO
github.com/stretchr/testify v1.8.2 h1:+h33VjcLVPDHtOdpUCuF+7gSuG3yGIftsP1YvFihtJ8=
github.com/stretchr/testify v1.8.2/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
github.com/yuin/goldmark v1.3.5/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k=
github.com/zitadel/logging v0.3.5-0.20230824152050-9b8a8a0bdf73 h1:vYoTHKhD3upeAXNTBcoSmdZkRF9WOcJzozJX/1SiXUI=
github.com/zitadel/logging v0.3.5-0.20230824152050-9b8a8a0bdf73/go.mod h1:p1XQg2/CP5BGGwTrZ2thanc3cvGpkHALLCrMiO+ULsY=
github.com/zitadel/schema v1.3.0 h1:kQ9W9tvIwZICCKWcMvCEweXET1OcOyGEuFbHs4o5kg0=
github.com/zitadel/schema v1.3.0/go.mod h1:NptN6mkBDFvERUCvZHlvWmmME+gmZ44xzwRXwhzsbtc=
golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
@ -104,6 +106,7 @@ gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntN
gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q=
gopkg.in/square/go-jose.v2 v2.6.0 h1:NGk74WTnPKBNUhNzQX7PYcTLUjoq7mzKk2OKbvwk2iI=
gopkg.in/square/go-jose.v2 v2.6.0/go.mod h1:M9dMgbHiYLoDGQrXy7OpJDJWiKiU//h+vD76mk0e1AI=
gopkg.in/yaml.v2 v2.2.8 h1:obN1ZagJSUGI0Ek/LBmuj4SNLPfIny3KsKFopxRdj10=
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

View file

@ -20,7 +20,7 @@ func AuthRequestError(w http.ResponseWriter, r *http.Request, authReq ErrAuthReq
logger := authorizer.Logger().With("oidc_error", e)
if authReq == nil {
logger.Log(r.Context(), e.LogLevel(), "auth request nil")
logger.Log(r.Context(), e.LogLevel(), "auth request")
http.Error(w, err.Error(), http.StatusBadRequest)
return
}
@ -42,7 +42,7 @@ func AuthRequestError(w http.ResponseWriter, r *http.Request, authReq ErrAuthReq
http.Error(w, err.Error(), http.StatusBadRequest)
return
}
logger.Log(r.Context(), e.LogLevel(), "auth request error")
logger.Log(r.Context(), e.LogLevel(), "auth request")
http.Redirect(w, r, url, http.StatusFound)
}

View file

@ -1,114 +0,0 @@
package op
import (
"context"
"net/http"
"time"
"github.com/rs/xid"
"golang.org/x/exp/slog"
)
func newLogger(logger *slog.Logger) *slog.Logger {
if logger == nil {
logger = slog.Default()
}
return slog.New(&logHandler{
handler: logger.Handler(),
})
}
type LogKey int
const (
RequestID LogKey = iota
maxLogKey
)
type logHandler struct {
handler slog.Handler
}
func (h *logHandler) Enabled(ctx context.Context, level slog.Level) bool {
return h.handler.Enabled(ctx, level)
}
type logAttributes []slog.Attr
func (attrs *logAttributes) appendFromContext(ctx context.Context, ctxKey any, logKey string) {
v := ctx.Value(RequestID)
if v == nil {
return
}
*attrs = append(*attrs, slog.Group("request", slog.Attr{
Key: "id",
Value: slog.AnyValue(v),
}))
}
func (h *logHandler) Handle(ctx context.Context, record slog.Record) error {
attrs := make(logAttributes, 0, maxLogKey)
attrs.appendFromContext(ctx, RequestID, "id")
handler := h.handler.WithAttrs(attrs)
return handler.Handle(ctx, record)
}
func (h *logHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
return &logHandler{
handler: h.handler.WithAttrs(attrs),
}
}
func (h *logHandler) WithGroup(name string) slog.Handler {
return &logHandler{
handler: h.handler.WithGroup(name),
}
}
func (o *Provider) LogMiddleware() func(http.Handler) http.Handler {
return func(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
start := time.Now()
r = r.WithContext(context.WithValue(r.Context(), RequestID, xid.New()))
lw := &loggedWriter{
ResponseWriter: w,
}
next.ServeHTTP(lw, r)
logger := o.logger.With(
slog.Group("request", "method", r.Method, "url", r.URL),
slog.Group("response", "duration", time.Since(start), "status", lw.statusCode, "written", lw.written),
)
if lw.err != nil {
logger.ErrorContext(r.Context(), "response writer", "error", lw.err)
return
}
logger.InfoContext(r.Context(), "done")
})
}
}
type loggedWriter struct {
http.ResponseWriter
statusCode int
written int
err error
}
func (w *loggedWriter) WriteHeader(statusCode int) {
w.statusCode = statusCode
w.ResponseWriter.WriteHeader(statusCode)
}
func (w *loggedWriter) Write(b []byte) (int, error) {
if w.statusCode == 0 {
w.WriteHeader(http.StatusOK)
}
n, err := w.ResponseWriter.Write(b)
w.written += n
w.err = err
return n, err
}

View file

@ -87,9 +87,8 @@ type OpenIDProvider interface {
type HttpInterceptor func(http.Handler) http.Handler
func CreateRouter(o *Provider, interceptors ...HttpInterceptor) chi.Router {
func CreateRouter(o OpenIDProvider, interceptors ...HttpInterceptor) chi.Router {
router := chi.NewRouter()
router.Use(o.LogMiddleware())
router.Use(cors.New(defaultCORSOptions).Handler)
router.Use(intercept(o.IssuerFromRequest, interceptors...))
router.HandleFunc(healthEndpoint, healthHandler)
@ -534,7 +533,7 @@ func WithIDTokenHintVerifierOpts(opts ...IDTokenHintVerifierOpt) Option {
func WithLogger(logger *slog.Logger) Option {
return func(o *Provider) error {
o.logger = newLogger(logger)
o.logger = logger
return nil
}
}