diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/BUILD b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/BUILD index 2dcc5badfd..3dfc59bb54 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/BUILD +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/BUILD @@ -23,11 +23,14 @@ go_test( deps = [ "//vendor/k8s.io/api/authentication/v1:go_default_library", "//vendor/k8s.io/api/batch/v1:go_default_library", + "//vendor/k8s.io/apimachinery/pkg/apis/meta/v1:go_default_library", "//vendor/k8s.io/apimachinery/pkg/runtime:go_default_library", "//vendor/k8s.io/apimachinery/pkg/runtime/serializer:go_default_library", "//vendor/k8s.io/apimachinery/pkg/util/sets:go_default_library", "//vendor/k8s.io/apimachinery/pkg/util/wait:go_default_library", "//vendor/k8s.io/apiserver/pkg/apis/audit:go_default_library", + "//vendor/k8s.io/apiserver/pkg/apis/audit/v1alpha1:go_default_library", + "//vendor/k8s.io/apiserver/pkg/audit:go_default_library", "//vendor/k8s.io/apiserver/pkg/audit/policy:go_default_library", "//vendor/k8s.io/apiserver/pkg/authentication/authenticator:go_default_library", "//vendor/k8s.io/apiserver/pkg/authentication/user:go_default_library", @@ -35,6 +38,7 @@ go_test( "//vendor/k8s.io/apiserver/pkg/endpoints/handlers/responsewriters:go_default_library", "//vendor/k8s.io/apiserver/pkg/endpoints/request:go_default_library", "//vendor/k8s.io/apiserver/plugin/pkg/audit/log:go_default_library", + "//vendor/k8s.io/apiserver/plugin/pkg/audit/webhook:go_default_library", ], ) diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit_test.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit_test.go index b85f6c8c23..d1dfa73a6c 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit_test.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit_test.go @@ -30,12 +30,18 @@ import ( "testing" "time" + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/util/wait" auditinternal "k8s.io/apiserver/pkg/apis/audit" + auditv1alpha1 "k8s.io/apiserver/pkg/apis/audit/v1alpha1" + "k8s.io/apiserver/pkg/audit" "k8s.io/apiserver/pkg/audit/policy" "k8s.io/apiserver/pkg/authentication/user" "k8s.io/apiserver/pkg/endpoints/request" pluginlog "k8s.io/apiserver/plugin/pkg/audit/log" + // import to call webhook's init() function to register audit.Event to schema + _ "k8s.io/apiserver/plugin/pkg/audit/webhook" ) type fakeAuditSink struct { @@ -177,7 +183,7 @@ func (*fakeHTTPHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) { w.WriteHeader(200) } -func TestAudit(t *testing.T) { +func TestAuditLegacy(t *testing.T) { writingShortRunningPrefix := func(stage string) string { return fmt.Sprintf(`[\d\:\-\.\+TZ]+ AUDIT: id="[\w-]+" stage="%s" ip="127.0.0.1" method="update" user="admin" groups="" as="" asgroups="" namespace="default" uri="/api/v1/namespaces/default/pods/foo"`, stage) } @@ -380,7 +386,7 @@ func TestAudit(t *testing.T) { }, } { var buf bytes.Buffer - backend := pluginlog.NewBackend(&buf) + backend := pluginlog.NewBackend(&buf, pluginlog.FormatLegacy) policyChecker := policy.FakeChecker(auditinternal.LevelRequestResponse) handler := WithAudit(http.HandlerFunc(test.handler), &fakeRequestContextMapper{ user: &user.DefaultInfo{Name: "admin"}, @@ -420,6 +426,411 @@ func TestAudit(t *testing.T) { } } +func TestAuditJson(t *testing.T) { + shortRunningPath := "/api/v1/namespaces/default/pods/foo" + longRunningPath := "/api/v1/namespaces/default/pods?watch=true" + + delay := 500 * time.Millisecond + + for _, test := range []struct { + desc string + path string + verb string + handler func(http.ResponseWriter, *http.Request) + expected []auditv1alpha1.Event + }{ + // short running requests with read-only verb + { + "read-only empty", + shortRunningPath, + "GET", + func(http.ResponseWriter, *http.Request) {}, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "get", + RequestURI: shortRunningPath, + }, + { + Stage: auditinternal.StageResponseComplete, + Verb: "get", + RequestURI: shortRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + }, + }, + { + "read-only panic", + shortRunningPath, + "GET", + func(w http.ResponseWriter, req *http.Request) { + panic("kaboom") + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "get", + RequestURI: shortRunningPath, + }, + { + Stage: auditinternal.StagePanic, + Verb: "get", + RequestURI: shortRunningPath, + ResponseStatus: &metav1.Status{Code: 500}, + }, + }, + }, + // short running request with non-read-only verb + { + "writing empty", + shortRunningPath, + "PUT", + func(http.ResponseWriter, *http.Request) {}, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "update", + RequestURI: shortRunningPath, + }, + { + Stage: auditinternal.StageResponseComplete, + Verb: "update", + RequestURI: shortRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + }, + }, + { + "writing sleep", + shortRunningPath, + "PUT", + func(http.ResponseWriter, *http.Request) { + time.Sleep(delay) + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "update", + RequestURI: shortRunningPath, + }, + { + Stage: auditinternal.StageResponseComplete, + Verb: "update", + RequestURI: shortRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + }, + }, + { + "writing 403+write", + shortRunningPath, + "PUT", + func(w http.ResponseWriter, req *http.Request) { + w.WriteHeader(403) + w.Write([]byte("foo")) + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "update", + RequestURI: shortRunningPath, + }, + { + Stage: auditinternal.StageResponseComplete, + Verb: "update", + RequestURI: shortRunningPath, + ResponseStatus: &metav1.Status{Code: 403}, + }, + }, + }, + { + "writing panic", + shortRunningPath, + "PUT", + func(w http.ResponseWriter, req *http.Request) { + panic("kaboom") + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "update", + RequestURI: shortRunningPath, + }, + { + Stage: auditinternal.StagePanic, + Verb: "update", + RequestURI: shortRunningPath, + ResponseStatus: &metav1.Status{Code: 500}, + }, + }, + }, + { + "writing write+panic", + shortRunningPath, + "PUT", + func(w http.ResponseWriter, req *http.Request) { + w.Write([]byte("foo")) + panic("kaboom") + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "update", + RequestURI: shortRunningPath, + }, + { + Stage: auditinternal.StagePanic, + Verb: "update", + RequestURI: shortRunningPath, + ResponseStatus: &metav1.Status{Code: 500}, + }, + }, + }, + // long running requests + { + "empty longrunning", + longRunningPath, + "GET", + func(http.ResponseWriter, *http.Request) {}, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "watch", + RequestURI: longRunningPath, + }, + { + Stage: auditinternal.StageResponseStarted, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + { + Stage: auditinternal.StageResponseComplete, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + }, + }, + { + "sleep longrunning", + longRunningPath, + "GET", + func(http.ResponseWriter, *http.Request) { + time.Sleep(delay) + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "watch", + RequestURI: longRunningPath, + }, + { + Stage: auditinternal.StageResponseStarted, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + { + Stage: auditinternal.StageResponseComplete, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + }, + }, + { + "sleep+403 longrunning", + longRunningPath, + "GET", + func(w http.ResponseWriter, req *http.Request) { + time.Sleep(delay) + w.WriteHeader(403) + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "watch", + RequestURI: longRunningPath, + }, + { + Stage: auditinternal.StageResponseStarted, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 403}, + }, + { + Stage: auditinternal.StageResponseComplete, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 403}, + }, + }, + }, + { + "write longrunning", + longRunningPath, + "GET", + func(w http.ResponseWriter, req *http.Request) { + w.Write([]byte("foo")) + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "watch", + RequestURI: longRunningPath, + }, + { + Stage: auditinternal.StageResponseStarted, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + { + Stage: auditinternal.StageResponseComplete, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + }, + }, + { + "403+write longrunning", + longRunningPath, + "GET", + func(w http.ResponseWriter, req *http.Request) { + w.WriteHeader(403) + w.Write([]byte("foo")) + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "watch", + RequestURI: longRunningPath, + }, + { + Stage: auditinternal.StageResponseStarted, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 403}, + }, + { + Stage: auditinternal.StageResponseComplete, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 403}, + }, + }, + }, + { + "panic longrunning", + longRunningPath, + "GET", + func(w http.ResponseWriter, req *http.Request) { + panic("kaboom") + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "watch", + RequestURI: longRunningPath, + }, + { + Stage: auditinternal.StagePanic, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 500}, + }, + }, + }, + { + "write+panic longrunning", + longRunningPath, + "GET", + func(w http.ResponseWriter, req *http.Request) { + w.Write([]byte("foo")) + panic("kaboom") + }, + []auditv1alpha1.Event{ + { + Stage: auditinternal.StageRequestReceived, + Verb: "watch", + RequestURI: longRunningPath, + }, + { + Stage: auditinternal.StageResponseStarted, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 200}, + }, + { + Stage: auditinternal.StagePanic, + Verb: "watch", + RequestURI: longRunningPath, + ResponseStatus: &metav1.Status{Code: 500}, + }, + }, + }, + } { + var buf bytes.Buffer + backend := pluginlog.NewBackend(&buf, pluginlog.FormatJson) + policyChecker := policy.FakeChecker(auditinternal.LevelRequestResponse) + handler := WithAudit(http.HandlerFunc(test.handler), &fakeRequestContextMapper{ + user: &user.DefaultInfo{Name: "admin"}, + }, backend, policyChecker, func(r *http.Request, ri *request.RequestInfo) bool { + // simplified long-running check + return ri.Verb == "watch" + }) + + req, _ := http.NewRequest(test.verb, test.path, nil) + req.RemoteAddr = "127.0.0.1" + + func() { + defer func() { + recover() + }() + handler.ServeHTTP(httptest.NewRecorder(), req) + }() + + t.Logf("[%s] audit log: %v", test.desc, buf.String()) + + line := strings.Split(strings.TrimSpace(buf.String()), "\n") + if len(line) != len(test.expected) { + t.Errorf("[%s] Unexpected amount of lines in audit log: %d", test.desc, len(line)) + continue + } + + for i, expect := range test.expected { + // decode events back to check json elements. + event := &auditv1alpha1.Event{} + decoder := audit.Codecs.UniversalDecoder(auditv1alpha1.SchemeGroupVersion) + if err := runtime.DecodeInto(decoder, []byte(line[i]), event); err != nil { + t.Errorf("failed decoding line %s: %v", line[i], err) + continue + } + if "admin" != event.User.Username { + t.Errorf("[%s] Unexpected username: %s", test.desc, event.User.Username) + } + if event.Stage != expect.Stage { + t.Errorf("[%s] Unexpected Stage: %s", test.desc, event.Stage) + } + if event.Verb != expect.Verb { + t.Errorf("[%s] Unexpected Verb: %s", test.desc, event.Verb) + } + if event.RequestURI != expect.RequestURI { + t.Errorf("[%s] Unexpected RequestURI: %s", test.desc, event.RequestURI) + } + if (event.ResponseStatus == nil) != (expect.ResponseStatus == nil) { + t.Errorf("[%s] Unexpected ResponseStatus: %v", test.desc, event.ResponseStatus) + continue + } + if (event.ResponseStatus != nil) && (event.ResponseStatus.Code != expect.ResponseStatus.Code) { + t.Errorf("[%s] Unexpected status code : %d", test.desc, event.ResponseStatus.Code) + } + } + } +} + type fakeRequestContextMapper struct { user *user.DefaultInfo } diff --git a/staging/src/k8s.io/apiserver/pkg/server/options/audit.go b/staging/src/k8s.io/apiserver/pkg/server/options/audit.go index d1421e66dd..1c8b1627ef 100644 --- a/staging/src/k8s.io/apiserver/pkg/server/options/audit.go +++ b/staging/src/k8s.io/apiserver/pkg/server/options/audit.go @@ -63,6 +63,7 @@ type AuditLogOptions struct { MaxAge int MaxBackups int MaxSize int + Format string } // AuditWebhookOptions control the webhook configuration for audit events. @@ -78,6 +79,7 @@ type AuditWebhookOptions struct { func NewAuditOptions() *AuditOptions { return &AuditOptions{ WebhookOptions: AuditWebhookOptions{Mode: pluginwebhook.ModeBatch}, + LogOptions: AuditLogOptions{Format: pluginlog.FormatLegacy}, } } @@ -104,6 +106,18 @@ func (o *AuditOptions) Validate() []error { if !validMode { allErrors = append(allErrors, fmt.Errorf("invalid audit webhook mode %s, allowed modes are %q", o.WebhookOptions.Mode, strings.Join(pluginwebhook.AllowedModes, ","))) } + + // check log format + validFormat := false + for _, f := range pluginlog.AllowedFormats { + if f == o.LogOptions.Format { + validFormat = true + break + } + } + if !validFormat { + allErrors = append(allErrors, fmt.Errorf("invalid audit log format %s, allowed formats are %q", o.LogOptions.Format, strings.Join(pluginlog.AllowedFormats, ","))) + } } return allErrors } @@ -161,6 +175,10 @@ func (o *AuditLogOptions) AddFlags(fs *pflag.FlagSet) { "The maximum number of old audit log files to retain.") fs.IntVar(&o.MaxSize, "audit-log-maxsize", o.MaxSize, "The maximum size in megabytes of the audit log file before it gets rotated.") + fs.StringVar(&o.Format, "audit-log-format", o.Format, + "Format of saved audits. \"legacy\" indicates 1-line text format for each event."+ + " \"json\" indicates structured json format. Requires the 'AdvancedAuditing' feature"+ + " gate. Known formats are "+strings.Join(pluginlog.AllowedFormats, ",")+".") } func (o *AuditLogOptions) getWriter() io.Writer { @@ -182,7 +200,7 @@ func (o *AuditLogOptions) getWriter() io.Writer { func (o *AuditLogOptions) advancedApplyTo(c *server.Config) error { if w := o.getWriter(); w != nil { - c.AuditBackend = appendBackend(c.AuditBackend, pluginlog.NewBackend(w)) + c.AuditBackend = appendBackend(c.AuditBackend, pluginlog.NewBackend(w, o.Format)) } return nil } diff --git a/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/BUILD b/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/BUILD index 82005d6ab3..897aa13666 100644 --- a/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/BUILD +++ b/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/BUILD @@ -12,7 +12,9 @@ go_library( srcs = ["backend.go"], tags = ["automanaged"], deps = [ + "//vendor/k8s.io/apimachinery/pkg/runtime:go_default_library", "//vendor/k8s.io/apiserver/pkg/apis/audit:go_default_library", + "//vendor/k8s.io/apiserver/pkg/apis/audit/v1alpha1:go_default_library", "//vendor/k8s.io/apiserver/pkg/audit:go_default_library", ], ) diff --git a/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/backend.go b/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/backend.go index 6464d8373f..2794e76eb5 100644 --- a/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/backend.go +++ b/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/backend.go @@ -19,20 +19,38 @@ package log import ( "fmt" "io" + "strings" + "k8s.io/apimachinery/pkg/runtime" auditinternal "k8s.io/apiserver/pkg/apis/audit" + auditv1alpha1 "k8s.io/apiserver/pkg/apis/audit/v1alpha1" "k8s.io/apiserver/pkg/audit" ) +const ( + // FormatLegacy saves event in 1-line text format. + FormatLegacy = "legacy" + // FormatJson saves event in structured json format. + FormatJson = "json" +) + +// AllowedFormats are the formats known by log backend. +var AllowedFormats = []string{ + FormatLegacy, + FormatJson, +} + type backend struct { - out io.Writer + out io.Writer + format string } var _ audit.Backend = &backend{} -func NewBackend(out io.Writer) *backend { +func NewBackend(out io.Writer, format string) *backend { return &backend{ - out: out, + out: out, + format: format, } } @@ -43,8 +61,23 @@ func (b *backend) ProcessEvents(events ...*auditinternal.Event) { } func (b *backend) logEvent(ev *auditinternal.Event) { - line := audit.EventString(ev) - if _, err := fmt.Fprintln(b.out, line); err != nil { + line := "" + switch b.format { + case FormatLegacy: + line = audit.EventString(ev) + "\n" + case FormatJson: + bs, err := runtime.Encode(audit.Codecs.LegacyCodec(auditv1alpha1.SchemeGroupVersion), ev) + if err != nil { + audit.HandlePluginError("log", err, ev) + return + } + line = string(bs[:]) + default: + audit.HandlePluginError("log", fmt.Errorf("log format %q is not in list of known formats (%s)", + b.format, strings.Join(AllowedFormats, ",")), ev) + return + } + if _, err := fmt.Fprint(b.out, line); err != nil { audit.HandlePluginError("log", err, ev) } }