From f4910835f5cbd6b9879551b0a292d78ce5bc6b9d Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 9 May 2023 10:50:32 +0200 Subject: [PATCH 01/26] Use profile in tests --- cmd/profiles.go | 60 +++++++++++++++++++- cmd/stack.go | 55 ------------------ cmd/testrunner.go | 8 +++ internal/testrunner/runners/system/runner.go | 43 ++++++++++++++ internal/testrunner/testrunner.go | 3 + 5 files changed, 112 insertions(+), 57 deletions(-) diff --git a/cmd/profiles.go b/cmd/profiles.go index 33dd0fd6ca..b372752139 100644 --- a/cmd/profiles.go +++ b/cmd/profiles.go @@ -8,6 +8,7 @@ import ( "encoding/json" "fmt" "os" + "strings" "time" "github.com/olekukonko/tablewriter" @@ -18,6 +19,7 @@ import ( "github.com/elastic/elastic-package/internal/configuration/locations" "github.com/elastic/elastic-package/internal/install" "github.com/elastic/elastic-package/internal/profile" + "github.com/elastic/elastic-package/internal/stack" ) // jsonFormat is the format for JSON output @@ -28,8 +30,8 @@ const tableFormat = "table" func setupProfilesCommand() *cobraext.Command { profilesLongDescription := `Use this command to add, remove, and manage multiple config profiles. - -Individual user profiles appear in ~/.elastic-package/stack, and contain all the config files needed by the "stack" subcommand. + +Individual user profiles appear in ~/.elastic-package/stack, and contain all the config files needed by the "stack" subcommand. Once a new profile is created, it can be specified with the -p flag, or the ELASTIC_PACKAGE_PROFILE environment variable. User profiles can be configured with a "config.yml" file in the profile directory.` @@ -235,3 +237,57 @@ func availableProfilesAsAList() ([]string, error) { return profileNames, nil } + +func getProfileFlag(cmd *cobra.Command) (*profile.Profile, error) { + profileName, err := cmd.Flags().GetString(cobraext.ProfileFlagName) + if err != nil { + return nil, cobraext.FlagParsingError(err, cobraext.ProfileFlagName) + } + if profileName == "" { + config, err := install.Configuration() + if err != nil { + return nil, fmt.Errorf("cannot read configuration: %w", err) + } + profileName = config.CurrentProfile() + } + + p, err := profile.LoadProfile(profileName) + if errors.Is(err, profile.ErrNotAProfile) { + list, err := availableProfilesAsAList() + if err != nil { + return nil, errors.Wrap(err, "error listing known profiles") + } + if len(list) == 0 { + return nil, fmt.Errorf("%s is not a valid profile", profileName) + } + return nil, fmt.Errorf("%s is not a valid profile, known profiles are: %s", profileName, strings.Join(list, ", ")) + } + if err != nil { + return nil, errors.Wrap(err, "error loading profile") + } + + return p, nil +} + +func getProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkFlag bool) (stack.Provider, error) { + var providerName = stack.DefaultProvider + stackConfig, err := stack.LoadConfig(profile) + if err != nil { + return nil, err + } + if stackConfig.Provider != "" { + providerName = stackConfig.Provider + } + + if checkFlag { + providerFlag, err := cmd.Flags().GetString(cobraext.StackProviderFlagName) + if err != nil { + return nil, cobraext.FlagParsingError(err, cobraext.StackProviderFlagName) + } + if providerFlag != "" { + providerName = providerFlag + } + } + + return stack.BuildProvider(providerName, profile) +} diff --git a/cmd/stack.go b/cmd/stack.go index 4039ad32b2..3c5d791d1d 100644 --- a/cmd/stack.go +++ b/cmd/stack.go @@ -15,7 +15,6 @@ import ( "github.com/elastic/elastic-package/internal/cobraext" "github.com/elastic/elastic-package/internal/common" "github.com/elastic/elastic-package/internal/install" - "github.com/elastic/elastic-package/internal/profile" "github.com/elastic/elastic-package/internal/stack" ) @@ -321,57 +320,3 @@ func printStatus(cmd *cobra.Command, servicesStatus []stack.ServiceStatus) { t.SetStyle(table.StyleRounded) cmd.Println(t.Render()) } - -func getProfileFlag(cmd *cobra.Command) (*profile.Profile, error) { - profileName, err := cmd.Flags().GetString(cobraext.ProfileFlagName) - if err != nil { - return nil, cobraext.FlagParsingError(err, cobraext.ProfileFlagName) - } - if profileName == "" { - config, err := install.Configuration() - if err != nil { - return nil, fmt.Errorf("cannot read configuration: %w", err) - } - profileName = config.CurrentProfile() - } - - p, err := profile.LoadProfile(profileName) - if errors.Is(err, profile.ErrNotAProfile) { - list, err := availableProfilesAsAList() - if err != nil { - return nil, errors.Wrap(err, "error listing known profiles") - } - if len(list) == 0 { - return nil, fmt.Errorf("%s is not a valid profile", profileName) - } - return nil, fmt.Errorf("%s is not a valid profile, known profiles are: %s", profileName, strings.Join(list, ", ")) - } - if err != nil { - return nil, errors.Wrap(err, "error loading profile") - } - - return p, nil -} - -func getProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkFlag bool) (stack.Provider, error) { - var providerName = stack.DefaultProvider - stackConfig, err := stack.LoadConfig(profile) - if err != nil { - return nil, err - } - if stackConfig.Provider != "" { - providerName = stackConfig.Provider - } - - if checkFlag { - providerFlag, err := cmd.Flags().GetString(cobraext.StackProviderFlagName) - if err != nil { - return nil, cobraext.FlagParsingError(err, cobraext.StackProviderFlagName) - } - if providerFlag != "" { - providerName = providerFlag - } - } - - return stack.BuildProvider(providerName, profile) -} diff --git a/cmd/testrunner.go b/cmd/testrunner.go index 2be5235f82..cba65d7bbf 100644 --- a/cmd/testrunner.go +++ b/cmd/testrunner.go @@ -16,6 +16,7 @@ import ( "github.com/elastic/elastic-package/internal/cobraext" "github.com/elastic/elastic-package/internal/common" "github.com/elastic/elastic-package/internal/elasticsearch" + "github.com/elastic/elastic-package/internal/install" "github.com/elastic/elastic-package/internal/packages" "github.com/elastic/elastic-package/internal/signal" "github.com/elastic/elastic-package/internal/testrunner" @@ -71,6 +72,7 @@ func setupTestCommand() *cobraext.Command { cmd.PersistentFlags().BoolP(cobraext.TestCoverageFlagName, "", false, cobraext.TestCoverageFlagDescription) cmd.PersistentFlags().DurationP(cobraext.DeferCleanupFlagName, "", 0, cobraext.DeferCleanupFlagDescription) cmd.PersistentFlags().String(cobraext.VariantFlagName, "", cobraext.VariantFlagDescription) + cmd.PersistentFlags().StringP(cobraext.ProfileFlagName, "p", "", fmt.Sprintf(cobraext.ProfileFlagDescription, install.ProfileNameEnvVar)) for testType, runner := range testrunner.TestRunners() { action := testTypeCommandActionFactory(runner) @@ -207,6 +209,11 @@ func testTypeCommandActionFactory(runner testrunner.TestRunner) cobraext.Command variantFlag, _ := cmd.Flags().GetString(cobraext.VariantFlagName) + profile, err := getProfileFlag(cmd) + if err != nil { + return err + } + esClient, err := elasticsearch.NewClient() if err != nil { return errors.Wrap(err, "can't create Elasticsearch client") @@ -226,6 +233,7 @@ func testTypeCommandActionFactory(runner testrunner.TestRunner) cobraext.Command DeferCleanup: deferCleanup, ServiceVariant: variantFlag, WithCoverage: testCoverage, + Profile: profile, }) results = append(results, r...) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index ba019459c3..8eff0919c0 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -7,6 +7,8 @@ package system import ( "encoding/json" "fmt" + "io/fs" + "log" "math/rand" "os" "path/filepath" @@ -24,6 +26,7 @@ import ( "github.com/elastic/elastic-package/internal/multierror" "github.com/elastic/elastic-package/internal/packages" "github.com/elastic/elastic-package/internal/signal" + "github.com/elastic/elastic-package/internal/stack" "github.com/elastic/elastic-package/internal/testrunner" "github.com/elastic/elastic-package/internal/testrunner/runners/system/servicedeployer" ) @@ -182,6 +185,46 @@ func (r *runner) run() (results []testrunner.TestResult, err error) { } } } + + // check agent logs + tempDir, err := os.MkdirTemp("", "test-system-") + if err != nil { + log.Fatal(err) + } + defer os.RemoveAll(tempDir) + + dumpFolder, err := stack.Dump(stack.DumpOptions{ + Output: tempDir, + Profile: r.options.Profile, + }) + if err != nil { + return nil, err + } + + // logs from elastic-agent >8.6.0 + // stack.ParseErrorLogs() + containers := []string{"elastic_agent"} + for _, c := range containers { + elasticAgentLogsFolder := filepath.Join(dumpFolder, "logs", "elastic-agent-internal") + + err = filepath.WalkDir(elasticAgentLogsFolder, func(path string, d fs.DirEntry, err error) error { + if err != nil { + return err + } + if d.IsDir() { + return nil + } + + logger.Debugf("Checking file as elastic-agent log: %s", path) + + // read file and look for errors + return nil + }) + if err != nil { + return nil, err + } + } + return results, nil } diff --git a/internal/testrunner/testrunner.go b/internal/testrunner/testrunner.go index 4c2a4e912f..e81fa44819 100644 --- a/internal/testrunner/testrunner.go +++ b/internal/testrunner/testrunner.go @@ -15,6 +15,7 @@ import ( "github.com/pkg/errors" "github.com/elastic/elastic-package/internal/elasticsearch" + "github.com/elastic/elastic-package/internal/profile" ) // TestType represents the various supported test types @@ -30,6 +31,8 @@ type TestOptions struct { DeferCleanup time.Duration ServiceVariant string WithCoverage bool + + Profile *profile.Profile } // TestRunner is the interface all test runners must implement. From 74d0851604ef46c6db870545885c6606de0ff275 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 9 May 2023 15:47:10 +0200 Subject: [PATCH 02/26] Add method to check errors in logs --- internal/testrunner/runners/system/runner.go | 90 ++++++++++++-------- 1 file changed, 55 insertions(+), 35 deletions(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index 8eff0919c0..e3d806ee36 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -7,8 +7,6 @@ package system import ( "encoding/json" "fmt" - "io/fs" - "log" "math/rand" "os" "path/filepath" @@ -25,6 +23,7 @@ import ( "github.com/elastic/elastic-package/internal/logger" "github.com/elastic/elastic-package/internal/multierror" "github.com/elastic/elastic-package/internal/packages" + "github.com/elastic/elastic-package/internal/profile" "github.com/elastic/elastic-package/internal/signal" "github.com/elastic/elastic-package/internal/stack" "github.com/elastic/elastic-package/internal/testrunner" @@ -54,6 +53,11 @@ const ( waitForDataDefaultTimeout = 10 * time.Minute ) +var errorPatterns = map[string][]string{ + "elastic-agent": []string{"State changed to STOPPED"}, + "package-registry": []string{}, +} + type runner struct { options testrunner.TestOptions @@ -187,42 +191,24 @@ func (r *runner) run() (results []testrunner.TestResult, err error) { } // check agent logs - tempDir, err := os.MkdirTemp("", "test-system-") - if err != nil { - log.Fatal(err) + startTime := time.Now() + err = r.anyErrorMessages(r.options.Profile, "elastic-agent") + if e, ok := err.(testrunner.ErrTestCaseFailed); ok { + tr := testrunner.TestResult{ + TestType: TestType, + Name: "(logs)", + Package: r.options.TestFolder.Package, + DataStream: r.options.TestFolder.DataStream, + } + tr.FailureMsg = e.Error() + tr.FailureDetails = e.Details + tr.TimeElapsed = time.Since(startTime) + results = append(results, tr) + return results, nil } - defer os.RemoveAll(tempDir) - dumpFolder, err := stack.Dump(stack.DumpOptions{ - Output: tempDir, - Profile: r.options.Profile, - }) if err != nil { - return nil, err - } - - // logs from elastic-agent >8.6.0 - // stack.ParseErrorLogs() - containers := []string{"elastic_agent"} - for _, c := range containers { - elasticAgentLogsFolder := filepath.Join(dumpFolder, "logs", "elastic-agent-internal") - - err = filepath.WalkDir(elasticAgentLogsFolder, func(path string, d fs.DirEntry, err error) error { - if err != nil { - return err - } - if d.IsDir() { - return nil - } - - logger.Debugf("Checking file as elastic-agent log: %s", path) - - // read file and look for errors - return nil - }) - if err != nil { - return nil, err - } + return result.WithError(fmt.Errorf("check log messages failed: %s", err)) } return results, nil @@ -955,3 +941,37 @@ func (r *runner) generateTestResult(docs []common.MapStr) error { return nil } + +func (r *runner) anyErrorMessages(profile *profile.Profile, serviceName string) error { + tempDir, err := os.MkdirTemp("", "test-system-") + if err != nil { + return err + } + defer os.RemoveAll(tempDir) + + logs, err := stack.ParseLogs(stack.ParseLogsOptions{ + ServiceName: serviceName, + Profile: r.options.Profile, + LogsPath: tempDir, + }) + if err != nil { + return err + } + + var multiErr multierror.Error + for _, log := range logs { + for _, pattern := range errorPatterns[serviceName] { + if strings.Contains(log.Message, pattern) { + multiErr = append(multiErr, fmt.Errorf("service %s raised this error %q", serviceName, log.Message)) + } + } + } + if len(multiErr) > 0 { + multiErr = multiErr.Unique() + return testrunner.ErrTestCaseFailed{ + Reason: fmt.Sprintf("one or more errors found while examining logs from services"), + Details: multiErr.Error(), + } + } + return nil +} From 7a565a68c1868d451893627d6e1a80631e588311 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 9 May 2023 15:57:16 +0200 Subject: [PATCH 03/26] Do no run check errors if there are no patterns --- internal/testrunner/runners/system/runner.go | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index e3d806ee36..28cc4a6f38 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -943,6 +943,11 @@ func (r *runner) generateTestResult(docs []common.MapStr) error { } func (r *runner) anyErrorMessages(profile *profile.Profile, serviceName string) error { + if _, found := errorPatterns[serviceName]; !found { + logger.Debugf("No error patterns defined for %s", serviceName) + return nil + } + tempDir, err := os.MkdirTemp("", "test-system-") if err != nil { return err From a392d52489ef615bf83c84c861ae7793e2aa3522 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 9 May 2023 16:37:00 +0200 Subject: [PATCH 04/26] Update README --- README.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index df4dfa73d9..f526203bdb 100644 --- a/README.md +++ b/README.md @@ -263,8 +263,8 @@ The command ensures that the package is aligned with the package spec and the RE _Context: global_ Use this command to add, remove, and manage multiple config profiles. - -Individual user profiles appear in ~/.elastic-package/stack, and contain all the config files needed by the "stack" subcommand. + +Individual user profiles appear in ~/.elastic-package/stack, and contain all the config files needed by the "stack" subcommand. Once a new profile is created, it can be specified with the -p flag, or the ELASTIC_PACKAGE_PROFILE environment variable. User profiles can be configured with a "config.yml" file in the profile directory. From 3434fa16ad8d710c90c1843223f85cc98298819c Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 9 May 2023 16:37:14 +0200 Subject: [PATCH 05/26] Add service name into reason --- internal/testrunner/runners/system/runner.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index 28cc4a6f38..f532b01d18 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -974,7 +974,7 @@ func (r *runner) anyErrorMessages(profile *profile.Profile, serviceName string) if len(multiErr) > 0 { multiErr = multiErr.Unique() return testrunner.ErrTestCaseFailed{ - Reason: fmt.Sprintf("one or more errors found while examining logs from services"), + Reason: fmt.Sprintf("one or more errors found while examining logs from service %s", serviceName), Details: multiErr.Error(), } } From 889473c156e3bfba7d7a46399d1b8f9a31e4b51c Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 9 May 2023 16:38:02 +0200 Subject: [PATCH 06/26] Add stack parse logs --- internal/stack/parse_logs.go | 72 ++++++++++++++++++++++++++++++++++++ 1 file changed, 72 insertions(+) create mode 100644 internal/stack/parse_logs.go diff --git a/internal/stack/parse_logs.go b/internal/stack/parse_logs.go new file mode 100644 index 0000000000..a4c48c11ea --- /dev/null +++ b/internal/stack/parse_logs.go @@ -0,0 +1,72 @@ +// Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one +// or more contributor license agreements. Licensed under the Elastic License; +// you may not use this file except in compliance with the Elastic License. + +package stack + +import ( + "bufio" + "encoding/json" + "fmt" + "os" + "path/filepath" + "strings" + "time" + + "github.com/elastic/elastic-package/internal/profile" +) + +type ParseLogsOptions struct { + ServiceName string + LogsPath string + Profile *profile.Profile +} + +type DockerComposeLogs []LogLine +type LogLine struct { + LogLevel string `json:"log.lovel"` + Timestamp time.Time `json:"@timestamp"` + Message string `json:"message"` +} + +func ParseLogs(options ParseLogsOptions) (DockerComposeLogs, error) { + // create dump + outputPath, err := Dump(DumpOptions{Output: options.LogsPath, Profile: options.Profile}) + if err != nil { + return nil, err + } + + // check logs for a service + serviceLogs := filepath.Join(outputPath, "logs", fmt.Sprintf("%s.log", options.ServiceName)) + + file, err := os.Open(serviceLogs) + if err != nil { + return nil, err + } + defer file.Close() + + var logs DockerComposeLogs + scanner := bufio.NewScanner(file) + for scanner.Scan() { + line := scanner.Text() + + messageSlice := strings.SplitN(line, "|", 2) + + if len(messageSlice) != 2 { + return nil, fmt.Errorf("malformed docker-compose log line") + } + + // service := messageSlice[0] + messageLog := messageSlice[1] + + var log LogLine + err := json.Unmarshal([]byte(messageLog), &log) + if err != nil { + log.Message = strings.TrimSpace(messageLog) + } + + logs = append(logs, log) + } + + return logs, nil +} From b1c8d3f524a678111694423862bbe17ed5e9ab93 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 9 May 2023 16:47:21 +0200 Subject: [PATCH 07/26] Add comments --- internal/stack/parse_logs.go | 5 +++-- internal/testrunner/runners/system/runner.go | 1 + 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/internal/stack/parse_logs.go b/internal/stack/parse_logs.go index a4c48c11ea..38b4347d73 100644 --- a/internal/stack/parse_logs.go +++ b/internal/stack/parse_logs.go @@ -29,6 +29,7 @@ type LogLine struct { Message string `json:"message"` } +// ParseLogs returns all the logs for a given service name func ParseLogs(options ParseLogsOptions) (DockerComposeLogs, error) { // create dump outputPath, err := Dump(DumpOptions{Output: options.LogsPath, Profile: options.Profile}) @@ -36,7 +37,7 @@ func ParseLogs(options ParseLogsOptions) (DockerComposeLogs, error) { return nil, err } - // check logs for a service + // TODO: should we parse files of internal logs (elastic-agent and fleet-server)? serviceLogs := filepath.Join(outputPath, "logs", fmt.Sprintf("%s.log", options.ServiceName)) file, err := os.Open(serviceLogs) @@ -56,12 +57,12 @@ func ParseLogs(options ParseLogsOptions) (DockerComposeLogs, error) { return nil, fmt.Errorf("malformed docker-compose log line") } - // service := messageSlice[0] messageLog := messageSlice[1] var log LogLine err := json.Unmarshal([]byte(messageLog), &log) if err != nil { + // there are logs that are just plain text in these logs log.Message = strings.TrimSpace(messageLog) } diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index f532b01d18..abaec5f005 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -53,6 +53,7 @@ const ( waitForDataDefaultTimeout = 10 * time.Minute ) +// FIXME use regex instead of plain strings var errorPatterns = map[string][]string{ "elastic-agent": []string{"State changed to STOPPED"}, "package-registry": []string{}, From 7e44426f17e3bd45d575c988011e3048c2c94abf Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 9 May 2023 18:05:49 +0200 Subject: [PATCH 08/26] Use regex --- internal/testrunner/runners/system/runner.go | 17 +++++++++++------ 1 file changed, 11 insertions(+), 6 deletions(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index abaec5f005..e63c7a11e5 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -10,6 +10,7 @@ import ( "math/rand" "os" "path/filepath" + "regexp" "strings" "time" @@ -53,10 +54,11 @@ const ( waitForDataDefaultTimeout = 10 * time.Minute ) -// FIXME use regex instead of plain strings var errorPatterns = map[string][]string{ - "elastic-agent": []string{"State changed to STOPPED"}, - "package-registry": []string{}, + "elastic-agent": []string{ + "Cannot index event publisher.Event", + "(panic|runtime error)", + }, } type runner struct { @@ -965,9 +967,12 @@ func (r *runner) anyErrorMessages(profile *profile.Profile, serviceName string) } var multiErr multierror.Error - for _, log := range logs { - for _, pattern := range errorPatterns[serviceName] { - if strings.Contains(log.Message, pattern) { + + for _, pattern := range errorPatterns[serviceName] { + r := regexp.MustCompile(pattern) + + for _, log := range logs { + if r.MatchString(log.Message) { multiErr = append(multiErr, fmt.Errorf("service %s raised this error %q", serviceName, log.Message)) } } From 9e6d45ec778b98faa1e016bb89f32915f8481253 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Wed, 10 May 2023 11:42:23 +0200 Subject: [PATCH 09/26] Comments from code review Do not store all the messages of docker-compose logs in memory, they are now processed with a function passed as a parameter. Removed unnecessary variables. --- .../stack/{parse_logs.go => parselogs.go} | 29 ++++++++--- internal/testrunner/runners/system/runner.go | 50 +++++++++---------- 2 files changed, 46 insertions(+), 33 deletions(-) rename internal/stack/{parse_logs.go => parselogs.go} (69%) diff --git a/internal/stack/parse_logs.go b/internal/stack/parselogs.go similarity index 69% rename from internal/stack/parse_logs.go rename to internal/stack/parselogs.go index 38b4347d73..5d6365e22f 100644 --- a/internal/stack/parse_logs.go +++ b/internal/stack/parselogs.go @@ -13,16 +13,17 @@ import ( "strings" "time" + "github.com/elastic/elastic-package/internal/logger" "github.com/elastic/elastic-package/internal/profile" ) type ParseLogsOptions struct { ServiceName string + StartTime time.Time LogsPath string Profile *profile.Profile } -type DockerComposeLogs []LogLine type LogLine struct { LogLevel string `json:"log.lovel"` Timestamp time.Time `json:"@timestamp"` @@ -30,11 +31,11 @@ type LogLine struct { } // ParseLogs returns all the logs for a given service name -func ParseLogs(options ParseLogsOptions) (DockerComposeLogs, error) { +func ParseLogs(options ParseLogsOptions, process func(log LogLine) error) error { // create dump outputPath, err := Dump(DumpOptions{Output: options.LogsPath, Profile: options.Profile}) if err != nil { - return nil, err + return err } // TODO: should we parse files of internal logs (elastic-agent and fleet-server)? @@ -42,11 +43,12 @@ func ParseLogs(options ParseLogsOptions) (DockerComposeLogs, error) { file, err := os.Open(serviceLogs) if err != nil { - return nil, err + return err } defer file.Close() - var logs DockerComposeLogs + startProcessing := false + scanner := bufio.NewScanner(file) for scanner.Scan() { line := scanner.Text() @@ -54,7 +56,7 @@ func ParseLogs(options ParseLogsOptions) (DockerComposeLogs, error) { messageSlice := strings.SplitN(line, "|", 2) if len(messageSlice) != 2 { - return nil, fmt.Errorf("malformed docker-compose log line") + return fmt.Errorf("malformed docker-compose log line") } messageLog := messageSlice[1] @@ -66,8 +68,19 @@ func ParseLogs(options ParseLogsOptions) (DockerComposeLogs, error) { log.Message = strings.TrimSpace(messageLog) } - logs = append(logs, log) + // There could be valid messages with just plain text without timestamp + if !startProcessing && log.Timestamp.Before(options.StartTime) { + logger.Debugf("found old message (%s): %s", options.StartTime, log) + continue + } + startProcessing = true + + logger.Debugf("processing (%s): %s", options.StartTime, log) + err = process(log) + if err != nil { + return err + } } - return logs, nil + return nil } diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index e63c7a11e5..add16c67e8 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -24,7 +24,6 @@ import ( "github.com/elastic/elastic-package/internal/logger" "github.com/elastic/elastic-package/internal/multierror" "github.com/elastic/elastic-package/internal/packages" - "github.com/elastic/elastic-package/internal/profile" "github.com/elastic/elastic-package/internal/signal" "github.com/elastic/elastic-package/internal/stack" "github.com/elastic/elastic-package/internal/testrunner" @@ -54,10 +53,10 @@ const ( waitForDataDefaultTimeout = 10 * time.Minute ) -var errorPatterns = map[string][]string{ - "elastic-agent": []string{ - "Cannot index event publisher.Event", - "(panic|runtime error)", +var errorPatterns = map[string][]*regexp.Regexp{ + "elastic-agent": []*regexp.Regexp{ + regexp.MustCompile("Cannot index event publisher.Event"), + regexp.MustCompile("(panic|runtime error)"), }, } @@ -183,6 +182,7 @@ func (r *runner) run() (results []testrunner.TestResult, err error) { return result.WithError(errors.Wrap(err, "can't read service variant")) } + startTesting := time.Now() for _, cfgFile := range cfgFiles { for _, variantName := range r.selectVariants(variantsFile) { partial, err := r.runTestPerVariant(result, locationManager, cfgFile, dataStreamPath, variantName) @@ -195,7 +195,13 @@ func (r *runner) run() (results []testrunner.TestResult, err error) { // check agent logs startTime := time.Now() - err = r.anyErrorMessages(r.options.Profile, "elastic-agent") + serviceName := "elastic-agent" + if _, found := errorPatterns[serviceName]; !found { + logger.Debugf("No error patterns defined for ", serviceName) + return results, nil + } + + err = r.anyErrorMessages(serviceName, startTesting, errorPatterns[serviceName]) if e, ok := err.(testrunner.ErrTestCaseFailed); ok { tr := testrunner.TestResult{ TestType: TestType, @@ -945,38 +951,32 @@ func (r *runner) generateTestResult(docs []common.MapStr) error { return nil } -func (r *runner) anyErrorMessages(profile *profile.Profile, serviceName string) error { - if _, found := errorPatterns[serviceName]; !found { - logger.Debugf("No error patterns defined for %s", serviceName) - return nil - } - +func (r *runner) anyErrorMessages(serviceName string, startTime time.Time, errorPatterns []*regexp.Regexp) error { tempDir, err := os.MkdirTemp("", "test-system-") if err != nil { return err } defer os.RemoveAll(tempDir) - logs, err := stack.ParseLogs(stack.ParseLogsOptions{ + var multiErr multierror.Error + processLog := func(log stack.LogLine) error { + for _, pattern := range errorPatterns { + if pattern.MatchString(log.Message) { + multiErr = append(multiErr, fmt.Errorf("found error %q", log.Message)) + } + } + return nil + } + err = stack.ParseLogs(stack.ParseLogsOptions{ ServiceName: serviceName, + StartTime: startTime, Profile: r.options.Profile, LogsPath: tempDir, - }) + }, processLog) if err != nil { return err } - var multiErr multierror.Error - - for _, pattern := range errorPatterns[serviceName] { - r := regexp.MustCompile(pattern) - - for _, log := range logs { - if r.MatchString(log.Message) { - multiErr = append(multiErr, fmt.Errorf("service %s raised this error %q", serviceName, log.Message)) - } - } - } if len(multiErr) > 0 { multiErr = multiErr.Unique() return testrunner.ErrTestCaseFailed{ From 49069bdb0df822440c9ba6daa02e153070a28c8b Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Wed, 10 May 2023 11:52:18 +0200 Subject: [PATCH 10/26] Move helpers to internal/cobraext --- cmd/profiles.go | 56 ----------------------------- internal/cobraext/profiles.go | 67 +++++++++++++++++++++++++++++++++++ 2 files changed, 67 insertions(+), 56 deletions(-) create mode 100644 internal/cobraext/profiles.go diff --git a/cmd/profiles.go b/cmd/profiles.go index b372752139..7b519c0f85 100644 --- a/cmd/profiles.go +++ b/cmd/profiles.go @@ -8,7 +8,6 @@ import ( "encoding/json" "fmt" "os" - "strings" "time" "github.com/olekukonko/tablewriter" @@ -19,7 +18,6 @@ import ( "github.com/elastic/elastic-package/internal/configuration/locations" "github.com/elastic/elastic-package/internal/install" "github.com/elastic/elastic-package/internal/profile" - "github.com/elastic/elastic-package/internal/stack" ) // jsonFormat is the format for JSON output @@ -237,57 +235,3 @@ func availableProfilesAsAList() ([]string, error) { return profileNames, nil } - -func getProfileFlag(cmd *cobra.Command) (*profile.Profile, error) { - profileName, err := cmd.Flags().GetString(cobraext.ProfileFlagName) - if err != nil { - return nil, cobraext.FlagParsingError(err, cobraext.ProfileFlagName) - } - if profileName == "" { - config, err := install.Configuration() - if err != nil { - return nil, fmt.Errorf("cannot read configuration: %w", err) - } - profileName = config.CurrentProfile() - } - - p, err := profile.LoadProfile(profileName) - if errors.Is(err, profile.ErrNotAProfile) { - list, err := availableProfilesAsAList() - if err != nil { - return nil, errors.Wrap(err, "error listing known profiles") - } - if len(list) == 0 { - return nil, fmt.Errorf("%s is not a valid profile", profileName) - } - return nil, fmt.Errorf("%s is not a valid profile, known profiles are: %s", profileName, strings.Join(list, ", ")) - } - if err != nil { - return nil, errors.Wrap(err, "error loading profile") - } - - return p, nil -} - -func getProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkFlag bool) (stack.Provider, error) { - var providerName = stack.DefaultProvider - stackConfig, err := stack.LoadConfig(profile) - if err != nil { - return nil, err - } - if stackConfig.Provider != "" { - providerName = stackConfig.Provider - } - - if checkFlag { - providerFlag, err := cmd.Flags().GetString(cobraext.StackProviderFlagName) - if err != nil { - return nil, cobraext.FlagParsingError(err, cobraext.StackProviderFlagName) - } - if providerFlag != "" { - providerName = providerFlag - } - } - - return stack.BuildProvider(providerName, profile) -} diff --git a/internal/cobraext/profiles.go b/internal/cobraext/profiles.go new file mode 100644 index 0000000000..39c187c6cf --- /dev/null +++ b/internal/cobraext/profiles.go @@ -0,0 +1,67 @@ +package cobraext + +import ( + "fmt" + "strings" + + "github.com/pkg/errors" + "github.com/spf13/cobra" + + "github.com/elastic/elastic-package/internal/install" + "github.com/elastic/elastic-package/internal/profile" + "github.com/elastic/elastic-package/internal/stack" +) + +func getProfileFlag(cmd *cobra.Command) (*profile.Profile, error) { + profileName, err := cmd.Flags().GetString(cobraext.ProfileFlagName) + if err != nil { + return nil, cobraext.FlagParsingError(err, cobraext.ProfileFlagName) + } + if profileName == "" { + config, err := install.Configuration() + if err != nil { + return nil, fmt.Errorf("cannot read configuration: %w", err) + } + profileName = config.CurrentProfile() + } + + p, err := profile.LoadProfile(profileName) + if errors.Is(err, profile.ErrNotAProfile) { + list, err := availableProfilesAsAList() + if err != nil { + return nil, errors.Wrap(err, "error listing known profiles") + } + if len(list) == 0 { + return nil, fmt.Errorf("%s is not a valid profile", profileName) + } + return nil, fmt.Errorf("%s is not a valid profile, known profiles are: %s", profileName, strings.Join(list, ", ")) + } + if err != nil { + return nil, errors.Wrap(err, "error loading profile") + } + + return p, nil +} + +func getProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkFlag bool) (stack.Provider, error) { + var providerName = stack.DefaultProvider + stackConfig, err := stack.LoadConfig(profile) + if err != nil { + return nil, err + } + if stackConfig.Provider != "" { + providerName = stackConfig.Provider + } + + if checkFlag { + providerFlag, err := cmd.Flags().GetString(cobraext.StackProviderFlagName) + if err != nil { + return nil, cobraext.FlagParsingError(err, cobraext.StackProviderFlagName) + } + if providerFlag != "" { + providerName = providerFlag + } + } + + return stack.BuildProvider(providerName, profile) +} From 2c8e538baa830f7a22c4c5ddede43f9650518cf3 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Wed, 10 May 2023 11:54:46 +0200 Subject: [PATCH 11/26] Add missing license header --- internal/cobraext/profiles.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/internal/cobraext/profiles.go b/internal/cobraext/profiles.go index 39c187c6cf..c05f655a11 100644 --- a/internal/cobraext/profiles.go +++ b/internal/cobraext/profiles.go @@ -1,3 +1,7 @@ +// Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one +// or more contributor license agreements. Licensed under the Elastic License; +// you may not use this file except in compliance with the Elastic License. + package cobraext import ( From 8d20ebf64cf7a8963714f7856499dcc797f8e0ea Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Wed, 10 May 2023 11:55:56 +0200 Subject: [PATCH 12/26] Remove debug messages --- internal/stack/parselogs.go | 3 --- 1 file changed, 3 deletions(-) diff --git a/internal/stack/parselogs.go b/internal/stack/parselogs.go index 5d6365e22f..4c4167a5bf 100644 --- a/internal/stack/parselogs.go +++ b/internal/stack/parselogs.go @@ -13,7 +13,6 @@ import ( "strings" "time" - "github.com/elastic/elastic-package/internal/logger" "github.com/elastic/elastic-package/internal/profile" ) @@ -70,12 +69,10 @@ func ParseLogs(options ParseLogsOptions, process func(log LogLine) error) error // There could be valid messages with just plain text without timestamp if !startProcessing && log.Timestamp.Before(options.StartTime) { - logger.Debugf("found old message (%s): %s", options.StartTime, log) continue } startProcessing = true - logger.Debugf("processing (%s): %s", options.StartTime, log) err = process(log) if err != nil { return err From a580527888b0b12cb5700a2e0942a2c42ca95eee Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Wed, 10 May 2023 12:30:59 +0200 Subject: [PATCH 13/26] Fix errors related to helpers --- cmd/profiles.go | 18 ------------------ internal/cobraext/profiles.go | 27 +++++++++++++++++++++++---- 2 files changed, 23 insertions(+), 22 deletions(-) diff --git a/cmd/profiles.go b/cmd/profiles.go index 7b519c0f85..e17bb750ff 100644 --- a/cmd/profiles.go +++ b/cmd/profiles.go @@ -217,21 +217,3 @@ func profileToList(profiles []profile.Metadata) [][]string { return profileList } - -func availableProfilesAsAList() ([]string, error) { - loc, err := locations.NewLocationManager() - if err != nil { - return []string{}, errors.Wrap(err, "error fetching profile path") - } - - profileNames := []string{} - profileList, err := profile.FetchAllProfiles(loc.ProfileDir()) - if err != nil { - return profileNames, errors.Wrap(err, "error fetching all profiles") - } - for _, prof := range profileList { - profileNames = append(profileNames, prof.Name) - } - - return profileNames, nil -} diff --git a/internal/cobraext/profiles.go b/internal/cobraext/profiles.go index c05f655a11..73d10b8e4f 100644 --- a/internal/cobraext/profiles.go +++ b/internal/cobraext/profiles.go @@ -11,15 +11,16 @@ import ( "github.com/pkg/errors" "github.com/spf13/cobra" + "github.com/elastic/elastic-package/internal/configuration/locations" "github.com/elastic/elastic-package/internal/install" "github.com/elastic/elastic-package/internal/profile" "github.com/elastic/elastic-package/internal/stack" ) func getProfileFlag(cmd *cobra.Command) (*profile.Profile, error) { - profileName, err := cmd.Flags().GetString(cobraext.ProfileFlagName) + profileName, err := cmd.Flags().GetString(ProfileFlagName) if err != nil { - return nil, cobraext.FlagParsingError(err, cobraext.ProfileFlagName) + return nil, FlagParsingError(err, ProfileFlagName) } if profileName == "" { config, err := install.Configuration() @@ -47,6 +48,24 @@ func getProfileFlag(cmd *cobra.Command) (*profile.Profile, error) { return p, nil } +func availableProfilesAsAList() ([]string, error) { + loc, err := locations.NewLocationManager() + if err != nil { + return []string{}, errors.Wrap(err, "error fetching profile path") + } + + profileNames := []string{} + profileList, err := profile.FetchAllProfiles(loc.ProfileDir()) + if err != nil { + return profileNames, errors.Wrap(err, "error fetching all profiles") + } + for _, prof := range profileList { + profileNames = append(profileNames, prof.Name) + } + + return profileNames, nil +} + func getProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkFlag bool) (stack.Provider, error) { var providerName = stack.DefaultProvider stackConfig, err := stack.LoadConfig(profile) @@ -58,9 +77,9 @@ func getProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkF } if checkFlag { - providerFlag, err := cmd.Flags().GetString(cobraext.StackProviderFlagName) + providerFlag, err := cmd.Flags().GetString(StackProviderFlagName) if err != nil { - return nil, cobraext.FlagParsingError(err, cobraext.StackProviderFlagName) + return nil, FlagParsingError(err, StackProviderFlagName) } if providerFlag != "" { providerName = providerFlag From 64513fb93541e92fdccf1452c794cea31e1f21b2 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Wed, 10 May 2023 12:42:26 +0200 Subject: [PATCH 14/26] Make public the helpers --- cmd/stack.go | 22 +++++++++++----------- cmd/testrunner.go | 2 +- internal/cobraext/profiles.go | 6 ++++-- 3 files changed, 16 insertions(+), 14 deletions(-) diff --git a/cmd/stack.go b/cmd/stack.go index 3c5d791d1d..dbec07bd05 100644 --- a/cmd/stack.go +++ b/cmd/stack.go @@ -72,12 +72,12 @@ func setupStackCommand() *cobraext.Command { return cobraext.FlagParsingError(err, cobraext.StackVersionFlagName) } - profile, err := getProfileFlag(cmd) + profile, err := cobraext.GetProfileFlag(cmd) if err != nil { return err } - provider, err := getProviderFromProfile(cmd, profile, true) + provider, err := cobraext.GetProviderFromProfile(cmd, profile, true) if err != nil { return err } @@ -111,12 +111,12 @@ func setupStackCommand() *cobraext.Command { RunE: func(cmd *cobra.Command, args []string) error { cmd.Println("Take down the Elastic stack") - profile, err := getProfileFlag(cmd) + profile, err := cobraext.GetProfileFlag(cmd) if err != nil { return err } - provider, err := getProviderFromProfile(cmd, profile, false) + provider, err := cobraext.GetProviderFromProfile(cmd, profile, false) if err != nil { return err } @@ -140,12 +140,12 @@ func setupStackCommand() *cobraext.Command { RunE: func(cmd *cobra.Command, args []string) error { cmd.Println("Update the Elastic stack") - profile, err := getProfileFlag(cmd) + profile, err := cobraext.GetProfileFlag(cmd) if err != nil { return err } - provider, err := getProviderFromProfile(cmd, profile, false) + provider, err := cobraext.GetProviderFromProfile(cmd, profile, false) if err != nil { return err } @@ -183,7 +183,7 @@ func setupStackCommand() *cobraext.Command { fmt.Fprintf(cmd.OutOrStderr(), "Detected shell: %s\n", shellName) } - profile, err := getProfileFlag(cmd) + profile, err := cobraext.GetProfileFlag(cmd) if err != nil { return err } @@ -208,12 +208,12 @@ func setupStackCommand() *cobraext.Command { return cobraext.FlagParsingError(err, cobraext.StackDumpOutputFlagName) } - profile, err := getProfileFlag(cmd) + profile, err := cobraext.GetProfileFlag(cmd) if err != nil { return err } - provider, err := getProviderFromProfile(cmd, profile, false) + provider, err := cobraext.GetProviderFromProfile(cmd, profile, false) if err != nil { return err } @@ -238,12 +238,12 @@ func setupStackCommand() *cobraext.Command { Use: "status", Short: "Show status of the stack services", RunE: func(cmd *cobra.Command, args []string) error { - profile, err := getProfileFlag(cmd) + profile, err := cobraext.GetProfileFlag(cmd) if err != nil { return err } - provider, err := getProviderFromProfile(cmd, profile, false) + provider, err := cobraext.GetProviderFromProfile(cmd, profile, false) if err != nil { return err } diff --git a/cmd/testrunner.go b/cmd/testrunner.go index cba65d7bbf..603f60ba26 100644 --- a/cmd/testrunner.go +++ b/cmd/testrunner.go @@ -209,7 +209,7 @@ func testTypeCommandActionFactory(runner testrunner.TestRunner) cobraext.Command variantFlag, _ := cmd.Flags().GetString(cobraext.VariantFlagName) - profile, err := getProfileFlag(cmd) + profile, err := cobraext.GetProfileFlag(cmd) if err != nil { return err } diff --git a/internal/cobraext/profiles.go b/internal/cobraext/profiles.go index 73d10b8e4f..abf6736378 100644 --- a/internal/cobraext/profiles.go +++ b/internal/cobraext/profiles.go @@ -17,7 +17,8 @@ import ( "github.com/elastic/elastic-package/internal/stack" ) -func getProfileFlag(cmd *cobra.Command) (*profile.Profile, error) { +// GetProfileFlag returns the profile information +func GetProfileFlag(cmd *cobra.Command) (*profile.Profile, error) { profileName, err := cmd.Flags().GetString(ProfileFlagName) if err != nil { return nil, FlagParsingError(err, ProfileFlagName) @@ -66,7 +67,8 @@ func availableProfilesAsAList() ([]string, error) { return profileNames, nil } -func getProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkFlag bool) (stack.Provider, error) { +// GetProviderFromProfile returns the provider related to the given profile +func GetProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkFlag bool) (stack.Provider, error) { var providerName = stack.DefaultProvider stackConfig, err := stack.LoadConfig(profile) if err != nil { From 65784c76e9d4152d95afedb71308e58669ad7ad3 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Wed, 10 May 2023 13:24:17 +0200 Subject: [PATCH 15/26] Use logs file path instead of service name --- internal/stack/dump.go | 5 +++ internal/stack/parselogs.go | 19 +++-------- internal/testrunner/runners/system/runner.go | 33 ++++++++++++-------- 3 files changed, 29 insertions(+), 28 deletions(-) diff --git a/internal/stack/dump.go b/internal/stack/dump.go index abe088a806..116cb03a1b 100644 --- a/internal/stack/dump.go +++ b/internal/stack/dump.go @@ -76,3 +76,8 @@ func writeLogFiles(logsPath, serviceName string, content []byte) { logger.Errorf("can't write service logs (service: %s): %v", serviceName, err) } } + +// DumpLogsFile returns the file path to the logs of a given service +func DumpLogsFile(options DumpOptions, serviceName string) string { + return filepath.Join(options.Output, "logs", fmt.Sprintf("%s.log", serviceName)) +} diff --git a/internal/stack/parselogs.go b/internal/stack/parselogs.go index 4c4167a5bf..e57c05fd01 100644 --- a/internal/stack/parselogs.go +++ b/internal/stack/parselogs.go @@ -9,7 +9,6 @@ import ( "encoding/json" "fmt" "os" - "path/filepath" "strings" "time" @@ -17,10 +16,9 @@ import ( ) type ParseLogsOptions struct { - ServiceName string - StartTime time.Time - LogsPath string - Profile *profile.Profile + LogsFilePath string + StartTime time.Time + Profile *profile.Profile } type LogLine struct { @@ -31,16 +29,7 @@ type LogLine struct { // ParseLogs returns all the logs for a given service name func ParseLogs(options ParseLogsOptions, process func(log LogLine) error) error { - // create dump - outputPath, err := Dump(DumpOptions{Output: options.LogsPath, Profile: options.Profile}) - if err != nil { - return err - } - - // TODO: should we parse files of internal logs (elastic-agent and fleet-server)? - serviceLogs := filepath.Join(outputPath, "logs", fmt.Sprintf("%s.log", options.ServiceName)) - - file, err := os.Open(serviceLogs) + file, err := os.Open(options.LogsFilePath) if err != nil { return err } diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index add16c67e8..bc9e87a342 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -201,7 +201,20 @@ func (r *runner) run() (results []testrunner.TestResult, err error) { return results, nil } - err = r.anyErrorMessages(serviceName, startTesting, errorPatterns[serviceName]) + tempDir, err := os.MkdirTemp("", "test-system-") + if err != nil { + return result.WithError(fmt.Errorf("can't create temporal directory: %w", err)) + } + defer os.RemoveAll(tempDir) + dumpOptions := stack.DumpOptions{Output: tempDir, Profile: r.options.Profile} + _, err = stack.Dump(dumpOptions) + if err != nil { + return result.WithError(fmt.Errorf("dump failed: %w", err)) + } + + serviceLogsFile := stack.DumpLogsFile(dumpOptions, serviceName) + + err = r.anyErrorMessages(serviceLogsFile, startTesting, errorPatterns[serviceName]) if e, ok := err.(testrunner.ErrTestCaseFailed); ok { tr := testrunner.TestResult{ TestType: TestType, @@ -951,12 +964,7 @@ func (r *runner) generateTestResult(docs []common.MapStr) error { return nil } -func (r *runner) anyErrorMessages(serviceName string, startTime time.Time, errorPatterns []*regexp.Regexp) error { - tempDir, err := os.MkdirTemp("", "test-system-") - if err != nil { - return err - } - defer os.RemoveAll(tempDir) +func (r *runner) anyErrorMessages(logsFilePath string, startTime time.Time, errorPatterns []*regexp.Regexp) error { var multiErr multierror.Error processLog := func(log stack.LogLine) error { @@ -967,11 +975,10 @@ func (r *runner) anyErrorMessages(serviceName string, startTime time.Time, error } return nil } - err = stack.ParseLogs(stack.ParseLogsOptions{ - ServiceName: serviceName, - StartTime: startTime, - Profile: r.options.Profile, - LogsPath: tempDir, + err := stack.ParseLogs(stack.ParseLogsOptions{ + LogsFilePath: logsFilePath, + StartTime: startTime, + Profile: r.options.Profile, }, processLog) if err != nil { return err @@ -980,7 +987,7 @@ func (r *runner) anyErrorMessages(serviceName string, startTime time.Time, error if len(multiErr) > 0 { multiErr = multiErr.Unique() return testrunner.ErrTestCaseFailed{ - Reason: fmt.Sprintf("one or more errors found while examining logs from service %s", serviceName), + Reason: fmt.Sprintf("one or more errors found while examining %s logs", filepath.Base(logsFilePath)), Details: multiErr.Error(), } } From 039d67206313699ed9fc3563f8112c6c9634e642 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Wed, 10 May 2023 13:36:31 +0200 Subject: [PATCH 16/26] Comment panic/runtime errors --- internal/testrunner/runners/system/runner.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index bc9e87a342..d945dff9a5 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -56,7 +56,7 @@ const ( var errorPatterns = map[string][]*regexp.Regexp{ "elastic-agent": []*regexp.Regexp{ regexp.MustCompile("Cannot index event publisher.Event"), - regexp.MustCompile("(panic|runtime error)"), + // regexp.MustCompile("(panic|runtime error)"), }, } From 58fb1bd722ac7febd47aeb8b63cbf44805838ab1 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Thu, 11 May 2023 10:24:27 +0200 Subject: [PATCH 17/26] Support check logs from several services --- internal/testrunner/runners/system/runner.go | 52 ++++++++++---------- 1 file changed, 27 insertions(+), 25 deletions(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index d945dff9a5..34445d61f0 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -56,7 +56,6 @@ const ( var errorPatterns = map[string][]*regexp.Regexp{ "elastic-agent": []*regexp.Regexp{ regexp.MustCompile("Cannot index event publisher.Event"), - // regexp.MustCompile("(panic|runtime error)"), }, } @@ -194,43 +193,46 @@ func (r *runner) run() (results []testrunner.TestResult, err error) { } // check agent logs - startTime := time.Now() - serviceName := "elastic-agent" - if _, found := errorPatterns[serviceName]; !found { - logger.Debugf("No error patterns defined for ", serviceName) - return results, nil - } - tempDir, err := os.MkdirTemp("", "test-system-") if err != nil { return result.WithError(fmt.Errorf("can't create temporal directory: %w", err)) } defer os.RemoveAll(tempDir) + dumpOptions := stack.DumpOptions{Output: tempDir, Profile: r.options.Profile} _, err = stack.Dump(dumpOptions) if err != nil { return result.WithError(fmt.Errorf("dump failed: %w", err)) } - serviceLogsFile := stack.DumpLogsFile(dumpOptions, serviceName) + checkServices := []string{"elastic-agent", "package-registry"} + for _, serviceName := range checkServices { + startTime := time.Now() + if _, found := errorPatterns[serviceName]; !found { + logger.Debugf("No error patterns defined for ", serviceName) + return results, nil + } + + serviceLogsFile := stack.DumpLogsFile(dumpOptions, serviceName) - err = r.anyErrorMessages(serviceLogsFile, startTesting, errorPatterns[serviceName]) - if e, ok := err.(testrunner.ErrTestCaseFailed); ok { - tr := testrunner.TestResult{ - TestType: TestType, - Name: "(logs)", - Package: r.options.TestFolder.Package, - DataStream: r.options.TestFolder.DataStream, + err = r.anyErrorMessages(serviceLogsFile, startTesting, errorPatterns[serviceName]) + if e, ok := err.(testrunner.ErrTestCaseFailed); ok { + tr := testrunner.TestResult{ + TestType: TestType, + Name: fmt.Sprintf("(%s logs)", serviceName), + Package: r.options.TestFolder.Package, + DataStream: r.options.TestFolder.DataStream, + } + tr.FailureMsg = e.Error() + tr.FailureDetails = e.Details + tr.TimeElapsed = time.Since(startTime) + results = append(results, tr) + continue } - tr.FailureMsg = e.Error() - tr.FailureDetails = e.Details - tr.TimeElapsed = time.Since(startTime) - results = append(results, tr) - return results, nil - } - if err != nil { - return result.WithError(fmt.Errorf("check log messages failed: %s", err)) + if err != nil { + return result.WithError(fmt.Errorf("check log messages failed: %s", err)) + } } return results, nil @@ -987,7 +989,7 @@ func (r *runner) anyErrorMessages(logsFilePath string, startTime time.Time, erro if len(multiErr) > 0 { multiErr = multiErr.Unique() return testrunner.ErrTestCaseFailed{ - Reason: fmt.Sprintf("one or more errors found while examining %s logs", filepath.Base(logsFilePath)), + Reason: fmt.Sprintf("one or more errors found while examining %s", filepath.Base(logsFilePath)), Details: multiErr.Error(), } } From 4d48fd98e8facc361058b5b82f159d3875e20c43 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Thu, 11 May 2023 10:30:48 +0200 Subject: [PATCH 18/26] Use just errorPatterns to check services --- internal/testrunner/runners/system/runner.go | 28 +++++++++++--------- 1 file changed, 16 insertions(+), 12 deletions(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index 34445d61f0..455fc44d3c 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -53,11 +53,20 @@ const ( waitForDataDefaultTimeout = 10 * time.Minute ) -var errorPatterns = map[string][]*regexp.Regexp{ - "elastic-agent": []*regexp.Regexp{ - regexp.MustCompile("Cannot index event publisher.Event"), - }, -} +var ( + errorPatterns = map[string][]*regexp.Regexp{ + "elastic-agent": []*regexp.Regexp{ + regexp.MustCompile("Cannot index event publisher.Event"), + regexp.MustCompile("New State ID"), + }, + "fleet-server": []*regexp.Regexp{ + regexp.MustCompile("New State ID"), + }, + "package-registry": []*regexp.Regexp{ + regexp.MustCompile("GET"), + }, + } +) type runner struct { options testrunner.TestOptions @@ -205,17 +214,12 @@ func (r *runner) run() (results []testrunner.TestResult, err error) { return result.WithError(fmt.Errorf("dump failed: %w", err)) } - checkServices := []string{"elastic-agent", "package-registry"} - for _, serviceName := range checkServices { + for serviceName, patterns := range errorPatterns { startTime := time.Now() - if _, found := errorPatterns[serviceName]; !found { - logger.Debugf("No error patterns defined for ", serviceName) - return results, nil - } serviceLogsFile := stack.DumpLogsFile(dumpOptions, serviceName) - err = r.anyErrorMessages(serviceLogsFile, startTesting, errorPatterns[serviceName]) + err = r.anyErrorMessages(serviceLogsFile, startTesting, patterns) if e, ok := err.(testrunner.ErrTestCaseFailed); ok { tr := testrunner.TestResult{ TestType: TestType, From 1ffcafac80649437ba03beef6da794557babb0a7 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Thu, 11 May 2023 10:45:20 +0200 Subject: [PATCH 19/26] Remove debug patterns --- internal/testrunner/runners/system/runner.go | 7 ------- 1 file changed, 7 deletions(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index 455fc44d3c..4d65f064c8 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -57,13 +57,6 @@ var ( errorPatterns = map[string][]*regexp.Regexp{ "elastic-agent": []*regexp.Regexp{ regexp.MustCompile("Cannot index event publisher.Event"), - regexp.MustCompile("New State ID"), - }, - "fleet-server": []*regexp.Regexp{ - regexp.MustCompile("New State ID"), - }, - "package-registry": []*regexp.Regexp{ - regexp.MustCompile("GET"), }, } ) From d5f338b8bb300cb49fb99c9754ca64e7a1371956 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Thu, 11 May 2023 12:26:16 +0200 Subject: [PATCH 20/26] Add a new regex for elastic-agent --- internal/testrunner/runners/system/runner.go | 1 + 1 file changed, 1 insertion(+) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index 4d65f064c8..ef1f950ae5 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -57,6 +57,7 @@ var ( errorPatterns = map[string][]*regexp.Regexp{ "elastic-agent": []*regexp.Regexp{ regexp.MustCompile("Cannot index event publisher.Event"), + regexp.MustCompile("->(FAILED|DEGRADED)"), }, } ) From 4e8b885e1e1821560b22c855bb55bc2292ea54c6 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Mon, 15 May 2023 17:58:06 +0200 Subject: [PATCH 21/26] Add includes and excludes regex --- internal/testrunner/runners/system/runner.go | 51 +++++++++++++++++--- 1 file changed, 44 insertions(+), 7 deletions(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index ef1f950ae5..73da289478 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -53,11 +53,36 @@ const ( waitForDataDefaultTimeout = 10 * time.Minute ) +type logsRegexp struct { + includes *regexp.Regexp + excludes []*regexp.Regexp +} + var ( - errorPatterns = map[string][]*regexp.Regexp{ - "elastic-agent": []*regexp.Regexp{ - regexp.MustCompile("Cannot index event publisher.Event"), - regexp.MustCompile("->(FAILED|DEGRADED)"), + errorPatterns = map[string][]logsRegexp{ + "elastic-agent": []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile("^Cannot index event publisher.Event"), + excludes: []*regexp.Regexp{ + // this regex is excluded to ensure that logs coming from the `system` package installed by default are not taken into account + regexp.MustCompile(`action \[indices:data\/write\/bulk\[s\]\] is unauthorized for API key id \[.*\] of user \[.*\] on indices \[.*\], this action is granted by the index privileges \[.*\]`), + }, + }, + // logsRegexp{ + // includes: regexp.MustCompile("New State ID"), + // excludes: []*regexp.Regexp{ + // regexp.MustCompile("is unahorized API key id"), + // }, + // }, + // logsRegexp{ + // includes: regexp.MustCompile("->HEALTHY"), + // excludes: []*regexp.Regexp{ + // regexp.MustCompile(`Healthy$`), + // }, + // }, + logsRegexp{ + includes: regexp.MustCompile("->(FAILED|DEGRADED)"), + }, }, } ) @@ -964,14 +989,26 @@ func (r *runner) generateTestResult(docs []common.MapStr) error { return nil } -func (r *runner) anyErrorMessages(logsFilePath string, startTime time.Time, errorPatterns []*regexp.Regexp) error { +func (r *runner) anyErrorMessages(logsFilePath string, startTime time.Time, errorPatterns []logsRegexp) error { var multiErr multierror.Error processLog := func(log stack.LogLine) error { for _, pattern := range errorPatterns { - if pattern.MatchString(log.Message) { - multiErr = append(multiErr, fmt.Errorf("found error %q", log.Message)) + if !pattern.includes.MatchString(log.Message) { + continue } + isExcluded := false + for _, excludes := range pattern.excludes { + if excludes.MatchString(log.Message) { + isExcluded = true + break + } + } + if isExcluded { + continue + } + + multiErr = append(multiErr, fmt.Errorf("found error %q", log.Message)) } return nil } From 5e915586205b4aba8c2124bedd11d293c0665dde Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 16 May 2023 11:47:22 +0200 Subject: [PATCH 22/26] Rename function --- cmd/stack.go | 10 +++++----- internal/cobraext/profiles.go | 4 ++-- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/cmd/stack.go b/cmd/stack.go index dbec07bd05..03e20bc55d 100644 --- a/cmd/stack.go +++ b/cmd/stack.go @@ -77,7 +77,7 @@ func setupStackCommand() *cobraext.Command { return err } - provider, err := cobraext.GetProviderFromProfile(cmd, profile, true) + provider, err := cobraext.GetStackProviderFromProfile(cmd, profile, true) if err != nil { return err } @@ -116,7 +116,7 @@ func setupStackCommand() *cobraext.Command { return err } - provider, err := cobraext.GetProviderFromProfile(cmd, profile, false) + provider, err := cobraext.GetStackProviderFromProfile(cmd, profile, false) if err != nil { return err } @@ -145,7 +145,7 @@ func setupStackCommand() *cobraext.Command { return err } - provider, err := cobraext.GetProviderFromProfile(cmd, profile, false) + provider, err := cobraext.GetStackProviderFromProfile(cmd, profile, false) if err != nil { return err } @@ -213,7 +213,7 @@ func setupStackCommand() *cobraext.Command { return err } - provider, err := cobraext.GetProviderFromProfile(cmd, profile, false) + provider, err := cobraext.GetStackProviderFromProfile(cmd, profile, false) if err != nil { return err } @@ -243,7 +243,7 @@ func setupStackCommand() *cobraext.Command { return err } - provider, err := cobraext.GetProviderFromProfile(cmd, profile, false) + provider, err := cobraext.GetStackProviderFromProfile(cmd, profile, false) if err != nil { return err } diff --git a/internal/cobraext/profiles.go b/internal/cobraext/profiles.go index abf6736378..968631243e 100644 --- a/internal/cobraext/profiles.go +++ b/internal/cobraext/profiles.go @@ -67,8 +67,8 @@ func availableProfilesAsAList() ([]string, error) { return profileNames, nil } -// GetProviderFromProfile returns the provider related to the given profile -func GetProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkFlag bool) (stack.Provider, error) { +// GetStackProviderFromProfile returns the provider related to the given profile +func GetStackProviderFromProfile(cmd *cobra.Command, profile *profile.Profile, checkFlag bool) (stack.Provider, error) { var providerName = stack.DefaultProvider stackConfig, err := stack.LoadConfig(profile) if err != nil { From acfe286feb465582b450eca047d77508d6cf797f Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 16 May 2023 15:19:40 +0200 Subject: [PATCH 23/26] Add test for checkAgentLogs --- internal/stack/parselogs.go | 3 - internal/testrunner/runners/system/runner.go | 91 +++++---- .../testrunner/runners/system/runner_test.go | 190 ++++++++++++++++++ 3 files changed, 242 insertions(+), 42 deletions(-) diff --git a/internal/stack/parselogs.go b/internal/stack/parselogs.go index e57c05fd01..6b8557e2f0 100644 --- a/internal/stack/parselogs.go +++ b/internal/stack/parselogs.go @@ -11,14 +11,11 @@ import ( "os" "strings" "time" - - "github.com/elastic/elastic-package/internal/profile" ) type ParseLogsOptions struct { LogsFilePath string StartTime time.Time - Profile *profile.Profile } type LogLine struct { diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index 73da289478..fa5bd2b730 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -58,6 +58,11 @@ type logsRegexp struct { excludes []*regexp.Regexp } +type logsByContainer struct { + containerName string + logsRegexp []logsRegexp +} + var ( errorPatterns = map[string][]logsRegexp{ "elastic-agent": []logsRegexp{ @@ -68,18 +73,18 @@ var ( regexp.MustCompile(`action \[indices:data\/write\/bulk\[s\]\] is unauthorized for API key id \[.*\] of user \[.*\] on indices \[.*\], this action is granted by the index privileges \[.*\]`), }, }, - // logsRegexp{ - // includes: regexp.MustCompile("New State ID"), - // excludes: []*regexp.Regexp{ - // regexp.MustCompile("is unahorized API key id"), - // }, - // }, - // logsRegexp{ - // includes: regexp.MustCompile("->HEALTHY"), - // excludes: []*regexp.Regexp{ - // regexp.MustCompile(`Healthy$`), - // }, - // }, + logsRegexp{ + includes: regexp.MustCompile("New State ID"), + excludes: []*regexp.Regexp{ + regexp.MustCompile("is unahorized API key id"), + }, + }, + logsRegexp{ + includes: regexp.MustCompile("->HEALTHY"), + excludes: []*regexp.Regexp{ + regexp.MustCompile(`Healthy$`), + }, + }, logsRegexp{ includes: regexp.MustCompile("->(FAILED|DEGRADED)"), }, @@ -220,43 +225,23 @@ func (r *runner) run() (results []testrunner.TestResult, err error) { } } - // check agent logs tempDir, err := os.MkdirTemp("", "test-system-") if err != nil { - return result.WithError(fmt.Errorf("can't create temporal directory: %w", err)) + return nil, fmt.Errorf("can't create temporal directory: %w", err) } defer os.RemoveAll(tempDir) dumpOptions := stack.DumpOptions{Output: tempDir, Profile: r.options.Profile} _, err = stack.Dump(dumpOptions) if err != nil { - return result.WithError(fmt.Errorf("dump failed: %w", err)) + return nil, fmt.Errorf("dump failed: %w", err) } - for serviceName, patterns := range errorPatterns { - startTime := time.Now() - - serviceLogsFile := stack.DumpLogsFile(dumpOptions, serviceName) - - err = r.anyErrorMessages(serviceLogsFile, startTesting, patterns) - if e, ok := err.(testrunner.ErrTestCaseFailed); ok { - tr := testrunner.TestResult{ - TestType: TestType, - Name: fmt.Sprintf("(%s logs)", serviceName), - Package: r.options.TestFolder.Package, - DataStream: r.options.TestFolder.DataStream, - } - tr.FailureMsg = e.Error() - tr.FailureDetails = e.Details - tr.TimeElapsed = time.Since(startTime) - results = append(results, tr) - continue - } - - if err != nil { - return result.WithError(fmt.Errorf("check log messages failed: %s", err)) - } + logResults, err := r.checkAgentLogs(dumpOptions, startTesting, errorPatterns) + if err != nil { + return result.WithError(err) } + results = append(results, logResults...) return results, nil } @@ -989,6 +974,35 @@ func (r *runner) generateTestResult(docs []common.MapStr) error { return nil } +func (r *runner) checkAgentLogs(dumpOptions stack.DumpOptions, startTesting time.Time, errorPatterns map[string][]logsRegexp) (results []testrunner.TestResult, err error) { + + for serviceName, patterns := range errorPatterns { + startTime := time.Now() + + serviceLogsFile := stack.DumpLogsFile(dumpOptions, serviceName) + + err = r.anyErrorMessages(serviceLogsFile, startTesting, patterns) + if e, ok := err.(testrunner.ErrTestCaseFailed); ok { + tr := testrunner.TestResult{ + TestType: TestType, + Name: fmt.Sprintf("(%s logs)", serviceName), + Package: r.options.TestFolder.Package, + DataStream: r.options.TestFolder.DataStream, + } + tr.FailureMsg = e.Error() + tr.FailureDetails = e.Details + tr.TimeElapsed = time.Since(startTime) + results = append(results, tr) + continue + } + + if err != nil { + return nil, fmt.Errorf("check log messages failed: %s", err) + } + } + return results, nil +} + func (r *runner) anyErrorMessages(logsFilePath string, startTime time.Time, errorPatterns []logsRegexp) error { var multiErr multierror.Error @@ -1015,7 +1029,6 @@ func (r *runner) anyErrorMessages(logsFilePath string, startTime time.Time, erro err := stack.ParseLogs(stack.ParseLogsOptions{ LogsFilePath: logsFilePath, StartTime: startTime, - Profile: r.options.Profile, }, processLog) if err != nil { return err diff --git a/internal/testrunner/runners/system/runner_test.go b/internal/testrunner/runners/system/runner_test.go index ab187ca890..f3da8a7925 100644 --- a/internal/testrunner/runners/system/runner_test.go +++ b/internal/testrunner/runners/system/runner_test.go @@ -5,12 +5,20 @@ package system import ( + "fmt" + "os" + "path/filepath" + "regexp" + "strings" "testing" + "time" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "github.com/elastic/elastic-package/internal/packages" + "github.com/elastic/elastic-package/internal/stack" + "github.com/elastic/elastic-package/internal/testrunner" ) func TestFindPolicyTemplateForInput(t *testing.T) { @@ -158,3 +166,185 @@ func TestFindPolicyTemplateForInput(t *testing.T) { }) } } + +func TestCheckAgentLogs(t *testing.T) { + var testCases = []struct { + testName string + startingTime string + errorPatterns map[string][]logsRegexp + sampleLogs map[string][]string + expectedErrors int + expectedMessage []string + expectedDetails []string + }{ + { + testName: "all logs found", + startingTime: "2023-05-15T12:00:00.000Z", + errorPatterns: map[string][]logsRegexp{ + "service": []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*"), + }, + }, + }, + sampleLogs: map[string][]string{ + "service": []string{ + `service_1 | {"@timestamp": "2023-05-15T13:00:00.000Z", "message": "something"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:01.000Z", "message": "foo"}`, + }, + }, + expectedErrors: 1, + expectedMessage: []string{ + "test case failed: one or more errors found while examining service.log", + }, + expectedDetails: []string{ + "[0] found error \"foo\"\n[1] found error \"something\"", + }, + }, + { + testName: "skipped logs because starting time", + startingTime: "2023-05-15T13:00:02.000Z", + errorPatterns: map[string][]logsRegexp{ + "service": []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*"), + }, + }, + }, + sampleLogs: map[string][]string{ + "service": []string{ + `service_1 | {"@timestamp": "2023-05-15T13:00:00.000Z", "message": "something"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:05.000Z", "message": "foo"}`, + }, + }, + expectedErrors: 1, + expectedMessage: []string{"test case failed: one or more errors found while examining service.log"}, + expectedDetails: []string{"[0] found error \"foo\""}, + }, + { + testName: "no logs found because starting time", + startingTime: "2023-05-15T14:00:00.000Z", + errorPatterns: map[string][]logsRegexp{ + "service": []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*"), + }, + }, + }, + sampleLogs: map[string][]string{ + "service": []string{ + `service_1 | {"@timestamp": "2023-05-15T13:00:00.000Z", "message": "something"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:05.000Z", "message": "foo"}`, + }, + }, + expectedErrors: 0, + }, + { + testName: "filter logs by regex", + startingTime: "2023-05-15T12:00:00.000Z", + errorPatterns: map[string][]logsRegexp{ + "service": []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*thing$"), + }, + }, + }, + sampleLogs: map[string][]string{ + "service": []string{ + `service_1 | {"@timestamp": "2023-05-15T13:00:00.000Z", "message": "initial"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:02.000Z", "message": "something"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:05.000Z", "message": "foo"}`, + }, + }, + expectedErrors: 1, + expectedMessage: []string{"test case failed: one or more errors found while examining service.log"}, + expectedDetails: []string{"[0] found error \"something\""}, + }, + { + testName: "erros found in two services - filtered", + startingTime: "2023-05-15T13:00:01.000Z", + errorPatterns: map[string][]logsRegexp{ + "service": []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*thing$"), + }, + }, + "external": []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(" other "), + }, + }, + }, + sampleLogs: map[string][]string{ + "service": []string{ + `service_1 | {"@timestamp": "2023-05-15T13:00:00.000Z", "message": "service: initial"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:02.000Z", "message": "service: something"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:05.000Z", "message": "service: foo"}`, + }, + "external": []string{ + `external_1 | {"@timestamp": "2023-05-15T13:00:00.000Z", "message": "external: initial"}`, + `external_1 | {"@timestamp": "2023-05-15T13:00:05.000Z", "message": "external: foo"}`, + `external_1 | {"@timestamp": "2023-05-15T13:00:08.000Z", "message": "external: any other thing"}`, + }, + }, + expectedErrors: 2, + expectedMessage: []string{ + "test case failed: one or more errors found while examining service.log", + "test case failed: one or more errors found while examining external.log", + }, + expectedDetails: []string{ + "[0] found error \"service: something\"", + "[0] found error \"external: any other thing\"", + }, + }, + } + + for _, tc := range testCases { + t.Run(tc.testName, func(t *testing.T) { + logsDirTemp := t.TempDir() + + startTime, err := time.Parse(time.RFC3339, tc.startingTime) + require.NoError(t, err) + + err = os.MkdirAll(filepath.Join(logsDirTemp, "logs"), 0755) + require.NoError(t, err) + + for service, logs := range tc.sampleLogs { + logsFile := filepath.Join(logsDirTemp, "logs", fmt.Sprintf("%s.log", service)) + file, err := os.Create(logsFile) + require.NoError(t, err) + + _, err = file.WriteString(strings.Join(logs, "\n")) + require.NoError(t, err) + file.Close() + } + + runner := runner{ + options: testrunner.TestOptions{ + TestFolder: testrunner.TestFolder{ + Package: "package", + DataStream: "datastream", + }, + }, + } + + dumpOptions := stack.DumpOptions{ + Output: logsDirTemp, + } + results, err := runner.checkAgentLogs(dumpOptions, startTime, tc.errorPatterns) + require.NoError(t, err) + + require.Len(t, results, tc.expectedErrors) + + if tc.expectedErrors == 0 { + assert.Nil(t, results) + return + } + + for i := 0; i < tc.expectedErrors; i++ { + assert.Contains(t, tc.expectedMessage, results[i].FailureMsg) + assert.Contains(t, tc.expectedDetails, results[i].FailureDetails) + } + }) + } +} From e483b4ff3ead95c3c0551679a9fa11d4c83a9659 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 16 May 2023 15:49:28 +0200 Subject: [PATCH 24/26] Change struct to ensure same order for logs found --- internal/testrunner/runners/system/runner.go | 57 ++++++------- .../testrunner/runners/system/runner_test.go | 82 +++++++++++-------- 2 files changed, 79 insertions(+), 60 deletions(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index fa5bd2b730..ea6f05ae81 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -60,33 +60,36 @@ type logsRegexp struct { type logsByContainer struct { containerName string - logsRegexp []logsRegexp + patterns []logsRegexp } var ( - errorPatterns = map[string][]logsRegexp{ - "elastic-agent": []logsRegexp{ - logsRegexp{ - includes: regexp.MustCompile("^Cannot index event publisher.Event"), - excludes: []*regexp.Regexp{ - // this regex is excluded to ensure that logs coming from the `system` package installed by default are not taken into account - regexp.MustCompile(`action \[indices:data\/write\/bulk\[s\]\] is unauthorized for API key id \[.*\] of user \[.*\] on indices \[.*\], this action is granted by the index privileges \[.*\]`), + errorPatterns = []logsByContainer{ + logsByContainer{ + containerName: "elastic-agent", + patterns: []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile("^Cannot index event publisher.Event"), + excludes: []*regexp.Regexp{ + // this regex is excluded to ensure that logs coming from the `system` package installed by default are not taken into account + regexp.MustCompile(`action \[indices:data\/write\/bulk\[s\]\] is unauthorized for API key id \[.*\] of user \[.*\] on indices \[.*\], this action is granted by the index privileges \[.*\]`), + }, }, - }, - logsRegexp{ - includes: regexp.MustCompile("New State ID"), - excludes: []*regexp.Regexp{ - regexp.MustCompile("is unahorized API key id"), + logsRegexp{ + includes: regexp.MustCompile("New State ID"), + excludes: []*regexp.Regexp{ + regexp.MustCompile("is unahorized API key id"), + }, }, - }, - logsRegexp{ - includes: regexp.MustCompile("->HEALTHY"), - excludes: []*regexp.Regexp{ - regexp.MustCompile(`Healthy$`), + logsRegexp{ + includes: regexp.MustCompile("->HEALTHY"), + excludes: []*regexp.Regexp{ + regexp.MustCompile(`Healthy$`), + }, + }, + logsRegexp{ + includes: regexp.MustCompile("->(FAILED|DEGRADED)"), }, - }, - logsRegexp{ - includes: regexp.MustCompile("->(FAILED|DEGRADED)"), }, }, } @@ -974,18 +977,18 @@ func (r *runner) generateTestResult(docs []common.MapStr) error { return nil } -func (r *runner) checkAgentLogs(dumpOptions stack.DumpOptions, startTesting time.Time, errorPatterns map[string][]logsRegexp) (results []testrunner.TestResult, err error) { +func (r *runner) checkAgentLogs(dumpOptions stack.DumpOptions, startTesting time.Time, errorPatterns []logsByContainer) (results []testrunner.TestResult, err error) { - for serviceName, patterns := range errorPatterns { + for _, patternsContainer := range errorPatterns { startTime := time.Now() - serviceLogsFile := stack.DumpLogsFile(dumpOptions, serviceName) + serviceLogsFile := stack.DumpLogsFile(dumpOptions, patternsContainer.containerName) - err = r.anyErrorMessages(serviceLogsFile, startTesting, patterns) + err = r.anyErrorMessages(serviceLogsFile, startTesting, patternsContainer.patterns) if e, ok := err.(testrunner.ErrTestCaseFailed); ok { tr := testrunner.TestResult{ TestType: TestType, - Name: fmt.Sprintf("(%s logs)", serviceName), + Name: fmt.Sprintf("(%s logs)", patternsContainer.containerName), Package: r.options.TestFolder.Package, DataStream: r.options.TestFolder.DataStream, } @@ -1004,7 +1007,6 @@ func (r *runner) checkAgentLogs(dumpOptions stack.DumpOptions, startTesting time } func (r *runner) anyErrorMessages(logsFilePath string, startTime time.Time, errorPatterns []logsRegexp) error { - var multiErr multierror.Error processLog := func(log stack.LogLine) error { for _, pattern := range errorPatterns { @@ -1035,7 +1037,6 @@ func (r *runner) anyErrorMessages(logsFilePath string, startTime time.Time, erro } if len(multiErr) > 0 { - multiErr = multiErr.Unique() return testrunner.ErrTestCaseFailed{ Reason: fmt.Sprintf("one or more errors found while examining %s", filepath.Base(logsFilePath)), Details: multiErr.Error(), diff --git a/internal/testrunner/runners/system/runner_test.go b/internal/testrunner/runners/system/runner_test.go index f3da8a7925..36cc3c0929 100644 --- a/internal/testrunner/runners/system/runner_test.go +++ b/internal/testrunner/runners/system/runner_test.go @@ -171,7 +171,7 @@ func TestCheckAgentLogs(t *testing.T) { var testCases = []struct { testName string startingTime string - errorPatterns map[string][]logsRegexp + errorPatterns []logsByContainer sampleLogs map[string][]string expectedErrors int expectedMessage []string @@ -180,10 +180,13 @@ func TestCheckAgentLogs(t *testing.T) { { testName: "all logs found", startingTime: "2023-05-15T12:00:00.000Z", - errorPatterns: map[string][]logsRegexp{ - "service": []logsRegexp{ - logsRegexp{ - includes: regexp.MustCompile(".*"), + errorPatterns: []logsByContainer{ + logsByContainer{ + containerName: "service", + patterns: []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*"), + }, }, }, }, @@ -198,16 +201,19 @@ func TestCheckAgentLogs(t *testing.T) { "test case failed: one or more errors found while examining service.log", }, expectedDetails: []string{ - "[0] found error \"foo\"\n[1] found error \"something\"", + "[0] found error \"something\"\n[1] found error \"foo\"", }, }, { - testName: "skipped logs because starting time", + testName: "remove old logs", startingTime: "2023-05-15T13:00:02.000Z", - errorPatterns: map[string][]logsRegexp{ - "service": []logsRegexp{ - logsRegexp{ - includes: regexp.MustCompile(".*"), + errorPatterns: []logsByContainer{ + logsByContainer{ + containerName: "service", + patterns: []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*"), + }, }, }, }, @@ -222,12 +228,15 @@ func TestCheckAgentLogs(t *testing.T) { expectedDetails: []string{"[0] found error \"foo\""}, }, { - testName: "no logs found because starting time", + testName: "all logs older", startingTime: "2023-05-15T14:00:00.000Z", - errorPatterns: map[string][]logsRegexp{ - "service": []logsRegexp{ - logsRegexp{ - includes: regexp.MustCompile(".*"), + errorPatterns: []logsByContainer{ + logsByContainer{ + containerName: "service", + patterns: []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*"), + }, }, }, }, @@ -242,10 +251,13 @@ func TestCheckAgentLogs(t *testing.T) { { testName: "filter logs by regex", startingTime: "2023-05-15T12:00:00.000Z", - errorPatterns: map[string][]logsRegexp{ - "service": []logsRegexp{ - logsRegexp{ - includes: regexp.MustCompile(".*thing$"), + errorPatterns: []logsByContainer{ + logsByContainer{ + containerName: "service", + patterns: []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*thing$"), + }, }, }, }, @@ -261,17 +273,23 @@ func TestCheckAgentLogs(t *testing.T) { expectedDetails: []string{"[0] found error \"something\""}, }, { - testName: "erros found in two services - filtered", + testName: "logs found for two services", startingTime: "2023-05-15T13:00:01.000Z", - errorPatterns: map[string][]logsRegexp{ - "service": []logsRegexp{ - logsRegexp{ - includes: regexp.MustCompile(".*thing$"), + errorPatterns: []logsByContainer{ + logsByContainer{ + containerName: "service", + patterns: []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(".*thing$"), + }, }, }, - "external": []logsRegexp{ - logsRegexp{ - includes: regexp.MustCompile(" other "), + logsByContainer{ + containerName: "external", + patterns: []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile(" foo$"), + }, }, }, }, @@ -284,7 +302,7 @@ func TestCheckAgentLogs(t *testing.T) { "external": []string{ `external_1 | {"@timestamp": "2023-05-15T13:00:00.000Z", "message": "external: initial"}`, `external_1 | {"@timestamp": "2023-05-15T13:00:05.000Z", "message": "external: foo"}`, - `external_1 | {"@timestamp": "2023-05-15T13:00:08.000Z", "message": "external: any other thing"}`, + `external_1 | {"@timestamp": "2023-05-15T13:00:08.000Z", "message": "external: any other foo"}`, }, }, expectedErrors: 2, @@ -294,7 +312,7 @@ func TestCheckAgentLogs(t *testing.T) { }, expectedDetails: []string{ "[0] found error \"service: something\"", - "[0] found error \"external: any other thing\"", + "[0] found error \"external: foo\"\n[1] found error \"external: any other foo\"", }, }, } @@ -342,8 +360,8 @@ func TestCheckAgentLogs(t *testing.T) { } for i := 0; i < tc.expectedErrors; i++ { - assert.Contains(t, tc.expectedMessage, results[i].FailureMsg) - assert.Contains(t, tc.expectedDetails, results[i].FailureDetails) + assert.Equal(t, tc.expectedMessage[i], results[i].FailureMsg) + assert.Equal(t, tc.expectedDetails[i], results[i].FailureDetails) } }) } From 1167bcdc3a01840044f47b5351cbca38dfd4e452 Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 16 May 2023 16:00:00 +0200 Subject: [PATCH 25/26] Remove debug regexes --- internal/testrunner/runners/system/runner.go | 12 ------------ 1 file changed, 12 deletions(-) diff --git a/internal/testrunner/runners/system/runner.go b/internal/testrunner/runners/system/runner.go index ea6f05ae81..aba8394fb6 100644 --- a/internal/testrunner/runners/system/runner.go +++ b/internal/testrunner/runners/system/runner.go @@ -75,18 +75,6 @@ var ( regexp.MustCompile(`action \[indices:data\/write\/bulk\[s\]\] is unauthorized for API key id \[.*\] of user \[.*\] on indices \[.*\], this action is granted by the index privileges \[.*\]`), }, }, - logsRegexp{ - includes: regexp.MustCompile("New State ID"), - excludes: []*regexp.Regexp{ - regexp.MustCompile("is unahorized API key id"), - }, - }, - logsRegexp{ - includes: regexp.MustCompile("->HEALTHY"), - excludes: []*regexp.Regexp{ - regexp.MustCompile(`Healthy$`), - }, - }, logsRegexp{ includes: regexp.MustCompile("->(FAILED|DEGRADED)"), }, From f2dca7a06d3e15c5ded07cce121c6f84d0d728fd Mon Sep 17 00:00:00 2001 From: Mario Rodriguez Molins Date: Tue, 16 May 2023 17:03:15 +0200 Subject: [PATCH 26/26] Add test using excludes --- .../testrunner/runners/system/runner_test.go | 30 +++++++++++++++++++ 1 file changed, 30 insertions(+) diff --git a/internal/testrunner/runners/system/runner_test.go b/internal/testrunner/runners/system/runner_test.go index 36cc3c0929..bbc0e1f31b 100644 --- a/internal/testrunner/runners/system/runner_test.go +++ b/internal/testrunner/runners/system/runner_test.go @@ -315,6 +315,36 @@ func TestCheckAgentLogs(t *testing.T) { "[0] found error \"external: foo\"\n[1] found error \"external: any other foo\"", }, }, + { + testName: "usage of includes and excludes", + startingTime: "2023-05-15T12:00:00.000Z", + errorPatterns: []logsByContainer{ + logsByContainer{ + containerName: "service", + patterns: []logsRegexp{ + logsRegexp{ + includes: regexp.MustCompile("^(something|foo)"), + excludes: []*regexp.Regexp{ + regexp.MustCompile("foo$"), + regexp.MustCompile("42"), + }, + }, + }, + }, + }, + sampleLogs: map[string][]string{ + "service": []string{ + `service_1 | {"@timestamp": "2023-05-15T13:00:00.000Z", "message": "something"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:05.000Z", "message": "something foo"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:10.000Z", "message": "foo bar"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:15.000Z", "message": "foo bar 42"}`, + `service_1 | {"@timestamp": "2023-05-15T13:00:20.000Z", "message": "other message"}`, + }, + }, + expectedErrors: 1, + expectedMessage: []string{"test case failed: one or more errors found while examining service.log"}, + expectedDetails: []string{"[0] found error \"something\"\n[1] found error \"foo bar\""}, + }, } for _, tc := range testCases {