Merge pull request #810 from axone-protocol/feat/telemetry

Feat/telemetry

x/logic/keeper/interpreter.go

@@ -105,6 +105,8 @@ func (k Keeper) newInterpreter(ctx context.Context, params types.Params) (*prolo
 		interpreter.WithHooks(
 			whitelistBlacklistHookFn(whitelistPredicates, blacklistPredicates),
 			gasMeterHookFn(sdkctx, params.GetGasPolicy()),
+			telemetryPredicateCallCounterHookFn(),
+			telemetryPredicateDurationHookFn(),
 		),
 		interpreter.WithPredicates(ctx, interpreter.RegistryNames),
 		interpreter.WithBootstrap(ctx, util.NonZeroOrDefault(interpreterParams.GetBootstrap(), bootstrap.Bootstrap())),
@@ -135,23 +137,24 @@ func whitelistBlacklistHookFn(whitelist, blacklist []string) engine.HookFunc {
 			return nil
 		}
 
-		predicateStringer, ok := operand.(fmt.Stringer)
+		predicate, ok := stringifyOperand(operand)
 		if !ok {
 			return engine.SyntaxError(operand, env)
 		}
 
-		predicate := predicateStringer.String()
+		if !interpreter.IsRegistered(predicate) {
+			return nil
+		}
 
-		if interpreter.IsRegistered(predicate) {
-			if _, found := allowed.Get(predicate); !found {
-				return engine.PermissionError(
-					prolog2.AtomOperationExecute,
-					prolog2.AtomPermissionForbiddenPredicate,
-					engine.NewAtom(predicate),
-					env,
-				)
-			}
+		if _, found := allowed.Get(predicate); !found {
+			return engine.PermissionError(
+				prolog2.AtomOperationExecute,
+				prolog2.AtomPermissionForbiddenPredicate,
+				engine.NewAtom(predicate),
+				env,
+			)
 		}
+
 		return nil
 	}
 }
@@ -166,13 +169,11 @@ func gasMeterHookFn(ctx context.Context, gasPolicy types.GasPolicy) engine.HookF
 			return nil
 		}
 
-		operandStringer, ok := operand.(fmt.Stringer)
+		predicate, ok := stringifyOperand(operand)
 		if !ok {
 			return engine.SyntaxError(operand, env)
 		}
 
-		predicate := operandStringer.String()
-
 		cost := lookupCost(predicate,
 			lo.CoalesceOrEmpty(gasPolicy.DefaultPredicateCost, defaultPredicateCost),
 			gasPolicy.PredicateCosts)

x/logic/keeper/metrics.go

@@ -0,0 +1,80 @@
+package keeper
+
+import (
+	"fmt"
+	"time"
+
+	"github.com/axone-protocol/prolog/engine"
+	"github.com/hashicorp/go-metrics"
+
+	"github.com/cosmos/cosmos-sdk/telemetry"
+
+	"github.com/axone-protocol/axoned/v10/x/logic/interpreter"
+	"github.com/axone-protocol/axoned/v10/x/logic/types"
+)
+
+var metricsKeys = []string{types.ModuleName, "vm", "predicate"}
+
+const (
+	labelPredicate = "predicate"
+)
+
+func telemetryPredicateCallCounterHookFn() engine.HookFunc {
+	return func(opcode engine.Opcode, operand engine.Term, _ *engine.Env) error {
+		if opcode != engine.OpCall {
+			return nil
+		}
+
+		predicate, ok := stringifyOperand(operand)
+		if !ok {
+			return nil
+		}
+
+		if !interpreter.IsRegistered(predicate) {
+			return nil
+		}
+
+		telemetry.IncrCounterWithLabels(
+			metricsKeys,
+			1,
+			[]metrics.Label{
+				telemetry.NewLabel(labelPredicate, predicate),
+			},
+		)
+
+		return nil
+	}
+}
+
+func telemetryPredicateDurationHookFn() engine.HookFunc {
+	var predicate string
+	var start time.Time
+	return func(opcode engine.Opcode, operand engine.Term, _ *engine.Env) error {
+		if opcode != engine.OpCall {
+			if predicate != "" {
+				telemetry.MeasureSince(start, append(metricsKeys, predicate)...)
+				predicate = ""
+				start = time.Time{}
+			}
+			return nil
+		}
+
+		var ok bool
+		if predicate, ok = stringifyOperand(operand); !ok {
+			return nil
+		}
+
+		start = telemetry.Now()
+
+		return nil
+	}
+}
+
+// stringifyOperand returns the string representation of the operand if it implements fmt.Stringer.
+// It returns an empty string and false if the operand does not have a string representation.
+func stringifyOperand(operand engine.Term) (string, bool) {
+	if stringer, ok := operand.(fmt.Stringer); ok {
+		return stringer.String(), true
+	}
+	return "", false
+}

x/logic/keeper/metrics_test.go

@@ -0,0 +1,51 @@
+package keeper
+
+import (
+	"fmt"
+	"testing"
+
+	"github.com/axone-protocol/prolog/engine"
+
+	. "github.com/smartystreets/goconvey/convey"
+)
+
+func TestStringifyOperand(t *testing.T) {
+	Convey("Given various inputs to stringifyOperand", t, func() {
+		testCases := []struct {
+			description string
+			input       engine.Term
+			expected    string
+			ok          bool
+		}{
+			{
+				description: "an operand implementing fmt.Stringer",
+				input:       engine.NewAtom("foo"),
+				expected:    "foo",
+				ok:          true,
+			},
+			{
+				description: "an operand not implementing fmt.Stringer",
+				input:       engine.NewAtom("foo").Apply(engine.NewAtom("bar")),
+				expected:    "",
+				ok:          false,
+			},
+			{
+				description: "the nil operand",
+				input:       nil,
+				expected:    "",
+				ok:          false,
+			},
+		}
+
+		for _, tc := range testCases {
+			Convey(fmt.Sprintf("When input is %s", tc.description), func() {
+				result, ok := stringifyOperand(tc.input)
+
+				Convey("Then the result should match the expected output", func() {
+					So(result, ShouldEqual, tc.expected)
+					So(ok, ShouldEqual, tc.ok)
+				})
+			})
+		}
+	})
+}