[endpoint] - Add more info in audit log

In order to increase the visibility we have in the audit logs for some of our most recent endeavors like:
- Migrations to FIPS
- Clients using Protobuf instead of JSON

We need to surface the informations that is related to the specific of the queries.
We could add this into metrics but we would lose out on the specifics of who is making those request.
Which is the important part when trying to get people to migrate and know the overall state of the platform.

This PR aims to rely on the facilities already present in the audit logs.
Namely, the custom annotations that are set.
We can already see in some case annotation being set on the slow queries >500ms.
This would effectively do the same.

This patch should be fairly easy to cherry pick in the future as well, if we decide to keep it around once the migration are done.

Arguably some of this could be of interest for upstream. Probably the content type more than the TLS cipher. So if we decide to keep it around long term we should create the relevant issue and possibly PR that in.

datadog:patch

staging/src/k8s.io/apiserver/pkg/endpoints/filters/ddog.go

@@ -0,0 +1,47 @@
+/*
+Copyright 2019 The Kubernetes Authors.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package filters
+
+import (
+	"crypto/tls"
+	"k8s.io/apiserver/pkg/audit"
+	"net/http"
+)
+
+// WithDDOGAudits adds additional information about the request to the audit logs.
+// This is useful for debugging and troubleshooting.
+// TLS Cipher for fips
+// Content-Type of the response to track JSON vs protobuf
+func WithDDOGAudits(handler http.Handler) http.Handler {
+	return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
+		ctx := req.Context()
+
+		// Set the content type annotation if it is set
+		if _, ok := w.Header()["Content-Type"]; ok {
+			audit.AddAuditAnnotation(ctx, "audit.datadoghq.com/contentType", w.Header().Get("Content-Type"))
+		}
+
+		// Set the TLS Cipher annotation if TLS and CipherSuite are set
+		if req.TLS != nil {
+			if req.TLS.CipherSuite > 0 {
+				audit.AddAuditAnnotation(ctx, "audit.datadoghq.com/cipher", tls.CipherSuiteName(req.TLS.CipherSuite))
+			}
+		}
+
+		handler.ServeHTTP(w, req)
+	})
+}

staging/src/k8s.io/apiserver/pkg/endpoints/filters/ddog_test.go

@@ -0,0 +1,130 @@
+package filters
+
+import (
+	"crypto/tls"
+	"crypto/x509"
+	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
+	auditinternal "k8s.io/apiserver/pkg/apis/audit"
+	"k8s.io/apiserver/pkg/audit/policy"
+	"k8s.io/apiserver/pkg/authentication/user"
+	"k8s.io/apiserver/pkg/endpoints/request"
+	"net/http"
+	"net/http/httptest"
+	"testing"
+)
+
+func TestWithDDOGAudits(t *testing.T) {
+	handler := func(http.ResponseWriter, *http.Request) {}
+	shortRunningPath := "/api/v1/namespaces/default/pods/foo"
+
+	for _, test := range []struct {
+		desc        string
+		tlsCipher   uint16
+		contentType string
+		expected    []auditinternal.Event
+	}{
+		{
+			"TLS Cipher set & Content Type set",
+			tls.TLS_RSA_WITH_RC4_128_SHA,
+			"application/json",
+			[]auditinternal.Event{
+				{
+					Stage:          auditinternal.StageResponseComplete,
+					Verb:           "get",
+					RequestURI:     shortRunningPath,
+					ResponseStatus: &metav1.Status{Code: 200},
+					Annotations: map[string]string{
+						"audit.datadoghq.com/cipher":      "TLS_RSA_WITH_RC4_128_SHA",
+						"audit.datadoghq.com/contentType": "application/json",
+					},
+				},
+			},
+		}, {
+			"TLS Cipher set & Content Type unset",
+			tls.TLS_RSA_WITH_RC4_128_SHA,
+			"",
+			[]auditinternal.Event{
+				{
+					Stage:          auditinternal.StageResponseComplete,
+					Verb:           "get",
+					RequestURI:     shortRunningPath,
+					ResponseStatus: &metav1.Status{Code: 200},
+					Annotations: map[string]string{
+						"audit.datadoghq.com/cipher": "TLS_RSA_WITH_RC4_128_SHA",
+					},
+				},
+			},
+		}, {
+			"TLS Cipher unset & Content Type unset",
+			0,
+			"",
+			[]auditinternal.Event{
+				{
+					Stage:          auditinternal.StageResponseComplete,
+					Verb:           "get",
+					RequestURI:     shortRunningPath,
+					ResponseStatus: &metav1.Status{Code: 200},
+				},
+			},
+		}, {
+			"TLS Cipher unset & Content Type set",
+			0,
+			"application/json",
+			[]auditinternal.Event{
+				{
+					Stage:          auditinternal.StageResponseComplete,
+					Verb:           "get",
+					RequestURI:     shortRunningPath,
+					ResponseStatus: &metav1.Status{Code: 200},
+					Annotations: map[string]string{
+						"audit.datadoghq.com/contentType": "application/json",
+					},
+				},
+			},
+		},
+	} {
+		t.Run(test.desc, func(t *testing.T) {
+			sink := &fakeAuditSink{}
+			fakeRuleEvaluator := policy.NewFakePolicyRuleEvaluator(auditinternal.LevelRequestResponse, []auditinternal.Stage{auditinternal.StageRequestReceived, auditinternal.StageResponseStarted})
+			handler := WithAudit(http.HandlerFunc(handler), sink, fakeRuleEvaluator, func(r *http.Request, ri *request.RequestInfo) bool { return true })
+			handler = WithAuditInit(handler)
+			handler = WithDDOGAudits(handler)
+
+			req, _ := http.NewRequest("GET", shortRunningPath, nil)
+			req.RemoteAddr = "127.0.0.1"
+			req = withTestContext(req, &user.DefaultInfo{Name: "admin"}, nil)
+			res := httptest.NewRecorder()
+
+			if test.tlsCipher > 0 {
+				req.TLS = &tls.ConnectionState{PeerCertificates: []*x509.Certificate{{}}, CipherSuite: test.tlsCipher}
+			}
+			if test.contentType != "" {
+				res.Header().Set("Content-Type", test.contentType)
+			}
+
+			func() {
+				defer func() {
+					recover()
+				}()
+				handler.ServeHTTP(res, req)
+			}()
+
+			events := sink.Events()
+			t.Logf("audit log: %v", events)
+			if len(events) != len(test.expected) {
+				t.Fatalf("Unexpected amount of lines in audit log: %d", len(events))
+			}
+			for i, _ := range test.expected {
+				event := events[i]
+				if len(event.Annotations) != len(test.expected[i].Annotations) {
+					t.Errorf("[%s] expected %d annotations, got %d", test.desc, len(test.expected[i].Annotations), len(event.Annotations))
+				}
+				for y, _ := range event.Annotations {
+					if test.expected[i].Annotations[y] != event.Annotations[y] {
+						t.Errorf("[%s] expected annotation %s to be %s, got %s", test.desc, y, test.expected[i].Annotations[y], event.Annotations[y])
+					}
+				}
+			}
+		})
+	}
+}

staging/src/k8s.io/apiserver/pkg/server/config.go

@@ -1069,6 +1069,7 @@ func DefaultBuildHandlerChain(apiHandler http.Handler, c *Config) http.Handler {
 	handler = genericapifilters.WithMuxAndDiscoveryComplete(handler, c.lifecycleSignals.MuxAndDiscoveryComplete.Signaled())
 	handler = genericfilters.WithPanicRecovery(handler, c.RequestInfoResolver)
 	handler = genericapifilters.WithAuditInit(handler)
+	handler = genericapifilters.WithDDOGAudits(handler)
 	return handler
 }