Report code on metrics when error

agent/agent.go

@@ -23,7 +23,7 @@ package agent
 import (
 	"context"
 	gojson "encoding/json"
-	"errors"
+	e "errors"
 	"fmt"
 	"net"
 	"strings"
@@ -36,6 +36,7 @@ import (
 	"github.com/topfreegames/pitaya/conn/message"
 	"github.com/topfreegames/pitaya/conn/packet"
 	"github.com/topfreegames/pitaya/constants"
+	"github.com/topfreegames/pitaya/errors"
 	"github.com/topfreegames/pitaya/logger"
 	"github.com/topfreegames/pitaya/metrics"
 	"github.com/topfreegames/pitaya/protos"
@@ -168,14 +169,14 @@ func (a *Agent) ResponseMID(ctx context.Context, mid uint, v interface{}, isErro
 	if a.GetStatus() == constants.StatusClosed {
 		err := constants.ErrBrokenPipe
 		tracing.FinishSpan(ctx, err)
-		metrics.ReportTimingFromCtx(ctx, a.metricsReporters, handlerType, true)
+		metrics.ReportTimingFromCtx(ctx, a.metricsReporters, handlerType, err)
 		return err
 	}
 
 	if mid <= 0 {
 		err := constants.ErrSessionOnNotify
 		tracing.FinishSpan(ctx, err)
-		metrics.ReportTimingFromCtx(ctx, a.metricsReporters, handlerType, true)
+		metrics.ReportTimingFromCtx(ctx, a.metricsReporters, handlerType, err)
 		return err
 	}
 
@@ -355,7 +356,7 @@ func (a *Agent) write() {
 				if err != nil {
 					tracing.FinishSpan(data.ctx, err)
 					if data.typ == message.Response {
-						metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, true)
+						metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, err)
 					}
 					logger.Log.Error("cannot serialize message and respond to the client ", err.Error())
 					break
@@ -374,7 +375,7 @@ func (a *Agent) write() {
 			if err != nil {
 				tracing.FinishSpan(data.ctx, err)
 				if data.typ == message.Response {
-					metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, true)
+					metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, err)
 				}
 				logger.Log.Error(err.Error())
 				break
@@ -385,7 +386,7 @@ func (a *Agent) write() {
 			if err != nil {
 				tracing.FinishSpan(data.ctx, err)
 				if data.typ == message.Response {
-					metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, true)
+					metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, err)
 				}
 				logger.Log.Error(err)
 				break
@@ -394,15 +395,23 @@ func (a *Agent) write() {
 			if _, err := a.conn.Write(p); err != nil {
 				tracing.FinishSpan(data.ctx, err)
 				if data.typ == message.Response {
-					metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, true)
+					metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, err)
 				}
 				logger.Log.Error(err.Error())
 				return
 			}
 			var e error
 			tracing.FinishSpan(data.ctx, e)
 			if data.typ == message.Response {
-				metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, m.Err)
+				var rErr error
+
+				if m.Err {
+					// default code is overwritten, if any
+					rErr = &errors.Error{Code: errors.ErrUnknownCode}
+					_ = a.serializer.Unmarshal(m.Data, rErr)
+				}
+
+				metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, rErr)
 			}
 		case <-a.chStopWrite:
 			return
@@ -412,7 +421,7 @@ func (a *Agent) write() {
 
 // SendRequest sends a request to a server
 func (a *Agent) SendRequest(ctx context.Context, serverID, route string, v interface{}) (*protos.Response, error) {
-	return nil, errors.New("not implemented")
+	return nil, e.New("not implemented")
 }
 
 // AnswerWithError answers with an error

cluster/grpc_rpc_client.go

@@ -112,8 +112,7 @@ func (gs *GRPCClient) Call(ctx context.Context, rpcType protos.RPCType, route *r
 				startTime := time.Now()
 				ctxT = pcontext.AddToPropagateCtx(ctxT, constants.StartTimeKey, startTime.UnixNano())
 				ctxT = pcontext.AddToPropagateCtx(ctxT, constants.RouteKey, route.String())
-				errored := err != nil
-				metrics.ReportTimingFromCtx(ctx, gs.metricsReporters, "rpc", errored)
+				metrics.ReportTimingFromCtx(ctx, gs.metricsReporters, "rpc", err)
 			}
 			done()
 		}()

cluster/nats_rpc_client.go

@@ -171,8 +171,7 @@ func (ns *NatsRPCClient) Call(
 		ctx = pcontext.AddToPropagateCtx(ctx, constants.RouteKey, route.String())
 		defer func() {
 			typ := "rpc"
-			errored := err != nil
-			metrics.ReportTimingFromCtx(ctx, ns.metricsReporters, typ, errored)
+			metrics.ReportTimingFromCtx(ctx, ns.metricsReporters, typ, err)
 		}()
 	}
 	m, err = ns.conn.Request(getChannel(server.Type, server.ID), marshalledData, ns.reqTimeout)

errors/errors.go

@@ -74,3 +74,23 @@ func mergeMetadatas(pitayaErr *Error, metadata map[string]string) {
 		pitayaErr.Metadata[key] = value
 	}
 }
+
+// CodeFromError returns the code of error.
+// If error is nil, return empty string.
+// If error is not a pitaya error, returns unkown code
+func CodeFromError(err error) string {
+	if err == nil {
+		return ""
+	}
+
+	pitayaErr, ok := err.(*Error)
+	if !ok {
+		return ErrUnknownCode
+	}
+
+	if pitayaErr == nil {
+		return ""
+	}
+
+	return pitayaErr.Code
+}

errors/errors_test.go

@@ -106,3 +106,42 @@ func TestErrorError(t *testing.T) {
 	errStr := err.Error()
 	assert.Equal(t, sourceErr.Error(), errStr)
 }
+
+func TestCodeFromError(t *testing.T) {
+	t.Parallel()
+
+	errTest := errors.New("error")
+	codeNotFound := "GAME-404"
+
+	tables := map[string]struct {
+		err  error
+		code string
+	}{
+		"test_not_error": {
+			err:  nil,
+			code: "",
+		},
+
+		"test_not_pitaya_error": {
+			err:  errTest,
+			code: ErrUnknownCode,
+		},
+
+		"test_nil_pitaya_error": {
+			err:  func() *Error { var err *Error; return err }(),
+			code: "",
+		},
+
+		"test_pitaya_error": {
+			err:  NewError(errTest, codeNotFound),
+			code: codeNotFound,
+		},
+	}
+
+	for name, table := range tables {
+		t.Run(name, func(t *testing.T) {
+			code := CodeFromError(table.err)
+			assert.Equal(t, table.code, code)
+		})
+	}
+}

metrics/prometheus_reporter.go

@@ -118,7 +118,7 @@ func (p *PrometheusReporter) registerMetrics(
 			Objectives:  map[float64]float64{0.7: 0.02, 0.95: 0.005, 0.99: 0.001},
 			ConstLabels: constLabels,
 		},
-		append([]string{"route", "status", "type"}, additionalLabelsKeys...),
+		append([]string{"route", "status", "type", "code"}, additionalLabelsKeys...),
 	)
 
 	// ProcessDelay summary

metrics/report.go

@@ -26,13 +26,16 @@ import (
 	"time"
 
 	"github.com/topfreegames/pitaya/constants"
+	"github.com/topfreegames/pitaya/errors"
+
 	pcontext "github.com/topfreegames/pitaya/context"
 )
 
 // ReportTimingFromCtx reports the latency from the context
