2017-02-08 51 views
0

轉到ENV:golang請求頭併發讀寫

GOARCH = 「AMD64」

GOBIN = 「/根/」

GOEXE = 「」

GOHOSTARCH =「amd64」

GOHOSTOS =「linux」

GOOS = 「LINUX」

GOPATH = 「/數據/工作區/ kubernetes」

GORACE = 「」

GOROOT = 「/ USR /本地/去」

GOTOOLDIR = 「在/ usr /本地/去/包裝/工具/ linux_amd64」

GO15VENDOREXPERIMENT = 「1」

CC = 「海灣合作委員會」

GOGCCFLAGS = 「 - 子卡-m64 -pthread -fmessage長度= 0」

CXX = 「克++」

CGO_ENABLED = 「1」

轉到版本:

go版本go1.6.3 linux/amd64

這個問題在高負載的「性能測試env」kube-apiserver上發生。 KUBE-API服務器恐慌和退出:

fatal error: concurrent map read and map write 

goroutine 77930636 [running]: 
runtime.throw(0x2f4c4c0, 0x21) 
    /root/.gvm/gos/go1.6.3/src/runtime/panic.go:547 +0x90 fp=0xca67b477f0  sp=0xca67b477d8 
runtime.mapaccess1_faststr(0x2a8e520, 0xc9e29000f0, 0x2c11220, 0xa, 0x433e360) 
    /root/.gvm/gos/go1.6.3/src/runtime/hashmap_fast.go:202 +0x5b fp=0xca67b47850 sp=0xca67b477f0 
k8s.io/kubernetes/pkg/httplog.(*respLogger).Log(0xcbddf2ae70) 
     /data/gerrit/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/httplog/log.go:180 +0x43d fp=0xca67b47af8 sp=0xca67b47850 
k8s.io/kubernetes/pkg/apiserver.RecoverPanics.func1(0x7f099f157090, 0xcbddf2ae70, 0xcd7569e380) 
    /data/gerrit/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:174 +0x15d fp=0xca67b47b50 sp=0xca67b47af8 
    net/http.HandlerFunc.ServeHTTP(0xc821a4eac0, 0x7f099f157058, 0xca0f4eb450, 0xcd7569e380) 
    /root/.gvm/gos/go1.6.3/src/net/http/server.go:1618 +0x3a fp=0xca67b47b70 sp=0xca67b47b50 
net/http.serverHandler.ServeHTTP(0xc8215a7b80, 0x7f099f157058, 0xca0f4eb450, 0xcd7569e380) 
    /root/.gvm/gos/go1.6.3/src/net/http/server.go:2081 +0x19e fp=0xca67b47bd0 sp=0xca67b47b70 
net/http.(*conn).serve(0xc8b5d6b980) 
    /root/.gvm/gos/go1.6.3/src/net/http/server.go:1472 +0xf2e fp=0xca67b47f98 sp=0xca67b47bd0 
runtime.goexit() 
    /root/.gvm/gos/go1.6.3/src/runtime/asm_amd64.s:1998 +0x1 fp=0xca67b47fa0 sp=0xca67b47f98 
created by net/http.(*Server).Serve 
    /root/.gvm/gos/go1.6.3/src/net/http/server.go:2137 +0x44e 

對應的源代碼:

PKG/API服務器/ handlers.go

145 func RecoverPanics(handler http.Handler) http.Handler { 
146 return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { 
147 defer func() { 
148  if x := recover(); x != nil { 
149   http.Error(w, "apis panic. Look in log for details.", http.StatusInternalServerError) 
150   glog.Errorf("APIServer panic'd on %v %v: %v\n%s\n", req.Method, req.RequestURI, x, debug.Stack()) 
151  } 
152 }() 
153 defer httplog.NewLogged(req, &w).StacktraceWhen(
     httplog.StatusIsNot(
      http.StatusOK, 
      http.StatusCreated, 
      http.StatusAccepted, 
      http.StatusBadRequest, 
      http.StatusMovedPermanently, 
      http.StatusTemporaryRedirect, 
      http.StatusConflict, 
      http.StatusNotFound, 
      http.StatusUnauthorized, 
      http.StatusForbidden, 
      errors.StatusUnprocessableEntity, 
      http.StatusSwitchingProtocols, 
      http.StatusRequestTimeout, 
      errors.StatusTooManyRequests, 
     ), 
170).Log() 

    // Dispatch to the internal handler 
    handler.ServeHTTP(w, req) 
174 }) 
} 

