From 53dd45ad968197114fafa86527725f1b48bc4133 Mon Sep 17 00:00:00 2001 From: "mergify[bot]" <37929162+mergify[bot]@users.noreply.github.com> Date: Wed, 28 Apr 2021 18:35:15 +0200 Subject: [PATCH] [elastic-agent] Improve log messages (#25372) (#25393) This PR improves the log messages to make them easier to consume by users. * Change unroll to unenroll, that is what we use in the UI too * Trigger unenroll only when the maxCounter is exceeded (nit) * Move Artifact has been built with security disable to info. This only happens for internal builds * Move log message around binary already exists to debug level as this is an expected behaviour * Be more specific about binary downloads * For state changes, move the message first. That is the most interesting part for a user (cherry picked from commit 89d2b36765e57deaae816ff927b50117dec985eb) Co-authored-by: Nicolas Ruflin --- .../agent/application/gateway/fleet/fleet_gateway.go | 10 ++++++---- x-pack/elastic-agent/pkg/agent/cmd/run.go | 2 +- .../pkg/agent/operation/operation_fetch.go | 4 ++-- x-pack/elastic-agent/pkg/reporter/log/format.go | 4 ++-- x-pack/elastic-agent/pkg/reporter/log/reporter.go | 2 +- x-pack/elastic-agent/pkg/reporter/log/reporter_test.go | 2 +- 6 files changed, 13 insertions(+), 11 deletions(-) diff --git a/x-pack/elastic-agent/pkg/agent/application/gateway/fleet/fleet_gateway.go b/x-pack/elastic-agent/pkg/agent/application/gateway/fleet/fleet_gateway.go index 6018e2bc5f98..8b2082578282 100644 --- a/x-pack/elastic-agent/pkg/agent/application/gateway/fleet/fleet_gateway.go +++ b/x-pack/elastic-agent/pkg/agent/application/gateway/fleet/fleet_gateway.go @@ -25,6 +25,7 @@ import ( "github.com/elastic/beats/v7/x-pack/elastic-agent/pkg/scheduler" ) +// Max number of times an invalid API Key is checked const maxUnauthCounter int = 6 // Default Configuration for the Fleet Gateway. @@ -244,8 +245,8 @@ func (f *fleetGateway) execute(ctx context.Context) (*fleetapi.CheckinResponse, if isUnauth(err) { f.unauthCounter++ - if f.shouldUnroll() { - f.log.Warnf("retrieved unauthorized for '%d' times. Unrolling.", f.unauthCounter) + if f.shouldUnenroll() { + f.log.Warnf("retrieved an invalid api key error '%d' times. Starting to unenroll the elastic agent.", f.unauthCounter) return &fleetapi.CheckinResponse{ Actions: []fleetapi.Action{&fleetapi.ActionUnenroll{ActionID: "", ActionType: "UNENROLL", IsDetected: true}}, }, nil @@ -273,8 +274,9 @@ func (f *fleetGateway) execute(ctx context.Context) (*fleetapi.CheckinResponse, return resp, nil } -func (f *fleetGateway) shouldUnroll() bool { - return f.unauthCounter >= maxUnauthCounter +// shouldUnenroll checks if the max number of trying an invalid key is reached +func (f *fleetGateway) shouldUnenroll() bool { + return f.unauthCounter > maxUnauthCounter } func isUnauth(err error) bool { diff --git a/x-pack/elastic-agent/pkg/agent/cmd/run.go b/x-pack/elastic-agent/pkg/agent/cmd/run.go index 2c0bb76cdb0b..e49d60b59370 100644 --- a/x-pack/elastic-agent/pkg/agent/cmd/run.go +++ b/x-pack/elastic-agent/pkg/agent/cmd/run.go @@ -130,7 +130,7 @@ func run(streams *cli.IOStreams, override cfgOverrider) error { // Windows: Mark } if allowEmptyPgp, _ := release.PGP(); allowEmptyPgp { - logger.Warn("Artifact has been build with security disabled. Elastic Agent will not verify signatures of used artifacts.") + logger.Info("Artifact has been built with security disabled. Elastic Agent will not verify signatures of the artifacts.") } execPath, err := reexecPath() diff --git a/x-pack/elastic-agent/pkg/agent/operation/operation_fetch.go b/x-pack/elastic-agent/pkg/agent/operation/operation_fetch.go index 0f66842abce0..00450a641c9a 100644 --- a/x-pack/elastic-agent/pkg/agent/operation/operation_fetch.go +++ b/x-pack/elastic-agent/pkg/agent/operation/operation_fetch.go @@ -58,7 +58,7 @@ func (o *operationFetch) Check(_ context.Context, _ Application) (bool, error) { return true, nil } - o.logger.Infof("%s.%s already exists in %s. Skipping operation %s", o.program.BinaryName(), o.program.Version(), fullPath, o.Name()) + o.logger.Debugf("binary '%s.%s' already exists in %s. Skipping operation %s", o.program.BinaryName(), o.program.Version(), fullPath, o.Name()) return false, err } @@ -72,7 +72,7 @@ func (o *operationFetch) Run(ctx context.Context, application Application) (err fullPath, err := o.downloader.Download(ctx, o.program.Spec(), o.program.Version()) if err == nil { - o.logger.Infof("operation '%s' downloaded %s.%s into %s", o.Name(), o.program.BinaryName(), o.program.Version(), fullPath) + o.logger.Infof("downloaded binary '%s.%s' into '%s' as part of operation '%s'", o.program.BinaryName(), o.program.Version(), fullPath, o.Name()) } return err diff --git a/x-pack/elastic-agent/pkg/reporter/log/format.go b/x-pack/elastic-agent/pkg/reporter/log/format.go index dcb08f5b1c47..3cac93aa0cfa 100644 --- a/x-pack/elastic-agent/pkg/reporter/log/format.go +++ b/x-pack/elastic-agent/pkg/reporter/log/format.go @@ -20,8 +20,8 @@ const ( ) const ( - // e.g "2006-01-02T15:04:05: type: 'STATE': event type: 'STARTING' message: Application 'filebeat' is starting." - defaultLogFormat = "%s: type: '%s': sub_type: '%s' message: %s" + // e.g "2006-01-02T15:04:05 - message: Application 'filebeat' is starting. - type: 'STATE' - event type: 'STARTING'" + defaultLogFormat = "%s - message: %s - type: '%s' - sub_type: '%s'" timeFormat = time.RFC3339 ) diff --git a/x-pack/elastic-agent/pkg/reporter/log/reporter.go b/x-pack/elastic-agent/pkg/reporter/log/reporter.go index 8651d7b800bf..a202bd7cbda3 100644 --- a/x-pack/elastic-agent/pkg/reporter/log/reporter.go +++ b/x-pack/elastic-agent/pkg/reporter/log/reporter.go @@ -47,9 +47,9 @@ func (r *Reporter) Close() error { return nil } func defaultFormatFunc(e reporter.Event) string { return fmt.Sprintf(defaultLogFormat, e.Time().Format(timeFormat), + e.Message(), e.Type(), e.SubType(), - e.Message(), ) } diff --git a/x-pack/elastic-agent/pkg/reporter/log/reporter_test.go b/x-pack/elastic-agent/pkg/reporter/log/reporter_test.go index f58518ca70e3..7aa7362f1fa0 100644 --- a/x-pack/elastic-agent/pkg/reporter/log/reporter_test.go +++ b/x-pack/elastic-agent/pkg/reporter/log/reporter_test.go @@ -94,5 +94,5 @@ func (testEvent) Payload() map[string]interface{} { return map[string]interface{ func DefaultString(event testEvent) string { timestamp := event.timestamp.Format(timeFormat) - return fmt.Sprintf("%s: type: '%s': sub_type: '%s' message: message", timestamp, event.Type(), event.SubType()) + return fmt.Sprintf("%s - message: message - type: '%s' - sub_type: '%s'", timestamp, event.Type(), event.SubType()) }