k8s.io/apiserver@v0.31.1/pkg/endpoints/filters/audit.go (about) 1 /* 2 Copyright 2016 The Kubernetes Authors. 3 4 Licensed under the Apache License, Version 2.0 (the "License"); 5 you may not use this file except in compliance with the License. 6 You may obtain a copy of the License at 7 8 http://www.apache.org/licenses/LICENSE-2.0 9 10 Unless required by applicable law or agreed to in writing, software 11 distributed under the License is distributed on an "AS IS" BASIS, 12 WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 See the License for the specific language governing permissions and 14 limitations under the License. 15 */ 16 17 package filters 18 19 import ( 20 "bufio" 21 "context" 22 "errors" 23 "fmt" 24 "net" 25 "net/http" 26 "sync" 27 "time" 28 29 metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" 30 utilruntime "k8s.io/apimachinery/pkg/util/runtime" 31 auditinternal "k8s.io/apiserver/pkg/apis/audit" 32 "k8s.io/apiserver/pkg/audit" 33 "k8s.io/apiserver/pkg/endpoints/handlers/responsewriters" 34 "k8s.io/apiserver/pkg/endpoints/request" 35 "k8s.io/apiserver/pkg/endpoints/responsewriter" 36 ) 37 38 // WithAudit decorates a http.Handler with audit logging information for all the 39 // requests coming to the server. Audit level is decided according to requests' 40 // attributes and audit policy. Logs are emitted to the audit sink to 41 // process events. If sink or audit policy is nil, no decoration takes place. 42 func WithAudit(handler http.Handler, sink audit.Sink, policy audit.PolicyRuleEvaluator, longRunningCheck request.LongRunningRequestCheck) http.Handler { 43 if sink == nil || policy == nil { 44 return handler 45 } 46 return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { 47 ac, err := evaluatePolicyAndCreateAuditEvent(req, policy) 48 if err != nil { 49 utilruntime.HandleError(fmt.Errorf("failed to create audit event: %v", err)) 50 responsewriters.InternalError(w, req, errors.New("failed to create audit event")) 51 return 52 } 53 54 if !ac.Enabled() { 55 handler.ServeHTTP(w, req) 56 return 57 } 58 ev := &ac.Event 59 60 ctx := req.Context() 61 omitStages := ac.RequestAuditConfig.OmitStages 62 63 ev.Stage = auditinternal.StageRequestReceived 64 if processed := processAuditEvent(ctx, sink, ev, omitStages); !processed { 65 audit.ApiserverAuditDroppedCounter.WithContext(ctx).Inc() 66 responsewriters.InternalError(w, req, errors.New("failed to store audit event")) 67 return 68 } 69 70 // intercept the status code 71 var longRunningSink audit.Sink 72 if longRunningCheck != nil { 73 ri, _ := request.RequestInfoFrom(ctx) 74 if longRunningCheck(req, ri) { 75 longRunningSink = sink 76 } 77 } 78 respWriter := decorateResponseWriter(ctx, w, ev, longRunningSink, omitStages) 79 80 // send audit event when we leave this func, either via a panic or cleanly. In the case of long 81 // running requests, this will be the second audit event. 82 defer func() { 83 if r := recover(); r != nil { 84 defer panic(r) 85 ev.Stage = auditinternal.StagePanic 86 ev.ResponseStatus = &metav1.Status{ 87 Code: http.StatusInternalServerError, 88 Status: metav1.StatusFailure, 89 Reason: metav1.StatusReasonInternalError, 90 Message: fmt.Sprintf("APIServer panic'd: %v", r), 91 } 92 processAuditEvent(ctx, sink, ev, omitStages) 93 return 94 } 95 96 // if no StageResponseStarted event was sent b/c neither a status code nor a body was sent, fake it here 97 // But Audit-Id http header will only be sent when http.ResponseWriter.WriteHeader is called. 98 fakedSuccessStatus := &metav1.Status{ 99 Code: http.StatusOK, 100 Status: metav1.StatusSuccess, 101 Message: "Connection closed early", 102 } 103 if ev.ResponseStatus == nil && longRunningSink != nil { 104 ev.ResponseStatus = fakedSuccessStatus 105 ev.Stage = auditinternal.StageResponseStarted 106 processAuditEvent(ctx, longRunningSink, ev, omitStages) 107 } 108 109 ev.Stage = auditinternal.StageResponseComplete 110 if ev.ResponseStatus == nil { 111 ev.ResponseStatus = fakedSuccessStatus 112 } 113 processAuditEvent(ctx, sink, ev, omitStages) 114 }() 115 handler.ServeHTTP(respWriter, req) 116 }) 117 } 118 119 // evaluatePolicyAndCreateAuditEvent is responsible for evaluating the audit 120 // policy configuration applicable to the request and create a new audit 121 // event that will be written to the API audit log. 122 // - error if anything bad happened 123 func evaluatePolicyAndCreateAuditEvent(req *http.Request, policy audit.PolicyRuleEvaluator) (*audit.AuditContext, error) { 124 ctx := req.Context() 125 ac := audit.AuditContextFrom(ctx) 126 if ac == nil { 127 // Auditing not configured. 128 return nil, nil 129 } 130 131 attribs, err := GetAuthorizerAttributes(ctx) 132 if err != nil { 133 return ac, fmt.Errorf("failed to GetAuthorizerAttributes: %v", err) 134 } 135 136 rac := policy.EvaluatePolicyRule(attribs) 137 audit.ObservePolicyLevel(ctx, rac.Level) 138 ac.RequestAuditConfig = rac 139 if rac.Level == auditinternal.LevelNone { 140 // Don't audit. 141 return ac, nil 142 } 143 144 requestReceivedTimestamp, ok := request.ReceivedTimestampFrom(ctx) 145 if !ok { 146 requestReceivedTimestamp = time.Now() 147 } 148 audit.LogRequestMetadata(ctx, req, requestReceivedTimestamp, rac.Level, attribs) 149 150 return ac, nil 151 } 152 153 // writeLatencyToAnnotation writes the latency incurred in different 154 // layers of the apiserver to the annotations of the audit object. 155 // it should be invoked after ev.StageTimestamp has been set appropriately. 156 func writeLatencyToAnnotation(ctx context.Context, ev *auditinternal.Event) { 157 // we will track latency in annotation only when the total latency 158 // of the given request exceeds 500ms, this is in keeping with the 159 // traces in rest/handlers for create, delete, update, 160 // get, list, and deletecollection. 161 const threshold = 500 * time.Millisecond 162 latency := ev.StageTimestamp.Time.Sub(ev.RequestReceivedTimestamp.Time) 163 if latency <= threshold { 164 return 165 } 166 167 // if we are tracking latency incurred inside different layers within 168 // the apiserver, add these as annotation to the audit event object. 169 layerLatencies := request.AuditAnnotationsFromLatencyTrackers(ctx) 170 if len(layerLatencies) == 0 { 171 // latency tracking is not enabled for this request 172 return 173 } 174 175 // record the total latency for this request, for convenience. 176 layerLatencies["apiserver.latency.k8s.io/total"] = latency.String() 177 audit.AddAuditAnnotationsMap(ctx, layerLatencies) 178 } 179 180 func processAuditEvent(ctx context.Context, sink audit.Sink, ev *auditinternal.Event, omitStages []auditinternal.Stage) bool { 181 for _, stage := range omitStages { 182 if ev.Stage == stage { 183 return true 184 } 185 } 186 187 switch { 188 case ev.Stage == auditinternal.StageRequestReceived: 189 ev.StageTimestamp = metav1.NewMicroTime(ev.RequestReceivedTimestamp.Time) 190 case ev.Stage == auditinternal.StageResponseComplete: 191 ev.StageTimestamp = metav1.NewMicroTime(time.Now()) 192 writeLatencyToAnnotation(ctx, ev) 193 default: 194 ev.StageTimestamp = metav1.NewMicroTime(time.Now()) 195 } 196 197 audit.ObserveEvent(ctx) 198 return sink.ProcessEvents(ev) 199 } 200 201 func decorateResponseWriter(ctx context.Context, responseWriter http.ResponseWriter, ev *auditinternal.Event, sink audit.Sink, omitStages []auditinternal.Stage) http.ResponseWriter { 202 delegate := &auditResponseWriter{ 203 ctx: ctx, 204 ResponseWriter: responseWriter, 205 event: ev, 206 sink: sink, 207 omitStages: omitStages, 208 } 209 210 return responsewriter.WrapForHTTP1Or2(delegate) 211 } 212 213 var _ http.ResponseWriter = &auditResponseWriter{} 214 var _ responsewriter.UserProvidedDecorator = &auditResponseWriter{} 215 216 // auditResponseWriter intercepts WriteHeader, sets it in the event. If the sink is set, it will 217 // create immediately an event (for long running requests). 218 type auditResponseWriter struct { 219 http.ResponseWriter 220 ctx context.Context 221 event *auditinternal.Event 222 once sync.Once 223 sink audit.Sink 224 omitStages []auditinternal.Stage 225 } 226 227 func (a *auditResponseWriter) Unwrap() http.ResponseWriter { 228 return a.ResponseWriter 229 } 230 231 func (a *auditResponseWriter) processCode(code int) { 232 a.once.Do(func() { 233 if a.event.ResponseStatus == nil { 234 a.event.ResponseStatus = &metav1.Status{} 235 } 236 a.event.ResponseStatus.Code = int32(code) 237 a.event.Stage = auditinternal.StageResponseStarted 238 239 if a.sink != nil { 240 processAuditEvent(a.ctx, a.sink, a.event, a.omitStages) 241 } 242 }) 243 } 244 245 func (a *auditResponseWriter) Write(bs []byte) (int, error) { 246 // the Go library calls WriteHeader internally if no code was written yet. But this will go unnoticed for us 247 a.processCode(http.StatusOK) 248 return a.ResponseWriter.Write(bs) 249 } 250 251 func (a *auditResponseWriter) WriteHeader(code int) { 252 a.processCode(code) 253 a.ResponseWriter.WriteHeader(code) 254 } 255 256 func (a *auditResponseWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) { 257 // fake a response status before protocol switch happens 258 a.processCode(http.StatusSwitchingProtocols) 259 260 // the outer ResponseWriter object returned by WrapForHTTP1Or2 implements 261 // http.Hijacker if the inner object (a.ResponseWriter) implements http.Hijacker. 262 return a.ResponseWriter.(http.Hijacker).Hijack() 263 }