From 1c86e1e8013d03b1baa17eb1335299875141030c Mon Sep 17 00:00:00 2001 From: Marcus Efraimsson Date: Thu, 17 Oct 2024 15:57:20 +0200 Subject: [PATCH] Logging and metrics handler middlewares (#1117) Adds logging and metrics handler middlewares that (for now) can be used from Grafana. --- backend/logger_middleware.go | 223 ++++++++++++++++++++++++++++++++++ backend/metrics_middleware.go | 154 +++++++++++++++++++++++ 2 files changed, 377 insertions(+) create mode 100644 backend/logger_middleware.go create mode 100644 backend/metrics_middleware.go diff --git a/backend/logger_middleware.go b/backend/logger_middleware.go new file mode 100644 index 000000000..d92dbc8f0 --- /dev/null +++ b/backend/logger_middleware.go @@ -0,0 +1,223 @@ +package backend + +import ( + "context" + "errors" + "time" + + "github.com/grafana/grafana-plugin-sdk-go/backend/log" +) + +// NewLoggerMiddleware creates a new HandlerMiddleware that will +// log requests. +func NewLoggerMiddleware(logger log.Logger, extractLogParamsFn func(ctx context.Context, pCtx PluginContext) []any) HandlerMiddleware { + return HandlerMiddlewareFunc(func(next Handler) Handler { + return &loggerMiddleware{ + BaseHandler: NewBaseHandler(next), + logger: logger, + extractLogParamsFn: extractLogParamsFn, + } + }) +} + +type loggerMiddleware struct { + BaseHandler + logger log.Logger + extractLogParamsFn func(ctx context.Context, pCtx PluginContext) []any +} + +func (m *loggerMiddleware) logRequest(ctx context.Context, pCtx PluginContext, fn handlerWrapperFunc) error { + start := time.Now() + logParams := []any{} + + if m.extractLogParamsFn != nil { + logParams = append(logParams, m.extractLogParamsFn(ctx, pCtx)...) + } + + ctxLogger := m.logger.FromContext(ctx) + ctxLogger.Debug("Plugin Request Started", logParams...) + + status, err := fn(ctx) + logParams = append(logParams, "status", status.String(), "duration", time.Since(start).String()) + if err != nil { + logParams = append(logParams, "error", err) + } + logParams = append(logParams, "statusSource", string(ErrorSourceFromContext(ctx))) + + logFunc := ctxLogger.Info + + if status > RequestStatusCancelled { + logFunc = ctxLogger.Error + } + + logFunc("Plugin Request Completed", logParams...) + + return err +} + +func (m *loggerMiddleware) QueryData(ctx context.Context, req *QueryDataRequest) (*QueryDataResponse, error) { + if req == nil { + return m.BaseHandler.QueryData(ctx, req) + } + + var resp *QueryDataResponse + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.QueryData(ctx, req) + + status := RequestStatusFromQueryDataResponse(resp, innerErr) + if innerErr != nil { + return status, innerErr + } else if resp == nil { + return RequestStatusError, errors.New("both response and error are nil, but one must be provided") + } + + ctxLogger := m.logger.FromContext(ctx) + for refID, dr := range resp.Responses { + if dr.Error != nil { + logParams := []any{ + "refID", refID, + "status", int(dr.Status), + "error", dr.Error, + "statusSource", dr.ErrorSource.String(), + } + ctxLogger.Error("Partial data response error", logParams...) + } + } + + return status, nil + }) + + return resp, err +} + +func (m *loggerMiddleware) CallResource(ctx context.Context, req *CallResourceRequest, sender CallResourceResponseSender) error { + if req == nil { + return m.BaseHandler.CallResource(ctx, req, sender) + } + + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + innerErr := m.BaseHandler.CallResource(ctx, req, sender) + return RequestStatusFromError(innerErr), innerErr + }) + + return err +} + +func (m *loggerMiddleware) CheckHealth(ctx context.Context, req *CheckHealthRequest) (*CheckHealthResult, error) { + if req == nil { + return m.BaseHandler.CheckHealth(ctx, req) + } + + var resp *CheckHealthResult + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.CheckHealth(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} + +func (m *loggerMiddleware) CollectMetrics(ctx context.Context, req *CollectMetricsRequest) (*CollectMetricsResult, error) { + if req == nil { + return m.BaseHandler.CollectMetrics(ctx, req) + } + + var resp *CollectMetricsResult + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.CollectMetrics(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} + +func (m *loggerMiddleware) SubscribeStream(ctx context.Context, req *SubscribeStreamRequest) (*SubscribeStreamResponse, error) { + if req == nil { + return m.BaseHandler.SubscribeStream(ctx, req) + } + + var resp *SubscribeStreamResponse + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.SubscribeStream(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} + +func (m *loggerMiddleware) PublishStream(ctx context.Context, req *PublishStreamRequest) (*PublishStreamResponse, error) { + if req == nil { + return m.BaseHandler.PublishStream(ctx, req) + } + + var resp *PublishStreamResponse + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.PublishStream(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} + +func (m *loggerMiddleware) RunStream(ctx context.Context, req *RunStreamRequest, sender *StreamSender) error { + if req == nil { + return m.BaseHandler.RunStream(ctx, req, sender) + } + + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + innerErr := m.BaseHandler.RunStream(ctx, req, sender) + return RequestStatusFromError(innerErr), innerErr + }) + + return err +} + +func (m *loggerMiddleware) ValidateAdmission(ctx context.Context, req *AdmissionRequest) (*ValidationResponse, error) { + if req == nil { + return m.BaseHandler.ValidateAdmission(ctx, req) + } + + var resp *ValidationResponse + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.ValidateAdmission(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} + +func (m *loggerMiddleware) MutateAdmission(ctx context.Context, req *AdmissionRequest) (*MutationResponse, error) { + if req == nil { + return m.BaseHandler.MutateAdmission(ctx, req) + } + + var resp *MutationResponse + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.MutateAdmission(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} + +func (m *loggerMiddleware) ConvertObjects(ctx context.Context, req *ConversionRequest) (*ConversionResponse, error) { + if req == nil { + return m.BaseHandler.ConvertObjects(ctx, req) + } + + var resp *ConversionResponse + err := m.logRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.ConvertObjects(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} diff --git a/backend/metrics_middleware.go b/backend/metrics_middleware.go new file mode 100644 index 000000000..ba81af90a --- /dev/null +++ b/backend/metrics_middleware.go @@ -0,0 +1,154 @@ +package backend + +import ( + "context" + + "github.com/prometheus/client_golang/prometheus" +) + +// NewMetricsMiddleware creates a new HandlerMiddleware that will +// record metrics for requests. +func NewMetricsMiddleware(registerer prometheus.Registerer, namespace string, includePluginID bool) HandlerMiddleware { + labelNames := []string{"endpoint", "status", "status_source"} + + if includePluginID { + labelNames = append(labelNames, "plugin_id") + } + + requestCounter := prometheus.NewCounterVec(prometheus.CounterOpts{ + Namespace: namespace, + Subsystem: "plugin", + Name: "request_total", + Help: "The total amount of plugin requests", + }, labelNames) + + registerer.MustRegister(requestCounter) + + return HandlerMiddlewareFunc(func(next Handler) Handler { + return &metricsMiddleware{ + BaseHandler: NewBaseHandler(next), + requestCounter: requestCounter, + includePluginID: includePluginID, + } + }) +} + +type metricsMiddleware struct { + BaseHandler + requestCounter *prometheus.CounterVec + includePluginID bool +} + +func (m *metricsMiddleware) instrumentRequest(ctx context.Context, pCtx PluginContext, fn handlerWrapperFunc) error { + status, err := fn(ctx) + endpoint := EndpointFromContext(ctx) + + labelValues := []string{endpoint.String(), status.String(), string(ErrorSourceFromContext(ctx))} + + if m.includePluginID { + labelValues = append(labelValues, pCtx.PluginID) + } + + m.requestCounter.WithLabelValues(labelValues...).Inc() + return err +} + +func (m *metricsMiddleware) QueryData(ctx context.Context, req *QueryDataRequest) (*QueryDataResponse, error) { + var resp *QueryDataResponse + err := m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.QueryData(ctx, req) + return RequestStatusFromQueryDataResponse(resp, innerErr), innerErr + }) + + return resp, err +} + +func (m *metricsMiddleware) CallResource(ctx context.Context, req *CallResourceRequest, sender CallResourceResponseSender) error { + return m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + innerErr := m.BaseHandler.CallResource(ctx, req, sender) + return RequestStatusFromError(innerErr), innerErr + }) +} + +func (m *metricsMiddleware) CheckHealth(ctx context.Context, req *CheckHealthRequest) (*CheckHealthResult, error) { + var resp *CheckHealthResult + err := m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.CheckHealth(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} + +func (m *metricsMiddleware) CollectMetrics(ctx context.Context, req *CollectMetricsRequest) (*CollectMetricsResult, error) { + var resp *CollectMetricsResult + err := m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.CollectMetrics(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + return resp, err +} + +func (m *metricsMiddleware) SubscribeStream(ctx context.Context, req *SubscribeStreamRequest) (*SubscribeStreamResponse, error) { + var resp *SubscribeStreamResponse + err := m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.SubscribeStream(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + return resp, err +} + +func (m *metricsMiddleware) PublishStream(ctx context.Context, req *PublishStreamRequest) (*PublishStreamResponse, error) { + var resp *PublishStreamResponse + err := m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.PublishStream(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + return resp, err +} + +func (m *metricsMiddleware) RunStream(ctx context.Context, req *RunStreamRequest, sender *StreamSender) error { + err := m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + innerErr := m.BaseHandler.RunStream(ctx, req, sender) + return RequestStatusFromError(innerErr), innerErr + }) + return err +} + +func (m *metricsMiddleware) ValidateAdmission(ctx context.Context, req *AdmissionRequest) (*ValidationResponse, error) { + var resp *ValidationResponse + err := m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.ValidateAdmission(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} + +func (m *metricsMiddleware) MutateAdmission(ctx context.Context, req *AdmissionRequest) (*MutationResponse, error) { + var resp *MutationResponse + err := m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.MutateAdmission(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +} + +func (m *metricsMiddleware) ConvertObjects(ctx context.Context, req *ConversionRequest) (*ConversionResponse, error) { + var resp *ConversionResponse + err := m.instrumentRequest(ctx, req.PluginContext, func(ctx context.Context) (RequestStatus, error) { + var innerErr error + resp, innerErr = m.BaseHandler.ConvertObjects(ctx, req) + return RequestStatusFromError(innerErr), innerErr + }) + + return resp, err +}