From 5169beeec3fc73565871b0e314d6479a0293c7c1 Mon Sep 17 00:00:00 2001 From: Bartek Tofel Date: Mon, 20 May 2024 19:05:57 +0200 Subject: [PATCH] [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 --- integration-tests/docker/test_env/test_env.go | 1 + .../docker/test_env/test_env_builder.go | 117 +++++++----------- integration-tests/go.mod | 2 +- integration-tests/go.sum | 4 +- integration-tests/load/go.mod | 2 +- integration-tests/load/go.sum | 4 +- 6 files changed, 52 insertions(+), 78 deletions(-) diff --git a/integration-tests/docker/test_env/test_env.go b/integration-tests/docker/test_env/test_env.go index 5a1649155cb..6952f6489e9 100644 --- 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 index ad3b75a3ca4..ff6e132368b 100644 --- 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 index 9355e8007bc..db33fef86b1 100644 --- 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 index 5fc82cbff5d..aa9e4a55fb1 100644 --- 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 index 1e51191034c..0b389c3118a 100644 --- 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 index 9542f355788..07ebb37aff0 100644 --- 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=