Add middleware to support tracing-like functionalities

Dockerfile

@@ -70,7 +70,7 @@ ENV TB_ROOT_PATH=/app \
     TB_DEFAULT_NAMESPACE=default \
     TB_DEFAULT_CREDENTIALHOLDER=admin \
     TB_LOGFILE_PATH=/app/log/tumblebug.log \
-    TB_LOGFILE_MAXSIZE=10 \
+    TB_LOGFILE_MAXSIZE=1000 \
     TB_LOGFILE_MAXBACKUPS=3 \
     TB_LOGFILE_MAXAGE=30 \
     TB_LOGFILE_COMPRESS=false \

src/api/rest/server/middlewares/requestIdAndDetailsIssuer.go

@@ -0,0 +1,46 @@
+package middlewares
+
+import (
+	"fmt"
+	"time"
+
+	"github.com/cloud-barista/cb-tumblebug/src/core/common"
+	"github.com/labstack/echo/v4"
+)
+
+func RequestIdAndDetailsIssuer(next echo.HandlerFunc) echo.HandlerFunc {
+	return func(c echo.Context) error {
+		// log.Debug().Msg("Start - Request ID middleware")
+
+		// Make X-Request-Id visible to all handlers
+		c.Response().Header().Set("Access-Control-Expose-Headers", echo.HeaderXRequestID)
+
+		// Get or generate Request ID
+		reqID := c.Request().Header.Get(echo.HeaderXRequestID)
+		if reqID == "" {
+			reqID = fmt.Sprintf("%d", time.Now().UnixNano())
+		}
+
+		// Set Request on the context
+		c.Set("RequestID", reqID)
+
+		//log.Trace().Msgf("(Request ID middleware) Request ID: %s", reqID)
+		if _, ok := common.RequestMap.Load(reqID); ok {
+			return fmt.Errorf("the X-Request-Id is already in use")
+		}
+
+		// Set "X-Request-Id" in response header
+		c.Response().Header().Set(echo.HeaderXRequestID, reqID)
+
+		details := common.RequestDetails{
+			StartTime:   time.Now(),
+			Status:      "Handling",
+			RequestInfo: common.ExtractRequestInfo(c.Request()),
+		}
+		common.RequestMap.Store(reqID, details)
+
+		// log.Debug().Msg("End - Request ID middleware")
+
+		return next(c)
+	}
+}

src/api/rest/server/middlewares/custom-middleware/custom-middleware.go → src/api/rest/server/middlewares/responseBodyDump.go

@@ -3,121 +3,14 @@ package middlewares
 import (
 	"bytes"
 	"encoding/json"
-	"fmt"
-	"strings"
 	"time"
 
 	"github.com/cloud-barista/cb-tumblebug/src/core/common"
 	"github.com/labstack/echo/v4"
 	"github.com/labstack/echo/v4/middleware"
-
 	"github.com/rs/zerolog/log"
 )
 
