OOM in a Gin API Gateway: Caching Every Response Body

Use existing wheels whenever you can :sob: :sob: :sob: :sob: :sob: :sob:

Symptom: gateway memory spikes in minutes

We built an API gateway on top of Gin. After deploying it, we found that memory would surge in a short time and then the process would be OOM-killed. The memory trend looked like this:

1

Zooming in on one occurrence:

2

In the second chart you can see how fast memory grows: nearly 2 GB in a minute and a half.

For problems where memory spikes this fast, pprof is hard to use — unless you write a script that samples pprof on a timer.

Root cause: every request cached the response body

Another pass over the code turned up the cause:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
package server

import (
"bytes"
"fmt"

"github.com/gin-gonic/gin"
jsoniter "github.com/json-iterator/go"
)

var json = jsoniter.ConfigCompatibleWithStandardLibrary

type BodyDumpResponseWriter struct {
gin.ResponseWriter
body *bytes.Buffer
}

func (w *BodyDumpResponseWriter) Write(b []byte) (int, error) {
w.body.Write(b) // note this line
return w.ResponseWriter.Write(b)
}

func ReadResponseBody(ctx *gin.Context) {
rbw := &BodyDumpResponseWriter{body: &bytes.Buffer{}, ResponseWriter: ctx.Writer}
ctx.Writer = rbw

ctx.Next()

rawResp := rbw.body.String()
if len(rawResp) == 0 {
AbnormalPrint(ctx, "resp-empty", rawResp)
return
}
ctx.Set(ctx_raw_response_body, rawResp)

// serialize the Body and put it in the ctx
// the response Body is read so it can be written to the audit log
}

// AbnormalPrint logs diagnostic info on abnormal conditions
func AbnormalPrint(ctx *gin.Context, typ string, rawResp string) {
// actual code omitted
}

At a glance, isn’t this the standard way to capture the response body in Gin? After all, this is exactly how it is written on GitHub and Stack Overflow:
https://github.com/gin-gonic/gin/issues/1363
https://stackoverflow.com/questions/38501325/how-to-log-response-body-in-gin

So where is the problem?

Look at the code again: the logic keeps a complete copy of every response body in memory. For requests with large response bodies, that alone causes memory to spike — a log download, for example.

Fix: skip caching by request type

Once the cause was clear, the fix was simple: skip file-download requests based on the response headers, and skip SSE and WebSocket requests based on the request headers — streaming responses are of little value in the audit log, and they also break JSON serialization.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
package server

import (
"bytes"
"fmt"
"net/http"
"strings"

"github.com/gin-gonic/gin"
jsoniter "github.com/json-iterator/go"
)

var json = jsoniter.ConfigCompatibleWithStandardLibrary

type BodyDumpResponseWriter struct {
gin.ResponseWriter
body *bytes.Buffer
}

func (w *BodyDumpResponseWriter) Write(b []byte) (int, error) {
// file-download requests: no longer cache the response
if !isFileDownLoad(w.Header()) {
w.body.Write(b)
}
return w.ResponseWriter.Write(b)
}

func isNoNeedToReadResponse(req *http.Request) bool {
if isSSE(req) || isWebsocket(req) {
return true
}
return false
}

func isSSE(req *http.Request) bool {
contentType := req.Header.Get("Accept")
if contentType == "" {
contentType = req.Header.Get("accept")
}
contentType = strings.ToLower(contentType)
// sse
if !strings.Contains(contentType, "text/event-stream") {
return false
}
return true
}

// https://developer.mozilla.org/zh-CN/docs/Web/HTTP/Basics_of_HTTP/MIME_types
// https://developer.mozilla.org/en-US/docs/Web/HTTP/Headers/Content-Disposition
func isFileDownLoad(responseHeader http.Header) bool {
contentType := strings.ToLower(responseHeader.Get("Content-Type"))
if strings.Contains(contentType, "application/octet-stream") {
return true
}
contentDisposition := responseHeader.Get("Content-Disposition")
if contentDisposition != "" {
return true
}
return false
}

