measure duration of plan.Run()

api/graphite.go

@@ -35,6 +35,9 @@ var (
 
 	// metric api.request.render.series is the number of targets a /render request is handling.
 	reqRenderTargetCount = stats.NewMeter32("api.request.render.targets", false)
+
+	// metric plan.run is the time spent running the plan for a request (function processing of all targets and runtime consolidation)
+	planRunDuration = stats.NewLatencyHistogram15s32("plan.run")
 )
 
 type Series struct {
@@ -583,5 +586,8 @@ func (s *Server) executePlan(orgId int, plan expr.Plan) ([]models.Series, error)
 		data[q] = append(data[q], serie)
 	}
 
-	return plan.Run(data)
+	preRun := time.Now()
+	out, err = plan.Run(data)
+	planRunDuration.Value(time.Since(preRun))
+	return out, err
 }

dashboard.json

@@ -1150,6 +1150,11 @@
               "refId": "F",
               "target": "alias(metrictank.stats.$environment.$instance.mem.to_iter.latency.mean.gauge32, 'mem to iter')",
               "textEditor": false
+            },
+	    {
+              "refId": "G",
+              "target": "alias(metrictank.stats.$environment.$instance.plan.run.latency.mean.gauge32, 'plan run')",
+              "textEditor": false
             }
           ],
           "thresholds": [],

docs/metrics.md

@@ -176,6 +176,8 @@ a counter of the number of GC cycles since process start
 a count of times a metric did not validate
 * `metrics_decode_err`:  
 a count of times an input message (MetricData, MetricDataArray or carbon line) failed to parse
+* `plan.run`:
+the time spent running the plan for a request (function processing of all targets and runtime consolidation)
 * `store.cassandra.chunk_operations.save_fail`:  
 counter of failed saves
 * `store.cassandra.chunk_operations.save_ok`: