app engine profiling in go

app.yaml

module: default
version: none
runtime: go
api_version: go1

handlers:
- url: /.*
  script: _go_app

bigquery

Go to Monitoring->Logs->Exports and enable streaming to BigQuery, 
then you can read the log data with a query like this:

SELECT
  SUM(INTEGER(JSON_EXTRACT_SCALAR(SUBSTR(protoPayload.line.logMessage, 10), '$.read'))) AS reads,
FROM requests.appengine_googleapis_com_request_log_20150317
WHERE
  protoPayload.line.severity = 'INFO'
  AND REGEXP_MATCH(protoPayload.line.logMessage, r'^\[PROFILE\] ')

main.go

package main

import (
	"encoding/json"
	"net/http"
	"time"

	"appengine"
	"appengine/datastore"

	"appengine_internal"
	internal_datastore "appengine_internal/datastore"
	internal_urlfetch "appengine_internal/urlfetch"
)

func init() {
	http.HandleFunc("/", handler)
}

type profileContext struct {
	appengine.Context
}

func NewProfileContext(parent appengine.Context) appengine.Context {
	return &profileContext{Context: parent}
}

func (c *profileContext) Call(service, method string, in, out appengine_internal.ProtoMessage, opts *appengine_internal.CallOptions) error {
	start := time.Now().UTC()
	err := c.Context.Call(service, method, in, out, opts)
	elapsed := time.Now().UTC().Sub(start)

	data := map[string]interface{}{}

	if err == nil {
		switch response := out.(type) {
		case *internal_datastore.GetResponse:
			data["rpc"] = "get"
			data["read"] = 1
		case *internal_datastore.PutResponse:
			writes := response.GetCost().GetIndexWrites() + response.GetCost().GetEntityWrites()
			if writes > 0 { // this will be zero if we're in a transaction
				data["rpc"] = "put"
				data["write"] = writes
			}
		case *internal_datastore.QueryResult:
			data["rpc"] = "query"
			if *response.KeysOnly {
				data["read"] = 1
				data["small"] = len(response.Result)
			} else {
				data["read"] = 1 + len(response.Result)
			}
		case *internal_urlfetch.URLFetchResponse:
			data["rpc"] = "urlfetch"
			request := in.(*internal_urlfetch.URLFetchRequest)
			data["url"] = request.GetUrl()
		case *internal_datastore.CommitResponse:
			data["rpc"] = "commit"
			data["write"] = response.GetCost().GetIndexWrites() + response.GetCost().GetEntityWrites()
		}

		if len(data) > 0 {
			data["elapsed"] = float64(elapsed.Nanoseconds()) / 1e9
			jsonData, _ := json.Marshal(data)
			c.Infof(`[PROFILE] %s`, jsonData)
		}
	}

	return err
}

func handler(w http.ResponseWriter, r *http.Request) {
	c := NewProfileContext(appengine.NewContext(r))

	c.Infof("hello!")
	datastore.Get(c, datastore.NewKey(c, "Test", "test", 0, nil), &datastore.PropertyList{})
}