Skip to content

Commit b9bef0d

Browse files
jvillafanezjvillafanez
committed
feat: improve log information
1 parent 5c1be18 commit b9bef0d

File tree

12 files changed

+248
-19
lines changed

12 files changed

+248
-19
lines changed

‎ocis-pkg/log/log.go‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -137,6 +137,11 @@ func (l Logger) SubloggerWithRequestID(c context.Context) Logger {
137137
}
138138
}
139139

140+
func Ctx(ctx context.Context) Logger {
141+
l := zerolog.Ctx(ctx)
142+
return Logger{*l}
143+
}
144+
140145
// Deprecation logs a deprecation message,
141146
// it is used to inform the user that a certain feature is deprecated and will be removed in the future.
142147
// Do not use a logger here because the message MUST be visible independent of the log level.

‎ocis-pkg/middleware/contextlogger.go‎

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,29 @@
1+
package middleware
2+
3+
import (
4+
"net/http"
5+
6+
"github.com/owncloud/ocis/v2/ocis-pkg/log"
7+
)
8+
9+
func NewContextLogger(logger *log.Logger) func(http.Handler) http.Handler {
10+
return func(next http.Handler) http.Handler {
11+
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
12+
newLogger := logger.With().
13+
Str(log.RequestIDString, r.Header.Get("X-Request-ID")).
14+
Str("proto", r.Proto).
15+
Str("method", r.Method).
16+
Str("host", r.Host).
17+
Str("path", r.URL.Path).
18+
Str("query", r.URL.RawQuery).
19+
Str("fragment", r.URL.Fragment).
20+
Str("remote-addr", r.RemoteAddr).
21+
Str("user-agent", r.Header.Get("User-Agent")).
22+
Str("content-length", r.Header.Get("Content-Length")).
23+
Str("content-type", r.Header.Get("Content-Type")).
24+
Logger()
25+
26+
next.ServeHTTP(w, r.WithContext(newLogger.WithContext(r.Context())))
27+
})
28+
}
29+
}

‎ocis-pkg/service/grpc/client.go‎

