diff --git a/posting/lists.go b/posting/lists.go index 96342559cf1f4f5e26d095e3efdda45b33794b35..a12874dbe00596a56fb62f36e0d8239fc4ab307b 100644 --- a/posting/lists.go +++ b/posting/lists.go @@ -103,7 +103,6 @@ func Init(posting *store.Store, log *commit.Logger) { lhmap = gotomic.NewHash() pstore = posting clog = log - lc = new(lcounters) go checkMemoryUsage() } diff --git a/posting/worker.go b/posting/worker.go index 77987671d2308428fe3b3273c61e4b4a0b692a7a..bbaa558c475f3c1ffc65e9ac1ae50cb1a4252b86 100644 --- a/posting/worker.go +++ b/posting/worker.go @@ -21,13 +21,13 @@ func ProcessTask(query []byte) (result []byte, rerr error) { key := Key(uid, attr) pl := GetOrCreate(key) - task.ValueStart(b) var valoffset flatbuffers.UOffsetT if val, err := pl.Value(); err != nil { valoffset = b.CreateByteVector(x.Nilbyte) } else { valoffset = b.CreateByteVector(val) } + task.ValueStart(b) task.ValueAddVal(b, valoffset) voffsets[i] = task.ValueEnd(b) diff --git a/query/query.go b/query/query.go index fa1fa741abedbe11bb30273cb6c09897a963b430..d28a0febccbc73d47afcf3973ec43d235e8d8c68 100644 --- a/query/query.go +++ b/query/query.go @@ -21,6 +21,7 @@ import ( "encoding/json" "fmt" "reflect" + "time" "github.com/Sirupsen/logrus" "github.com/dgraph-io/dgraph/posting" @@ -85,6 +86,23 @@ import ( var glog = x.Log("query") +type Latency struct { + Start time.Time `json:"-"` + Parsing time.Duration `json:"query_parsing"` + Processing time.Duration `json:"processing"` + Json time.Duration `json:"json_conversion"` +} + +func (l *Latency) ToMap() map[string]string { + m := make(map[string]string) + j := time.Since(l.Start) - l.Processing - l.Parsing + m["parsing"] = l.Parsing.String() + m["processing"] = l.Processing.String() + m["json"] = j.String() + m["total"] = time.Since(l.Start).String() + return m +} + // SubGraph is the way to represent data internally. It contains both the // query and the response. Once generated, this can then be encoded to other // client convenient formats, like GraphQL / JSON. @@ -212,15 +230,18 @@ func postTraverse(g *SubGraph) (result map[uint64]interface{}, rerr error) { return result, nil } -func (g *SubGraph) ToJson() (js []byte, rerr error) { +func (g *SubGraph) ToJson(l *Latency) (js []byte, rerr error) { r, err := postTraverse(g) if err != nil { x.Err(glog, err).Error("While doing traversal") return js, err } + l.Json = time.Since(l.Start) - l.Parsing - l.Processing if len(r) == 1 { for _, ival := range r { - return json.Marshal(ival) + m := ival.(map[string]interface{}) + m["server_latency"] = l.ToMap() + return json.Marshal(m) } } else { glog.Fatal("We don't currently support more than 1 uid at root.") diff --git a/server/main.go b/server/main.go index ec9d02a3d9c5520763dae5181c5f88a2069384c1..e502c161ffe5132ef9b387845e7f40514eba3a70 100644 --- a/server/main.go +++ b/server/main.go @@ -40,6 +40,8 @@ var mutationDir = flag.String("mutations", "", "Directory to store mutations") var port = flag.String("port", "8080", "Port to run server on.") func queryHandler(w http.ResponseWriter, r *http.Request) { + var l query.Latency + l.Start = time.Now() if r.Method != "POST" { x.SetStatus(w, x.E_INVALID_METHOD, "Invalid method") return @@ -53,14 +55,13 @@ func queryHandler(w http.ResponseWriter, r *http.Request) { return } glog.WithField("q", string(q)).Debug("Query received.") - now := time.Now() sg, err := gql.Parse(string(q)) if err != nil { x.Err(glog, err).Error("While parsing query") x.SetStatus(w, x.E_INVALID_REQUEST, err.Error()) return } - parseLat := time.Since(now) + l.Parsing = time.Since(l.Start) glog.WithField("q", string(q)).Debug("Query parsed.") rch := make(chan error) go query.ProcessGraph(sg, rch) @@ -70,23 +71,21 @@ func queryHandler(w http.ResponseWriter, r *http.Request) { x.SetStatus(w, x.E_ERROR, err.Error()) return } - processLat := time.Since(now) + l.Processing = time.Since(l.Start) - l.Parsing glog.WithField("q", string(q)).Debug("Graph processed.") - js, err := sg.ToJson() + js, err := sg.ToJson(&l) if err != nil { x.Err(glog, err).Error("While converting to Json.") x.SetStatus(w, x.E_ERROR, err.Error()) return } - jsonLat := time.Since(now) glog.WithFields(logrus.Fields{ - "total": time.Since(now), - "parsing": parseLat.String(), - "process": processLat - parseLat, - "json": jsonLat - processLat, + "total": time.Since(l.Start), + "parsing": l.Parsing, + "process": l.Processing, + "json": l.Json, }).Info("Query Latencies") - glog.WithField("latency", time.Since(now).String()).Info("Query Latency") w.Header().Set("Content-Type", "application/json") fmt.Fprint(w, string(js)) } diff --git a/server/main_test.go b/server/main_test.go index d1038d6ccf90f602875d4650f407388e7148871a..268427dce6657957162f960a09cfd532d7c637dc 100644 --- a/server/main_test.go +++ b/server/main_test.go @@ -136,7 +136,8 @@ func TestQuery(t *testing.T) { t.Error(err) return } - js, err := g.ToJson() + var l query.Latency + js, err := g.ToJson(&l) if err != nil { t.Error(err) return @@ -188,7 +189,8 @@ func BenchmarkQuery(b *testing.B) { b.Error(err) return } - _, err = g.ToJson() + var l query.Latency + _, err = g.ToJson(&l) if err != nil { b.Error(err) return diff --git a/server/notes.txt b/server/notes.txt index 51be067be115df3d0cba2edf737f4c58f8062670..9dfafc0cb4d55f32e30facd2f82f35d5938e093b 100644 --- a/server/notes.txt +++ b/server/notes.txt @@ -2,14 +2,17 @@ curl localhost:8080/query -XPOST -d '{ me(_xid_: m.06pj8) { type.object.name.en film.director.film { - type.object.name.en film.film.starring { + type.object.name.en film.performance.actor { film.director.film { type.object.name.en } type.object.name.en } + film.performance.character { + type.object.name.en + } } film.film.initial_release_date film.film.country