-func ReportTimingFromCtx(ctx context.Context, reporters []Reporter, typ string, errored bool) {
+func ReportTimingFromCtx(ctx context.Context, reporters []Reporter, typ string, err error) {
+	code := errors.CodeFromError(err)
 	status := "ok"
-	if errored {
+	if err != nil {
 		status = "failed"
 	}
 	if len(reporters) > 0 {
@@ -43,6 +46,7 @@ func ReportTimingFromCtx(ctx context.Context, reporters []Reporter, typ string,
 			"route":  route.(string),
 			"status": status,
 			"type":   typ,
+			"code":   code,
 		})
 		for _, r := range reporters {
 			r.ReportSummary(ResponseTime, tags, float64(elapsed.Nanoseconds()))

metrics/report_test.go

@@ -22,6 +22,7 @@ package metrics
 
 import (
 	"context"
+	"errors"
 	"testing"
 	"time"
 
@@ -30,6 +31,7 @@ import (
 	"github.com/stretchr/testify/assert"
 	"github.com/topfreegames/pitaya/constants"
 	pcontext "github.com/topfreegames/pitaya/context"
+	e "github.com/topfreegames/pitaya/errors"
 	"github.com/topfreegames/pitaya/metrics/mocks"
 )
 
@@ -42,7 +44,7 @@ func TestReportTimingFromCtx(t *testing.T) {
 		originalTs := time.Now().UnixNano()
 		expectedRoute := uuid.New().String()
 		expectedType := uuid.New().String()
-		expectedErrored := true
+		expectedErr := errors.New(uuid.New().String())
 		ctx := pcontext.AddToPropagateCtx(context.Background(), constants.StartTimeKey, originalTs)
 		ctx = pcontext.AddToPropagateCtx(ctx, constants.RouteKey, expectedRoute)
 
@@ -53,7 +55,7 @@ func TestReportTimingFromCtx(t *testing.T) {
 			},
 		)
 
-		ReportTimingFromCtx(ctx, []Reporter{mockMetricsReporter}, expectedType, expectedErrored)
+		ReportTimingFromCtx(ctx, []Reporter{mockMetricsReporter}, expectedType, expectedErr)
 	})
 
 	t.Run("test-tags", func(t *testing.T) {
@@ -64,7 +66,7 @@ func TestReportTimingFromCtx(t *testing.T) {
 		originalTs := time.Now().UnixNano()
 		expectedRoute := uuid.New().String()
 		expectedType := uuid.New().String()
-		expectedErrored := false
+		var expectedErr error
 		ctx := pcontext.AddToPropagateCtx(context.Background(), constants.StartTimeKey, originalTs)
 		ctx = pcontext.AddToPropagateCtx(ctx, constants.RouteKey, expectedRoute)
 		ctx = pcontext.AddToPropagateCtx(ctx, constants.MetricTagsKey, map[string]string{
@@ -76,11 +78,12 @@ func TestReportTimingFromCtx(t *testing.T) {
 			"status": "ok",
 			"type":   expectedType,
 			"key":    "value",
+			"code":   "",
 		}
 
 		mockMetricsReporter.EXPECT().ReportSummary(ResponseTime, expectedTags, gomock.Any())
 
-		ReportTimingFromCtx(ctx, []Reporter{mockMetricsReporter}, expectedType, expectedErrored)
+		ReportTimingFromCtx(ctx, []Reporter{mockMetricsReporter}, expectedType, expectedErr)
 	})
 
 	t.Run("test-tags-not-correct-type", func(t *testing.T) {
@@ -91,7 +94,7 @@ func TestReportTimingFromCtx(t *testing.T) {
 		originalTs := time.Now().UnixNano()
 		expectedRoute := uuid.New().String()
 		expectedType := uuid.New().String()
-		expectedErrored := false
+		var expectedErr error
 		ctx := pcontext.AddToPropagateCtx(context.Background(), constants.StartTimeKey, originalTs)
 		ctx = pcontext.AddToPropagateCtx(ctx, constants.RouteKey, expectedRoute)
 		ctx = pcontext.AddToPropagateCtx(ctx, constants.MetricTagsKey, "not-map")
@@ -100,11 +103,57 @@ func TestReportTimingFromCtx(t *testing.T) {
 			"route":  expectedRoute,
 			"status": "ok",
 			"type":   expectedType,
+			"code":   "",
 		}
 
 		mockMetricsReporter.EXPECT().ReportSummary(ResponseTime, expectedTags, gomock.Any())
 
-		ReportTimingFromCtx(ctx, []Reporter{mockMetricsReporter}, expectedType, expectedErrored)
+		ReportTimingFromCtx(ctx, []Reporter{mockMetricsReporter}, expectedType, expectedErr)
+	})
+
+	t.Run("test-failed-route-with-pitaya-error", func(t *testing.T) {
+		ctrl := gomock.NewController(t)
+		defer ctrl.Finish()
+		mockMetricsReporter := mocks.NewMockReporter(ctrl)
+
+		originalTs := time.Now().UnixNano()
+		expectedRoute := uuid.New().String()
+		expectedType := uuid.New().String()
+		code := "GAME-404"
+		expectedErr := e.NewError(errors.New("error"), code)
+		ctx := pcontext.AddToPropagateCtx(context.Background(), constants.StartTimeKey, originalTs)
+		ctx = pcontext.AddToPropagateCtx(ctx, constants.RouteKey, expectedRoute)
+
+		mockMetricsReporter.EXPECT().ReportSummary(ResponseTime, map[string]string{
+			"route":  expectedRoute,
+			"status": "failed",
+			"type":   expectedType,
+			"code":   code,
+		}, gomock.Any())
+
+		ReportTimingFromCtx(ctx, []Reporter{mockMetricsReporter}, expectedType, expectedErr)
+	})
+
+	t.Run("test-failed-route", func(t *testing.T) {
+		ctrl := gomock.NewController(t)
+		defer ctrl.Finish()
+		mockMetricsReporter := mocks.NewMockReporter(ctrl)
+
+		originalTs := time.Now().UnixNano()
+		expectedRoute := uuid.New().String()
+		expectedType := uuid.New().String()
+		expectedErr := errors.New("error")
+		ctx := pcontext.AddToPropagateCtx(context.Background(), constants.StartTimeKey, originalTs)
+		ctx = pcontext.AddToPropagateCtx(ctx, constants.RouteKey, expectedRoute)
+
+		mockMetricsReporter.EXPECT().ReportSummary(ResponseTime, map[string]string{
+			"route":  expectedRoute,
+			"status": "failed",
+			"type":   expectedType,
+			"code":   e.ErrUnknownCode,
+		}, gomock.Any())
+
+		ReportTimingFromCtx(ctx, []Reporter{mockMetricsReporter}, expectedType, expectedErr)
 	})
 }
 

service/handler.go

@@ -318,7 +318,7 @@ func (h *HandlerService) localProcess(ctx context.Context, a *agent.Agent, route
 			a.Session.ResponseMID(ctx, mid, ret)
 		}
 	} else {
-		metrics.ReportTimingFromCtx(ctx, h.metricsReporters, handlerType, false)
+		metrics.ReportTimingFromCtx(ctx, h.metricsReporters, handlerType, nil)
 		tracing.FinishSpan(ctx, err)
 	}
 }