title: Google App Engine Go memory management
body: <p>I've run into a problem recently where App Engine would terminate my Go instance because it says it ran out of memory. The memory limit for the instance is set to 128Mb.</p>
  
  <p>However, I have trouble figuring out where all that memory is being allocated. When I run the following code:</p>
  
  <pre><code>var s runtime.MemStats
  runtime.ReadMemStats(&amp;s)
  c.Debugf("allocated memory: %d", s.Alloc)
  </code></pre>
  
  <p>it shows me that when allocated memory reaches about 39-40Mb, my app gets terminated with the following error:</p>
  
  <blockquote>
    <p>Exceeded soft private memory limit with 135.082 MB after servicing 1 requests total</p>
  </blockquote>
  
  <p>Similarly, when <code>runtime.ReadMemStats(&amp;s)</code> indicates that I'm using 20 Mb, the App Engine  console shows that my instance is using 92Mb. Redoing the same request, <code>runtime.ReadMemStats(&amp;s)</code> still shows 20Mb, while the App Engine console shows 119Mb.</p>
  
  <p>I have disabled <code>appstats</code>, still no help.</p>
  
  <p>Most of my memory is used up by a memory cache, which I could reduce to fit into the constraints (or increase the memory limit on my instance), but <em>I'd like to know where all that memory is being used</em>. If someone could shed some light on that, or how to correctly profile memory usage on App Engine, that would help a lot.</p>
  
  <h3>Update: managed to reproduce this locally.</h3>
  
  <p>The following is a sample application that allocates some integers in one request and garbage collects them in the next request:</p>
  
  <pre><code>// Package test implements a simple memory test for Google App Engine.
  package test
  
  import (
      "net/http"
      "runtime"
  
      "appengine"
  )
  
  var buffer []int64
  
  func init() {
      http.HandleFunc("/", handler)
  }
  
  func handler(w http.ResponseWriter, r *http.Request) {
      var s runtime.MemStats
      c := appengine.NewContext(r)
      if len(buffer) == 0 {
          // Allocate 2^22 integers.
          runtime.ReadMemStats(&amp;s)
          c.Debugf("Memory usage: %d bytes (%d system).", s.Alloc, s.Sys)
          buffer = make([]int64, 4*1024*1024)
          for i, _ := range buffer {
              buffer[i] = int64(i*i)
          }
          runtime.ReadMemStats(&amp;s)
          c.Debugf("Memory usage increased to: %d bytes (%d system).", s.Alloc, s.Sys)
      } else {
          // Remove all references to the slice pointed to by buffer.
          // This should mark it for garbage collection.
          runtime.ReadMemStats(&amp;s)
          c.Debugf("Memory usage: %d bytes (%d system).", s.Alloc, s.Sys)
          buffer = nil
          runtime.GC()
          runtime.ReadMemStats(&amp;s)
          c.Debugf("After GC event: %d bytes (%d system).", s.Alloc, s.Sys)
      }
      w.WriteHeader(http.StatusTeapot)
  }
  </code></pre>
  
  <p>When run using the development server:</p>
  
  <pre><code>$ ./go_appengine/dev_appserver.py test
  
  2013/09/16 12:28:28 DEBUG: Memory usage: 833096 bytes (272681032 system).
  2013/09/16 12:28:28 DEBUG: Memory usage increased to: 34335216 bytes (308332616 system).
  INFO     2013-09-16 12:28:28,884 module.py:593] default: "GET / HTTP/1.1" 418 -
  2013/09/16 12:28:29 DEBUG: Memory usage: 34345896 bytes (308332616 system).
  2013/09/16 12:28:29 DEBUG: After GC event: 781504 bytes (308332616 system).
  INFO     2013-09-16 12:28:29,560 module.py:593] default: "GET / HTTP/1.1" 418 -
  2013/09/16 12:28:30 DEBUG: Memory usage: 791616 bytes (308332616 system).
  2013/09/16 12:28:30 DEBUG: Memory usage increased to: 34337392 bytes (308332616 system).
  INFO     2013-09-16 12:28:30,276 module.py:593] default: "GET / HTTP/1.1" 418 -
  2013/09/16 12:28:36 DEBUG: Memory usage: 34347536 bytes (308332616 system).
  2013/09/16 12:28:36 DEBUG: After GC event: 783632 bytes (308332616 system).
  INFO     2013-09-16 12:28:36,224 module.py:593] default: "GET / HTTP/1.1" 418 -
  </code></pre>
  
  <p>It appears that memory allocation and garbage collection works fine. However, looking at <code>ps</code> output, it seems that deallocating memory does not decrease the virtual memory usage of the process:</p>
  
  <pre><code>$ ps axo command,vsize,rss | ag go_app
  /usr/bin/python2.7 ./go_app 381248 56608
  $ ps axo command,vsize,rss | ag go_app
  /usr/bin/python2.7 ./go_app 676324 57652
  $ ps axo command,vsize,rss | ag go_app
  /usr/bin/python2.7 ./go_app 750056 57856
  $ ps axo command,vsize,rss | ag go_app
  /usr/bin/python2.7 ./go_app 750056 57856
  </code></pre>
  
  <p>It seems that the Python process that runs the underlying Go instance keeps growing its virtual memory, but it never gets freed. It also seems that a similar thing happens on the production server: the allocated memory reported by the instance runtime is different than the used memory reported by the kernel.</p>
  
  <p>As suggested by @Kluyg, it seems that the admin console shows the <strong>system allocated memory</strong>, which makes sense.</p>