Lines changed: 19 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ import (
99
mgrpcc "github.com/go-micro/plugins/v4/client/grpc"
1010
mtracer "github.com/go-micro/plugins/v4/wrapper/trace/opentelemetry"
1111
"github.com/owncloud/ocis/v2/ocis-pkg/registry"
12+
ocisgrpcmeta "github.com/owncloud/ocis/v2/ocis-pkg/service/grpc/handler/metadata"
1213
"github.com/owncloud/ocis/v2/ocis-pkg/shared"
1314
"go-micro.dev/v4/client"
1415
"go.opentelemetry.io/otel/trace"
@@ -17,9 +18,11 @@ import (
1718

1819
// ClientOptions represent options (e.g. tls settings) for the grpc clients
1920
type ClientOptions struct {
20-
tlsMode string
21-
caCert string
22-
tp trace.TracerProvider
21+
tlsMode string
22+
caCert string
23+
tp trace.TracerProvider
24+
clientName string
25+
clientVersion string
2326
}
2427

2528
// Option is used to pass client options
@@ -50,6 +53,13 @@ func WithTraceProvider(tp trace.TracerProvider) ClientOption {
5053
}
5154
}
5255

56+
func WithClientNameAndVersion(name, version string) ClientOption {
57+
return func(o *ClientOptions) {
58+
o.clientName = name
59+
o.clientVersion = version
60+
}
61+
}
62+
5363
func GetClientOptions(t *shared.GRPCClientTLS) []ClientOption {
5464
opts := []ClientOption{
5565
WithTLSMode(t.Mode),
@@ -68,6 +78,12 @@ func NewClient(opts ...ClientOption) (client.Client, error) {
6878
var tlsConfig *tls.Config
6979
cOpts := []client.Option{
7080
client.Registry(reg),
81+
client.Wrap(ocisgrpcmeta.NewClientWrapper(
82+
map[string]string{
83+
"Client-Name": options.clientName,
84+
"Client-Version": options.clientVersion,
85+
},
86+
)),
7187
client.Wrap(mtracer.NewClientWrapper(
7288
mtracer.WithTraceProvider(options.tp),
7389
)),

‎ocis-pkg/service/grpc/handler/metadata/client.go‎

Lines changed: 39 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,39 @@
1+
package metadata
2+
3+
import (
4+
"context"
5+
6+
"go-micro.dev/v4/client"
7+
"go-micro.dev/v4/metadata"
8+
)
9+
10+
type clientWrapper struct {
11+
client.Client
12+
mdata metadata.Metadata
13+
}
14+
15+
func NewClientWrapper(mdata map[string]string) client.Wrapper {
16+
meta := metadata.Metadata(mdata)
17+
return func(c client.Client) client.Client {
18+
w := &clientWrapper{
19+
Client: c,
20+
mdata: meta,
21+
}
22+
return w
23+
}
24+
}
25+
26+
func (w *clientWrapper) Call(ctx context.Context, req client.Request, rsp interface{}, opts ...client.CallOption) error {
27+
newCtx := metadata.MergeContext(ctx, w.mdata, true)
28+
return w.Client.Call(newCtx, req, rsp, opts...)
29+
}
30+
31+
func (w *clientWrapper) Stream(ctx context.Context, req client.Request, opts ...client.CallOption) (client.Stream, error) {
32+
newCtx := metadata.MergeContext(ctx, w.mdata, true)
33+
return w.Client.Stream(newCtx, req, opts...)
34+
}
35+
36+
func (w *clientWrapper) Publish(ctx context.Context, p client.Message, opts ...client.PublishOption) error {
37+
newCtx := metadata.MergeContext(ctx, w.mdata, true)
38+
return w.Client.Publish(newCtx, p, opts...)
39+
}

‎ocis-pkg/service/grpc/handler/metadata/server.go‎

Lines changed: 97 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,97 @@
1+
package metadata
2+
3+
import (
4+
"context"
5+
"sort"
6+
7+
"github.com/owncloud/ocis/v2/ocis-pkg/log"
8+
"google.golang.org/grpc"
9+
"google.golang.org/grpc/metadata"
10+
11+
micrometa "go-micro.dev/v4/metadata"
12+
"go-micro.dev/v4/server"
13+
)
14+
15+
func NewMetadataLogHandler(l *log.Logger) func(fn server.HandlerFunc) server.HandlerFunc {
16+
return func(fn server.HandlerFunc) server.HandlerFunc {
17+
return func(ctx context.Context, req server.Request, rsp interface{}) error {
18+
if mdata, ok := micrometa.FromContext(ctx); ok {
19+
keys := make([]string, 0, len(mdata))
20+
for k, _ := range mdata {
21+
keys = append(keys, k)
22+
}
23+
sort.Strings(keys)
24+
25+
logContext := l.With()
26+
for _, sortedKey := range keys {
27+
value, _ := mdata.Get(sortedKey)
28+
logContext = logContext.Str(sortedKey, value)
29+
}
30+
31+
mdataLogger := logContext.Str("target", req.Service()).
32+
Str("method", req.Method()).
33+
Str("endpoint", req.Endpoint()).
34+
Bool("isStream", req.Stream()).
35+
Logger()
36+
ctx = mdataLogger.WithContext(ctx)
37+
}
38+
return fn(ctx, req, rsp)
39+
}
40+
}
41+
}
42+
43+
func NewUnaryInterceptor(l *log.Logger) grpc.UnaryServerInterceptor {
44+
return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) {
45+
if mdata, ok := metadata.FromIncomingContext(ctx); ok {
46+
keys := make([]string, 0, len(mdata))
47+
for k, _ := range mdata {
48+
keys = append(keys, k)
49+
}
50+
sort.Strings(keys)
51+
52+
logContext := l.With()
53+
for _, sortedKey := range keys {
54+
values := mdata.Get(sortedKey)
55+
logContext = logContext.Strs(sortedKey, values)
56+
}
57+
mdataLogger := logContext.Logger()
58+
ctx = mdataLogger.WithContext(ctx)
59+
}
60+
return handler(ctx, req)
61+
}
62+
}
63+
64+
type serverStreamWrapper struct {
65+
grpc.ServerStream
66+
ctx context.Context
67+
}
68+
69+
func newServerStreamWrapper(ss grpc.ServerStream, ctx context.Context) grpc.ServerStream {
70+
return &serverStreamWrapper{ss, ctx}
71+
}
72+
73+
func (w *serverStreamWrapper) Context() context.Context {
74+
return w.ctx
75+
}
76+
77+
func NewStreamInterceptor(l *log.Logger) grpc.StreamServerInterceptor {
78+
return func(srv interface{}, ss grpc.ServerStream, info *grpc.StreamServerInfo, handler grpc.StreamHandler) error {
79+
ctx := ss.Context()
80+
if mdata, ok := metadata.FromIncomingContext(ctx); ok {
81+
keys := make([]string, 0, len(mdata))
82+
for k, _ := range mdata {
83+
keys = append(keys, k)
84+
}
85+
sort.Strings(keys)
86+
87+
logContext := l.With()
88+
for _, sortedKey := range keys {
89+
values := mdata.Get(sortedKey)
90+
logContext = logContext.Strs(sortedKey, values)
91+
}
92+
mdataLogger := logContext.Logger()
93+
ctx = mdataLogger.WithContext(ctx)
94+
}
95+
return handler(srv, newServerStreamWrapper(ss, ctx))
96+
}
97+
}

‎ocis-pkg/service/grpc/service.go‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ import (
2121
ociscrypto "github.com/owncloud/ocis/v2/ocis-pkg/crypto"
2222
"github.com/owncloud/ocis/v2/ocis-pkg/log"
2323
"github.com/owncloud/ocis/v2/ocis-pkg/registry"
24+
ocisgrpcmeta "github.com/owncloud/ocis/v2/ocis-pkg/service/grpc/handler/metadata"
2425
)
2526

2627
// Service simply wraps the go-micro grpc service.
@@ -64,6 +65,7 @@ func NewServiceWithClient(client client.Client, opts ...Option) (Service, error)
6465
mtracer.NewHandlerWrapper(
6566
mtracer.WithTraceProvider(sopts.TraceProvider),
6667
),
68+
ocisgrpcmeta.NewMetadataLogHandler(&sopts.Logger),
6769
}
6870
if sopts.Logger.GetLevel() == zerolog.DebugLevel {
6971
handlerWrappers = append(handlerWrappers, LogHandler(&sopts.Logger))

‎services/collaboration/pkg/middleware/accesslog.go‎

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -36,3 +36,27 @@ func AccessLog(logger log.Logger) func(http.Handler) http.Handler {
3636
})
3737
}
3838
}
39+
40+
func AccessLog2() func(http.Handler) http.Handler {
41+
return func(next http.Handler) http.Handler {
42+
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
43+
logger := log.Ctx(r.Context())
44+
45+
start := time.Now()
46+
requestID := middleware.GetReqID(r.Context())
47+
// add Request Id to all responses
48+
w.Header().Set(middleware.RequestIDHeader, requestID)
49+
wrap := middleware.NewWrapResponseWriter(w, r.ProtoMajor)
50+
next.ServeHTTP(wrap, r)
51+
52+
spanContext := trace.SpanContextFromContext(r.Context())
53+
logger.Info().
54+
Str("traceid", spanContext.TraceID().String()).
55+
Str("wopi-action", r.Header.Get("X-WOPI-Override")).
56+
Int("status", wrap.Status()).
57+
Dur("duration", time.Since(start)).
58+
Int("bytes", wrap.BytesWritten()).
59+
Msg("access-log")
60+
})
61+
}
62+
}

