Merge eb1ccc0 into 1966351

runtime/middlewares.go

@@ -22,8 +22,16 @@ package zanzibar
 
 import (
 	"context"
+	"time"
 
 	jsonschema "github.com/mcuadros/go-jsonschema-generator"
+	"github.com/uber-go/tally"
+)
+
+const (
+	middlewareRequestLatencyTag  = "middleware.request.latency"
+	middlewareResponseLatencyTag = "middleware.response.latency"
+	middlewareRequestStatusTag   = "middleware.request.status"
 )
 
 // MiddlewareStack is a stack of Middleware Handlers that can be invoked as an Handle.
@@ -103,24 +111,57 @@ func (m *MiddlewareStack) Handle(
 	res *ServerHTTPResponse) context.Context {
 
 	shared := NewSharedState(m.middlewares)
+	middlewareRequestStartTime := time.Now()
 
 	for i := 0; i < len(m.middlewares); i++ {
 		ctx, ok := m.middlewares[i].HandleRequest(ctx, req, res, shared)
 		// If a middleware errors and writes to the response header
 		// then abort the rest of the stack and evaluate the response
 		// handlers for the middlewares seen so far.
 		if ok == false {
+			//record latency for middlewares requests in unsuccessful case as the middleware requests calls are terminated
+			m.recordLatency(middlewareRequestLatencyTag, middlewareRequestStartTime, req.scope)
+
+			middlewareResponseStartTime := time.Now() // start the timer for middleware responses
 			for j := i; j >= 0; j-- {
 				m.middlewares[j].HandleResponse(ctx, res, shared)
 			}
+			//record latency for middlewares responses in unsuccessful case
+			m.recordLatency(middlewareResponseLatencyTag, middlewareResponseStartTime, req.scope)
+
+			//for error metrics only emit when there is gateway error and not request error
+			// the percentage can be calculated via error_count/total_request
+			if res.pendingStatusCode >= 500 {
+				m.emitAvailabilityError(middlewareRequestStatusTag, req.scope)
+			}
 			return ctx
 		}
 	}
+	// record latency for middlewares requests in successful case
+	m.recordLatency(middlewareRequestLatencyTag, middlewareRequestStartTime, req.scope)
 
 	ctx = m.handle(ctx, req, res)
 
+	middlewareResponseStartTime := time.Now()
 	for i := len(m.middlewares) - 1; i >= 0; i-- {
 		m.middlewares[i].HandleResponse(ctx, res, shared)
 	}
+	// record latency for middlewares responses in successful case
+	m.recordLatency(middlewareResponseLatencyTag, middlewareResponseStartTime, req.scope)
 	return ctx
 }
+
+// recordLatency measures the latency as per the tagName and start time given.
+func (m *MiddlewareStack) recordLatency(tagName string, startTime time.Time, scope tally.Scope) {
+	elapsed := time.Now().Sub(startTime)
+	scope.Timer(tagName).Record(elapsed)
+	scope.Histogram(tagName, tally.DefaultBuckets).RecordDuration(elapsed)
+}
+
+// emitAvailability is used to increment the error counter for a particular tagName.
+func (m *MiddlewareStack) emitAvailabilityError(tagName string, scope tally.Scope) {
+	tagged := scope.Tagged(map[string]string{
+		scopeTagStatus: "error",
+	})
+	tagged.Counter(tagName).Inc(1)
+}

runtime/middlewares_test.go

@@ -110,6 +110,7 @@ func (c *countMiddleware) HandleRequest(
 	if !c.reqBail {
 		res.WriteJSONBytes(200, nil, []byte(""))
 	}
+	res.WriteJSONBytes(500, nil, []byte(""))
 
 	return ctx, !c.reqBail
 }
@@ -183,7 +184,7 @@ func TestMiddlewareRequestAbort(t *testing.T) {
 	if !assert.NoError(t, err) {
 		return
 	}
-	assert.Equal(t, resp.StatusCode, http.StatusOK)
+	assert.Equal(t, resp.StatusCode, http.StatusInternalServerError)
 
 	assert.Equal(t, mid1.reqCounter, 1)
 	assert.Equal(t, mid1.resCounter, 1)

test/endpoints/bar/bar_metrics_test.go

@@ -62,7 +62,7 @@ func TestCallMetrics(t *testing.T) {
 		},
 	)
 
-	numMetrics := 16
+	numMetrics := 20
 	cg := gateway.(*testGateway.ChildProcessGateway)
 	cg.MetricsWaitGroup.Add(numMetrics)
 

test/endpoints/baz/baz_metrics_test.go

@@ -79,7 +79,7 @@ func TestCallMetrics(t *testing.T) {
 	headers["device"] = "ios"
 	headers["deviceversion"] = "carbon"
 
-	numMetrics := 14
+	numMetrics := 18
 	cg.MetricsWaitGroup.Add(numMetrics)
 
 	_, err = gateway.MakeRequest(