diff --git a/internal/internal.go b/internal/internal.go index 53bb264ed..dd92e1c0e 100644 --- a/internal/internal.go +++ b/internal/internal.go @@ -391,21 +391,21 @@ func (p *envoyExtAuthzGrpcServer) check(ctx context.Context, req interface{}) (* stop := func() *rpc_status.Status { stopeval() - if internalErr.Unwrap() != nil || internalErr.Code != "" { + if p.cfg.EnablePerformanceMetrics { var topdownError *topdown.Error - if errors.As(internalErr.Unwrap(), &topdownError) { + if internalErr.Unwrap() != nil && errors.As(internalErr.Unwrap(), &topdownError) { p.metricErrorCounter.With(prometheus.Labels{"reason": topdownError.Code}).Inc() } else if internalErr.Code != "" { p.metricErrorCounter.With(prometheus.Labels{"reason": internalErr.Code}).Inc() - } else { - p.metricErrorCounter.With(prometheus.Labels{"reason": "unknown_check_error"}).Inc() } } logErr := p.log(ctx, input, result, err) if logErr != nil { _ = txnClose(ctx, logErr) // Ignore error - p.Logger().Debug("Error when logging event: %v", logErr) - p.metricErrorCounter.With(prometheus.Labels{"reason": "unknown_log_error"}).Inc() + p.Logger().WithFields(map[string]interface{}{"err": logErr}).Debug("Error when logging event") + if p.cfg.EnablePerformanceMetrics { + p.metricErrorCounter.With(prometheus.Labels{"reason": "unknown_log_error"}).Inc() + } return &rpc_status.Status{ Code: int32(code.Code_UNKNOWN), Message: logErr.Error(), diff --git a/internal/internal_test.go b/internal/internal_test.go index 4d7074a5b..f95b8850a 100644 --- a/internal/internal_test.go +++ b/internal/internal_test.go @@ -530,6 +530,50 @@ func TestCheckContextTimeout(t *testing.T) { assertErrorCounterMetric(t, server, CheckRequestTimeoutErr) } +func TestCheckContextTimeoutMetricsDisabled(t *testing.T) { + var req ext_authz.CheckRequest + if err := util.Unmarshal([]byte(exampleAllowedRequest), &req); err != nil { + panic(err) + } + + // create custom logger + customLogger := &testPlugin{} + + server := testAuthzServer(&Config{EnablePerformanceMetrics: false}, withCustomLogger(customLogger)) + + ctx, cancel := context.WithTimeout(context.Background(), time.Nanosecond*1) + defer cancel() + + time.Sleep(time.Millisecond * 1) + _, err := server.Check(ctx, &req) + if err == nil { + t.Fatal("Expected error but got nil") + } + + expectedErrMsg := "check request timed out before query execution: context deadline exceeded" + if err.Error() != expectedErrMsg { + t.Fatalf("Expected error message %v but got %v", expectedErrMsg, err.Error()) + } + + if len(customLogger.events) != 1 { + t.Fatal("Unexpected events:", customLogger.events) + } + + event := customLogger.events[0] + + if event.Error == nil { + t.Fatal("Expected error but got nil") + } + + if event.Error.Error() != expectedErrMsg { + t.Fatalf("Expected error message %v but got %v", expectedErrMsg, event.Error.Error()) + } + + if len((*event.Input).(map[string]interface{})) == 0 { + t.Fatalf("Expected non empty input but got %v", *event.Input) + } +} + func TestCheckIllegalDecisionWithLogger(t *testing.T) { // Example Envoy Check Request for input: // curl --user alice:password -o /dev/null -s -w "%{http_code}\n" http://${GATEWAY_URL}/api/v1/products