github.com/wfusion/gofusion@v1.1.14/http/middleware/logging.go (about)

     1  package middleware
     2  
     3  import (
     4  	"context"
     5  	"fmt"
     6  	"log"
     7  	"net/http"
     8  	"net/url"
     9  	"strconv"
    10  	"time"
    11  
    12  	"github.com/gin-gonic/gin"
    13  	"github.com/go-resty/resty/v2"
    14  	"github.com/iancoleman/strcase"
    15  	"github.com/spf13/cast"
    16  	"github.com/wfusion/gofusion/config"
    17  	"github.com/wfusion/gofusion/metrics"
    18  
    19  	"github.com/wfusion/gofusion/common/utils"
    20  	"github.com/wfusion/gofusion/common/utils/clone"
    21  	"github.com/wfusion/gofusion/http/consts"
    22  
    23  	fusCtx "github.com/wfusion/gofusion/context"
    24  	fusLog "github.com/wfusion/gofusion/log"
    25  )
    26  
    27  var (
    28  	metricsLatencyKey     = []string{"http", "latency"}
    29  	metricsTotalKey       = []string{"http", "request", "total"}
    30  	metricsLatencyBuckets = []float64{
    31  		10, 15, 20, 30, 40, 50, 60, 70, 80, 90, 99, 99.9,
    32  		100, 150, 200, 300, 400, 500, 600, 700, 800, 900, 990, 999,
    33  		1000, 1500, 2000, 3000, 4000, 5000, 6000, 7000, 8000, 9000, 9900, 9990,
    34  		10000, 15000, 20000, 30000, 40000, 50000, 60000,
    35  	}
    36  )
    37  
    38  func logging(rootCtx context.Context, c *gin.Context, logger resty.Logger, rawURL *url.URL, metricsHeaders []string,
    39  	appName string) {
    40  	ctx := fusCtx.New(fusCtx.Gin(c))
    41  	cost := float64(consts.GetReqCost(c)) / float64(time.Millisecond)
    42  	status := c.Writer.Status()
    43  	fields := fusLog.Fields{
    44  		"path":        rawURL.Path,
    45  		"method":      c.Request.Method,
    46  		"status":      status,
    47  		"referer":     c.Request.Referer(),
    48  		"req_size":    c.Request.ContentLength,
    49  		"rsp_size":    c.Writer.Size(),
    50  		"cost":        cost,
    51  		"user_agent":  c.Request.UserAgent(),
    52  		"client_addr": c.ClientIP(),
    53  	}
    54  
    55  	// skip health check logging
    56  	if rawURL.Path == "/health" && c.Request.Method == http.MethodGet {
    57  		return
    58  	}
    59  
    60  	msg := fmt.Sprintf(
    61  		"%s -> %s %s %d %d %d (%.2fms)",
    62  		c.ClientIP(), utils.LocalIP.String(),
    63  		strconv.Quote(fmt.Sprintf("%s %s", c.Request.Method, rawURL)),
    64  		c.Request.ContentLength, c.Writer.Size(), status, cost,
    65  	)
    66  
    67  	if logger != nil {
    68  		switch {
    69  		case status < http.StatusBadRequest:
    70  			logger.Debugf(msg, ctx, fields)
    71  		case status >= http.StatusBadRequest && status < http.StatusInternalServerError:
    72  			logger.Warnf(msg, ctx, fields)
    73  		default:
    74  			logger.Errorf(msg, ctx, fields)
    75  		}
    76  	} else {
    77  		log.Printf(msg+" %s", utils.MustJsonMarshal(fields))
    78  	}
    79  
    80  	headerLabels := make(map[string]string, len(metricsHeaders))
    81  	for _, metricsHeader := range metricsHeaders {
    82  		headerLabels[metricsHeader] = c.Request.Header.Get(metricsHeader)
    83  	}
    84  
    85  	go metricsLogging(rootCtx, appName, rawURL.Path, c.Request.Method, headerLabels,
    86  		status, c.Writer.Size(), c.Request.ContentLength, cost)
    87  }
    88  
    89  func metricsLogging(ctx context.Context, appName, path, method string, headerLabels map[string]string,
    90  	status, rspSize int, reqSize int64, cost float64) {
    91  	select {
    92  	case <-ctx.Done():
    93  		return
    94  	default:
    95  	}
    96  
    97  	labels := []metrics.Label{
    98  		{Key: "path", Value: path},
    99  		{Key: "method", Value: method},
   100  		{Key: "status", Value: cast.ToString(status)},
   101  		{Key: "req_size", Value: cast.ToString(reqSize)},
   102  		{Key: "rsp_size", Value: cast.ToString(rspSize)},
   103  	}
   104  	for k, v := range headerLabels {
   105  		labels = append(labels, metrics.Label{Key: strcase.ToSnake(k), Value: v})
   106  	}
   107  
   108  	app := config.Use(appName).AppName()
   109  	latencyKey := append([]string{app}, metricsLatencyKey...)
   110  	totalKey := append([]string{app}, metricsTotalKey...)
   111  	for _, m := range metrics.Internal(metrics.AppName(appName)) {
   112  		select {
   113  		case <-ctx.Done():
   114  			return
   115  		default:
   116  			if m.IsEnableServiceLabel() {
   117  				m.IncrCounter(ctx, totalKey, 1, metrics.Labels(labels))
   118  				m.AddSample(ctx, latencyKey, cost, metrics.Labels(labels),
   119  					metrics.PrometheusBuckets(metricsLatencyBuckets))
   120  			} else {
   121  				m.IncrCounter(ctx, metricsTotalKey, 1, metrics.Labels(labels))
   122  				m.AddSample(ctx, metricsLatencyKey, cost, metrics.Labels(labels),
   123  					metrics.PrometheusBuckets(metricsLatencyBuckets))
   124  			}
   125  		}
   126  	}
   127  }
   128  
   129  func Logging(ctx context.Context, appName string, metricsHeaders []string, logger resty.Logger) gin.HandlerFunc {
   130  	return func(c *gin.Context) {
   131  		reqURL := clone.Clone(c.Request.URL)
   132  		defer logging(ctx, c, logger, reqURL, metricsHeaders, appName)
   133  
   134  		c.Next()
   135  	}
   136  
   137  }