[CRE-954] Extra logging limits in WASM Module

+ set a missing "mode" field on executor

Author: bolekk

pkg/workflows/wasm/host/execution.go

@@ -27,6 +27,8 @@ type execution[T any] struct {
 	mode                 sdkpb.Mode
 	donSeed              int64
 	nodeSeed             int64
+	donLogCount          uint32
+	nodeLogCount         uint32
 }
 
 // callCapAsync async calls a capability by placing execution results onto a
@@ -139,6 +141,35 @@ func (e *execution[T]) awaitSecrets(ctx context.Context, acr *sdkpb.AwaitSecrets
 }
 
 func (e *execution[T]) log(caller *wasmtime.Caller, ptr int32, ptrlen int32) {
+	switch e.mode {
+	case sdkpb.Mode_MODE_DON:
+		e.donLogCount++
+		if e.donLogCount == e.module.cfg.MaxLogCountDONMode {
+			e.module.cfg.Logger.Warnf("max log count for don mode reached: %d - all subsequent logs will be dropped", e.donLogCount)
+		}
+		if e.donLogCount > e.module.cfg.MaxLogCountDONMode {
+			// silently drop to avoid spamming logs
+			return
+		}
+	case sdkpb.Mode_MODE_NODE:
+		e.nodeLogCount++
+		if e.nodeLogCount == e.module.cfg.MaxLogCountNodeMode {
+			e.module.cfg.Logger.Warnf("max log count for node mode reached: %d - all subsequent logs will be dropped", e.nodeLogCount)
+		}
+		if e.nodeLogCount > e.module.cfg.MaxLogCountNodeMode {
+			// silently drop to avoid spamming logs
+			return
+		}
+	default:
+		// unexpected / malicious
+		return
+	}
+
+	if ptrlen > int32(e.module.cfg.MaxLogLenBytes) {
+		e.module.cfg.Logger.Warnf("log message too long: %d - dropping", ptrlen)
+		return
+	}
+
 	b, innerErr := wasmRead(caller, ptr, ptrlen)
 	if innerErr != nil {
 		e.module.cfg.Logger.Errorf("error calling log: %s", innerErr)

pkg/workflows/wasm/host/module.go

@@ -41,6 +41,9 @@ var (
 	defaultMaxCompressedBinarySize   = 20 * 1024 * 1024  // 20 MB
 	defaultMaxDecompressedBinarySize = 100 * 1024 * 1024 // 100 MB
 	defaultMaxResponseSizeBytes      = 5 * 1024 * 1024   // 5 MB
+	defaultMaxLogLenBytes            = 1024 * 1024       // 1 MB
+	defaultMaxLogCountDONMode        = 10_000
+	defaultMaxLogCountNodeMode       = 10_000
 	ResponseBufferTooSmall           = "response buffer too small"
 )
 
@@ -62,6 +65,10 @@ type ModuleConfig struct {
 	MaxDecompressedBinarySize uint64
 	MaxResponseSizeBytes      uint64
 
+	MaxLogLenBytes      uint32
+	MaxLogCountDONMode  uint32
+	MaxLogCountNodeMode uint32
+
 	// Labeler is used to emit messages from the module.
 	Labeler custmsg.MessageEmitter
 
@@ -183,6 +190,15 @@ func NewModule(modCfg *ModuleConfig, binary []byte, opts ...func(*ModuleConfig))
 	if modCfg.MaxResponseSizeBytes == 0 {
 		modCfg.MaxResponseSizeBytes = uint64(defaultMaxResponseSizeBytes)
 	}
+	if modCfg.MaxLogLenBytes == 0 {
+		modCfg.MaxLogLenBytes = uint32(defaultMaxLogLenBytes)
+	}
+	if modCfg.MaxLogCountDONMode == 0 {
+		modCfg.MaxLogCountDONMode = uint32(defaultMaxLogCountDONMode)
+	}
+	if modCfg.MaxLogCountNodeMode == 0 {
+		modCfg.MaxLogCountNodeMode = uint32(defaultMaxLogCountNodeMode)
+	}
 
 	// Take the max of the min and the configured max memory mbs.
 	// We do this because Go requires a minimum of 16 megabytes to run,

pkg/workflows/wasm/host/standard_tests/logging/main_wasip1.go

@@ -2,9 +2,11 @@ package main
 
 import (
 	"github.com/smartcontractkit/chainlink-common/pkg/workflows/wasm/host/internal/rawsdk"
+	"github.com/smartcontractkit/chainlink-protos/cre/go/sdk"
 )
 
 func main() {
+	rawsdk.SwitchModes(int32(sdk.Mode_MODE_DON))
 	request := rawsdk.GetRequest()
 	msg := []byte("log from wasm!")
 	rawsdk.Log(rawsdk.BufferToPointerLen(msg))

pkg/workflows/wasm/host/test/logging_limits/cmd/main_wasip1.go

@@ -0,0 +1,20 @@
+package main
+
+import (
+	"github.com/smartcontractkit/chainlink-common/pkg/workflows/wasm/host/internal/rawsdk"
+	"github.com/smartcontractkit/chainlink-protos/cre/go/sdk"
+)
+
+func main() {
+	rawsdk.SwitchModes(int32(sdk.Mode_MODE_DON))
+	request := rawsdk.GetRequest()
+	msg := []byte("short log 1")
+	rawsdk.Log(rawsdk.BufferToPointerLen(msg))
+	msg = []byte("super duper excessively long log 2") // exceeding 20 byte limit set in the test
+	rawsdk.Log(rawsdk.BufferToPointerLen(msg))
+	msg = []byte("short log 3")
+	rawsdk.Log(rawsdk.BufferToPointerLen(msg))
+	msg = []byte("short log 4")
+	rawsdk.Log(rawsdk.BufferToPointerLen(msg))
+	rawsdk.SendResponse(request.Config)
+}

pkg/workflows/wasm/host/wasm_nodag_test.go

@@ -9,15 +9,19 @@ import (
 
 	"google.golang.org/protobuf/types/known/emptypb"
 
+	"github.com/smartcontractkit/chainlink-common/pkg/capabilities/v2/protoc/pkg/test_capabilities/basictrigger"
 	"github.com/smartcontractkit/chainlink-common/pkg/logger"
 	"github.com/smartcontractkit/chainlink-protos/cre/go/sdk"
 
+	mock "github.com/stretchr/testify/mock"
 	"github.com/stretchr/testify/require"
 )
 
 const (
-	nodagRandomBinaryCmd      = "standard_tests/multiple_triggers"
-	nodagRandomBinaryLocation = nodagRandomBinaryCmd + "/testmodule.wasm"
+	nodagRandomBinaryCmd        = "standard_tests/multiple_triggers"
+	nodagRandomBinaryLocation   = nodagRandomBinaryCmd + "/testmodule.wasm"
+	loggingLimitsBinaryCmd      = "test/logging_limits/cmd"
+	loggingLimitsBinaryLocation = loggingLimitsBinaryCmd + "/testmodule.wasm"
 )
 
 func Test_Sleep_Timeout(t *testing.T) {
@@ -89,6 +93,48 @@ func Test_NoDag_Run(t *testing.T) {
 	})
 }
 
+func Test_NoDAG_LoggingWithLimits(t *testing.T) {
+	t.Parallel()
+	mockExecutionHelper := NewMockExecutionHelper(t)
+	mockExecutionHelper.EXPECT().GetWorkflowExecutionID().Return("id")
+	mockExecutionHelper.EXPECT().GetNodeTime().RunAndReturn(func() time.Time {
+		return time.Now()
+	}).Maybe()
+	mockExecutionHelper.EXPECT().GetDONTime().RunAndReturn(func() (time.Time, error) {
+		return time.Now(), nil
+	}).Maybe()
+
+	logs := []string{}
+	mockExecutionHelper.EXPECT().EmitUserLog(mock.Anything).RunAndReturn(func(s string) error {
+		logs = append(logs, s)
+		return nil
+	})
+
+	trigger := &basictrigger.Outputs{CoolOutput: anyTestTriggerValue}
+	executeRequest := triggerExecuteRequest(t, 0, trigger)
+	cfg := &ModuleConfig{
+		Logger:              logger.Test(t),
+		IsUncompressed:      true,
+		MaxLogLenBytes:      20,
+		MaxLogCountDONMode:  3,
+		MaxLogCountNodeMode: 3,
+	}
+
+	binary := createTestBinary(loggingLimitsBinaryCmd, loggingLimitsBinaryLocation, true, t)
+
+	m, err := NewModule(cfg, binary)
+	require.NoError(t, err)
+
+	_, err = m.Execute(t.Context(), executeRequest, mockExecutionHelper)
+	require.NoError(t, err)
+
+	// allowed 3 logs max, one of which got rejected because it was too long
+	// so expect 2 logs to be emitted
+	require.Equal(t, 2, len(logs))
+	require.Equal(t, "short log 1", logs[0])
+	require.Equal(t, "short log 3", logs[1])
+}
+
 func defaultNoDAGModCfg(t testing.TB) *ModuleConfig {
 	return &ModuleConfig{
 		Logger:         logger.Test(t),