From f7dcc29e3d759e74b87f162a687b5b6daa5b973b Mon Sep 17 00:00:00 2001
From: Rintaro Okamura <rintaro.okamura@gmail.com>
Date: Thu, 19 Nov 2020 17:58:56 +0900
Subject: [PATCH] :construction: wip: add AccessLogInterceptor
 (UnaryInterceptor)

Signed-off-by: Rintaro Okamura <rintaro.okamura@gmail.com>
---
 internal/net/grpc/interceptor.go     | 63 ++++++++++++++++++++++++++++
 pkg/agent/core/ngt/usecase/agentd.go |  5 ++-
 2 files changed, 67 insertions(+), 1 deletion(-)

diff --git a/internal/net/grpc/interceptor.go b/internal/net/grpc/interceptor.go
index ee34e00118c..8868ab5c79f 100644
--- a/internal/net/grpc/interceptor.go
+++ b/internal/net/grpc/interceptor.go
@@ -19,7 +19,11 @@ package grpc
 
 import (
 	"context"
+	"path"
+	"time"
 
+	"github.com/vdaas/vald/internal/log"
+	"github.com/vdaas/vald/internal/observability/trace"
 	"github.com/vdaas/vald/internal/safety"
 	"google.golang.org/grpc"
 )
@@ -61,3 +65,62 @@ func RecoverStreamInterceptor() StreamServerInterceptor {
 		})()
 	}
 }
+
+func AccessLogInterceptor() UnaryServerInterceptor {
+	return func(
+		ctx context.Context,
+		req interface{},
+		info *grpc.UnaryServerInfo,
+		handler grpc.UnaryHandler,
+	) (resp interface{}, err error) {
+		var traceID string
+
+		span := trace.FromContext(ctx)
+		if span != nil {
+			traceID = span.SpanContext().TraceID.String()
+		}
+
+		start := time.Now()
+
+		resp, err = handler(ctx, req)
+
+		latency := float64(time.Since(start)) / float64(time.Second)
+		startTime := float64(start.UnixNano()) / float64(time.Second)
+
+		service, method := parseMethod(info.FullMethod)
+
+		if err != nil {
+			log.Error(
+				"rpc call proceeded",
+				map[string]interface{}{
+					"grpcService": service,
+					"grpcMethod":  method,
+					"startTime":   startTime,
+					"latency":     latency,
+					"traceID":     traceID,
+					"error":       err,
+				},
+			)
+		} else {
+			log.Info(
+				"rpc call proceeded",
+				map[string]interface{}{
+					"grpcService": service,
+					"grpcMethod":  method,
+					"startTime":   startTime,
+					"latency":     latency,
+					"traceID":     traceID,
+				},
+			)
+		}
+
+		return resp, err
+	}
+}
+
+func parseMethod(fullMethod string) (service, method string) {
+	service = path.Dir(fullMethod)[1:]
+	method = path.Base(fullMethod)
+
+	return service, method
+}
diff --git a/pkg/agent/core/ngt/usecase/agentd.go b/pkg/agent/core/ngt/usecase/agentd.go
index dbd939453dd..6c9e7ac9ae8 100644
--- a/pkg/agent/core/ngt/usecase/agentd.go
+++ b/pkg/agent/core/ngt/usecase/agentd.go
@@ -78,7 +78,10 @@ func New(cfg *config.Data) (r runner.Runner, err error) {
 			agent.RegisterAgentServer(srv, g)
 		}),
 		server.WithGRPCOption(
-			grpc.ChainUnaryInterceptor(grpc.RecoverInterceptor()),
+			grpc.ChainUnaryInterceptor(
+				grpc.RecoverInterceptor(),
+				grpc.AccessLogInterceptor(),
+			),
 			grpc.ChainStreamInterceptor(grpc.RecoverStreamInterceptor()),
 		),
 		server.WithPreStartFunc(func() error {