[TT-1187] Fix missing Loki log on CL node log scanner match (#13257)

* save test summary & flush logs if log scanner detects failing logs; fix attaching log stream to evm nodes * fail in CI due to log scan * display error log only once, do not fail on purpose * use tagged CTF
smartcontractkit · May 20, 2024 · 5169bee · 5169bee
1 parent dfc399d
commit 5169bee
Show file tree

Hide file tree

Showing 6 changed files with 52 additions and 78 deletions.
diff --git a/integration-tests/docker/test_env/test_env.go b/integration-tests/docker/test_env/test_env.go
@@ -112,6 +112,7 @@ func (te *CLClusterTestEnv) StartEthereumNetwork(cfg *ctf_config.EthereumNetwork
 	builder := test_env.NewEthereumNetworkBuilder()
 	c, err := builder.WithExistingConfig(*cfg).
 		WithTest(te.t).
+		WithLogStream(te.LogStream).
 		Build()
 	if err != nil {
 		return blockchain.EVMNetwork{}, test_env.RpcProvider{}, err

diff --git a/integration-tests/docker/test_env/test_env_builder.go b/integration-tests/docker/test_env/test_env_builder.go
@@ -1,19 +1,19 @@
 package test_env
 
 import (
-	"context"
 	"fmt"
 	"math/big"
 	"os"
 	"slices"
+	"strings"
 	"testing"
 
 	"github.com/pkg/errors"
 	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/log"
+
 	"github.com/smartcontractkit/seth"
 	"go.uber.org/zap/zapcore"
-	"golang.org/x/sync/errgroup"
 
 	"github.com/smartcontractkit/chainlink-testing-framework/blockchain"
 	ctf_config "github.com/smartcontractkit/chainlink-testing-framework/config"
@@ -28,7 +28,6 @@ import (
 	actions_seth "github.com/smartcontractkit/chainlink/integration-tests/actions/seth"
 	"github.com/smartcontractkit/chainlink/integration-tests/contracts"
 	"github.com/smartcontractkit/chainlink/integration-tests/types/config/node"
-	"github.com/smartcontractkit/chainlink/integration-tests/utils"
 )
 
 type CleanUpType string
@@ -85,8 +84,8 @@ var DefaultChainlinkNodeLogScannerSettings = ChainlinkNodeLogScannerSettings{
 func GetDefaultChainlinkNodeLogScannerSettingsWithExtraAllowedMessages(extraAllowedMessages ...testreporters.AllowedLogMessage) ChainlinkNodeLogScannerSettings {
 	allowedMessages := append(DefaultAllowedMessages, extraAllowedMessages...)
 	return ChainlinkNodeLogScannerSettings{
-		FailingLogLevel: zapcore.DPanicLevel,
-		Threshold:       1,
+		FailingLogLevel: DefaultChainlinkNodeLogScannerSettings.FailingLogLevel,
+		Threshold:       DefaultChainlinkNodeLogScannerSettings.Threshold,
 		AllowedMessages: allowedMessages,
 	}
 }
@@ -288,55 +287,54 @@ func (b *CLTestEnvBuilder) Build() (*CLClusterTestEnv, error) {
 					b.l.Info().Str("Absolute path", logPath).Msg("LogStream logs folder location")
 				}
 
-				var scanClNodeLogs = func() {
-					//filter out non-cl logs
-					logLocation := b.te.LogStream.GetLogLocation()
-					logFiles, err := testreporters.FindAllLogFilesToScan(logLocation, "cl-node")
-					if err != nil {
-						b.l.Warn().Err(err).Msg("Error looking for Chainlink Node log files to scan")
-					} else {
-						// we ignore the context returned by errgroup here, since we have no way of interrupting ongoing scanning of logs
-						verifyLogsGroup, _ := errgroup.WithContext(context.Background())
-						for _, f := range logFiles {
-							file := f
-							verifyLogsGroup.Go(func() error {
-								logErr := testreporters.VerifyLogFile(file, b.chainlinkNodeLogScannerSettings.FailingLogLevel, b.chainlinkNodeLogScannerSettings.Threshold, b.chainlinkNodeLogScannerSettings.AllowedMessages...)
-								if logErr != nil {
-									return errors.Wrapf(logErr, "Found a concerning log in %s", file.Name())
-								}
-								return nil
-							})
-						}
-						if err := verifyLogsGroup.Wait(); err != nil {
-							b.l.Error().Err(err).Msg("Found a concerning log. Failing test.")
-							b.t.Fatalf("Found a concerning log in Chainklink Node logs: %v", err)
-						}
+				var flushLogStreamFn = func() error {
+					// we can't do much if this fails, so we just log the error in LogStream
+					if flushErr := b.te.LogStream.FlushAndShutdown(); flushErr != nil {
+						b.l.Error().Err(flushErr).Msg("Error flushing and shutting down LogStream")
+						return flushErr
 					}
-					b.l.Info().Msg("Finished scanning Chainlink Node logs for concerning errors")
+					b.te.LogStream.PrintLogTargetsLocations()
+					b.te.LogStream.SaveLogLocationInTestSummary()
+
+					return nil
 				}
 
+				// flush logs when test failed or when we are explicitly told to collect logs
 				if b.t.Failed() || *b.testConfig.GetLoggingConfig().TestLogCollect {
-					// we can't do much if this fails, so we just log the error in logstream
-					flushErr := b.te.LogStream.FlushAndShutdown()
-					if flushErr != nil {
-						b.l.Error().Err(flushErr).Msg("Error flushing and shutting down LogStream")
+					if shutdownErr := flushLogStreamFn(); shutdownErr != nil {
 						return
 					}
-					b.te.LogStream.PrintLogTargetsLocations()
-					b.te.LogStream.SaveLogLocationInTestSummary()
+				}
 
-					// if test hasn't failed, but we have chainlinkNodeLogScannerSettings, we should check the logs
-					if !b.t.Failed() && b.chainlinkNodeLogScannerSettings != nil {
-						scanClNodeLogs()
-					}
-				} else if b.chainlinkNodeLogScannerSettings != nil {
-					flushErr := b.te.LogStream.FlushAndShutdown()
-					if flushErr != nil {
-						b.l.Error().Err(flushErr).Msg("Error flushing and shutting down LogStream")
-						return
+				// run even if test has failed, as we might be able to catch additional problems without running the test again
+				if b.chainlinkNodeLogScannerSettings != nil {
+					logProcessor := logstream.NewLogProcessor[int](b.te.LogStream)
+
+					processFn := func(log logstream.LogContent, count *int) error {
+						countSoFar := count
+						newCount, err := testreporters.ScanLogLine(b.l, string(log.Content), b.chainlinkNodeLogScannerSettings.FailingLogLevel, uint(*countSoFar), b.chainlinkNodeLogScannerSettings.Threshold, b.chainlinkNodeLogScannerSettings.AllowedMessages)
+						if err != nil {
+							return err
+						}
+						*count = int(newCount)
+						return nil
 					}
 
-					scanClNodeLogs()
+					// we cannot do parallel processing here, because ProcessContainerLogs() locks a mutex that controls whether
+					// new logs can be added to the log stream, so parallel processing would get stuck on waiting for it to be unlocked
+					for i := 0; i < b.clNodesCount; i++ {
+						// ignore count return, because we are only interested in the error
+						_, err := logProcessor.ProcessContainerLogs(b.te.ClCluster.Nodes[i].ContainerName, processFn)
+						if err != nil && !strings.Contains(err.Error(), testreporters.MultipleLogsAtLogLevelErr) && !strings.Contains(err.Error(), testreporters.OneLogAtLogLevelErr) {
+							b.l.Error().Err(err).Msg("Error processing logs")
+							return
+						} else if err != nil && (strings.Contains(err.Error(), testreporters.MultipleLogsAtLogLevelErr) || strings.Contains(err.Error(), testreporters.OneLogAtLogLevelErr)) {
+							// err return ignored on purpose since we are already failing the test
+							_ = flushLogStreamFn()
+							b.t.Fatalf("Found a concerning log in Chainklink Node logs: %v", err)
+						}
+					}
+					b.l.Info().Msg("Finished scanning Chainlink Node logs for concerning errors")
 				}
 			})
 		} else {
@@ -377,22 +375,6 @@ func (b *CLTestEnvBuilder) Build() (*CLClusterTestEnv, error) {
 		return b.te, fmt.Errorf("test environment builder failed: %w", fmt.Errorf("explicit cleanup type must be set when building test environment"))
 	}
 
-	if b.te.LogStream != nil {
-		// this is not the cleanest way to do this, but when we originally build ethereum networks, we don't have the logstream reference,
-		// so we need to rebuild them here and pass logstream to them
-		for i := range b.privateEthereumNetworks {
-			builder := test_env.NewEthereumNetworkBuilder()
-			netWithLs, err := builder.
-				WithExistingConfig(*b.privateEthereumNetworks[i]).
-				WithLogStream(b.te.LogStream).
-				Build()
-			if err != nil {
-				return nil, err
-			}
-			b.privateEthereumNetworks[i] = &netWithLs.EthereumNetworkConfig
-		}
-	}
-
 	if b.te.LogStream == nil && b.chainlinkNodeLogScannerSettings != nil {
 		log.Warn().Msg("Chainlink node log scanner settings provided, but LogStream is not enabled. Ignoring Chainlink node log scanner settings, as no logs will be available.")
 	}
@@ -418,12 +400,12 @@ func (b *CLTestEnvBuilder) Build() (*CLClusterTestEnv, error) {
 			}
 
 			if b.hasSeth {
-				seth, err := actions_seth.GetChainClient(b.testConfig, networkConfig)
+				sethClient, err := actions_seth.GetChainClient(b.testConfig, networkConfig)
 				if err != nil {
 					return nil, err
 				}
 
-				b.te.sethClients[networkConfig.ChainID] = seth
+				b.te.sethClients[networkConfig.ChainID] = sethClient
 			}
 
 			b.te.rpcProviders[networkConfig.ChainID] = &rpcProvider
@@ -529,15 +511,6 @@ func (b *CLTestEnvBuilder) Build() (*CLClusterTestEnv, error) {
 
 		if b.hasSeth {
 			b.te.sethClients = make(map[int64]*seth.Client)
-			readSethCfg := b.testConfig.GetSethConfig()
-			sethCfg, err := utils.MergeSethAndEvmNetworkConfigs(networkConfig, *readSethCfg)
-			if err != nil {
-				return nil, err
-			}
-			err = utils.ValidateSethNetworkConfig(sethCfg.Network)
-			if err != nil {
-				return nil, err
-			}
 			sethClient, err := actions_seth.GetChainClient(b.testConfig, networkConfig)
 			if err != nil {
 				return nil, err

diff --git a/integration-tests/go.mod b/integration-tests/go.mod
@@ -28,7 +28,7 @@ require (
 	github.com/slack-go/slack v0.12.2
 	github.com/smartcontractkit/chainlink-automation v1.0.3
 	github.com/smartcontractkit/chainlink-common v0.1.7-0.20240517134904-f4446b816a28
-	github.com/smartcontractkit/chainlink-testing-framework v1.28.14
+	github.com/smartcontractkit/chainlink-testing-framework v1.28.15
 	github.com/smartcontractkit/chainlink-vrf v0.0.0-20231120191722-fef03814f868
 	github.com/smartcontractkit/chainlink/v2 v2.0.0-00010101000000-000000000000
 	github.com/smartcontractkit/libocr v0.0.0-20240419185742-fd3cab206b2c

diff --git a/integration-tests/go.sum b/integration-tests/go.sum
@@ -1524,8 +1524,8 @@ github.com/smartcontractkit/chainlink-solana v1.0.3-0.20240510181707-46b1311a5a8
 github.com/smartcontractkit/chainlink-solana v1.0.3-0.20240510181707-46b1311a5a83/go.mod h1:RdAtOeBUWq2zByw2kEbwPlXaPIb7YlaDOmnn+nVUBJI=
 github.com/smartcontractkit/chainlink-starknet/relayer v0.0.1-beta-test.0.20240508155030-1024f2b55c69 h1:ssh/w3oXWu+C6bE88GuFRC1+0Bx/4ihsbc80XMLrl2k=
 github.com/smartcontractkit/chainlink-starknet/relayer v0.0.1-beta-test.0.20240508155030-1024f2b55c69/go.mod h1:VsfjhvWgjxqWja4q+FlXEtX5lu8BSxn10xRo6gi948g=
-github.com/smartcontractkit/chainlink-testing-framework v1.28.14 h1:LChhbd/dJWf+yainZ/mjbfu6XP8IbGQ9S64MDTg+tt4=
-github.com/smartcontractkit/chainlink-testing-framework v1.28.14/go.mod h1:x1zDOz8zcLjEvs9fNA9y/DMguLam/2+CJdpxX0+rM8A=
+github.com/smartcontractkit/chainlink-testing-framework v1.28.15 h1:mga7N6jtXQ3UOCt43IdsEnCMBh9xjOWPaE9BiM6kr6Q=
+github.com/smartcontractkit/chainlink-testing-framework v1.28.15/go.mod h1:x1zDOz8zcLjEvs9fNA9y/DMguLam/2+CJdpxX0+rM8A=
 github.com/smartcontractkit/chainlink-testing-framework/grafana v0.0.0-20240328204215-ac91f55f1449 h1:fX/xmGm1GBsD1ZZnooNT+eWA0hiTAqFlHzOC5CY4dy8=
 github.com/smartcontractkit/chainlink-testing-framework/grafana v0.0.0-20240328204215-ac91f55f1449/go.mod h1:DC8sQMyTlI/44UCTL8QWFwb0bYNoXCfjwCv2hMivYZU=
 github.com/smartcontractkit/chainlink-vrf v0.0.0-20231120191722-fef03814f868 h1:FFdvEzlYwcuVHkdZ8YnZR/XomeMGbz5E2F2HZI3I3w8=

diff --git a/integration-tests/load/go.mod b/integration-tests/load/go.mod
@@ -17,7 +17,7 @@ require (
 	github.com/slack-go/slack v0.12.2
 	github.com/smartcontractkit/chainlink-automation v1.0.3
 	github.com/smartcontractkit/chainlink-common v0.1.7-0.20240517134904-f4446b816a28
-	github.com/smartcontractkit/chainlink-testing-framework v1.28.14
+	github.com/smartcontractkit/chainlink-testing-framework v1.28.15
 	github.com/smartcontractkit/chainlink/integration-tests v0.0.0-20240214231432-4ad5eb95178c
 	github.com/smartcontractkit/chainlink/v2 v2.9.0-beta0.0.20240216210048-da02459ddad8
 	github.com/smartcontractkit/libocr v0.0.0-20240419185742-fd3cab206b2c

diff --git a/integration-tests/load/go.sum b/integration-tests/load/go.sum
@@ -1514,8 +1514,8 @@ github.com/smartcontractkit/chainlink-solana v1.0.3-0.20240510181707-46b1311a5a8
 github.com/smartcontractkit/chainlink-solana v1.0.3-0.20240510181707-46b1311a5a83/go.mod h1:RdAtOeBUWq2zByw2kEbwPlXaPIb7YlaDOmnn+nVUBJI=
 github.com/smartcontractkit/chainlink-starknet/relayer v0.0.1-beta-test.0.20240508155030-1024f2b55c69 h1:ssh/w3oXWu+C6bE88GuFRC1+0Bx/4ihsbc80XMLrl2k=
 github.com/smartcontractkit/chainlink-starknet/relayer v0.0.1-beta-test.0.20240508155030-1024f2b55c69/go.mod h1:VsfjhvWgjxqWja4q+FlXEtX5lu8BSxn10xRo6gi948g=
-github.com/smartcontractkit/chainlink-testing-framework v1.28.14 h1:LChhbd/dJWf+yainZ/mjbfu6XP8IbGQ9S64MDTg+tt4=
-github.com/smartcontractkit/chainlink-testing-framework v1.28.14/go.mod h1:x1zDOz8zcLjEvs9fNA9y/DMguLam/2+CJdpxX0+rM8A=
+github.com/smartcontractkit/chainlink-testing-framework v1.28.15 h1:mga7N6jtXQ3UOCt43IdsEnCMBh9xjOWPaE9BiM6kr6Q=
+github.com/smartcontractkit/chainlink-testing-framework v1.28.15/go.mod h1:x1zDOz8zcLjEvs9fNA9y/DMguLam/2+CJdpxX0+rM8A=
 github.com/smartcontractkit/chainlink-testing-framework/grafana v0.0.0-20240328204215-ac91f55f1449 h1:fX/xmGm1GBsD1ZZnooNT+eWA0hiTAqFlHzOC5CY4dy8=
 github.com/smartcontractkit/chainlink-testing-framework/grafana v0.0.0-20240328204215-ac91f55f1449/go.mod h1:DC8sQMyTlI/44UCTL8QWFwb0bYNoXCfjwCv2hMivYZU=
 github.com/smartcontractkit/chainlink-vrf v0.0.0-20231120191722-fef03814f868 h1:FFdvEzlYwcuVHkdZ8YnZR/XomeMGbz5E2F2HZI3I3w8=