diff --git a/staging/src/k8s.io/apiserver/pkg/apis/audit/types.go b/staging/src/k8s.io/apiserver/pkg/apis/audit/types.go index ead79439f81..00b5c1dc07b 100644 --- a/staging/src/k8s.io/apiserver/pkg/apis/audit/types.go +++ b/staging/src/k8s.io/apiserver/pkg/apis/audit/types.go @@ -77,15 +77,10 @@ const ( // Event captures all the information that can be included in an API audit log. type Event struct { metav1.TypeMeta - // ObjectMeta is included for interoperability with API infrastructure. - // +optional - metav1.ObjectMeta // AuditLevel at which event was generated Level Level - // Time the request reached the apiserver. - Timestamp metav1.Time // Unique audit ID, generated for each request. AuditID types.UID // Stage of the request handling when this event instance was generated. @@ -121,10 +116,15 @@ type Event struct { // +optional RequestObject *runtime.Unknown // API object returned in the response, in JSON. The ResponseObject is recorded after conversion - // to the external type, and serialized as JSON. Omitted for non-resource requests. Only logged + // to the external type, and serialized as JSON. Omitted for non-resource requests. Only logged // at Response Level. // +optional ResponseObject *runtime.Unknown + + // Time the request reached the apiserver. + RequestReceivedTimestamp metav1.MicroTime + // Time the request reached current audit stage. + StageTimestamp metav1.MicroTime } // +k8s:deepcopy-gen:interfaces=k8s.io/apimachinery/pkg/runtime.Object diff --git a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/conversion.go b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/conversion.go index 5f9cc5c1e11..78e5eab09dc 100644 --- a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/conversion.go +++ b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/conversion.go @@ -19,6 +19,7 @@ package v1alpha1 import ( "strings" + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/conversion" "k8s.io/apiserver/pkg/apis/audit" ) @@ -52,3 +53,26 @@ func Convert_v1alpha1_ObjectReference_To_audit_ObjectReference(in *ObjectReferen } return nil } + +func Convert_v1alpha1_Event_To_audit_Event(in *Event, out *audit.Event, s conversion.Scope) error { + if err := autoConvert_v1alpha1_Event_To_audit_Event(in, out, s); err != nil { + return err + } + if out.StageTimestamp.IsZero() { + out.StageTimestamp = metav1.NewMicroTime(in.CreationTimestamp.Time) + } + if out.RequestReceivedTimestamp.IsZero() { + out.RequestReceivedTimestamp = metav1.NewMicroTime(in.Timestamp.Time) + } + return nil +} + +func Convert_audit_Event_To_v1alpha1_Event(in *audit.Event, out *Event, s conversion.Scope) error { + if err := autoConvert_audit_Event_To_v1alpha1_Event(in, out, s); err != nil { + return err + } + out.CreationTimestamp = metav1.NewTime(in.StageTimestamp.Time) + out.Timestamp = metav1.NewTime(in.RequestReceivedTimestamp.Time) + return nil + +} diff --git a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/conversion_test.go b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/conversion_test.go index 38918e75b36..8b704ab77dc 100644 --- a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/conversion_test.go +++ b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/conversion_test.go @@ -19,7 +19,9 @@ package v1alpha1 import ( "reflect" "testing" + "time" + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/runtime/schema" auditinternal "k8s.io/apiserver/pkg/apis/audit" @@ -36,7 +38,7 @@ func init() { RegisterConversions(scheme) } -func TestConversion(t *testing.T) { +func TestConversionObjectReference(t *testing.T) { scheme.Log(t) testcases := []struct { @@ -92,3 +94,114 @@ func TestConversion(t *testing.T) { }) } } + +func TestConversionEventToInternal(t *testing.T) { + scheme.Log(t) + + time1 := time.Now() + time2 := time.Now() + testcases := []struct { + desc string + old *Event + expected *auditinternal.Event + }{ + { + "StageTimestamp is empty", + &Event{ + ObjectMeta: metav1.ObjectMeta{ + CreationTimestamp: metav1.NewTime(time1), + }, + }, + &auditinternal.Event{ + StageTimestamp: metav1.NewMicroTime(time1), + }, + }, + { + "StageTimestamp is not empty", + &Event{ + ObjectMeta: metav1.ObjectMeta{ + CreationTimestamp: metav1.NewTime(time1), + }, + StageTimestamp: metav1.NewMicroTime(time2), + }, + &auditinternal.Event{ + StageTimestamp: metav1.NewMicroTime(time2), + }, + }, + { + "RequestReceivedTimestamp is empty", + &Event{ + Timestamp: metav1.NewTime(time1), + }, + &auditinternal.Event{ + RequestReceivedTimestamp: metav1.NewMicroTime(time1), + }, + }, + { + "RequestReceivedTimestamp is not empty", + &Event{ + Timestamp: metav1.NewTime(time1), + RequestReceivedTimestamp: metav1.NewMicroTime(time2), + }, + &auditinternal.Event{ + RequestReceivedTimestamp: metav1.NewMicroTime(time2), + }, + }, + } + for _, tc := range testcases { + t.Run(tc.desc, func(t *testing.T) { + internal := &auditinternal.Event{} + if err := scheme.Convert(tc.old, internal, nil); err != nil { + t.Errorf("unexpected error: %v", err) + } + if !reflect.DeepEqual(internal, tc.expected) { + t.Errorf("expected\n\t%#v, got \n\t%#v", tc.expected, internal) + } + }) + } +} + +func TestConversionInternalToEvent(t *testing.T) { + scheme.Log(t) + + now := time.Now() + testcases := []struct { + desc string + old *auditinternal.Event + expected *Event + }{ + { + "convert stageTimestamp", + &auditinternal.Event{ + StageTimestamp: metav1.NewMicroTime(now), + }, + &Event{ + ObjectMeta: metav1.ObjectMeta{ + CreationTimestamp: metav1.NewTime(now), + }, + StageTimestamp: metav1.NewMicroTime(now), + }, + }, + { + "convert RequestReceivedTimestamp", + &auditinternal.Event{ + RequestReceivedTimestamp: metav1.NewMicroTime(now), + }, + &Event{ + Timestamp: metav1.NewTime(now), + RequestReceivedTimestamp: metav1.NewMicroTime(now), + }, + }, + } + for _, tc := range testcases { + t.Run(tc.desc, func(t *testing.T) { + event := &Event{} + if err := scheme.Convert(tc.old, event, nil); err != nil { + t.Errorf("unexpected error: %v", err) + } + if !reflect.DeepEqual(event, tc.expected) { + t.Errorf("expected\n\t%#v, got \n\t%#v", tc.expected, event) + } + }) + } +} diff --git a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/types.go b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/types.go index 6698ad3b7b3..ba00bf733e7 100644 --- a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/types.go +++ b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1alpha1/types.go @@ -126,6 +126,12 @@ type Event struct { // at Response Level. // +optional ResponseObject *runtime.Unknown `json:"responseObject,omitempty" protobuf:"bytes,14,opt,name=responseObject"` + // Time the request reached the apiserver. + // +optional + RequestReceivedTimestamp metav1.MicroTime `json:"requestReceivedTimestamp" protobuf:"bytes,15,opt,name=requestReceivedTimestamp"` + // Time the request reached current audit stage. + // +optional + StageTimestamp metav1.MicroTime `json:"stageTimestamp" protobuf:"bytes,16,opt,name=stageTimestamp"` } // +k8s:deepcopy-gen:interfaces=k8s.io/apimachinery/pkg/runtime.Object diff --git a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/conversion.go b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/conversion.go new file mode 100644 index 00000000000..bccdcb72437 --- /dev/null +++ b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/conversion.go @@ -0,0 +1,45 @@ +/* +Copyright 2017 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 v1beta1 + +import ( + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + "k8s.io/apimachinery/pkg/conversion" + "k8s.io/apiserver/pkg/apis/audit" +) + +func Convert_v1beta1_Event_To_audit_Event(in *Event, out *audit.Event, s conversion.Scope) error { + if err := autoConvert_v1beta1_Event_To_audit_Event(in, out, s); err != nil { + return err + } + if out.StageTimestamp.IsZero() { + out.StageTimestamp = metav1.NewMicroTime(in.CreationTimestamp.Time) + } + if out.RequestReceivedTimestamp.IsZero() { + out.RequestReceivedTimestamp = metav1.NewMicroTime(in.Timestamp.Time) + } + return nil +} + +func Convert_audit_Event_To_v1beta1_Event(in *audit.Event, out *Event, s conversion.Scope) error { + if err := autoConvert_audit_Event_To_v1beta1_Event(in, out, s); err != nil { + return err + } + out.CreationTimestamp = metav1.NewTime(in.StageTimestamp.Time) + out.Timestamp = metav1.NewTime(in.RequestReceivedTimestamp.Time) + return nil +} diff --git a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/conversion_test.go b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/conversion_test.go new file mode 100644 index 00000000000..e0a1bed552c --- /dev/null +++ b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/conversion_test.go @@ -0,0 +1,150 @@ +/* +Copyright 2017 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 v1beta1 + +import ( + "reflect" + "testing" + "time" + + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + "k8s.io/apimachinery/pkg/runtime" + "k8s.io/apimachinery/pkg/runtime/schema" + auditinternal "k8s.io/apiserver/pkg/apis/audit" +) + +var scheme = runtime.NewScheme() + +func init() { + addKnownTypes(scheme) + internalGV := schema.GroupVersion{Group: auditinternal.GroupName, Version: runtime.APIVersionInternal} + scheme.AddKnownTypes(internalGV, + &auditinternal.Event{}, + ) + RegisterConversions(scheme) +} + +func TestConversionEventToInternal(t *testing.T) { + scheme.Log(t) + + time1 := time.Now() + time2 := time.Now() + testcases := []struct { + desc string + old *Event + expected *auditinternal.Event + }{ + { + "StageTimestamp is empty", + &Event{ + ObjectMeta: metav1.ObjectMeta{ + CreationTimestamp: metav1.NewTime(time1), + }, + }, + &auditinternal.Event{ + StageTimestamp: metav1.NewMicroTime(time1), + }, + }, + { + "StageTimestamp is not empty", + &Event{ + ObjectMeta: metav1.ObjectMeta{ + CreationTimestamp: metav1.NewTime(time1), + }, + StageTimestamp: metav1.NewMicroTime(time2), + }, + &auditinternal.Event{ + StageTimestamp: metav1.NewMicroTime(time2), + }, + }, + { + "RequestReceivedTimestamp is empty", + &Event{ + Timestamp: metav1.NewTime(time1), + }, + &auditinternal.Event{ + RequestReceivedTimestamp: metav1.NewMicroTime(time1), + }, + }, + { + "RequestReceivedTimestamp is not empty", + &Event{ + Timestamp: metav1.NewTime(time1), + RequestReceivedTimestamp: metav1.NewMicroTime(time2), + }, + &auditinternal.Event{ + RequestReceivedTimestamp: metav1.NewMicroTime(time2), + }, + }, + } + for _, tc := range testcases { + t.Run(tc.desc, func(t *testing.T) { + internal := &auditinternal.Event{} + if err := scheme.Convert(tc.old, internal, nil); err != nil { + t.Errorf("unexpected error: %v", err) + } + if !reflect.DeepEqual(internal, tc.expected) { + t.Errorf("expected\n\t%#v, got \n\t%#v", tc.expected, internal) + } + }) + } +} + +func TestConversionInternalToEvent(t *testing.T) { + scheme.Log(t) + + now := time.Now() + testcases := []struct { + desc string + old *auditinternal.Event + expected *Event + }{ + { + "convert stageTimestamp", + &auditinternal.Event{ + StageTimestamp: metav1.NewMicroTime(now), + }, + &Event{ + ObjectMeta: metav1.ObjectMeta{ + CreationTimestamp: metav1.NewTime(now), + }, + StageTimestamp: metav1.NewMicroTime(now), + }, + }, + { + "convert RequestReceivedTimestamp", + &auditinternal.Event{ + RequestReceivedTimestamp: metav1.NewMicroTime(now), + }, + &Event{ + Timestamp: metav1.NewTime(now), + RequestReceivedTimestamp: metav1.NewMicroTime(now), + }, + }, + } + for _, tc := range testcases { + t.Run(tc.desc, func(t *testing.T) { + event := &Event{} + if err := scheme.Convert(tc.old, event, nil); err != nil { + t.Errorf("unexpected error: %v", err) + } + if !reflect.DeepEqual(event, tc.expected) { + t.Errorf("expected\n\t%#v, got \n\t%#v", tc.expected, event) + } + }) + } +} diff --git a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/types.go b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/types.go index 1de8d75748c..b76170f4492 100644 --- a/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/types.go +++ b/staging/src/k8s.io/apiserver/pkg/apis/audit/v1beta1/types.go @@ -73,12 +73,15 @@ type Event struct { metav1.TypeMeta `json:",inline"` // ObjectMeta is included for interoperability with API infrastructure. // +optional + // DEPRECATED: Use StageTimestamp which supports micro second instead of ObjectMeta.CreateTimestamp + // and the rest of the object is not used metav1.ObjectMeta `json:"metadata,omitempty" protobuf:"bytes,1,opt,name=metadata"` // AuditLevel at which event was generated Level Level `json:"level" protobuf:"bytes,2,opt,name=level,casttype=Level"` // Time the request reached the apiserver. + // DEPRECATED: Use RequestReceivedTimestamp which supports micro second instead. Timestamp metav1.Time `json:"timestamp" protobuf:"bytes,3,opt,name=timestamp"` // Unique audit ID, generated for each request. AuditID types.UID `json:"auditID" protobuf:"bytes,4,opt,name=auditID,casttype=k8s.io/apimachinery/pkg/types.UID"` @@ -119,6 +122,12 @@ type Event struct { // at Response Level. // +optional ResponseObject *runtime.Unknown `json:"responseObject,omitempty" protobuf:"bytes,14,opt,name=responseObject"` + // Time the request reached the apiserver. + // +optional + RequestReceivedTimestamp metav1.MicroTime `json:"requestReceivedTimestamp" protobuf:"bytes,15,opt,name=requestReceivedTimestamp"` + // Time the request reached current audit stage. + // +optional + StageTimestamp metav1.MicroTime `json:"stageTimestamp" protobuf:"bytes,16,opt,name=stageTimestamp"` } // +k8s:deepcopy-gen:interfaces=k8s.io/apimachinery/pkg/runtime.Object diff --git a/staging/src/k8s.io/apiserver/pkg/audit/format.go b/staging/src/k8s.io/apiserver/pkg/audit/format.go index 62076d695c5..bf805f52573 100644 --- a/staging/src/k8s.io/apiserver/pkg/audit/format.go +++ b/staging/src/k8s.io/apiserver/pkg/audit/format.go @@ -61,7 +61,7 @@ func EventString(ev *auditinternal.Event) string { } return fmt.Sprintf("%s AUDIT: id=%q stage=%q ip=%q method=%q user=%q groups=%q as=%q asgroups=%q namespace=%q uri=%q response=\"%s\"", - ev.Timestamp.Format(time.RFC3339Nano), ev.AuditID, ev.Stage, ip, ev.Verb, username, groups, asuser, asgroups, namespace, ev.RequestURI, response) + ev.RequestReceivedTimestamp.Format(time.RFC3339Nano), ev.AuditID, ev.Stage, ip, ev.Verb, username, groups, asuser, asgroups, namespace, ev.RequestURI, response) } func auditStringSlice(inList []string) string { diff --git a/staging/src/k8s.io/apiserver/pkg/audit/request.go b/staging/src/k8s.io/apiserver/pkg/audit/request.go index 955cef2e104..b738076a74f 100644 --- a/staging/src/k8s.io/apiserver/pkg/audit/request.go +++ b/staging/src/k8s.io/apiserver/pkg/audit/request.go @@ -40,7 +40,7 @@ import ( func NewEventFromRequest(req *http.Request, level auditinternal.Level, attribs authorizer.Attributes) (*auditinternal.Event, error) { ev := &auditinternal.Event{ - Timestamp: metav1.NewTime(time.Now()), + RequestReceivedTimestamp: metav1.NewMicroTime(time.Now()), Verb: attribs.GetVerb(), RequestURI: req.URL.RequestURI(), } diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit.go index 26af50b1d37..01fc957c1ce 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit.go @@ -148,7 +148,12 @@ func processAuditEvent(sink audit.Sink, ev *auditinternal.Event, omitStages []au return } } - ev.CreationTimestamp = metav1.NewTime(time.Now()) + + if ev.Stage == auditinternal.StageRequestReceived { + ev.StageTimestamp = metav1.NewMicroTime(ev.RequestReceivedTimestamp.Time) + } else { + ev.StageTimestamp = metav1.NewMicroTime(time.Now()) + } audit.ObserveEvent() sink.ProcessEvents(ev) } diff --git a/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/backend_test.go b/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/backend_test.go index 84a3f066119..44f01a0c666 100644 --- a/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/backend_test.go +++ b/staging/src/k8s.io/apiserver/plugin/pkg/audit/log/backend_test.go @@ -73,10 +73,10 @@ func TestLogEventsLegacy(t *testing.T) { SourceIPs: []string{ "127.0.0.1", }, - Timestamp: metav1.NewTime(time.Now()), - AuditID: types.UID(uuid.NewRandom().String()), - Stage: auditinternal.StageRequestReceived, - Verb: "get", + RequestReceivedTimestamp: metav1.NewMicroTime(time.Now()), + AuditID: types.UID(uuid.NewRandom().String()), + Stage: auditinternal.StageRequestReceived, + Verb: "get", User: auditinternal.UserInfo{ Username: "admin", Groups: []string{ @@ -130,13 +130,11 @@ func TestLogEventsJson(t *testing.T) { SourceIPs: []string{ "127.0.0.1", }, - // When encoding to json format, the nanosecond part of timestamp is - // lost and it will become zero when we decode event back, so we rounding - // timestamp down to a multiple of second. - Timestamp: metav1.NewTime(time.Now().Truncate(time.Second)), - AuditID: types.UID(uuid.NewRandom().String()), - Stage: auditinternal.StageRequestReceived, - Verb: "get", + RequestReceivedTimestamp: metav1.NewMicroTime(time.Now().Truncate(time.Microsecond)), + StageTimestamp: metav1.NewMicroTime(time.Now().Truncate(time.Microsecond)), + AuditID: types.UID(uuid.NewRandom().String()), + Stage: auditinternal.StageRequestReceived, + Verb: "get", User: auditinternal.UserInfo{ Username: "admin", Groups: []string{