diff --git a/core/capabilities/transmission/local_target_capability_test.go b/core/capabilities/transmission/local_target_capability_test.go index a6b7b8303c5..8c0cfd80ce8 100644 --- a/core/capabilities/transmission/local_target_capability_test.go +++ b/core/capabilities/transmission/local_target_capability_test.go @@ -4,6 +4,7 @@ import ( "context" "crypto/rand" "testing" + "testing/synctest" "time" "github.com/stretchr/testify/assert" @@ -108,7 +109,7 @@ func TestScheduledExecutionStrategy_LocalDON(t *testing.T) { } for _, tc := range testCases { - t.Run(tc.name, func(t *testing.T) { + synctestrun(t, tc.name, func(t *testing.T) { startTime := time.Now() m, err := values.NewMap(map[string]any{ @@ -191,3 +192,11 @@ func (m *mockCapability) RegisterToWorkflow(ctx context.Context, request capabil func (m *mockCapability) UnregisterFromWorkflow(ctx context.Context, request capabilities.UnregisterFromWorkflowRequest) error { return nil } + +func synctestrun(t *testing.T, name string, f func(*testing.T)) { + t.Helper() + t.Run(name, func(t *testing.T) { + t.Helper() + synctest.Test(t, f) + }) +} diff --git a/core/services/ocr2/plugins/promwrapper/plugin.go b/core/services/ocr2/plugins/promwrapper/plugin.go index aa60ab88005..977e80ac230 100644 --- a/core/services/ocr2/plugins/promwrapper/plugin.go +++ b/core/services/ocr2/plugins/promwrapper/plugin.go @@ -16,7 +16,8 @@ import ( "github.com/smartcontractkit/libocr/offchainreporting2plus/types" ) -const ( +// var instead of const to make it overridable in tests +var ( // defaultExpiration is the default expiration time for cache items. defaultExpiration = 30 * time.Minute diff --git a/core/services/ocr2/plugins/promwrapper/plugin_test.go b/core/services/ocr2/plugins/promwrapper/plugin_test.go index 371c03e78df..fb08d78852d 100644 --- a/core/services/ocr2/plugins/promwrapper/plugin_test.go +++ b/core/services/ocr2/plugins/promwrapper/plugin_test.go @@ -4,6 +4,7 @@ import ( "context" "math/big" "testing" + "testing/synctest" "time" "github.com/ethereum/go-ethereum/common" @@ -13,7 +14,6 @@ import ( "github.com/smartcontractkit/libocr/offchainreporting2plus/types" - "github.com/smartcontractkit/chainlink/v2/core/internal/testutils" "github.com/smartcontractkit/chainlink/v2/core/services/ocr2/plugins/promwrapper/mocks" ) @@ -78,155 +78,162 @@ func TestPlugin_MustInstantiate(t *testing.T) { } func TestPlugin_GetLatencies(t *testing.T) { - // Use arbitrary report timestamp and label values. - configDigest := common.BytesToHash(crypto.Keccak256([]byte("foobar"))) - reportTimestamp := types.ReportTimestamp{ - ConfigDigest: types.ConfigDigest(configDigest), - Epoch: 1, - Round: 1, - } - var assertCorrectLabelValues = func(labelValues []string) { - require.Equal( - t, - []string{ - "EVM", - "1", + synctest.Test(t, func(t *testing.T) { + { + // Use arbitrary report timestamp and label values. + configDigest := common.BytesToHash(crypto.Keccak256([]byte("foobar"))) + reportTimestamp := types.ReportTimestamp{ + ConfigDigest: types.ConfigDigest(configDigest), + Epoch: 1, + Round: 1, + } + var assertCorrectLabelValues = func(labelValues []string) { + require.Equal( + t, + []string{ + "EVM", + "1", + "test-plugin", + "0", + common.Bytes2Hex(configDigest[:]), + }, labelValues) + } + + // Instantiate prometheus backend mock. + backend := mocks.NewPrometheusBackend(t) + + // Assert intra-phase latencies. + backend.On("SetQueryDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + duration := time.Duration(args[1].(float64)) + assertCorrectLabelValues(labelValues) + require.Equal(t, duration, qDuration) + require.Less(t, duration, oDuration) + }).Return() + backend.On("SetObservationDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + duration := time.Duration(args[1].(float64)) + assertCorrectLabelValues(labelValues) + require.Equal(t, duration, oDuration) + require.Less(t, duration, rDuration) + }).Return() + backend.On("SetReportDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + duration := time.Duration(args[1].(float64)) + assertCorrectLabelValues(labelValues) + require.Equal(t, duration, rDuration) + require.Less(t, duration, aDuration) + }).Return() + backend.On("SetShouldAcceptFinalizedReportDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + duration := time.Duration(args[1].(float64)) + assertCorrectLabelValues(labelValues) + require.Equal(t, duration, aDuration) + require.Less(t, duration, tDuration) + }).Return() + backend.On("SetShouldTransmitAcceptedReportDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + duration := time.Duration(args[1].(float64)) + assertCorrectLabelValues(labelValues) + require.Equal(t, duration, tDuration) + require.Less(t, duration, cDuration) + }).Return() + + // Assert inter-phase latencies. + backend.On("SetQueryToObservationLatency", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + latency := time.Duration(args[1].(float64)) + assertCorrectLabelValues(labelValues) + require.Equal(t, latency, qToOLatency) + require.Less(t, latency, oToRLatency) + }).Return() + backend.On("SetObservationToReportLatency", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + latency := time.Duration(args[1].(float64)) + assertCorrectLabelValues(labelValues) + require.Equal(t, latency, oToRLatency) + require.Less(t, latency, rToALatency) + }).Return() + backend.On("SetReportToAcceptFinalizedReportLatency", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + latency := time.Duration(args[1].(float64)) + assertCorrectLabelValues(labelValues) + require.Equal(t, latency, rToALatency) + require.Less(t, latency, aToTLatency) + }).Return() + backend.On("SetAcceptFinalizedReportToTransmitAcceptedReportLatency", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + latency := time.Duration(args[1].(float64)) + assertCorrectLabelValues(labelValues) + require.Equal(t, latency, aToTLatency) + require.Less(t, latency, cDuration) + }).Return() + + // Assert close correctly reported. + backend.On("SetCloseDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { + labelValues := args[0].([]string) + latency := time.Duration(args[1].(float64)) + require.Equal( + t, + []string{ + "EVM", + "1", + "test-plugin", + "0", + common.Bytes2Hex(configDigest[:]), + }, labelValues) + require.Equal(t, latency, cDuration) + require.Less(t, latency, ceiling) + }).Return() + + // Create promPlugin with mocked prometheus backend. + var reportingPlugin = &fakeReportingPlugin{} + // Zero defaultCleanupInterval to disable gc in "github.com/patrickmn/go-cache", since gc is not compatible + // with synctest. See https://github.com/patrickmn/go-cache/issues/185. + defaultCleanupInterval = 0 + var promPlugin = New( + reportingPlugin, "test-plugin", - "0", - common.Bytes2Hex(configDigest[:]), - }, labelValues) - } - - // Instantiate prometheus backend mock. - backend := mocks.NewPrometheusBackend(t) - - // Assert intra-phase latencies. - backend.On("SetQueryDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - duration := time.Duration(args[1].(float64)) - assertCorrectLabelValues(labelValues) - require.Greater(t, duration, qDuration) - require.Less(t, duration, oDuration) - }).Return() - backend.On("SetObservationDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - duration := time.Duration(args[1].(float64)) - assertCorrectLabelValues(labelValues) - require.Greater(t, duration, oDuration) - require.Less(t, duration, rDuration) - }).Return() - backend.On("SetReportDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - duration := time.Duration(args[1].(float64)) - assertCorrectLabelValues(labelValues) - require.Greater(t, duration, rDuration) - require.Less(t, duration, aDuration) - }).Return() - backend.On("SetShouldAcceptFinalizedReportDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - duration := time.Duration(args[1].(float64)) - assertCorrectLabelValues(labelValues) - require.Greater(t, duration, aDuration) - require.Less(t, duration, tDuration) - }).Return() - backend.On("SetShouldTransmitAcceptedReportDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - duration := time.Duration(args[1].(float64)) - assertCorrectLabelValues(labelValues) - require.Greater(t, duration, tDuration) - require.Less(t, duration, cDuration) - }).Return() - - // Assert inter-phase latencies. - backend.On("SetQueryToObservationLatency", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - latency := time.Duration(args[1].(float64)) - assertCorrectLabelValues(labelValues) - require.Greater(t, latency, qToOLatency) - require.Less(t, latency, oToRLatency) - }).Return() - backend.On("SetObservationToReportLatency", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - latency := time.Duration(args[1].(float64)) - assertCorrectLabelValues(labelValues) - require.Greater(t, latency, oToRLatency) - require.Less(t, latency, rToALatency) - }).Return() - backend.On("SetReportToAcceptFinalizedReportLatency", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - latency := time.Duration(args[1].(float64)) - assertCorrectLabelValues(labelValues) - require.Greater(t, latency, rToALatency) - require.Less(t, latency, aToTLatency) - }).Return() - backend.On("SetAcceptFinalizedReportToTransmitAcceptedReportLatency", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - latency := time.Duration(args[1].(float64)) - assertCorrectLabelValues(labelValues) - require.Greater(t, latency, aToTLatency) - require.Less(t, latency, cDuration) - }).Return() - - // Assert close correctly reported. - backend.On("SetCloseDuration", mock.Anything, mock.Anything).Run(func(args mock.Arguments) { - labelValues := args[0].([]string) - latency := time.Duration(args[1].(float64)) - require.Equal( - t, - []string{ "EVM", - "1", - "test-plugin", - "0", - common.Bytes2Hex(configDigest[:]), - }, labelValues) - require.Greater(t, latency, cDuration) - require.Less(t, latency, ceiling) - }).Return() - - // Create promPlugin with mocked prometheus backend. - var reportingPlugin = &fakeReportingPlugin{} - var promPlugin = New( - reportingPlugin, - "test-plugin", - "EVM", - big.NewInt(1), - types.ReportingPluginConfig{ConfigDigest: reportTimestamp.ConfigDigest}, - backend, - ).(*promPlugin) - require.NotNil(t, promPlugin) - - ctx := testutils.Context(t) - - // Run OCR methods. - _, err := promPlugin.Query(ctx, reportTimestamp) - require.NoError(t, err) - _, ok := promPlugin.queryEndTimes.Get(timestampToKey(reportTimestamp)) - require.True(t, ok) - time.Sleep(qToOLatency) - - _, err = promPlugin.Observation(ctx, reportTimestamp, nil) - require.NoError(t, err) - _, ok = promPlugin.observationEndTimes.Get(timestampToKey(reportTimestamp)) - require.True(t, ok) - time.Sleep(oToRLatency) - - _, _, err = promPlugin.Report(ctx, reportTimestamp, nil, nil) - require.NoError(t, err) - _, ok = promPlugin.reportEndTimes.Get(timestampToKey(reportTimestamp)) - require.True(t, ok) - time.Sleep(rToALatency) - - _, err = promPlugin.ShouldAcceptFinalizedReport(ctx, reportTimestamp, nil) - require.NoError(t, err) - _, ok = promPlugin.acceptFinalizedReportEndTimes.Get(timestampToKey(reportTimestamp)) - require.True(t, ok) - time.Sleep(aToTLatency) - - _, err = promPlugin.ShouldTransmitAcceptedReport(ctx, reportTimestamp, nil) - require.NoError(t, err) - - // Close. - err = promPlugin.Close() - require.NoError(t, err) + big.NewInt(1), + types.ReportingPluginConfig{ConfigDigest: reportTimestamp.ConfigDigest}, + backend, + ).(*promPlugin) + require.NotNil(t, promPlugin) + + ctx := t.Context() + + // Run OCR methods. + _, err := promPlugin.Query(ctx, reportTimestamp) + require.NoError(t, err) + _, ok := promPlugin.queryEndTimes.Get(timestampToKey(reportTimestamp)) + require.True(t, ok) + time.Sleep(qToOLatency) + + _, err = promPlugin.Observation(ctx, reportTimestamp, nil) + require.NoError(t, err) + _, ok = promPlugin.observationEndTimes.Get(timestampToKey(reportTimestamp)) + require.True(t, ok) + time.Sleep(oToRLatency) + + _, _, err = promPlugin.Report(ctx, reportTimestamp, nil, nil) + require.NoError(t, err) + _, ok = promPlugin.reportEndTimes.Get(timestampToKey(reportTimestamp)) + require.True(t, ok) + time.Sleep(rToALatency) + + _, err = promPlugin.ShouldAcceptFinalizedReport(ctx, reportTimestamp, nil) + require.NoError(t, err) + _, ok = promPlugin.acceptFinalizedReportEndTimes.Get(timestampToKey(reportTimestamp)) + require.True(t, ok) + time.Sleep(aToTLatency) + + _, err = promPlugin.ShouldTransmitAcceptedReport(ctx, reportTimestamp, nil) + require.NoError(t, err) + + // Close. + err = promPlugin.Close() + require.NoError(t, err) + } + }) }