profiling http handler in go lang

Question

I am trying to profile my http handler written in go. Which on every http request download an image from S3, resize it/crop it and write it in response.

I have followed this link and tried to profile my code as mentioned using easy method as well as hard method. Now, when i use the following line as mentioned in the code.

defer profile.Start(profile.CPUProfile).Stop()

It doesn't write anything in the /tmp/profie[some number]/cpu.pprof file

func main() {                                    

       defer profile.Start(profile.CPUProfile).Stop()   

      if err := http.ListenAndServe(":8081", http.HandlerFunc(serveHTTP)); err != nil {
       logFatal("Error when starting or running http server: %v", err)
    }       
}

func serveHTTP(w http.ResponseWriter, r *http.Request) {
        keyName := r.URL.Path[1:]
        s3Client := s3.New(session.New(), &aws.Config{Region: aws.String(region)})
        params := &s3.GetObjectInput{
        Bucket: aws.String(bucketName),
        Key: aws.String(keyName),
        }

    mw := imagick.NewMagickWand()
    defer mw.Destroy()
    ...
}

Moreover, when i used the defer profile.Start(profile.CPUProfile).Stop() line inside the serveHTTP like :

func serveHTTP(w http.ResponseWriter, r *http.Request) {

    defer profile.Start(profile.CPUProfile).Stop()
    ......
}

It creates multiple files in the /tmp/profile[some number] folder. So, first question is why it is not writing in the file and secondly shouldn't it be places inside the serveHTTP method because server will get started only once. Hence main() will be called once wheres serveHTTP wil be called on every request.

