Skip to content

Commit 303e1c1

Browse files
committed
Improve performance of http access logs
Fixes: * Don't call LogArgs if log will not be written due low verbosity * Create separate slice for hijacked to avoid append on main path * Shorten log message as this log is to common to be verbose name old time/op new time/op delta WithLogging-4 4.95µs ± 3% 3.52µs ± 1% -28.80% (p=0.000 n=10+8) name old alloc/op new alloc/op delta WithLogging-4 2.93kB ± 0% 1.22kB ± 0% -58.45% (p=0.000 n=10+9) name old allocs/op new allocs/op delta WithLogging-4 32.0 ± 0% 20.0 ± 0% -37.50% (p=0.000 n=10+10)
1 parent db8a887 commit 303e1c1

File tree

1 file changed

+19
-11
lines changed
  • staging/src/k8s.io/apiserver/pkg/server/httplog

1 file changed

+19
-11
lines changed

staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go

Lines changed: 19 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -85,7 +85,9 @@ func WithLogging(handler http.Handler, pred StacktracePred) http.Handler {
8585
rl := newLogged(req, w).StacktraceWhen(pred)
8686
req = req.WithContext(context.WithValue(ctx, respLoggerContextKey, rl))
8787

88-
defer func() { klog.V(3).InfoS("Received HTTP request", rl.LogArgs()...) }()
88+
if klog.V(3).Enabled() {
89+
defer func() { klog.InfoS("HTTP", rl.LogArgs()...) }()
90+
}
8991
handler.ServeHTTP(rl, req)
9092
})
9193
}
@@ -155,24 +157,30 @@ func (rl *respLogger) Addf(format string, data ...interface{}) {
155157

156158
func (rl *respLogger) LogArgs() []interface{} {
157159
latency := time.Since(rl.startTime)
160+
if rl.hijacked {
161+
return []interface{}{
162+
"verb", rl.req.Method,
163+
"URI", rl.req.RequestURI,
164+
"latency", latency,
165+
"userAgent", rl.req.UserAgent(),
166+
"srcIP", rl.req.RemoteAddr,
167+
"hijacked", true,
168+
}
169+
}
158170
args := []interface{}{
159171
"verb", rl.req.Method,
160172
"URI", rl.req.RequestURI,
161173
"latency", latency,
162174
"userAgent", rl.req.UserAgent(),
163175
"srcIP", rl.req.RemoteAddr,
176+
"resp", rl.status,
177+
}
178+
if len(rl.statusStack) > 0 {
179+
args = append(args, "statusStack", rl.statusStack)
164180
}
165-
if rl.hijacked {
166-
args = append(args, "hijacked", true)
167-
} else {
168-
args = append(args, "resp", rl.status)
169-
if len(rl.statusStack) > 0 {
170-
args = append(args, "statusStack", rl.statusStack)
171-
}
172181

173-
if len(rl.addedInfo) > 0 {
174-
args = append(args, "addedInfo", rl.addedInfo)
175-
}
182+
if len(rl.addedInfo) > 0 {
183+
args = append(args, "addedInfo", rl.addedInfo)
176184
}
177185
return args
178186
}

0 commit comments

Comments
 (0)