Return Audit-Id http header for trouble shooting

staging/src/k8s.io/apiserver/pkg/apis/audit/types.go

@@ -27,6 +27,13 @@ const (
 	// Header to hold the audit ID as the request is propagated through the serving hierarchy. The
 	// Audit-ID header should be set by the first server to receive the request (e.g. the federation
 	// server or kube-aggregator).
+	//
+	// Audit ID is also returned to client by http response header.
+	// It's not guaranteed Audit-Id http header is sent for all requests. When kube-apiserver didn't
+	// audit the events according to the audit policy, no Audit-ID is returned. Also, for request to
+	// pods/exec, pods/attach, pods/proxy, kube-apiserver works like a proxy and redirect the request
+	// to kubelet node, users will only get http headers sent from kubelet node, so no Audit-ID is
+	// sent when users run command like "kubectl exec" or "kubectl attach".
 	HeaderAuditID = "Audit-ID"
 )
 

staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/types.go

@@ -28,6 +28,13 @@ const (
 	// Header to hold the audit ID as the request is propagated through the serving hierarchy. The
 	// Audit-ID header should be set by the first server to receive the request (e.g. the federation
 	// server or kube-aggregator).
+	//
+	// Audit ID is also returned to client by http response header.
+	// It's not guaranteed Audit-Id http header is sent for all requests. When kube-apiserver didn't
+	// audit the events according to the audit policy, no Audit-ID is returned. Also, for request to
+	// pods/exec, pods/attach, pods/proxy, kube-apiserver works like a proxy and redirect the request
+	// to kubelet node, users will only get http headers sent from kubelet node, so no Audit-ID is
+	// sent when users run command like "kubectl exec" or "kubectl attach".
 	HeaderAuditID = "Audit-ID"
 )
 

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

@@ -107,6 +107,7 @@ func WithAudit(handler http.Handler, requestContextMapper request.RequestContext
 			}
 
 			// if no StageResponseStarted event was sent b/c neither a status code nor a body was sent, fake it here
+			// But Audit-Id http header will only be sent when http.ResponseWriter.WriteHeader is called.
 			fakedSuccessStatus := &metav1.Status{
 				Code:    http.StatusOK,
 				Status:  metav1.StatusSuccess,
@@ -162,6 +163,10 @@ type auditResponseWriter struct {
 	sink  audit.Sink
 }
 
+func (a *auditResponseWriter) setHttpHeader() {
+	a.ResponseWriter.Header().Set(auditinternal.HeaderAuditID, string(a.event.AuditID))
+}
+
 func (a *auditResponseWriter) processCode(code int) {
 	a.once.Do(func() {
 		if a.event.ResponseStatus == nil {
@@ -177,12 +182,16 @@ func (a *auditResponseWriter) processCode(code int) {
 }
 
 func (a *auditResponseWriter) Write(bs []byte) (int, error) {
-	a.processCode(http.StatusOK) // the Go library calls WriteHeader internally if no code was written yet. But this will go unnoticed for us
+	// the Go library calls WriteHeader internally if no code was written yet. But this will go unnoticed for us
+	a.processCode(http.StatusOK)
+	a.setHttpHeader()
+
 	return a.ResponseWriter.Write(bs)
 }
 
 func (a *auditResponseWriter) WriteHeader(code int) {
 	a.processCode(code)
+	a.setHttpHeader()
 	a.ResponseWriter.WriteHeader(code)
 }
 
@@ -204,6 +213,13 @@ func (f *fancyResponseWriterDelegator) Flush() {
 func (f *fancyResponseWriterDelegator) Hijack() (net.Conn, *bufio.ReadWriter, error) {
 	// fake a response status before protocol switch happens
 	f.processCode(http.StatusSwitchingProtocols)
+
+	// This will be ignored if WriteHeader() function has aready been called.
+	// It's not guaranteed Audit-ID http header is sent for all requests.
+	// For example, when user run "kubectl exec", apiserver uses a proxy handler
+	// to deal with the request, users can only get http headers returned by kubelet node.
+	f.setHttpHeader()
+
 	return f.ResponseWriter.(http.Hijacker).Hijack()
 }
 

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

@@ -442,6 +442,7 @@ func TestAuditJson(t *testing.T) {
 		auditID    string
 		handler    func(http.ResponseWriter, *http.Request)
 		expected   []auditv1alpha1.Event
+		respHeader bool
 	}{
 		// short running requests with read-only verb
 		{
@@ -463,13 +464,16 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 200},
 				},
 			},
+			false,
 		},
 		{
 			"short running with auditID",
 			shortRunningPath,
 			"GET",
 			uuid.NewRandom().String(),
-			func(http.ResponseWriter, *http.Request) {},
+			func(w http.ResponseWriter, req *http.Request) {
+				w.Write([]byte("foo"))
+			},
 			[]auditv1alpha1.Event{
 				{
 					Stage:      auditinternal.StageRequestReceived,
@@ -483,6 +487,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 200},
 				},
 			},
+			true,
 		},
 		{
 			"read-only panic",
@@ -505,6 +510,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 500},
 				},
 			},
+			false,
 		},
 		// short running request with non-read-only verb
 		{
@@ -526,13 +532,15 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 200},
 				},
 			},
+			false,
 		},
 		{
 			"writing sleep",
 			shortRunningPath,
 			"PUT",
 			"",
-			func(http.ResponseWriter, *http.Request) {
+			func(w http.ResponseWriter, req *http.Request) {
+				w.Write([]byte("foo"))
 				time.Sleep(delay)
 			},
 			[]auditv1alpha1.Event{
@@ -548,6 +556,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 200},
 				},
 			},
+			true,
 		},
 		{
 			"writing 403+write",
@@ -571,6 +580,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 403},
 				},
 			},
+			true,
 		},
 		{
 			"writing panic",
@@ -593,6 +603,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 500},
 				},
 			},
+			false,
 		},
 		{
 			"writing write+panic",
@@ -616,6 +627,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 500},
 				},
 			},
+			true,
 		},
 		// long running requests
 		{
@@ -643,13 +655,16 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 200},
 				},
 			},
+			false,
 		},
 		{
-			"empty longrunning",
+			"empty longrunning with audit id",
 			longRunningPath,
 			"GET",
 			uuid.NewRandom().String(),
-			func(http.ResponseWriter, *http.Request) {},
+			func(w http.ResponseWriter, req *http.Request) {
+				w.Write([]byte("foo"))
+			},
 			[]auditv1alpha1.Event{
 				{
 					Stage:      auditinternal.StageRequestReceived,
@@ -669,6 +684,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 200},
 				},
 			},
+			true,
 		},
 		{
 			"sleep longrunning",
@@ -697,6 +713,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 200},
 				},
 			},
+			false,
 		},
 		{
 			"sleep+403 longrunning",
@@ -726,6 +743,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 403},
 				},
 			},
+			true,
 		},
 		{
 			"write longrunning",
@@ -754,6 +772,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 200},
 				},
 			},
+			true,
 		},
 		{
 			"403+write longrunning",
@@ -783,6 +802,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 403},
 				},
 			},
+			true,
 		},
 		{
 			"panic longrunning",
@@ -805,6 +825,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 500},
 				},
 			},
+			false,
 		},
 		{
 			"write+panic longrunning",
@@ -834,6 +855,7 @@ func TestAuditJson(t *testing.T) {
 					ResponseStatus: &metav1.Status{Code: 500},
 				},
 			},
+			true,
 		},
 	} {
 		var buf bytes.Buffer
@@ -852,11 +874,12 @@ func TestAuditJson(t *testing.T) {
 		}
 		req.RemoteAddr = "127.0.0.1"
 
+		w := httptest.NewRecorder()
 		func() {
 			defer func() {
 				recover()
 			}()
-			handler.ServeHTTP(httptest.NewRecorder(), req)
+			handler.ServeHTTP(w, req)
 		}()
 
 		t.Logf("[%s] audit log: %v", test.desc, buf.String())
@@ -887,6 +910,11 @@ func TestAuditJson(t *testing.T) {
 			if event.RequestURI != expect.RequestURI {
 				t.Errorf("[%s] Unexpected RequestURI: %s", test.desc, event.RequestURI)
 			}
+			resp := w.Result()
+			if test.respHeader && string(event.AuditID) != resp.Header.Get("Audit-Id") {
+				t.Errorf("[%s] Unexpected Audit-Id http response header, Audit-Id http response header should be the same with AuditID in log %v xx %v", test.desc, event.AuditID, w.HeaderMap.Get("Audit-Id"))
+			}
+
 			if test.auditID != "" && event.AuditID != types.UID(test.auditID) {
 				t.Errorf("[%s] Unexpected AuditID in audit event, AuditID should be the same with Audit-ID http header", test.desc)
 			}