func isWebsocket(req *http.Request) bool {
conntype := strings.ToLower(req.Header.Get("Connection"))
upgrade := strings.ToLower(req.Header.Get("Upgrade"))
if conntype == "upgrade" && upgrade == "websocket" {
return true
}
return false
}

func ReadResponseBody(ctx *gin.Context) {

if isNoNeedToReadResponse(ctx.Request) {
return
}

rbw := &BodyDumpResponseWriter{body: &bytes.Buffer{}, ResponseWriter: ctx.Writer}
ctx.Writer = rbw

ctx.Next()

contentType := ctx.Writer.Header().Get("content-type")
if !strings.Contains(contentType, "application/json") {
return
}

rawResp := rbw.body.String()
if len(rawResp) == 0 {
AbnormalPrint(ctx, "resp-empty", rawResp)
return
}
ctx.Set(ctx_raw_response_body, rawResp)

// serialize the Body and put it in the ctx
// the response Body is read so it can be written to the audit log
}

// AbnormalPrint logs diagnostic info on abnormal conditions
func AbnormalPrint(ctx *gin.Context, typ string, rawResp string) {
// actual code omitted
}

Postmortem: when you copy code, mind your own scenario

The real point of this post is not how the problem was fixed, but this:

  • When you copy code, pay attention to whether it fits your scenario.
  • Use existing wheels whenever you can, instead of building your own.

While hand-writing the API gateway, we also ran into the following:

  • The first version of the network handling was hand-written too, which meant it handled the various Content-Types badly;
  • Because we had to parse the body, and had no bandwidth to support every compression scheme, compression had to be forcibly disabled at the gateway;
  • Hand-written network handling produces strange problems
    • For example: we support a terminal in the browser connecting to a K8S cluster over WebSocket. Suppose the service behind that connection is service A (browser <—-> gateway <—-> service A <—-> K8S cluster). Later, some requests going through the gateway would hit service A directly — skipping the gateway’s API router entirely and reusing the WebSocket connection — even when those APIs did not belong to service A.

A sketch of the first hand-written version of the request handling:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
func proxyHttp(ctx context.Context, proxy_req *http.Request, domain string) {
// origin request
req := ctx.Request()

response, err := HttpClient.Do(proxy_req)
if err != nil {
// log the error
return
}

defer response.Body.Close()

//copy response header
if response != nil && response.Header != nil {
for k, values := range response.Header {
for _, value := range values {
ctx.ResponseWriter().Header().Set(k, value)
}
}
}
// status code
ctx.StatusCode(response.StatusCode)
buf := make([]byte, 1024)

for {
len, err := response.Body.Read(buf)
if err != nil && err != io.EOF {
// log the error
break
}
if len == 0 {
break
}

ctx.ResponseWriter().Write(buf[:len])
ctx.ResponseWriter().Flush()
continue

}
ctx.Next()
}

func proxyWebSocket(ctx context.Context, request *http.Request, target string) {
var logger = ctx.Application().Logger()
responseWriter := http.ResponseWriter(ctx.ResponseWriter())

conn, err := net.Dial("tcp", target)
if err != nil {
// log the error
return
}
hijacker, ok := responseWriter.(http.Hijacker)
if !ok {
http.Error(responseWriter, "Not a hijacker?", 500)
return
}

nc, _, err := hijacker.Hijack()
if err != nil {
// log the error
return
}
defer nc.Close()
defer conn.Close()

err = request.Write(conn)
if err != nil {
// log the error
return
}

errc := make(chan error, 2)
cp := func(dst io.Writer, src io.Reader) {
_, err := io.Copy(dst, src)
errc <- err
}
go cp(conn, nc)
go cp(nc, conn)

// wait over
<-errc

ctx.Application().Logger().Infof("websocket proxy to %s over", target)
}

We eventually switched to the standard library’s httputil.ReverseProxy for connection handling, and the problem went away.

This article is the English edition of a post originally published in Chinese.