Part 1

 .               124:   s3Client := s3.New(session.New(), &aws.Config{Region: aws.String(region)})
 .          .    125:        params := &s3.GetObjectInput{
 .          .    126:       Bucket: aws.String(masterBucketName),
 .          .    127:       Key: aws.String(keyName),
 .    32.01kB    128:       }
 .          .    129:
 .          .    130:   mw := imagick.NewMagickWand()
 .          .    131:   defer mw.Destroy()
 .          .    132:   
 .          .    133:   out, err := s3Client.GetObject(params)          
 .          .    134:
 .          .    135:   if strings.EqualFold(keyName[strings.LastIndex(keyName,".")+1:len(keyName)], "gif") {
 .          .    136:
 .    40.11kB    137:       blobGiff, err := ioutil.ReadAll(out.Body)
 .          .    138:       w.Header().Set("Content-Type", "image/gif")
 .          .    139:       w.Header().Set("Cache-Control", "max-age: 604800, public")  
 .          .    140:       w.Header().Set("Last-Modified", time.Now().Format(http.TimeFormat))
 .          .    141:       w.Header().Set("Expires", time.Now().AddDate(1, 0, 0).Format(http.TimeFormat))  
 .          .    142:

Part 2 :

                                   else {
         .          .    167:       img, err := ioutil.ReadAll(out.Body)
         .          .    168:       if err != nil {
         .          .    169:          
         .          .    170:          w.WriteHeader(http.StatusNotFound) 
         .     1.56MB    171:          return      
         .          .    172:       }

Also, in the above two parts line 128, 137 and 171 has memory leaks, right? Also, I don't find any option to close/destroy the s3Client and blobGiff (byte []).

The `defer` in `main` never runs because `http.ListenAndServe` blocks forever. You get multiple files when you put it in the request handler because the handler is called multiple times and each time creates a new profile. — thwd, Feb 12 '16 at 11:36
but if i write it in the before calling `serveHTTP`. It's doesn't write anything in the file. — Naresh, Feb 12 '16 at 11:39
You can't use the `defer profile.Start(profile.CPUProfile).Stop()` line in main, as the defer will never be called (ListenAndServe blocks and waits forever). When you call `defer profile.Start(profile.CPUProfile).Stop()` in your serveHTTP function, the profiler is already running (from main) so it won't write anything (as the profiler can't run more than once at a time). — nussjustin, Feb 12 '16 at 13:06
You can't profile a single handler by itself. pprof is a sampling profiler, so unless the handler runs for a very long time, you're not going to get any samples. Profile your entire app, and just generate sufficient load on your handler. This is even easier if you import ["net/http/pprof"](https://golang.org/pkg/net/http/pprof/) and profile the running binary. — JimB, Feb 12 '16 at 14:11

score 7 · Answer 1 · answered Feb 12 '16 at 14:11

7

To profile a http server while it's running you can use the net/http/pprof package.

Just add

import _ "net/http/pprof"

to your imports and open http://localhost:8081/debug/pprof/ in your browser.

answered Feb 12 '16 at 14:11

fl0cke

2,804
1
16
25

2

+1. And if you really want to use the standard profiler, use `os/signal` to implement a graceful shutdown (or a graceful shutdown library), so your defer will be called when needed. – Elwinar Feb 12 '16 at 14:13
@fl0cke I wil try this. Could you please also tell. Lines which I have attached definitely has memory leaks and it clearly indicate it is due to [] byte and s3client. So, is there any method to destroy or close them in go lang – Naresh Feb 12 '16 at 19:25
1

@Naresh: this isn't what this kind of profiling is for, and those lines on their own don't signify any memory leak. Go is garbage collected, so there's no outright way to destroy a `[]byte`, and an `*S3` doesn't have a close method. We can't tell from the code fragments, but it looks like you're not checking the error returned from `GetObject` (*always check errors*), nor are you closing the response body from `GetObject`. – JimB Feb 12 '16 at 21:03
@JimB Thanking you. I handled the error and close the response body. Could you please tell me if i don't handle the error would it leave a memory leak? Moreover, If memory profiler doesn't give the true memory leak points then how do we find out from where does memory leak happens. – Naresh Feb 14 '16 at 11:29
@fl0cke As you suggested I imported the `"net/http/pprof"` and tried to browse the same Url. But it give the `ERROR: Not sufficient parameters were provided`. Reason being key passed to s3 client would be empty. FYI, as you can see I am using the default mux in my code – Naresh Feb 15 '16 at 10:05
@Naresh: go has a fully precise garbage collector, so in essence there is no such thing as a "memory leak" -- the only way to leak resources is to have running code referencing them. The memory profiler shows where memory is allocated, but it can't tell you where you should have released those resources. Even without looking at the source, it could be assumed that the response references a network connection, and probably everything required for an http request, which needs to be cleaned up. Not handling the error leaves the possibility of having an invalid response and possibility of panics. – JimB Feb 15 '16 at 16:29

score 5 · Accepted Answer · edited Feb 14 '21 at 02:17

First of all use import "net/http/pprof" NOT import _ "net/http/pprof. later one didn't recognize the pprof in the below routes.

I was using the default serveMux/multiplexer. But then I created my own as people suggested it has performance implication.

myMux := http.NewServeMux()

Then added the route for the request

myMux.HandleFunc("/", serveHTTP)

Morever, I also added the routes for to make the http://localhost:8081/debug/pprof/ work

        myMux.HandleFunc("/debug/pprof/", pprof.Index)
        myMux.HandleFunc("/debug/pprof/{action}", pprof.Index)
        myMux.HandleFunc("/debug/pprof/symbol", pprof.Symbol)

So, final code would be :

import "net/http/pprof

func main() {                                    
        
        myMux := http.NewServeMux()
        myMux.HandleFunc("/", serveHTTP)

        myMux.HandleFunc("/debug/pprof/", pprof.Index)
        myMux.HandleFunc("/debug/pprof/{action}", pprof.Index)
        myMux.HandleFunc("/debug/pprof/symbol", pprof.Symbol)   

    if err := http.ListenAndServe(":8081", myMux); err != nil {
        logFatal("Error when starting or running http server: %v", err)
    }       

}

profiling http handler in go lang

2 Answers2