14

Have a Go binary implement an http server:

package main

import (
    "net/http"
)

func main() {
    http.ListenAndServe(":8080", nil)
}

It will start with ~850 kb or so of memory. Send it some requests via your web browser. Observe it quickly rises to 1 mb. If you wait, you'll see it never goes down. Now hammer it with Apache Bench (using the script below) and see your memory usage continually increase. After sometime it will eventually plateau at around 8.2 MB or so.

Edit: It doesn't seem to stop at 8.2, rather it slows down significantly. It's currently at 9.2 and still rising.

In short, why is this happening? I used this shell script:

while [ true ]
do
    ab -n 1000 -c 100 http://127.0.0.1:8080/
    sleep 1
end

While trying to get to the bottom of this, I've tried to tweak the settings. I've tried closing using r.Close = true to prevent Keep-Alive. Nothing seems to work.

I found this originally while trying to determine if there was a memory leak in a program I'm writing. It has a lot of http handlers and I/O calls. After checking I had closed all my database connections I kept seeing it's memory usage rise. My program to plateau at around 433 MB.

Here's the output of Goenv:

GOARCH="amd64"
GOBIN=""
GOCHAR="6"
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/mark/Documents/Programming/Go"
GORACE=""
GOROOT="/usr/local/go"
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
TERM="dumb"
CC="clang"
GOGCCFLAGS="-g -O2 -fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fno-common"
CXX="clang++"
CGO_ENABLED="1"
Mark
  • 872
  • 2
  • 10
  • 19
  • Is it caching data, or collecting logs, debug information and diagnostics? –  Jan 12 '14 at 22:42
  • It's not really doing a lot. I'm hitting / which will open a file (ioutil.ReadAll), run it through text/template and output it. There aren't any SQL calls made on that page but everything is closed. No data/logs/info/diagnostics are recorded at this point. I removed everything I could think of. – Mark Jan 12 '14 at 22:48
  • What version of Go are you using? – Preetam Jinka Jan 12 '14 at 22:51
  • go version go1.2 darwin/amd64 – Mark Jan 12 '14 at 22:56
  • Have you tried `go prof`? – joshlf Jan 12 '14 at 22:57
  • I recently took one on my web app: https://gist.github.com/ancarda/92d82f4da8f63012424d -- I'm not really sure how to read the output of it though. – Mark Jan 12 '14 at 23:03
  • I'm not positive, but I would guess that means "this amount of memory was allocated from within this function" (probably with calls to `new` and `make` - this is only heap usage, right?). – joshlf Jan 12 '14 at 23:15
  • It gets really slow around 16k requests on `ab` because you've run out of ephemeral ports. See this answer https://stackoverflow.com/questions/1216267/ab-program-freezes-after-lots-of-requests-why – kouton Aug 02 '14 at 05:43

1 Answers1

19

From the heap pprof you have provided in comments, it looks like you are leaking memory via gorilla/sessions and gorilla/context (almost 400MB).

Refer to this ML thread: https://groups.google.com/forum/#!msg/gorilla-web/clJfCzenuWY/N_Xj9-5Lk6wJ and this GH issue: https://github.com/gorilla/sessions/issues/15

Here is a version that leaks extremely quickly:

package main

import (
    "fmt"
    // "github.com/gorilla/context"
    "github.com/gorilla/sessions"
    "net/http"
)

var (
    cookieStore = sessions.NewCookieStore([]byte("cookie-secret"))
)

func main() {
    http.HandleFunc("/", defaultHandler)
    http.ListenAndServe(":8080", nil)
}

func defaultHandler(w http.ResponseWriter, r *http.Request) {
    cookieStore.Get(r, "leak-test")
    fmt.Fprint(w, "Hi there")
}

Here is one that cleans up and has a relatively static RSS:

package main

import (
    "fmt"
    "github.com/gorilla/context"
    "github.com/gorilla/sessions"
    "net/http"
)

var (
    cookieStore = sessions.NewCookieStore([]byte("cookie-secret"))
)

func main() {
    http.HandleFunc("/", defaultHandler)
    http.ListenAndServe(":8080", context.ClearHandler(http.DefaultServeMux))
}

func defaultHandler(w http.ResponseWriter, r *http.Request) {
    cookieStore.Get(r, "leak-test")
    fmt.Fprint(w, "Hi there")
}
az_
  • 646
  • 1
  • 6
  • 13
  • Yeah, it looks like a leak in the CookieStore. When I stripped that away, the memory usage was fairly normal. I don't understand why I need `context.ClearHandler`. As for the rising memory usage on the barebones HTTP server, that seems to just be the garbage collector. – Mark Jan 12 '14 at 23:39
  • 5
    `gorilla/context` internally stores data in a `map[request]...` (and `sessions` uses `context`), so the handler is required to delete the request from the map after the request has terminated. It looks like `gorilla/sessions` was designed to be used with the `gorilla/mux` router (it clears the map automatically). – az_ Jan 12 '14 at 23:43
  • Thanks, I checked the website and there's nothing mentioning this. – Mark Jan 12 '14 at 23:45