-func Zerologger(skipPatterns [][]string) echo.MiddlewareFunc {
-	return middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{
-		Skipper: func(c echo.Context) bool {
-			path := c.Request().URL.Path
-			query := c.Request().URL.RawQuery
-			for _, patterns := range skipPatterns {
-				isAllMatched := true
-				for _, pattern := range patterns {
-					if !strings.Contains(path+query, pattern) {
-						isAllMatched = false
-						break
-					}
-				}
-				if isAllMatched {
-					return true
-				}
-			}
-			return false
-		},
-		LogError:         true,
-		LogRequestID:     true,
-		LogRemoteIP:      true,
-		LogHost:          true,
-		LogMethod:        true,
-		LogURI:           true,
-		LogUserAgent:     false,
-		LogStatus:        true,
-		LogLatency:       true,
-		LogContentLength: true,
-		LogResponseSize:  true,
-		// HandleError:      true, // forwards error to the global error handler, so it can decide appropriate status code
-		LogValuesFunc: func(c echo.Context, v middleware.RequestLoggerValues) error {
-			if v.Error == nil {
-				log.Info().
-					Str("id", v.RequestID).
-					Str("client_ip", v.RemoteIP).
-					//Str("host", v.Host).
-					Str("method", v.Method).
-					Str("URI", v.URI).
-					//Str("user_agent", v.UserAgent).
-					Int("status", v.Status).
-					//Int64("latency", v.Latency.Nanoseconds()).
-					Str("latency_human", v.Latency.String()).
-					Str("bytes_in", v.ContentLength).
-					Int64("bytes_out", v.ResponseSize).
-					Msg("request")
-			} else {
-				log.Error().
-					Err(v.Error).
-					Str("id", v.RequestID).
-					Str("client_ip", v.RemoteIP).
-					// Str("host", v.Host).
-					Str("method", v.Method).
-					Str("URI", v.URI).
-					//Str("user_agent", v.UserAgent).
-					Int("status", v.Status).
-					// Int64("latency", v.Latency.Nanoseconds()).
-					Str("latency_human", v.Latency.String()).
-					Str("bytes_in", v.ContentLength).
-					Int64("bytes_out", v.ResponseSize).
-					Msg("request error")
-			}
-			return nil
-		},
-	})
-}
-
-func RequestIdAndDetailsIssuer(next echo.HandlerFunc) echo.HandlerFunc {
-	return func(c echo.Context) error {
-		// log.Debug().Msg("Start - Request ID middleware")
-
-		// Make X-Request-Id visible to all handlers
-		c.Response().Header().Set("Access-Control-Expose-Headers", echo.HeaderXRequestID)
-
-		// Get or generate Request ID
-		reqID := c.Request().Header.Get(echo.HeaderXRequestID)
-		if reqID == "" {
-			reqID = fmt.Sprintf("%d", time.Now().UnixNano())
-		}
-
-		// Set Request on the context
-		c.Set("RequestID", reqID)
-
-		//log.Trace().Msgf("(Request ID middleware) Request ID: %s", reqID)
-		if _, ok := common.RequestMap.Load(reqID); ok {
-			return fmt.Errorf("the X-Request-Id is already in use")
-		}
-
-		// Set "X-Request-Id" in response header
-		c.Response().Header().Set(echo.HeaderXRequestID, reqID)
-
-		details := common.RequestDetails{
-			StartTime:   time.Now(),
-			Status:      "Handling",
-			RequestInfo: common.ExtractRequestInfo(c.Request()),
-		}
-		common.RequestMap.Store(reqID, details)
-
-		// log.Debug().Msg("End - Request ID middleware")
-
-		return next(c)
-	}
-}
-
 func ResponseBodyDump() echo.MiddlewareFunc {
 	return middleware.BodyDumpWithConfig(middleware.BodyDumpConfig{
 		Skipper: func(c echo.Context) bool {

src/api/rest/server/middlewares/tracing.go

@@ -0,0 +1,70 @@
+package middlewares
+
+import (
+	"context"
+	"fmt"
+	"time"
+
+	"github.com/cloud-barista/cb-tumblebug/src/core/common/logger"
+	"github.com/labstack/echo/v4"
+	"github.com/rs/zerolog/log"
+	// "go.opentelemetry.io/otel"
+)
+
+// Define Tracing middleware
+func TracingMiddleware(next echo.HandlerFunc) echo.HandlerFunc {
+	return func(c echo.Context) error {
+
+		// TODO: Be able to use this code when OpenTelemetry is integrated
+		// Start a new tracing context
+		// tracer := otel.Tracer("example-tracer")
+		// ctx, span := tracer.Start(c.Request().Context(), c.Path())
+		// defer span.End()
+
+		// Store trace and span IDs in the context
+		// traceId := span.SpanContext().TraceID().String()
+		// spanId := span.SpanContext().SpanID().String()
+
+		// Get the context
+		ctx := c.Request().Context()
+
+		// [NOTE]
+		// For now, we will use the request ID as the trace ID
+		// and generate a new span ID for each request
+		traceId := c.Response().Header().Get(echo.HeaderXRequestID)
+		spanId := fmt.Sprintf("%d", time.Now().UnixNano())
+
+		ctx = context.WithValue(ctx, logger.TraceIdKey, traceId)
+		ctx = context.WithValue(ctx, logger.SpanIdKey, spanId)
+
+		// Create a childLogger with trace_id and span_id and store it in the context
+		childLogger := log.With().Str(string(logger.TraceIdKey), traceId).Str(string(logger.SpanIdKey), spanId).Logger()
+		ctx = childLogger.WithContext(ctx)
+
+		// Set the context in the request
+		c.SetRequest(c.Request().WithContext(ctx))
+
+		// [Tracing log] when the request is received
+		traceLogger := logger.GetTraceLogger()
+
+		traceLogger.Trace().
+			Str(string(logger.TraceIdKey), traceId).
+			Str(string(logger.SpanIdKey), spanId).
+			Str("URI", c.Request().RequestURI).
+			Msg("[tracing] receive request")
+
+		// [Tracing log] before the response is sent
+		// Hooks: Before Response
+		c.Response().Before(func() {
+			// Log the request details
+			traceLogger.Trace().
+				Str(string(logger.TraceIdKey), traceId).
+				Str(string(logger.SpanIdKey), spanId).
+				Str("URI", c.Request().RequestURI).
+				Msg("[tracing] send response")
+		})
+
+		// Call the next handler
+		return next(c)
+	}
+}

src/api/rest/server/middlewares/zerologger.go

@@ -0,0 +1,77 @@
+package middlewares
+
+import (
+	"strings"
+
+	"github.com/labstack/echo/v4"
+	"github.com/labstack/echo/v4/middleware"
+
+	"github.com/rs/zerolog/log"
+)
+
+func Zerologger(skipPatterns [][]string) echo.MiddlewareFunc {
+	return middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{
+		Skipper: func(c echo.Context) bool {
+			path := c.Request().URL.Path
+			query := c.Request().URL.RawQuery
+			for _, patterns := range skipPatterns {
+				isAllMatched := true
+				for _, pattern := range patterns {
+					if !strings.Contains(path+query, pattern) {
+						isAllMatched = false
+						break
+					}
+				}
+				if isAllMatched {
+					return true
+				}
+			}
+			return false
+		},
+		LogError:         true,
+		LogRequestID:     true,
+		LogRemoteIP:      true,
+		LogHost:          true,
+		LogMethod:        true,
+		LogURI:           true,
+		LogUserAgent:     false,
+		LogStatus:        true,
+		LogLatency:       true,
+		LogContentLength: true,
+		LogResponseSize:  true,
+		// HandleError:      true, // forwards error to the global error handler, so it can decide appropriate status code
+		LogValuesFunc: func(c echo.Context, v middleware.RequestLoggerValues) error {
+			if v.Error == nil {
+				log.Info().
+					Str("id", v.RequestID).
+					Str("client_ip", v.RemoteIP).
+					//Str("host", v.Host).
+					Str("method", v.Method).
+					Str("URI", v.URI).
+					//Str("user_agent", v.UserAgent).
+					Int("status", v.Status).
+					//Int64("latency", v.Latency.Nanoseconds()).
+					Str("latency_human", v.Latency.String()).
+					Str("bytes_in", v.ContentLength).
+					Int64("bytes_out", v.ResponseSize).
+					Msg("request")
+			} else {
+				log.Error().
+					Err(v.Error).
+					Str("id", v.RequestID).
+					Str("client_ip", v.RemoteIP).
+					// Str("host", v.Host).
+					Str("method", v.Method).
+					Str("URI", v.URI).
+					//Str("user_agent", v.UserAgent).
+					Int("status", v.Status).
+					// Int64("latency", v.Latency.Nanoseconds()).
+					Str("latency_human", v.Latency.String()).
+					Str("bytes_in", v.ContentLength).
+					Int64("bytes_out", v.ResponseSize).
+					Msg("request error")
+			}
+			return nil
+		},
+	})
+}

src/api/rest/server/server.go

@@ -33,8 +33,8 @@ import (
 	rest_common "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/common"
 	rest_label "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/common/label"
 	rest_infra "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/infra"
+	"github.com/cloud-barista/cb-tumblebug/src/api/rest/server/middlewares"
 	"github.com/cloud-barista/cb-tumblebug/src/api/rest/server/middlewares/authmw"
-	middlewares "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/middlewares/custom-middleware"
 	rest_resource "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/resource"
 	rest_netutil "github.com/cloud-barista/cb-tumblebug/src/api/rest/server/util"
 
@@ -109,6 +109,9 @@ func RunServer(port string) {
 	// Custom middleware for RequestID and RequestDetails
 	e.Use(middlewares.RequestIdAndDetailsIssuer)
 
+	// Custom middleware for tracing
+	e.Use(middlewares.TracingMiddleware)
+
 	// Custom middleware for ResponseBodyDump
 	e.Use(middlewares.ResponseBodyDump())