Skip to content

Commit

Permalink
Merge pull request kubernetes#106112 from marseel/automated-cherry-pi…
Browse files Browse the repository at this point in the history
…ck-of-#105734-upstream-release-1.22

Automated cherry pick of kubernetes#105734: Fix race condition in logging when request times out
  • Loading branch information
k8s-ci-robot committed Nov 4, 2021
2 parents 33b5f0f + 9e778cb commit e091d57
Showing 1 changed file with 21 additions and 5 deletions.
26 changes: 21 additions & 5 deletions staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ import (
"net/http"
"runtime"
"strings"
"sync"
"time"

"k8s.io/apiserver/pkg/endpoints/metrics"
Expand Down Expand Up @@ -54,13 +55,17 @@ type respLogger struct {
statusRecorded bool
status int
statusStack string
addedInfo strings.Builder
startTime time.Time
// mutex is used when accessing addedInfo
// It can be modified by other goroutine when logging happens (in case of request timeout)
mutex sync.Mutex
addedInfo strings.Builder
startTime time.Time

captureErrorOutput bool

req *http.Request
w http.ResponseWriter
req *http.Request
userAgent string
w http.ResponseWriter

logStacktracePred StacktracePred
}
Expand Down Expand Up @@ -121,6 +126,7 @@ func newLoggedWithStartTime(req *http.Request, w http.ResponseWriter, startTime
return &respLogger{
startTime: startTime,
req: req,
userAgent: req.UserAgent(),
w: w,
logStacktracePred: DefaultStacktracePred,
}
Expand Down Expand Up @@ -171,6 +177,8 @@ func StatusIsNot(statuses ...int) StacktracePred {

// Addf adds additional data to be logged with this request.
func (rl *respLogger) Addf(format string, data ...interface{}) {
rl.mutex.Lock()
defer rl.mutex.Unlock()
rl.addedInfo.WriteString("\n")
rl.addedInfo.WriteString(fmt.Sprintf(format, data...))
}
Expand Down Expand Up @@ -200,10 +208,18 @@ func (rl *respLogger) Log() {
"verb", verb,
"URI", rl.req.RequestURI,
"latency", latency,
"userAgent", rl.req.UserAgent(),
// We can't get UserAgent from rl.req.UserAgent() here as it accesses headers map,
// which can be modified in another goroutine when apiserver request times out.
// For example authentication filter modifies request's headers,
// This can cause apiserver to crash with unrecoverable fatal error.
// More info about concurrent read and write for maps: https://golang.org/doc/go1.6#runtime
"userAgent", rl.userAgent,
"audit-ID", auditID,
"srcIP", rl.req.RemoteAddr,
}
// Lock for accessing addedInfo
rl.mutex.Lock()
defer rl.mutex.Unlock()

if rl.hijacked {
keysAndValues = append(keysAndValues, "hijacked", true)
Expand Down

0 comments on commit e091d57

Please sign in to comment.