diff --git a/staging/src/k8s.io/apiserver/pkg/storage/value/metrics.go b/staging/src/k8s.io/apiserver/pkg/storage/value/metrics.go index 9b29b1bd671..35ec0136920 100644 --- a/staging/src/k8s.io/apiserver/pkg/storage/value/metrics.go +++ b/staging/src/k8s.io/apiserver/pkg/storage/value/metrics.go @@ -61,7 +61,7 @@ var ( Namespace: namespace, Subsystem: subsystem, Name: "transformation_operations_total", - Help: "Total number of transformations.", + Help: "Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption", StabilityLevel: metrics.ALPHA, }, []string{"transformation_type", "transformer_prefix", "status"}, diff --git a/staging/src/k8s.io/apiserver/pkg/storage/value/metrics_test.go b/staging/src/k8s.io/apiserver/pkg/storage/value/metrics_test.go index 67ad9e17138..9b77a5856d4 100644 --- a/staging/src/k8s.io/apiserver/pkg/storage/value/metrics_test.go +++ b/staging/src/k8s.io/apiserver/pkg/storage/value/metrics_test.go @@ -56,7 +56,7 @@ func TestTotals(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="unknown-non-grpc",transformation_type="from_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 apiserver_storage_transformation_operations_total{status="unknown-non-grpc",transformation_type="to_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 @@ -69,7 +69,7 @@ func TestTotals(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="OK",transformation_type="from_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 apiserver_storage_transformation_operations_total{status="OK",transformation_type="to_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 @@ -82,7 +82,7 @@ func TestTotals(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="FailedPrecondition",transformation_type="from_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 apiserver_storage_transformation_operations_total{status="FailedPrecondition",transformation_type="to_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 @@ -95,7 +95,7 @@ func TestTotals(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="Internal",transformation_type="from_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 apiserver_storage_transformation_operations_total{status="Internal",transformation_type="to_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 @@ -108,7 +108,7 @@ func TestTotals(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="NotFound",transformation_type="from_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 apiserver_storage_transformation_operations_total{status="NotFound",transformation_type="to_storage",transformer_prefix="k8s:enc:kms:v1:"} 1 diff --git a/staging/src/k8s.io/apiserver/pkg/storage/value/transformer.go b/staging/src/k8s.io/apiserver/pkg/storage/value/transformer.go index 7b5307df208..c5e97ac2daa 100644 --- a/staging/src/k8s.io/apiserver/pkg/storage/value/transformer.go +++ b/staging/src/k8s.io/apiserver/pkg/storage/value/transformer.go @@ -25,6 +25,8 @@ import ( "k8s.io/apimachinery/pkg/runtime/schema" "k8s.io/apimachinery/pkg/util/errors" + genericapirequest "k8s.io/apiserver/pkg/endpoints/request" + "k8s.io/klog/v2" ) func init() { @@ -158,6 +160,7 @@ func (t *prefixTransformers) TransformFromStorage(ctx context.Context, data []by } } if err := errors.Reduce(errors.NewAggregate(errs)); err != nil { + logTransformErr(ctx, err, "failed to decrypt data") return nil, false, err } RecordTransformation("from_storage", "unknown", time.Since(start), t.err) @@ -171,6 +174,7 @@ func (t *prefixTransformers) TransformToStorage(ctx context.Context, data []byte result, err := transformer.Transformer.TransformToStorage(ctx, data, dataCtx) RecordTransformation("to_storage", string(transformer.Prefix), time.Since(start), err) if err != nil { + logTransformErr(ctx, err, "failed to encrypt data") return nil, err } prefixedData := make([]byte, len(transformer.Prefix), len(result)+len(transformer.Prefix)) @@ -178,3 +182,32 @@ func (t *prefixTransformers) TransformToStorage(ctx context.Context, data []byte prefixedData = append(prefixedData, result...) return prefixedData, nil } + +func logTransformErr(ctx context.Context, err error, message string) { + requestInfo := getRequestInfoFromContext(ctx) + if klogLevel6 := klog.V(6); klogLevel6.Enabled() { + klogLevel6.InfoSDepth( + 1, + message, + "err", err, + "group", requestInfo.APIGroup, + "version", requestInfo.APIVersion, + "resource", requestInfo.Resource, + "subresource", requestInfo.Subresource, + "verb", requestInfo.Verb, + "namespace", requestInfo.Namespace, + "name", requestInfo.Name, + ) + + return + } + + klog.ErrorSDepth(1, err, message) +} + +func getRequestInfoFromContext(ctx context.Context) *genericapirequest.RequestInfo { + if reqInfo, found := genericapirequest.RequestInfoFrom(ctx); found { + return reqInfo + } + return &genericapirequest.RequestInfo{} +} diff --git a/staging/src/k8s.io/apiserver/pkg/storage/value/transformer_test.go b/staging/src/k8s.io/apiserver/pkg/storage/value/transformer_test.go index 166a9af9d64..946bfc8aabe 100644 --- a/staging/src/k8s.io/apiserver/pkg/storage/value/transformer_test.go +++ b/staging/src/k8s.io/apiserver/pkg/storage/value/transformer_test.go @@ -19,12 +19,17 @@ package value import ( "bytes" "context" + "errors" + "flag" "fmt" + "regexp" "strings" "testing" + genericapirequest "k8s.io/apiserver/pkg/endpoints/request" "k8s.io/component-base/metrics/legacyregistry" "k8s.io/component-base/metrics/testutil" + "k8s.io/klog/v2" ) type testTransformer struct { @@ -129,7 +134,7 @@ func TestPrefixFromMetrics(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="OK",transformation_type="from_storage",transformer_prefix="identity"} 1 `, @@ -143,7 +148,7 @@ func TestPrefixFromMetrics(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="OK",transformation_type="from_storage",transformer_prefix="other:"} 1 `, @@ -157,7 +162,7 @@ func TestPrefixFromMetrics(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="unknown-non-grpc",transformation_type="from_storage",transformer_prefix="other:"} 1 `, @@ -171,7 +176,7 @@ func TestPrefixFromMetrics(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="unknown-non-grpc",transformation_type="from_storage",transformer_prefix="unknown"} 1 `, @@ -215,7 +220,7 @@ func TestPrefixToMetrics(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="OK",transformation_type="to_storage",transformer_prefix="other:"} 1 `, @@ -229,7 +234,7 @@ func TestPrefixToMetrics(t *testing.T) { "apiserver_storage_transformation_operations_total", }, want: ` - # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. + # HELP apiserver_storage_transformation_operations_total [ALPHA] Total number of transformations. Successful transformation will have a status 'OK' and a varied status string when the transformation fails. This status and transformation_type fields may be used for alerting on encryption/decryption failure using transformation_type from_storage for decryption and to_storage for encryption # TYPE apiserver_storage_transformation_operations_total counter apiserver_storage_transformation_operations_total{status="unknown-non-grpc",transformation_type="to_storage",transformer_prefix="other:"} 1 `, @@ -250,3 +255,63 @@ func TestPrefixToMetrics(t *testing.T) { }) } } + +func TestLogTransformErr(t *testing.T) { + klog.InitFlags(nil) + tests := []struct { + name string + ctx context.Context + err error + message string + expectedLog string + }{ + { + name: "log error with request info", + ctx: genericapirequest.WithRequestInfo(testContext(t), &genericapirequest.RequestInfo{ + APIGroup: "awesome.bears.com", + APIVersion: "v1", + Resource: "pandas", + Subresource: "status", + Namespace: "kube-system", + Name: "panda", + Verb: "update", + }), + err: errors.New("encryption failed"), + message: "failed to encrypt data", + expectedLog: "\"failed to encrypt data\" err=\"encryption failed\" group=\"awesome.bears.com\" version=\"v1\" resource=\"pandas\" subresource=\"status\" verb=\"update\" namespace=\"kube-system\" name=\"panda\"\n", + }, + { + name: "log error without request info", + ctx: context.Background(), + err: errors.New("decryption failed"), + message: "failed to decrypt data", + expectedLog: "\"failed to decrypt data\" err=\"decryption failed\" group=\"\" version=\"\" resource=\"\" subresource=\"\" verb=\"\" namespace=\"\" name=\"\"\n", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + var buf bytes.Buffer + flag.Set("v", "6") + flag.Parse() + klog.SetOutput(&buf) + klog.LogToStderr(false) + defer klog.LogToStderr(true) + + logTransformErr(tt.ctx, tt.err, tt.message) + + // remove timestamp and goroutine id from log message to make it easier to compare + gotLog := regexp.MustCompile(`\w+ \d+:\d+:\d+\.\d+.*\d+.*transformer_test.go:\d+].`).ReplaceAllString(buf.String(), "") + + if gotLog != tt.expectedLog { + t.Errorf("expected log message %q, got %q", tt.expectedLog, gotLog) + } + }) + } +} + +func testContext(t *testing.T) context.Context { + ctx, cancel := context.WithCancel(context.Background()) + t.Cleanup(cancel) + return ctx +}