github/kubernetes
1
0
Fork 0
mirror of https://github.com/k3s-io/kubernetes.git synced 2025-07-28 14:07:14 +00:00
Code Issues Projects Releases Wiki Activity

Migrate API server logs to Structured logging framewrok

Browse Source
This commit is contained in:
AkashSarda 2020-06-17 21:06:35 +00:00
parent 0281b85640
commit af60e7b34d
3 changed files with 23 additions and 22 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
staging/src/k8s.io/apiserver/pkg/endpoints/handlers/get.go
View File

@ -248,7 +248,7 @@ func ListResource(r rest.Lister, rw rest.Watcher, scope *RequestScope, forceWatc
if timeout == 0 && minRequestTimeout > 0 { if timeout == 0 && minRequestTimeout > 0 {
timeout = time.Duration(float64(minRequestTimeout) * (rand.Float64() + 1.0)) timeout = time.Duration(float64(minRequestTimeout) * (rand.Float64() + 1.0))
} }
klog.V(3).Infof("Starting watch for %s, rv=%s labels=%s fields=%s timeout=%s", req.URL.Path, opts.ResourceVersion, opts.LabelSelector, opts.FieldSelector, timeout) klog.V(3).InfoS("Starting watch", "path", req.URL.Path, "resourceVersion", opts.ResourceVersion, "labels", opts.LabelSelector, "fields", opts.FieldSelector, "timeout", timeout)
ctx, cancel := context.WithTimeout(ctx, timeout) ctx, cancel := context.WithTimeout(ctx, timeout)
defer cancel() defer cancel()
watcher, err := rw.Watch(ctx, &opts) watcher, err := rw.Watch(ctx, &opts)

34
staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go
View File

@ -85,7 +85,7 @@ func WithLogging(handler http.Handler, pred StacktracePred) http.Handler {
rl := newLogged(req, w).StacktraceWhen(pred) rl := newLogged(req, w).StacktraceWhen(pred)
req = req.WithContext(context.WithValue(ctx, respLoggerContextKey, rl)) req = req.WithContext(context.WithValue(ctx, respLoggerContextKey, rl))
defer rl.Log() defer func() { klog.V(3).InfoS("Received HTTP request", rl.LogArgs()...) }()
handler.ServeHTTP(rl, req) handler.ServeHTTP(rl, req)
}) })
} }
@ -153,24 +153,28 @@ func (rl *respLogger) Addf(format string, data ...interface{}) {
rl.addedInfo += "\n" + fmt.Sprintf(format, data...) rl.addedInfo += "\n" + fmt.Sprintf(format, data...)
} }
// Log is intended to be called once at the end of your request handler, via defer func (rl *respLogger) LogArgs() []interface{} {
func (rl *respLogger) Log() {
latency := time.Since(rl.startTime) latency := time.Since(rl.startTime)
if klog.V(3).Enabled() { args := []interface{}{
if !rl.hijacked { "verb", rl.req.Method,
klog.InfoDepth(1, fmt.Sprintf("verb=%q URI=%q latency=%v resp=%v UserAgent=%q srcIP=%q: %v%v", "URI", rl.req.RequestURI,
rl.req.Method, rl.req.RequestURI, "latency", latency,
latency, rl.status, "userAgent", rl.req.UserAgent(),
rl.req.UserAgent(), rl.req.RemoteAddr, "srcIP", rl.req.RemoteAddr,
rl.statusStack, rl.addedInfo, }
)) if rl.hijacked {
args = append(args, "hijacked", true)
} else { } else {
klog.InfoDepth(1, fmt.Sprintf("verb=%q URI=%q latency=%v UserAgent=%q srcIP=%q: hijacked", args = append(args, "resp", rl.status)
rl.req.Method, rl.req.RequestURI, if len(rl.statusStack) > 0 {
latency, rl.req.UserAgent(), rl.req.RemoteAddr, args = append(args, "statusStack", rl.statusStack)
)) }
if len(rl.addedInfo) > 0 {
args = append(args, "addedInfo", rl.addedInfo)
} }
} }
return args
} }
// Header implements http.ResponseWriter. // Header implements http.ResponseWriter.

7
staging/src/k8s.io/apiserver/pkg/storage/etcd3/watcher.go
View File

@ -261,8 +261,7 @@ func (wc *watchChan) processEvent(wg *sync.WaitGroup) {
continue continue
} }
if len(wc.resultChan) == outgoingBufSize { if len(wc.resultChan) == outgoingBufSize {
klog.V(3).Infof("Fast watcher, slow processing. Number of buffered events: %d."+ klog.V(3).InfoS("Fast watcher, slow processing. Probably caused by slow dispatching events to watchers", "outgoingEvents", outgoingBufSize)
"Probably caused by slow dispatching events to watchers", outgoingBufSize)
} }
// If user couldn't receive results fast enough, we also block incoming events from watcher. // If user couldn't receive results fast enough, we also block incoming events from watcher.
// Because storing events in local will cause more memory usage. // Because storing events in local will cause more memory usage.
@ -368,9 +367,7 @@ func (wc *watchChan) sendError(err error) {
func (wc *watchChan) sendEvent(e *event) { func (wc *watchChan) sendEvent(e *event) {
if len(wc.incomingEventChan) == incomingBufSize { if len(wc.incomingEventChan) == incomingBufSize {
klog.V(3).Infof("Fast watcher, slow processing. Number of buffered events: %d."+ klog.V(3).InfoS("Fast watcher, slow processing. Probably caused by slow decoding, user not receiving fast, or other processing logic", "incomingEvents", incomingBufSize)
"Probably caused by slow decoding, user not receiving fast, or other processing logic",
incomingBufSize)
} }
select { select {
case wc.incomingEventChan <- e: case wc.incomingEventChan <- e: