Golang 의 HTTP server 502 문제 분석
16432 단어 golang
『 8195 』 생산 환경 Golang 서 비 스 는 가끔 502 신고 가 발생 할 수 있 습 니 다. 조사 결과 대부분이 다음 과 같은 세 가지 원인 으로 인해 발생 한 것 입 니 다.
『 8195 』 세 번 째 케이스 는 매우 간단 하 므 로 본 고 는 앞의 두 가지 케이스 뒤의 심층 원인 을 중점적으로 분석 할 것 이다.
요청 링크 는 클 라 이언 트 = = > Nginx = = > Golang
WriteTimeout
Golang sdk 의 주석 은 "Write Timeout is the maximum duration before timing out writes of the response" 라 고 설명 합 니 다.http. server 는 클 라 이언 트 요청 을 읽 을 때 시간 초과 시간 을 설정 합 니 다.
func (c *conn) readRequest(ctx context.Context) (w *response, err error) {
if d := c.server.WriteTimeout; d != 0 {
defer func() {
c.rwc.SetWriteDeadline(time.Now().Add(d))
}()
}
}
분명히 요청 처리 시간 이 Write Timeout 을 초과 하면 시간 초과 현상 이 발생 할 수 있다.왜 시간 을 초과 하면 502 가 나 옵 니까?
작은 실험
『 8195 』 우 리 는 먼저 다음 과 같은 요청 처리 시간 초과 현상 을 모 의 한다.
package main
import (
"net/http"
"time"
)
type GinHandler struct {
}
func (* GinHandler) ServeHTTP(w http.ResponseWriter, r *http.Request){
time.Sleep(time.Duration(5) * time.Second)
w.Write([]byte("hello golang"))
}
func main() {
server := &http.Server{
Addr:"0.0.0.0:8080",
Handler: &GinHandler{},
ReadTimeout: time.Second * 3,
WriteTimeout: time.Second *3,
}
server.ListenAndServe()
}
요청 결 과 는 다음 과 같 습 니 다.
time curl http://127.0.0.1/test -H "Host:test.xueersi.com"
502 Bad Gateway
real 0m5.011s
Nginx 의 오류 로 그 를 보면 상류 에서 주동 적 으로 연결 을 닫 아서 생 긴 것 을 볼 수 있 습 니 다.
2020/08/12 21:18:07 [error] 30217#0: *8105 upstream prematurely closed connection while reading response header from upstream, client: 127.0.0.1, server: test.xueersi.com, request: "GET /test HTTP/1.1", upstream: "http://127.0.0.1:8080/test", host: "test.xueersi.com"
예.curl 명령 실행 시간 은 5 초 입 니 다. 이 는 5 초 후에 Golang 서비스 가 연결 을 끊 었 다 는 뜻 입 니 다. Write Timeout = 3 초 를 설정 하지 않 았 습 니까?왜 3 초 초과 시간 에 끊 기지 않 고 5 초 후에 끊 어 집 니까?
Write Timeout 뭐 했 어 요?
우 리 는 이 줄 의 프로그램 에서 답 을 찾 습 니 다. c. rwc. SetWrite Deadline.이곳 의 rwc 유형 은 net. Conn 으로 인터페이스 입 니 다.진정한 대상 은 l. Accept () 에서 돌아 오고 l 은 대상 TCPListener 입 니 다.아래 를 추적 해 보면 net. TCPConn 대상 을 만 들 었 고 이 대상 은 net. conn 을 계승 하 였 으 며, net. conn 은 net. Conn 인터페이스 (대소 문자 주의) 를 실현 하 였 습 니 다.
type TCPConn struct {
conn
}
type conn struct {
fd *netFD
}
func (c *conn) SetReadDeadline(t time.Time) error {
if err := c.fd.SetReadDeadline(t); err != nil {
}
}
다시 아래로 추적 하면 호출 체인 은 다음 과 같 습 니 다.
net.(c *conn).SetWriteDeadline()
net.(fd *netFD).SetWriteDeadline()
poll.(fd *FD).SetWriteDeadline()
poll.setDeadlineImpl()
poll.runtime_pollSetDeadline()
여기까지 쫓 아 오 면 쫓 아 갈 수 없다 는 걸 알 게 될 거 야, runtimepollSetDeadline 의 실현 논 리 는 무엇 입 니까?전역 검색 소 pollSetDeadline, runtime / netpoll. go 파일 을 찾 을 수 있 습 니 다.
//go:linkname poll_runtime_pollSetDeadline internal/poll.runtime_pollSetDeadline
func poll_runtime_pollSetDeadline(pd *pollDesc, d int64, mode int) {
}
네트워크 설명 자 를 봉인 하 는 데 사 용 됩 니 다. 주로 이 몇 개의 필드 에 관심 을 가 져 야 합 니 다.
type pollDesc struct {
fd uintptr
rg uintptr // pdReady, pdWait, G waiting for read or nil
rt timer // read deadline timer (set if rt.f != nil)
rd int64 // read deadline
wg uintptr // pdReady, pdWait, G waiting for write or nil
wt timer // write deadline timer
wd int64 // write deadline
}
* 8195 ° rt 는 현재 설명자 의 읽 기 타이머 입 니 다. rt 는 현재 설명자 에 읽 기 타이머 의 시간 초과 시간 을 설정 하 였 습 니 다.rg 는 세 개의 값 을 취 할 수 있 습 니 다. 1) pdReady 는 이 설명 자 를 읽 을 수 있 는 상태 에 있 음 을 표시 합 니 다.2) pdWait 는 이 설명자 가 막 혀 서 바 꿀 준비 가 되 어 있 음 을 나타 낸다.3) G, 포인터, 막 힌 협 정 대상 을 가리킨다.
함수 pollruntime_pollSetDeadline 은 읽 기 / 쓰기 시간 초과 에 따라 타 이 머 를 추가 하고 리 셋 함 수 를 설정 합 니 다.
//
pd.wt.f = netpollWriteDeadline
// ,
pd.wt.arg = pd
『 8195 』 우리 의 문 제 는 곧 밝 혀 질 것 입 니 다. 리 셋 함수 netpoll Write Deadline (통일 은 netpolldeadlineimpl 로 이 루어 집 니 다) 가 무엇 을 했 는 지 분석 하면 Write Timeout 이 무엇 인지 알 수 있 습 니 다.
func netpolldeadlineimpl(pd *pollDesc, seq uintptr, read, write bool) {
if write {
pd.wd = -1
atomic.StorepNoWB(unsafe.Pointer(&pd.wt.f), nil)
wg = netpollunblock(pd, 'w', false)
}
if wg != nil {
netpollgoready(wg, 0)
}
}
* 8195 에서 볼 수 있 습 니 다. pd. wd = - 1 을 설정 하고 이 설명자 의 타이머 가 만 료 되 었 는 지 여 부 를 판단 합 니 다.netpollunblock 과 netpollgoready 는 현재 설명자 가 막 혀 있 는 지 여 부 를 판단 하 는 데 사 용 됩 니 다. 이 상 태 를 실행 가능 한 상태 로 설정 하고 실행 가능 한 대기 열 에 추가 합 니 다.안 그러면 아무것도 안 해.
이제 모든 것 을 알 게 되 었 습 니 다. Write Timeout 은 읽 기와 쓰기 시간 초과 타이머 만 추 가 했 을 뿐 타이머 가 만 료 되 었 을 때 도 이 설명 자 를 설정 하여 읽 기와 쓰기 시간 초 과 를 설정 할 뿐 입 니 다.따라서 요청 처리 시간 이 Write Timeout 설정 의 시간 초과 시간 보다 5 초 라 도 이 요청 은 중단 되 지 않 고 끝 날 때 까지 정상적으로 실 행 됩 니 다. 클 라 이언 트 에 결 과 를 되 돌려 줄 때 이상 이 발생 합 니 다.
마지막 으로 dlv 디 버 깅 을 통 해 Write Timeout 을 설정 한 함수 호출 체인 을 인쇄 합 니 다.
0 0x0000000001034c23 in internal/poll.runtime_pollSetDeadline
at /usr/local/go/src/runtime/netpoll.go:224
1 0x00000000010ee3a0 in internal/poll.setDeadlineImpl
at /usr/local/go/src/internal/poll/fd_poll_runtime.go:155
2 0x00000000010ee14a in internal/poll.(*FD).SetReadDeadline
at /usr/local/go/src/internal/poll/fd_poll_runtime.go:132
3 0x00000000011cc868 in net.(*netFD).SetReadDeadline
at /usr/local/go/src/net/fd_unix.go:276
4 0x00000000011dffca in net.(*conn).SetReadDeadline
at /usr/local/go/src/net/net.go:251
5 0x000000000131491f in net/http.(*conn).readRequest
at /usr/local/go/src/net/http/server.go:953
6 0x000000000131bd5a in net/http.(*conn).serve
at /usr/local/go/src/net/http/server.go:1822
작은 사고: 바 텀 설명자 의 읽 기와 쓰기 시간 초과 사건 이 발생 한 후에 왜 이 설명 자 를 직접 닫 지 않 고 표시 만 합 니까?
502 이렇게 왔어요.
이번 에는 간단하게 추적 할 필요 가 없어 요.방금 시간 초과 설정 은 poll. (fd FD). setWrite Deadline 을 호출 합 니 다. FD 는 바 텀 설명자 pollDesc 를 추가 로 봉 인 했 습 니 다. 읽 기와 쓰기 처리 함 수 를 제공 합 니 다.우 리 는 poll. (fd FD). Write 중단 점:
(dlv) b poll.Write
Breakpoint 1 set at 0x10ef40b for internal/poll.(*FD).Write() /usr/local/go/src/internal/poll/fd_unix.go:254
(dlv) bt
0 0x00000000010ef40b in internal/poll.(*FD).Write
at /usr/local/go/src/internal/poll/fd_unix.go:254
1 0x00000000011cc0ac in net.(*netFD).Write
at /usr/local/go/src/net/fd_unix.go:220
2 0x00000000011df765 in net.(*conn).Write
at /usr/local/go/src/net/net.go:196
3 0x000000000132276c in net/http.checkConnErrorWriter.Write
at /usr/local/go/src/net/http/server.go:3434
4 0x0000000001177e91 in bufio.(*Writer).Flush
at /usr/local/go/src/bufio/bufio.go:591
5 0x000000000131a329 in net/http.(*response).finishRequest
at /usr/local/go/src/net/http/server.go:1594
6 0x000000000131c7c5 in net/http.(*conn).serve
at /usr/local/go/src/net/http/server.go:1900
지난 절 에서 말 한 바 와 같이 요청 처리 가 완 료 된 후에 시간 이 초과 되 더 라 도 상부 업 무 는 응답 결 과 를 쓰 려 고 시도 하고 최종 적 으로 pollDesc 가 시간 을 초과 하여 오 류 를 되 돌려 주 고 상부 업 무 는 연결 을 닫 는 것 으로 판단 합 니 다.
poll.(fd *FD).Write
poll.(pd *pollDesc).prepareWrite
poll.(pd *pollDesc).prepare
poll.runtime_pollReset
함수 runtimepollReset 의 실현 논 리 는 runtime / netpoll. go 파일 에 있 습 니 다.netpollchecker 를 통 해 검사 논 리 를 실현 합 니 다:
//go:linkname poll_runtime_pollReset internal/poll.runtime_pollReset
func poll_runtime_pollReset(pd *pollDesc, mode int) int {
}
func netpollcheckerr(pd *pollDesc, mode int32) int {
if pd.closing {
return 1 // ErrFileClosing or ErrNetClosing
}
if (mode == 'r' && pd.rd < 0) || (mode == 'w' && pd.wd < 0) {
return 2 // ErrTimeout
}
……
return 0
}
하부 쓰기 데이터 반환 오류, 상부 http. (c * conn). serve 방법 은 직접 되 돌아 가 고 돌아 가기 전에 defer 를 실행 하여 마무리 작업 을 합 니 다. 예 를 들 어 연결 을 닫 는 것 입 니 다.
시간 을 초과 하면 어떻게 제어 합 니까?
위의 분석 을 참조 하여 Write Timeout 을 통 해 요청 한 시간 초과 시간 을 제어 하고 두 가지 문제 가 존재 합 니 다. 1) 요청 처리 시간 초과 후 Golang 은 연결 을 끊 고 Nginx 는 502 가 나타 납 니 다.2) 요청 은 Write Timeout 시간 초과 로 중단 되 지 않 습 니 다. 요청 이 완 료 될 때 까지 기 다 려 야 합 니 다. 클 라 이언 트 가 응답 을 기다 리 는 시간 이 비교적 깁 니 다.느 린 요청 이 많 을 때 Golang 서비스 자원 의 점용 이 급 격 히 증가 합 니 다.
그렇다면 시간 초과 상황 을 어떻게 우아 하 게 통제 할 수 있 을 까?시간 이 지나 면 Golang 은 현재 요청 을 종료 하고 클 라 이언 트 에 게 기본 결 과 를 되 돌려 줍 니 다.context. context 를 이용 하여 구현 할 수 있 습 니 다. 이것 은 인터페이스 입 니 다. cancelCtx 가 취소 할 수 있 는 컨 텍스트, timerCtx 가 정시 에 취소 할 수 있 는 컨 텍스트, valueCtx 는 컨 텍스트 를 기반 으로 변 수 를 전달 할 수 있 습 니 다.
* 8195 ° context. context 정 의 는 다음 과 같 습 니 다.
type Context interface {
Deadline() (deadline time.Time, ok bool)
Done()
『 8195 』 다음 에 작은 예 를 들 어 보 겠 습 니 다.
ctx := context.Background()
ctx, cancel := context.WithCancel(ctx)
go Proc()
time.Sleep(time.Second)
cancel()
func Proc(ctx context.Context) {
for {
select {
case
더 많은 context. context 의 소 개 는 이 두 편의 글 을 참고 합 니 다.
『 8195 』 Write Timeout 으로 인 한 502 에 대해 우 리 는 이미 명확 하 게 분석 했다. 마지막 으로 우 리 는 협 정 이 읽 기와 쓰기 가 막 혀 서 발생 하 는 전환 절 차 를 다시 확대 했다.
for {
n, err := syscall.Read(fd.Sysfd, p)
if err != nil {
n = 0
if err == syscall.EAGAIN && fd.pd.pollable() {
if err = fd.pd.waitRead(fd.isFile);
}
……
}
}
poll.(fd *FD).Read
poll.(pd *pollDesc).waitRead
poll.(pd *pollDesc).wait
poll.runtime_pollWait
함수 runtimepollWait 의 실현 논 리 는 runtime / netpoll. go 파일 에 있 습 니 다.netpollblock 을 통 해 협 정 차단 논 리 를 실현 합 니 다.
//go:linkname poll_runtime_pollWait internal/poll.runtime_pollWait
func poll_runtime_pollWait(pd *pollDesc, mode int) int {
}
func netpollblock(pd *pollDesc, mode int32, waitio bool) bool {
……
if waitio || netpollcheckerr(pd, mode) == 0 {
gopark(netpollblockcommit, unsafe.Pointer(gpp), waitReasonIOWait, traceEvGoBlockNet, 5)
}
}
IdleTimeout + 긴 연결
* 8195: Golang sdk 의 설명 은 다음 과 같 습 니 다.
"IdleTimeout is the maximum amount of time to wait for the next request when keep-alives are enabled. If IdleTimeout is zero, the value of ReadTimeout is used. If both are zero, there is no timeout"。
* 8195: 게 이 트 웨 이 Nginx 와 상류 Golang 서비스 간 에 keep - alive 긴 연결 을 사용 할 때 만 이 설정 이 적 용 됩 니 다.특히 주의해 야 할 것 은 IdleTimeout 이 0 이면 ReadTimeout 의 값 을 기본 값 으로 가 져 옵 니 다.
주의: Nginx 는 proxy 를 통과 하고 있 습 니 다.pass 에서 리 트 윗 을 설정 할 때 기본적으로 HTTP 1.0 을 사용 하고 'Connection: close' 를 사용 합 니 다.따라서 다음 설정 을 추가 해 야 긴 연결 을 사용 할 수 있 습 니 다.
proxy_http_version 1.1;
proxy_set_header Connection "";
작은 실험
이 장면 에서 502 에 확률 문제 가 존재 하 는데 상류 Golang 서비스 가 연결 을 닫 고 새로운 요청 과 거의 동시에 발생 할 때 만 나타 날 수 있 습 니 다.따라서 결국 tcpdump 스냅 백 을 통 해 Golang 서버 가 연결 을 닫 는 것 을 관찰 합 니 다.
『 8195 』 주의: 이런 장면 은 뚜렷 한 특징 이 있 습 니 다. upstreamresponse_time 은 0 에 가깝다.
* 8195: 게 이 트 웨 이 Nginx 에서 Golang 서비스 사이 에 긴 연결 을 사용 하고 IdleTimeout = 5 초 를 설정 하 는 것 을 기억 합 니 다.한 번 만 요청 합 니 다. tcpdump 패키지 관찰 현상 은 다음 과 같 습 니 다.
15:15:03.155362 IP 127.0.0.1.20775 > 127.0.0.1.8080: Flags [S], seq 3293818352, win 43690, length 0
01:50:36.801131 IP 127.0.0.1.8080 > 127.0.0.1.20775: Flags [S.], seq 901857004, ack 3293818353, win 43690, length 0
15:15:03.155385 IP 127.0.0.1.20775 > 127.0.0.1.8080: Flags [.], ack 1, win 86, length 0
15:15:03.155406 IP 127.0.0.1.20775 > 127.0.0.1.8080: Flags [P.], seq 1:135, ack 1, win 86, length 134: HTTP: GET /test HTTP/1.1
15:15:03.155411 IP 127.0.0.1.8080 > 127.0.0.1.20775: Flags [.], ack 135, win 88, length 0
15:15:03.155886 IP 127.0.0.1.8080 > 127.0.0.1.20775: Flags [P.], seq 1:130, ack 135, win 88, length 129: HTTP: HTTP/1.1 200 OK
15:15:03.155894 IP 127.0.0.1.20775 > 127.0.0.1.8080: Flags [.], ack 130, win 88, length 0
//IdleTimeout 5 ,Golang
15:15:08.156130 IP 127.0.0.1.8080 > 127.0.0.1.20775: Flags [F.], seq 130, ack 135, win 88, length 0
15:15:08.156234 IP 127.0.0.1.20775 > 127.0.0.1.8080: Flags [F.], seq 135, ack 131, win 88, length 0
15:15:08.156249 IP 127.0.0.1.8080 > 127.0.0.1.20775: Flags [.], ack 136, win 88, length 0
Golang 서비스 가 자발적으로 연결 을 끊 으 면 게 이 트 웨 이 Nginx 가 502 가 발생 할 가능성 이 있 습 니 다.이 문 제 를 어떻게 해결 합 니까?매번 게 이 트 웨 이 Nginx 가 자발적으로 연결 을 끊 는 다 는 보장 만 있 으 면 됩 니 다.
ngx_http_upstream_module 모듈 은 새 버 전에 설정 파 라 메 터 를 추가 하 였 습 니 다. keepalivetimeout。이것 은 ngx 가 아 닙 니 다.http_core_module 모듈 에 있 는 두 매개 변수 이름 은 같 지만 용 도 는 다 릅 니 다.
Syntax: keepalive_timeout timeout;
Default:
keepalive_timeout 60s;
Context: upstream
This directive appeared in version 1.15.3.
Sets a timeout during which an idle keepalive connection to an upstream server will stay open.
Golang 서비스 가 설정 한 IdleTimeout 이 이곳 의 keepalive 보다 크 면timeout 하면 됩 니 다.
소스 코드 분석
전체 처리 과정 은 http. (c * conn). serve 방법 이 고 논 리 는 다음 과 같다.
func (c *conn) serve(ctx context.Context) {
defer func() {
//
c.close()
}()
//
for {
//
w, err := c.readRequest(ctx)
//
serverHandler{c.server}.ServeHTTP(w, w.req)
//
w.finishRequest()
// keepalive,
if !w.conn.server.doKeepAlives() {
return
}
if d := c.server.idleTimeout(); d != 0 {
// idleTimeout
c.rwc.SetReadDeadline(time.Now().Add(d))
// , idleTimeout ,
if _, err := c.bufr.Peek(4); err != nil {
return
}
}
// , ReadTimeout
c.rwc.SetReadDeadline(time.Time{})
}
}
읽 기 시간 초과 가 idleTimeout 으로 설 정 된 후에 다시 연결 에서 데 이 터 를 읽 는 것 을 볼 수 있 습 니 다. 이때 현재 협 정 을 막 을 수 있 습 니 다.시간 이 초과 되면 읽 기 동작 이 오 류 를 되 돌려 줍 니 다. 이 때 serve 방법 은 되 돌아 오기 전에 이 연결 을 닫 습 니 다.
panic
panic 은 프로그램의 이상 종 료 를 초래 하고 Golang 서비스 가 모두 종료 되 며 Nginx 는 순간 대량의 502 가 발생 할 것 입 니 다.대응 하 는 것 은 recover 를 통 해 이상 을 포착 하고 프로그램의 실행 을 회복 할 수 있 습 니 다.
『 8195 』 생산 환경 은 요청 입구 에 recover 를 더 하 는 것 이 좋 습 니 다.
defer func() {
if err := recover(); err != nil {
//
stack := stack(3)
//
httprequest, _ := httputil.DumpRequest(c.Request, false)
logger.E("[Recovery]", " %s panic recovered:
%s
%s
%s", time.Now().Format("2006/01/02 - 15:04:05"), string(httprequest), err, stack)
c.AbortWithStatus(500)
}
}()
또한 HTTP 처리 handler 의 경우 패 닉 이 나타 나 고 recover 가 없 을 때 Golang sdk 는 recover 논 리 를 제공 합 니 다. Golang sdk 는 연결 을 간단하게 닫 을 뿐 이 고 이 처리 역시 Nginx 를 502 로 되 돌려 줍 니 다.
func (c *conn) serve(ctx context.Context) {
defer func() {
if err := recover(); err != nil && err != ErrAbortHandler {
const size = 64 << 10
buf := make([]byte, size)
buf = buf[:runtime.Stack(buf, false)]
c.server.logf("http: panic serving %v: %v
%s", c.remoteAddr, err, buf)
}
if !c.hijacked() {
c.close()
c.setState(c.rwc, StateClosed)
}
}()
}
이 내용에 흥미가 있습니까?
현재 기사가 여러분의 문제를 해결하지 못하는 경우 AI 엔진은 머신러닝 분석(스마트 모델이 방금 만들어져 부정확한 경우가 있을 수 있음)을 통해 가장 유사한 기사를 추천합니다:
set containerThere is no built-in set container in Go How to implement Set struct{} => type struct{}{} => 0bytes How to create set :=...
텍스트를 자유롭게 공유하거나 복사할 수 있습니다.하지만 이 문서의 URL은 참조 URL로 남겨 두십시오.
CC BY-SA 2.5, CC BY-SA 3.0 및 CC BY-SA 4.0에 따라 라이센스가 부여됩니다.