‎services/collaboration/pkg/server/grpc/server.go‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ package grpc
22

33
import (
44
appproviderv1beta1 "github.com/cs3org/go-cs3apis/cs3/app/provider/v1beta1"
5+
"github.com/owncloud/ocis/v2/ocis-pkg/service/grpc/handler/metadata"
56
"github.com/owncloud/ocis/v2/ocis-pkg/tracing"
67
svc "github.com/owncloud/ocis/v2/services/collaboration/pkg/service/grpc/v0"
78
"go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc"
@@ -20,6 +21,12 @@ func Server(opts ...Option) (*grpc.Server, func(), error) {
2021
otelgrpc.WithPropagators(tracing.GetPropagator()),
2122
),
2223
),
24+
grpc.ChainUnaryInterceptor(
25+
metadata.NewUnaryInterceptor(&options.Logger),
26+
),
27+
grpc.ChainStreamInterceptor(
28+
metadata.NewStreamInterceptor(&options.Logger),
29+
),
2330
}
2431
grpcServer := grpc.NewServer(grpcOpts...)
2532

‎services/collaboration/pkg/server/http/server.go‎

Lines changed: 15 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,6 @@ import (
77
"github.com/go-chi/chi/v5"
88
chimiddleware "github.com/go-chi/chi/v5/middleware"
99
"github.com/owncloud/ocis/v2/ocis-pkg/account"
10-
"github.com/owncloud/ocis/v2/ocis-pkg/log"
1110
"github.com/owncloud/ocis/v2/ocis-pkg/middleware"
1211
"github.com/owncloud/ocis/v2/ocis-pkg/service/http"
1312
"github.com/owncloud/ocis/v2/ocis-pkg/tracing"
@@ -44,9 +43,8 @@ func Server(opts ...Option) (http.Service, error) {
4443
options.Config.Service.Name+"."+options.Config.App.Name,
4544
version.GetString(),
4645
),
47-
colabmiddleware.AccessLog(
48-
options.Logger,
49-
),
46+
middleware.NewContextLogger(&options.Logger),
47+
colabmiddleware.AccessLog2(),
5048
middleware.ExtractAccountUUID(
5149
account.Logger(options.Logger),
5250
account.JWTSecret(options.Config.TokenManager.JWTSecret),
@@ -95,19 +93,21 @@ func Server(opts ...Option) (http.Service, error) {
9593
// prepareRoutes will prepare all the implemented routes
9694
func prepareRoutes(r *chi.Mux, options Options) {
9795
adapter := options.Adapter
98-
logger := options.Logger
96+
//logger := options.Logger
9997
// prepare basic logger for the request
100-
r.Use(func(h stdhttp.Handler) stdhttp.Handler {
101-
return stdhttp.HandlerFunc(func(w stdhttp.ResponseWriter, r *stdhttp.Request) {
102-
ctx := logger.With().
103-
Str(log.RequestIDString, r.Header.Get("X-Request-ID")).
104-
Str("proto", r.Proto).
105-
Str("method", r.Method).
106-
Str("path", r.URL.Path).
107-
Logger().WithContext(r.Context())
108-
h.ServeHTTP(w, r.WithContext(ctx))
98+
/*
99+
r.Use(func(h stdhttp.Handler) stdhttp.Handler {
100+
return stdhttp.HandlerFunc(func(w stdhttp.ResponseWriter, r *stdhttp.Request) {
101+
ctx := logger.With().
102+
Str(log.RequestIDString, r.Header.Get("X-Request-ID")).
103+
Str("proto", r.Proto).
104+
Str("method", r.Method).
105+
Str("path", r.URL.Path).
106+
Logger().WithContext(r.Context())
107+
h.ServeHTTP(w, r.WithContext(ctx))
108+
})
109109
})
110-
})
110+
*/
111111
r.Route("/wopi", func(r chi.Router) {
112112

113113
r.Get("/", func(w stdhttp.ResponseWriter, r *stdhttp.Request) {

‎services/collaboration/pkg/service/grpc/v0/service.go‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,8 @@ func (s *Service) OpenInApp(
6767
ctx context.Context,
6868
req *appproviderv1beta1.OpenInAppRequest,
6969
) (*appproviderv1beta1.OpenInAppResponse, error) {
70+
ll := log.Ctx(ctx)
71+
ll.Error().Msg("collaboration openinapp") //FIXME: this is just for testing. It needs to be removed.
7072

7173
// get the current user
7274
var user *userv1beta1.User = nil

0 commit comments

Comments
 (0)