PKG/HTTPLOG/log.go:

159 func (rl *respLogger) Log() { 
160 latency := time.Since(rl.startTime) 
161 if glog.V(2) { 
162  extraInfo := "" 
163  if latency >= time.Millisecond*200 && latency < time.Second { 
     extraInfo = fmt.Sprintf("%d00.Millisecond", latency/(time.Millisecond*100)) 
    } else if latency >= time.Second && latency < time.Minute { // Warning 
     extraInfo = fmt.Sprintf("%d.Second", latency/(time.Second)) 
    } else if latency >= time.Minute { // nce will timeout 
     extraInfo = fmt.Sprintf("%d.Minutes", latency/(time.Minute)) 
    } 
    method := rl.req.Method 
    if len(rl.req.Header["Detailed-Method"]) > 0 { 
     method = rl.req.Header["Detailed-Method"][0] 
    } 

    remoteIP := rl.getXForwardIPAdress(rl.req) 


    if !rl.hijacked { 
     //glog.InfoDepth(1, fmt.Sprintf("%s %s: (%v) %v%v%v [%s %s]", rl.req.Method, rl.req.RequestURI, latency, rl.status, rl.statusStack, rl.addedInfo, rl.req.Header["User-Agent"], rl.req.RemoteAddr)) 
180   glog.InfoDepth(1, fmt.Sprintf("%v %s %s: (%sms) %v%v [%s %s]-%s %v", rl.req.Header["X-Requestid"], method, rl.req.RequestURI, GetMilliLatency(latency), rl.status, rl.addedInfo, rl.req.Header["User-Agent"], remoteIP, extraInfo, rl.statusStack)) 
    } else { 
     //glog.InfoDepth(1, fmt.Sprintf("%s %s: (%v) hijacked [%s %s]", rl.req.Method, rl.req.RequestURI, latency, rl.req.Header["User-Agent"], rl.req.RemoteAddr)) 
     glog.InfoDepth(1, fmt.Sprintf("%v %s %s: (%sms) hijacked [%s %s]-%s", rl.req.Header["X-Requestid"], method, rl.req.RequestURI, GetMilliLatency(latency), rl.req.Header["User-Agent"], remoteIP, extraInfo)) 
    } 
} 

}

在handler.ServeHTTP中,我更改了request.Header。我無法找到原因:

(1)「serveHTTP」和「延遲日誌」以串行方式工作。所以不存在「併發讀寫」

(2)即使存在「併發讀寫」,也存在「恢復」func來處理恐慌,所以kube-apiserver不應該退出。

這個問題花了我很多時間,誰能幫助我?謝謝

+0

會比賽檢測儀的幫助嗎? https://blog.golang.org/race-detector –

+0

感謝您的幫助。我用-race選項建立kube-apiserver,然後運行它,什麼都沒有發生,沒有「DATA RACE」bla bla。 – Bling

+0

「由於它的設計,比賽檢測器只有在實際觸發運行代碼時才能檢測競爭狀況,這意味着在逼真的工作負載下運行支持競態的二進制文件非常重要。」對不起,剛纔注意到了。 這種恐慌在我們的「性能測試環境」中只發生過一次,而且不容易重現。 – Bling

回答

0

我的猜測是,你已經加入了這樣一個事實,即全局超時處理程序不能實際停止處理請求的goroutines。所以當連接超時(1m除非你改變了它),它會返回一個錯誤。如果goroutine實際上同時完成,它也可以嘗試寫入連接。我以爲我們已經添加了一個鎖來防止這個問題的產生,但也許這些頭文件並不總是受鎖的保護。如果您可以在乾淨的源代碼樹中重現此問題,請在Kubernetes github回購中提出問題。

+0

感謝您的幫助。但在全局超時處理程序中,發生超時時,它不會讀取或更改請求標頭。 「併發地圖讀寫」發生的地方只有「讀」操作。 – Bling

+0

在resthandler.go中,我添加了自定義標頭,以便在工作時請求。 req.Request.Header [「Detailed-Method」] = [] string {「GET-」+ scope.Resource.Resource} 這是爲了操作方便,因爲打印在日誌中的方法是http標準而不是k8s標準。但我不認爲這是原因(他們是連續的)。 也許我不應該改變處理程序的請求,它可能會導致微不足道的問題。 – Bling