From f069daecd232433cdb4146589b40d2ea346f4333 Mon Sep 17 00:00:00 2001 From: Suhong Qin Date: Mon, 7 Aug 2023 19:24:12 +0000 Subject: [PATCH 1/8] feat: pull and validate cli --- pkg/cli/root.go | 3 + pkg/cli/validate_pull.go | 233 ++++++++++++++++++++++++++++++++++ pkg/cli/validate_pull_test.go | 161 +++++++++++++++++++++++ 3 files changed, 397 insertions(+) create mode 100644 pkg/cli/validate_pull.go create mode 100644 pkg/cli/validate_pull_test.go diff --git a/pkg/cli/root.go b/pkg/cli/root.go index 24029616..29f795b9 100644 --- a/pkg/cli/root.go +++ b/pkg/cli/root.go @@ -31,6 +31,9 @@ var rootCmd = func() cli.Command { "validate": func() cli.Command { return &ValidateCommand{} }, + "pull": func() cli.Command { + return &ValidatePullCommand{} + }, }, } } diff --git a/pkg/cli/validate_pull.go b/pkg/cli/validate_pull.go new file mode 100644 index 00000000..40d5d1b3 --- /dev/null +++ b/pkg/cli/validate_pull.go @@ -0,0 +1,233 @@ +// Copyright 2023 The Authors (see AUTHORS file) +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package cli + +import ( + "context" + "errors" + "fmt" + "time" + + "cloud.google.com/go/logging/apiv2/loggingpb" + "github.com/abcxyz/lumberjack/pkg/cloudlogging" + "github.com/abcxyz/lumberjack/pkg/validation" + "github.com/abcxyz/pkg/cli" + "google.golang.org/protobuf/encoding/protojson" + + logging "cloud.google.com/go/logging/apiv2" +) + +// Lumberjack specific log types. +const logType = `LOG_ID("audit.abcxyz/unspecified") OR ` + + `LOG_ID("audit.abcxyz/activity") OR ` + + `LOG_ID("audit.abcxyz/data_access") OR ` + + `LOG_ID("audit.abcxyz/consent") OR ` + + `LOG_ID("audit.abcxyz/system_event")` + +// logPuller interface that pulls log entries from cloud logging. +type logPuller interface { + Pull(context.Context, string, int) ([]*loggingpb.LogEntry, error) +} + +var _ cli.Command = (*ValidatePullCommand)(nil) + +// ValidatePullCommand validates lumberjack logs pulled. +type ValidatePullCommand struct { + cli.BaseCommand + + flagResource string + + flagMaxCount int + + flagDuration time.Duration + + flagCustomQuery string + + flagRemoveLumberjackLogType bool + + flagAdditionalCheck bool + + // For testing only. + testPuller logPuller +} + +func (c *ValidatePullCommand) Desc() string { + return `Pulls and Validates lumberjack logs from Cloud logging` +} + +func (c *ValidatePullCommand) Help() string { + return ` +Usage: {{ COMMAND }} [options] + +Pulls and validates the latest lumberjack log in the last 24 hours from resource: + + {{ COMMAND }} -resource "project/foo" + +Pulls and validates the latest lumberjack log filtered by additional custom query: + + {{ COMMAND }} -resource "project/foo" -query "severity = ERROR" + +Pulls and validates (with additional check) the latest 10 lumberjack log in the last 2 hours from resource: + + {{ COMMAND }} -resource "project/foo" -max-count 10 -duration 2h -additional-check + +Pulls and validates the latest non-lumberjack log type log: + + {{ COMMAND }} -resource "project/foo" -remove-lumberjack-log-type +` +} + +func (c *ValidatePullCommand) Flags() *cli.FlagSet { + set := cli.NewFlagSet() + + // Command options + f := set.NewSection("COMMAND OPTIONS") + + f.StringVar(&cli.StringVar{ + Name: "resource", + Aliases: []string{"r"}, + Target: &c.flagResource, + Example: `projects/foo`, + Usage: `Name of the parent resource from which to retrieve log entries,` + + `examples are: projects/[PROJECT_ID], folders/[FOLDER_ID],` + + `organizations/[ORGANIZATION_ID], billingAccounts/[BILLING_ACCOUNT_ID]`, + }) + + f.IntVar(&cli.IntVar{ + Name: "max-count", + Target: &c.flagMaxCount, + Default: 1, + Usage: `Number of most recent logs to validate, default is 1`, + }) + + f.DurationVar(&cli.DurationVar{ + Name: "duration", + Aliases: []string{"d"}, + Target: &c.flagDuration, + Example: "2h", + Default: 24 * time.Hour, + Usage: `How far back to search for log entries, default is 24 hours`, + }) + + f.StringVar(&cli.StringVar{ + Name: "query", + Target: &c.flagCustomQuery, + Example: `resource.type = "gae_app" AND severity = ERROR`, + Usage: `Custom log queries, see more on https://cloud.google.com/logging/docs/view/logging-query-language`, + }) + + f.BoolVar(&cli.BoolVar{ + Name: "remove-lumberjack-log-type", + Target: &c.flagRemoveLumberjackLogType, + Default: false, + Usage: `Turn on to remove lumberjack log type log filter`, + }) + + f.BoolVar(&cli.BoolVar{ + Name: "additional-check", + Target: &c.flagAdditionalCheck, + Default: false, + Usage: `Turn on for additional lumberjack specific checks on log labels.`, + }) + + return set +} + +func (c *ValidatePullCommand) Run(ctx context.Context, args []string) error { + f := c.Flags() + if err := f.Parse(args); err != nil { + return fmt.Errorf("failed to parse flags: %w", err) + } + args = f.Args() + if len(args) > 0 { + return fmt.Errorf("unexpected arguments: %q", args) + } + + if c.flagResource == "" { + return fmt.Errorf("resource is required") + } + + // Request with negative and greater than 1000 (log count limit) is rejected. + if c.flagMaxCount <= 0 || c.flagMaxCount > 1000 { + return fmt.Errorf("max count must be greater than 0 and less than 1000") + } + + // Pull logs. + ls, err := c.pull(ctx) + if err != nil { + return err + } + if len(ls) == 0 { + c.Outf("Log not found") + return nil + } + + // Validate logs. + var extra []validation.Validator + if c.flagAdditionalCheck { + extra = append(extra, validation.ValidateLabels) + } + var retErr error + for _, l := range ls { + js, err := protojson.Marshal(l) + if err != nil { + retErr = errors.Join(retErr, fmt.Errorf("failed to marshal log to json (InsertId: %q): %w", l.InsertId, err)) + } else { + if err := validation.Validate(string(js), extra...); err != nil { + retErr = errors.Join(retErr, fmt.Errorf("failed to validate log (InsertId: %q): %w", l.InsertId, err)) + } else { + c.Outf("Successfully validated log (InsertId: %q)", l.InsertId) + } + } + } + + return retErr +} + +func (c *ValidatePullCommand) pull(ctx context.Context) ([]*loggingpb.LogEntry, error) { + var p logPuller + if c.testPuller != nil { + p = c.testPuller + } else { + logClient, err := logging.NewClient(ctx) + if err != nil { + return nil, fmt.Errorf("failed to create logging client: %w", err) + } + p = cloudlogging.NewPuller(ctx, logClient, c.flagResource) + } + + ls, err := p.Pull(ctx, c.getFilter(), c.flagMaxCount) + if err != nil { + return nil, fmt.Errorf("failed to pull logs: %w", err) + } + + return ls, nil +} + +func (c *ValidatePullCommand) getFilter() string { + cutoff := fmt.Sprintf("timestamp >= %q", time.Now().UTC().Add(-c.flagDuration).Format(time.RFC3339)) + + var f string + if c.flagRemoveLumberjackLogType { + f = cutoff + } else { + f = fmt.Sprintf("%s AND %s", logType, cutoff) + } + + if c.flagCustomQuery == "" { + return f + } + return fmt.Sprintf("%s AND %s", f, c.flagCustomQuery) +} diff --git a/pkg/cli/validate_pull_test.go b/pkg/cli/validate_pull_test.go new file mode 100644 index 00000000..7d2620ee --- /dev/null +++ b/pkg/cli/validate_pull_test.go @@ -0,0 +1,161 @@ +// Copyright 2023 The Authors (see AUTHORS file) +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package cli + +import ( + "context" + "fmt" + "strings" + "testing" + "time" + + "cloud.google.com/go/logging/apiv2/loggingpb" + "github.com/abcxyz/pkg/testutil" + "github.com/google/go-cmp/cmp" + "google.golang.org/protobuf/types/known/structpb" +) + +func TestValidatePullCommand(t *testing.T) { + t.Parallel() + + ct := time.Now().UTC() + + cases := []struct { + name string + args []string + puller *fakePuller + expFilter string + expMaxCount int + expOut string + expErrSubstr string + }{ + { + name: "success", + args: []string{ + "-resource", "projects/foo", + "-duration", "2h", + "-query", `resource.type = "gae_app" AND severity = ERROR`, + "-additional-check", + "-max-count", "2", + }, + puller: &fakePuller{ + logEntries: []*loggingpb.LogEntry{ + { + InsertId: "test-log", + Payload: &loggingpb.LogEntry_JsonPayload{ + JsonPayload: &structpb.Struct{ + Fields: map[string]*structpb.Value{ + "service_name": structpb.NewStringValue("foo_service"), + "method_name": structpb.NewStringValue("foo_method"), + "resource_name": structpb.NewStringValue("foo_resource"), + "authentication_info": structpb.NewStructValue(&structpb.Struct{ + Fields: map[string]*structpb.Value{ + "principal_email": structpb.NewStringValue("foo@bet.com"), + }, + }), + }, + }, + }, + Labels: map[string]string{"environment": "dev", "accessing_process_name": "foo_apn"}, + }, + }, + }, + expFilter: fmt.Sprintf( + `LOG_ID("audit.abcxyz/unspecified") OR `+ + `LOG_ID("audit.abcxyz/activity") OR `+ + `LOG_ID("audit.abcxyz/data_access") OR `+ + `LOG_ID("audit.abcxyz/consent") OR `+ + `LOG_ID("audit.abcxyz/system_event") `+ + `AND timestamp >= %q AND resource.type = "gae_app" `+ + `AND severity = ERROR`, + ct.Add(-2*time.Hour).Format(time.RFC3339), + ), + expMaxCount: 2, + expOut: `Successfully validated log (InsertId: "test-log")`, + }, + { + name: "validate_fail", + args: []string{ + "-resource", "projects/foo", + "-remove-lumberjack-log-type", + }, + puller: &fakePuller{ + logEntries: []*loggingpb.LogEntry{{InsertId: "test"}}, + }, + expFilter: fmt.Sprintf( + `timestamp >= %q`, ct.Add(-24*time.Hour).Format(time.RFC3339), + ), + expMaxCount: 1, + expErrSubstr: "failed to validate log", + }, + { + name: "pull_fail", + args: []string{ + "-resource", "projects/foo", + "-remove-lumberjack-log-type", + }, + puller: &fakePuller{ + logEntries: []*loggingpb.LogEntry{{InsertId: "test"}}, + injectErr: fmt.Errorf("injected error"), + }, + expFilter: fmt.Sprintf( + `timestamp >= %q`, ct.Add(-24*time.Hour).Format(time.RFC3339), + ), + expMaxCount: 1, + expErrSubstr: "injected error", + }, + } + + for _, tc := range cases { + tc := tc + + t.Run(tc.name, func(t *testing.T) { + t.Parallel() + + ctx := context.Background() + + var cmd ValidatePullCommand + cmd.testPuller = tc.puller + _, stdout, _ := cmd.Pipe() + + err := cmd.Run(ctx, tc.args) + if diff := testutil.DiffErrString(err, tc.expErrSubstr); diff != "" { + t.Errorf("Process(%+v) got error diff (-want, +got):\n%s", tc.name, diff) + } + if diff := cmp.Diff(strings.TrimSpace(tc.expOut), strings.TrimSpace(stdout.String())); diff != "" { + t.Errorf("Process(%+v) got output diff (-want, +got):\n%s", tc.name, diff) + } + if diff := cmp.Diff(tc.expFilter, tc.puller.gotFilter); diff != "" { + t.Errorf("Process(%+v) got request diff (-want, +got):\n%s", tc.name, diff) + } + if tc.expMaxCount != tc.puller.gotMaxCount { + t.Errorf("Process(%+v) want max count %q but got %q", tc.name, tc.expMaxCount, tc.puller.gotMaxCount) + } + }) + } +} + +type fakePuller struct { + injectErr error + gotFilter string + gotMaxCount int + logEntries []*loggingpb.LogEntry +} + +func (p *fakePuller) Pull(ctx context.Context, filter string, maxCount int) ([]*loggingpb.LogEntry, error) { + p.gotFilter = filter + p.gotMaxCount = maxCount + return p.logEntries, p.injectErr +} From d455f0aa971e689a4d11df8c9cbf31200d99b176 Mon Sep 17 00:00:00 2001 From: Suhong Qin Date: Wed, 9 Aug 2023 21:43:59 +0000 Subject: [PATCH 2/8] rename and fix test --- pkg/cli/root.go | 2 +- pkg/cli/root_test.go | 1 + pkg/cli/validate_pull.go | 18 +++++++++--------- pkg/cli/validate_pull_test.go | 2 +- 4 files changed, 12 insertions(+), 11 deletions(-) diff --git a/pkg/cli/root.go b/pkg/cli/root.go index 29f795b9..2d36b11b 100644 --- a/pkg/cli/root.go +++ b/pkg/cli/root.go @@ -32,7 +32,7 @@ var rootCmd = func() cli.Command { return &ValidateCommand{} }, "pull": func() cli.Command { - return &ValidatePullCommand{} + return &PullCommand{} }, }, } diff --git a/pkg/cli/root_test.go b/pkg/cli/root_test.go index 5178686b..1ed1d161 100644 --- a/pkg/cli/root_test.go +++ b/pkg/cli/root_test.go @@ -25,6 +25,7 @@ func TestRootCommand_Help(t *testing.T) { exp := ` Usage: lumberctl COMMAND + pull Pulls and Validates lumberjack logs from Cloud logging validate Validate lumberjack log ` diff --git a/pkg/cli/validate_pull.go b/pkg/cli/validate_pull.go index 40d5d1b3..5ac179ae 100644 --- a/pkg/cli/validate_pull.go +++ b/pkg/cli/validate_pull.go @@ -41,10 +41,10 @@ type logPuller interface { Pull(context.Context, string, int) ([]*loggingpb.LogEntry, error) } -var _ cli.Command = (*ValidatePullCommand)(nil) +var _ cli.Command = (*PullCommand)(nil) -// ValidatePullCommand validates lumberjack logs pulled. -type ValidatePullCommand struct { +// PullCommand pulls and validates lumberjack logs. +type PullCommand struct { cli.BaseCommand flagResource string @@ -63,11 +63,11 @@ type ValidatePullCommand struct { testPuller logPuller } -func (c *ValidatePullCommand) Desc() string { +func (c *PullCommand) Desc() string { return `Pulls and Validates lumberjack logs from Cloud logging` } -func (c *ValidatePullCommand) Help() string { +func (c *PullCommand) Help() string { return ` Usage: {{ COMMAND }} [options] @@ -89,7 +89,7 @@ Pulls and validates the latest non-lumberjack log type log: ` } -func (c *ValidatePullCommand) Flags() *cli.FlagSet { +func (c *PullCommand) Flags() *cli.FlagSet { set := cli.NewFlagSet() // Command options @@ -145,7 +145,7 @@ func (c *ValidatePullCommand) Flags() *cli.FlagSet { return set } -func (c *ValidatePullCommand) Run(ctx context.Context, args []string) error { +func (c *PullCommand) Run(ctx context.Context, args []string) error { f := c.Flags() if err := f.Parse(args); err != nil { return fmt.Errorf("failed to parse flags: %w", err) @@ -196,7 +196,7 @@ func (c *ValidatePullCommand) Run(ctx context.Context, args []string) error { return retErr } -func (c *ValidatePullCommand) pull(ctx context.Context) ([]*loggingpb.LogEntry, error) { +func (c *PullCommand) pull(ctx context.Context) ([]*loggingpb.LogEntry, error) { var p logPuller if c.testPuller != nil { p = c.testPuller @@ -216,7 +216,7 @@ func (c *ValidatePullCommand) pull(ctx context.Context) ([]*loggingpb.LogEntry, return ls, nil } -func (c *ValidatePullCommand) getFilter() string { +func (c *PullCommand) getFilter() string { cutoff := fmt.Sprintf("timestamp >= %q", time.Now().UTC().Add(-c.flagDuration).Format(time.RFC3339)) var f string diff --git a/pkg/cli/validate_pull_test.go b/pkg/cli/validate_pull_test.go index 7d2620ee..1996f0ee 100644 --- a/pkg/cli/validate_pull_test.go +++ b/pkg/cli/validate_pull_test.go @@ -126,7 +126,7 @@ func TestValidatePullCommand(t *testing.T) { ctx := context.Background() - var cmd ValidatePullCommand + var cmd PullCommand cmd.testPuller = tc.puller _, stdout, _ := cmd.Pipe() From 997c5b5573ecabfad654fd4ebed4fb1f422c72aa Mon Sep 17 00:00:00 2001 From: Suhong Qin Date: Thu, 10 Aug 2023 01:27:25 +0000 Subject: [PATCH 3/8] rename and add validate flag --- pkg/cli/root.go | 4 +- pkg/cli/root_test.go | 2 +- pkg/cli/{validate_pull.go => tail.go} | 95 ++++++++++------- .../{validate_pull_test.go => tail_test.go} | 100 ++++++++++++++---- pkg/cli/validate.go | 18 ++-- pkg/cli/validate_test.go | 10 +- 6 files changed, 154 insertions(+), 75 deletions(-) rename pkg/cli/{validate_pull.go => tail.go} (64%) rename pkg/cli/{validate_pull_test.go => tail_test.go} (61%) diff --git a/pkg/cli/root.go b/pkg/cli/root.go index 2d36b11b..fe1108cc 100644 --- a/pkg/cli/root.go +++ b/pkg/cli/root.go @@ -31,8 +31,8 @@ var rootCmd = func() cli.Command { "validate": func() cli.Command { return &ValidateCommand{} }, - "pull": func() cli.Command { - return &PullCommand{} + "tail": func() cli.Command { + return &TailCommand{} }, }, } diff --git a/pkg/cli/root_test.go b/pkg/cli/root_test.go index 1ed1d161..3f489dee 100644 --- a/pkg/cli/root_test.go +++ b/pkg/cli/root_test.go @@ -25,7 +25,7 @@ func TestRootCommand_Help(t *testing.T) { exp := ` Usage: lumberctl COMMAND - pull Pulls and Validates lumberjack logs from Cloud logging + tail Tail lumberjack logs from Cloud logging and validate them when validation enabled validate Validate lumberjack log ` diff --git a/pkg/cli/validate_pull.go b/pkg/cli/tail.go similarity index 64% rename from pkg/cli/validate_pull.go rename to pkg/cli/tail.go index 5ac179ae..39ca5bb4 100644 --- a/pkg/cli/validate_pull.go +++ b/pkg/cli/tail.go @@ -41,15 +41,17 @@ type logPuller interface { Pull(context.Context, string, int) ([]*loggingpb.LogEntry, error) } -var _ cli.Command = (*PullCommand)(nil) +var _ cli.Command = (*TailCommand)(nil) -// PullCommand pulls and validates lumberjack logs. -type PullCommand struct { +// TailCommand tails and validates(optional) lumberjack logs. +type TailCommand struct { cli.BaseCommand flagResource string - flagMaxCount int + flagValidate bool + + flagMaxNum int flagDuration time.Duration @@ -57,31 +59,31 @@ type PullCommand struct { flagRemoveLumberjackLogType bool - flagAdditionalCheck bool + flagValidateWithAdditionalCheck bool // For testing only. testPuller logPuller } -func (c *PullCommand) Desc() string { - return `Pulls and Validates lumberjack logs from Cloud logging` +func (c *TailCommand) Desc() string { + return `Tail lumberjack logs from Cloud logging and validate them when validation enabled` } -func (c *PullCommand) Help() string { +func (c *TailCommand) Help() string { return ` Usage: {{ COMMAND }} [options] -Pulls and validates the latest lumberjack log in the last 24 hours from resource: +Tails and validates the latest lumberjack log in the last 24 hours from resource: - {{ COMMAND }} -resource "project/foo" + {{ COMMAND }} -resource "project/foo" -validate -Pulls and validates the latest lumberjack log filtered by additional custom query: +Tails the latest lumberjack log filtered by additional custom query: - {{ COMMAND }} -resource "project/foo" -query "severity = ERROR" + {{ COMMAND }} -resource "project/foo" -query "resource.type = \"foo\"" -Pulls and validates (with additional check) the latest 10 lumberjack log in the last 2 hours from resource: +Tails and validates (with additional check) the latest 10 lumberjack log in the last 2 hours from resource: - {{ COMMAND }} -resource "project/foo" -max-count 10 -duration 2h -additional-check + {{ COMMAND }} -resource "project/foo" -max-num 10 -duration 2h -validate-with-additional-check Pulls and validates the latest non-lumberjack log type log: @@ -89,7 +91,7 @@ Pulls and validates the latest non-lumberjack log type log: ` } -func (c *PullCommand) Flags() *cli.FlagSet { +func (c *TailCommand) Flags() *cli.FlagSet { set := cli.NewFlagSet() // Command options @@ -105,11 +107,20 @@ func (c *PullCommand) Flags() *cli.FlagSet { `organizations/[ORGANIZATION_ID], billingAccounts/[BILLING_ACCOUNT_ID]`, }) + f.BoolVar(&cli.BoolVar{ + Name: "validate", + Aliases: []string{"v"}, + Target: &c.flagValidate, + Default: false, + Usage: `Turn on for lumberjack log validation`, + }) + f.IntVar(&cli.IntVar{ - Name: "max-count", - Target: &c.flagMaxCount, + Name: "max-num", + Aliases: []string{"n"}, + Target: &c.flagMaxNum, Default: 1, - Usage: `Number of most recent logs to validate, default is 1`, + Usage: `Maximum number of most recent logs to validate, default is 1`, }) f.DurationVar(&cli.DurationVar{ @@ -125,7 +136,8 @@ func (c *PullCommand) Flags() *cli.FlagSet { Name: "query", Target: &c.flagCustomQuery, Example: `resource.type = "gae_app" AND severity = ERROR`, - Usage: `Custom log queries, see more on https://cloud.google.com/logging/docs/view/logging-query-language`, + Usage: `Optional custom log queries, see more on ` + + `https://cloud.google.com/logging/docs/view/logging-query-language`, }) f.BoolVar(&cli.BoolVar{ @@ -136,16 +148,17 @@ func (c *PullCommand) Flags() *cli.FlagSet { }) f.BoolVar(&cli.BoolVar{ - Name: "additional-check", - Target: &c.flagAdditionalCheck, + Name: "validate-with-additional-check", + Target: &c.flagValidateWithAdditionalCheck, Default: false, - Usage: `Turn on for additional lumberjack specific checks on log labels.`, + Usage: `Turn on for lumberjack log validation with additional ` + + `lumberjack specific checks on log labels.`, }) return set } -func (c *PullCommand) Run(ctx context.Context, args []string) error { +func (c *TailCommand) Run(ctx context.Context, args []string) error { f := c.Flags() if err := f.Parse(args); err != nil { return fmt.Errorf("failed to parse flags: %w", err) @@ -160,12 +173,12 @@ func (c *PullCommand) Run(ctx context.Context, args []string) error { } // Request with negative and greater than 1000 (log count limit) is rejected. - if c.flagMaxCount <= 0 || c.flagMaxCount > 1000 { - return fmt.Errorf("max count must be greater than 0 and less than 1000") + if c.flagMaxNum <= 0 || c.flagMaxNum > 1000 { + return fmt.Errorf("max number must be greater than 0 and less than 1000") } - // Pull logs. - ls, err := c.pull(ctx) + // Tail logs. + ls, err := c.tail(ctx) if err != nil { return err } @@ -174,9 +187,9 @@ func (c *PullCommand) Run(ctx context.Context, args []string) error { return nil } - // Validate logs. + // Output results. var extra []validation.Validator - if c.flagAdditionalCheck { + if c.flagValidateWithAdditionalCheck { extra = append(extra, validation.ValidateLabels) } var retErr error @@ -184,19 +197,27 @@ func (c *PullCommand) Run(ctx context.Context, args []string) error { js, err := protojson.Marshal(l) if err != nil { retErr = errors.Join(retErr, fmt.Errorf("failed to marshal log to json (InsertId: %q): %w", l.InsertId, err)) + continue + } + + // Output log entry in JSON format if validation is not enabled. + if !c.flagValidate && !c.flagValidateWithAdditionalCheck { + c.Outf(string(js)) + continue + } + + // Output validation result if validation is enabled. + if err := validation.Validate(string(js), extra...); err != nil { + retErr = errors.Join(retErr, fmt.Errorf("failed to validate log (InsertId: %q): %w", l.InsertId, err)) } else { - if err := validation.Validate(string(js), extra...); err != nil { - retErr = errors.Join(retErr, fmt.Errorf("failed to validate log (InsertId: %q): %w", l.InsertId, err)) - } else { - c.Outf("Successfully validated log (InsertId: %q)", l.InsertId) - } + c.Outf("Successfully validated log (InsertId: %q)", l.InsertId) } } return retErr } -func (c *PullCommand) pull(ctx context.Context) ([]*loggingpb.LogEntry, error) { +func (c *TailCommand) tail(ctx context.Context) ([]*loggingpb.LogEntry, error) { var p logPuller if c.testPuller != nil { p = c.testPuller @@ -208,7 +229,7 @@ func (c *PullCommand) pull(ctx context.Context) ([]*loggingpb.LogEntry, error) { p = cloudlogging.NewPuller(ctx, logClient, c.flagResource) } - ls, err := p.Pull(ctx, c.getFilter(), c.flagMaxCount) + ls, err := p.Pull(ctx, c.getFilter(), c.flagMaxNum) if err != nil { return nil, fmt.Errorf("failed to pull logs: %w", err) } @@ -216,7 +237,7 @@ func (c *PullCommand) pull(ctx context.Context) ([]*loggingpb.LogEntry, error) { return ls, nil } -func (c *PullCommand) getFilter() string { +func (c *TailCommand) getFilter() string { cutoff := fmt.Sprintf("timestamp >= %q", time.Now().UTC().Add(-c.flagDuration).Format(time.RFC3339)) var f string diff --git a/pkg/cli/validate_pull_test.go b/pkg/cli/tail_test.go similarity index 61% rename from pkg/cli/validate_pull_test.go rename to pkg/cli/tail_test.go index 1996f0ee..46e163b5 100644 --- a/pkg/cli/validate_pull_test.go +++ b/pkg/cli/tail_test.go @@ -27,7 +27,7 @@ import ( "google.golang.org/protobuf/types/known/structpb" ) -func TestValidatePullCommand(t *testing.T) { +func TestTailCommand(t *testing.T) { t.Parallel() ct := time.Now().UTC() @@ -37,18 +37,36 @@ func TestValidatePullCommand(t *testing.T) { args []string puller *fakePuller expFilter string - expMaxCount int + expMaxNum int expOut string expErrSubstr string }{ { - name: "success", + name: "success_tail", + args: []string{"-resource", "projects/foo"}, + puller: &fakePuller{ + logEntries: []*loggingpb.LogEntry{{}}, + }, + expFilter: fmt.Sprintf( + `LOG_ID("audit.abcxyz/unspecified") OR `+ + `LOG_ID("audit.abcxyz/activity") OR `+ + `LOG_ID("audit.abcxyz/data_access") OR `+ + `LOG_ID("audit.abcxyz/consent") OR `+ + `LOG_ID("audit.abcxyz/system_event") `+ + `AND timestamp >= %q`, + ct.Add(-24*time.Hour).Format(time.RFC3339), + ), + expMaxNum: 1, + expOut: `{}`, + }, + { + name: "success_validate", args: []string{ "-resource", "projects/foo", "-duration", "2h", "-query", `resource.type = "gae_app" AND severity = ERROR`, - "-additional-check", - "-max-count", "2", + "-validate", + "-max-num", "2", }, puller: &fakePuller{ logEntries: []*loggingpb.LogEntry{ @@ -68,7 +86,6 @@ func TestValidatePullCommand(t *testing.T) { }, }, }, - Labels: map[string]string{"environment": "dev", "accessing_process_name": "foo_apn"}, }, }, }, @@ -82,14 +99,55 @@ func TestValidatePullCommand(t *testing.T) { `AND severity = ERROR`, ct.Add(-2*time.Hour).Format(time.RFC3339), ), - expMaxCount: 2, - expOut: `Successfully validated log (InsertId: "test-log")`, + expMaxNum: 2, + expOut: `Successfully validated log (InsertId: "test-log")`, + }, + { + name: "success_validate_with_additional_check", + args: []string{ + "-resource", "projects/foo", + "-validate-with-additional-check", + }, + puller: &fakePuller{ + logEntries: []*loggingpb.LogEntry{ + { + InsertId: "test-log", + Payload: &loggingpb.LogEntry_JsonPayload{ + JsonPayload: &structpb.Struct{ + Fields: map[string]*structpb.Value{ + "service_name": structpb.NewStringValue("foo_service"), + "method_name": structpb.NewStringValue("foo_method"), + "resource_name": structpb.NewStringValue("foo_resource"), + "authentication_info": structpb.NewStructValue(&structpb.Struct{ + Fields: map[string]*structpb.Value{ + "principal_email": structpb.NewStringValue("foo@bet.com"), + }, + }), + }, + }, + }, + Labels: map[string]string{"environment": "dev", "accessing_process_name": "foo_apn"}, + }, + }, + }, + expFilter: fmt.Sprintf( + `LOG_ID("audit.abcxyz/unspecified") OR `+ + `LOG_ID("audit.abcxyz/activity") OR `+ + `LOG_ID("audit.abcxyz/data_access") OR `+ + `LOG_ID("audit.abcxyz/consent") OR `+ + `LOG_ID("audit.abcxyz/system_event") `+ + `AND timestamp >= %q`, + ct.Add(-24*time.Hour).Format(time.RFC3339), + ), + expMaxNum: 1, + expOut: `Successfully validated log (InsertId: "test-log")`, }, { name: "validate_fail", args: []string{ "-resource", "projects/foo", "-remove-lumberjack-log-type", + "-v", }, puller: &fakePuller{ logEntries: []*loggingpb.LogEntry{{InsertId: "test"}}, @@ -97,11 +155,11 @@ func TestValidatePullCommand(t *testing.T) { expFilter: fmt.Sprintf( `timestamp >= %q`, ct.Add(-24*time.Hour).Format(time.RFC3339), ), - expMaxCount: 1, + expMaxNum: 1, expErrSubstr: "failed to validate log", }, { - name: "pull_fail", + name: "tail_fail", args: []string{ "-resource", "projects/foo", "-remove-lumberjack-log-type", @@ -113,7 +171,7 @@ func TestValidatePullCommand(t *testing.T) { expFilter: fmt.Sprintf( `timestamp >= %q`, ct.Add(-24*time.Hour).Format(time.RFC3339), ), - expMaxCount: 1, + expMaxNum: 1, expErrSubstr: "injected error", }, } @@ -126,7 +184,7 @@ func TestValidatePullCommand(t *testing.T) { ctx := context.Background() - var cmd PullCommand + var cmd TailCommand cmd.testPuller = tc.puller _, stdout, _ := cmd.Pipe() @@ -138,24 +196,24 @@ func TestValidatePullCommand(t *testing.T) { t.Errorf("Process(%+v) got output diff (-want, +got):\n%s", tc.name, diff) } if diff := cmp.Diff(tc.expFilter, tc.puller.gotFilter); diff != "" { - t.Errorf("Process(%+v) got request diff (-want, +got):\n%s", tc.name, diff) + t.Errorf("Process(%+v) got filter diff (-want, +got):\n%s", tc.name, diff) } - if tc.expMaxCount != tc.puller.gotMaxCount { - t.Errorf("Process(%+v) want max count %q but got %q", tc.name, tc.expMaxCount, tc.puller.gotMaxCount) + if tc.expMaxNum != tc.puller.gotMaxNum { + t.Errorf("Process(%+v) want max number %q but got %q", tc.name, tc.expMaxNum, tc.puller.gotMaxNum) } }) } } type fakePuller struct { - injectErr error - gotFilter string - gotMaxCount int - logEntries []*loggingpb.LogEntry + injectErr error + gotFilter string + gotMaxNum int + logEntries []*loggingpb.LogEntry } -func (p *fakePuller) Pull(ctx context.Context, filter string, maxCount int) ([]*loggingpb.LogEntry, error) { +func (p *fakePuller) Pull(ctx context.Context, filter string, maxNum int) ([]*loggingpb.LogEntry, error) { p.gotFilter = filter - p.gotMaxCount = maxCount + p.gotMaxNum = maxNum return p.logEntries, p.injectErr } diff --git a/pkg/cli/validate.go b/pkg/cli/validate.go index 4aaed1ae..a45b1513 100644 --- a/pkg/cli/validate.go +++ b/pkg/cli/validate.go @@ -31,7 +31,7 @@ var _ cli.Command = (*ValidateCommand)(nil) type ValidateCommand struct { cli.BaseCommand - flagLog string + flagLogEntry string flagAdditionalCheck bool } @@ -46,11 +46,11 @@ Usage: {{ COMMAND }} [options] Validate lumberjack log: - {{ COMMAND }} -log "{\"foo\": \"bar\"}" + {{ COMMAND }} -log-entry "{\"foo\": \"bar\"}" Validate the lumberjack log read from pipe: - cat log.text | {{ COMMAND }} -log - + cat log.text | {{ COMMAND }} -log-entry - ` } @@ -61,9 +61,9 @@ func (c *ValidateCommand) Flags() *cli.FlagSet { f := set.NewSection("COMMAND OPTIONS") f.StringVar(&cli.StringVar{ - Name: "log", + Name: "log-entry", Aliases: []string{"l"}, - Target: &c.flagLog, + Target: &c.flagLogEntry, Example: `{"foo":"bar"}`, Usage: `The lumberjack/data access log, in JSON format. Set the value to` + ` "-" to read from stdin, it stops reading when it reaches end of file`, @@ -89,24 +89,24 @@ func (c *ValidateCommand) Run(ctx context.Context, args []string) error { return fmt.Errorf("unexpected arguments: %q", args) } - if c.flagLog == "" { + if c.flagLogEntry == "" { return fmt.Errorf("log is required") } - if c.flagLog == "-" { + if c.flagLogEntry == "-" { // Read log from stdin log, err := c.readFromStdin(ctx, "Enter log: ") if err != nil { return fmt.Errorf("failed to get log from prompt: %w", err) } - c.flagLog = log + c.flagLogEntry = log } var extra []validation.Validator if c.flagAdditionalCheck { extra = append(extra, validation.ValidateLabels) } - if err := validation.Validate(c.flagLog, extra...); err != nil { + if err := validation.Validate(c.flagLogEntry, extra...); err != nil { return fmt.Errorf("failed to validate log: %w", err) } c.Outf("Successfully validated log") diff --git a/pkg/cli/validate_test.go b/pkg/cli/validate_test.go index fdbd864a..c19b90a9 100644 --- a/pkg/cli/validate_test.go +++ b/pkg/cli/validate_test.go @@ -99,18 +99,18 @@ func TestValidateCommand(t *testing.T) { }{ { name: "success", - args: []string{"-log", validLog}, + args: []string{"-log-entry", validLog}, expOut: `Successfully validated log`, }, { name: "from_stdin", - args: []string{"-log", "-"}, + args: []string{"-log-entry", "-"}, stdin: strings.NewReader(validLog), expOut: `Successfully validated log`, }, { name: "additional_check", - args: []string{"-log", validLog, "-additional-check"}, + args: []string{"-log-entry", validLog, "-additional-check"}, expOut: `Successfully validated log`, }, { @@ -125,12 +125,12 @@ func TestValidateCommand(t *testing.T) { }, { name: "invalid_json", - args: []string{"-log", "invalid"}, + args: []string{"-log-entry", "invalid"}, expErr: "failed to validate log", }, { name: "additional_check_fail", - args: []string{"-log", missingLabel, "-additional-check"}, + args: []string{"-log-entry", missingLabel, "-additional-check"}, expErr: `missing required label`, }, } From 89e62c74effd21f420375c766c897249ac66c374 Mon Sep 17 00:00:00 2001 From: Suhong Qin Date: Thu, 10 Aug 2023 02:01:01 +0000 Subject: [PATCH 4/8] update description --- pkg/cli/root_test.go | 2 +- pkg/cli/tail.go | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/pkg/cli/root_test.go b/pkg/cli/root_test.go index 3f489dee..649d0799 100644 --- a/pkg/cli/root_test.go +++ b/pkg/cli/root_test.go @@ -25,7 +25,7 @@ func TestRootCommand_Help(t *testing.T) { exp := ` Usage: lumberctl COMMAND - tail Tail lumberjack logs from Cloud logging and validate them when validation enabled + tail Tail lumberjack logs from GCP Cloud logging validate Validate lumberjack log ` diff --git a/pkg/cli/tail.go b/pkg/cli/tail.go index 39ca5bb4..32edbfd5 100644 --- a/pkg/cli/tail.go +++ b/pkg/cli/tail.go @@ -66,7 +66,7 @@ type TailCommand struct { } func (c *TailCommand) Desc() string { - return `Tail lumberjack logs from Cloud logging and validate them when validation enabled` + return `Tail lumberjack logs from GCP Cloud logging` } func (c *TailCommand) Help() string { From 6c69e8ac8d01c26811ace5af29c4b0a43804d6b0 Mon Sep 17 00:00:00 2001 From: Suhong Qin Date: Thu, 10 Aug 2023 20:48:28 +0000 Subject: [PATCH 5/8] address comments --- pkg/cli/tail.go | 121 ++++++++++++++++++++++--------------------- pkg/cli/tail_test.go | 54 +++++++++++-------- 2 files changed, 95 insertions(+), 80 deletions(-) diff --git a/pkg/cli/tail.go b/pkg/cli/tail.go index 32edbfd5..3eb51462 100644 --- a/pkg/cli/tail.go +++ b/pkg/cli/tail.go @@ -47,7 +47,7 @@ var _ cli.Command = (*TailCommand)(nil) type TailCommand struct { cli.BaseCommand - flagResource string + flagScope string flagValidate bool @@ -55,11 +55,11 @@ type TailCommand struct { flagDuration time.Duration - flagCustomQuery string + flagAdditionalFilter string - flagRemoveLumberjackLogType bool + flagOverrideFilter string - flagValidateWithAdditionalCheck bool + flagAdditionalCheck bool // For testing only. testPuller logPuller @@ -73,21 +73,21 @@ func (c *TailCommand) Help() string { return ` Usage: {{ COMMAND }} [options] -Tails and validates the latest lumberjack log in the last 24 hours from resource: +Tails and validates the latest lumberjack log in the last 2 hours in the scope: - {{ COMMAND }} -resource "project/foo" -validate + {{ COMMAND }} -scope "project/foo" -validate -Tails the latest lumberjack log filtered by additional custom query: +Tails the latest lumberjack log filtered by additional custom log filter: - {{ COMMAND }} -resource "project/foo" -query "resource.type = \"foo\"" + {{ COMMAND }} -scope "project/foo" -additional-filter "resource.type = \"foo\"" -Tails and validates (with additional check) the latest 10 lumberjack log in the last 2 hours from resource: +Tails and validates (with additional check) the latest 10 lumberjack log in the last 4 hours in the scope: - {{ COMMAND }} -resource "project/foo" -max-num 10 -duration 2h -validate-with-additional-check + {{ COMMAND }} -scope "project/foo" -max-num 10 -duration 4h -validate -additional-check -Pulls and validates the latest non-lumberjack log type log: +Tails and validates the latest log using override log filter only: - {{ COMMAND }} -resource "project/foo" -remove-lumberjack-log-type + {{ COMMAND }} -scope "project/foo" -override-filter "YOUR_FILTER" ` } @@ -98,12 +98,12 @@ func (c *TailCommand) Flags() *cli.FlagSet { f := set.NewSection("COMMAND OPTIONS") f.StringVar(&cli.StringVar{ - Name: "resource", - Aliases: []string{"r"}, - Target: &c.flagResource, + Name: "scope", + Aliases: []string{"s"}, + Target: &c.flagScope, Example: `projects/foo`, - Usage: `Name of the parent resource from which to retrieve log entries,` + - `examples are: projects/[PROJECT_ID], folders/[FOLDER_ID],` + + Usage: `Name of the scope/parent resource from which to retrieve log ` + + `entries, examples are: projects/[PROJECT_ID], folders/[FOLDER_ID],` + `organizations/[ORGANIZATION_ID], billingAccounts/[BILLING_ACCOUNT_ID]`, }) @@ -127,32 +127,35 @@ func (c *TailCommand) Flags() *cli.FlagSet { Name: "duration", Aliases: []string{"d"}, Target: &c.flagDuration, - Example: "2h", - Default: 24 * time.Hour, - Usage: `How far back to search for log entries, default is 24 hours`, + Example: "4h", + Default: 2 * time.Hour, + Usage: `Log filter that determines how far back to search for log ` + + `entries, default is 2 hours`, }) f.StringVar(&cli.StringVar{ - Name: "query", - Target: &c.flagCustomQuery, + Name: "additional-filter", + Target: &c.flagAdditionalFilter, Example: `resource.type = "gae_app" AND severity = ERROR`, - Usage: `Optional custom log queries, see more on ` + + Usage: `Log filter in addition to lumberjack log filter used to tail ` + + `log entries, see more on ` + `https://cloud.google.com/logging/docs/view/logging-query-language`, }) - f.BoolVar(&cli.BoolVar{ - Name: "remove-lumberjack-log-type", - Target: &c.flagRemoveLumberjackLogType, - Default: false, - Usage: `Turn on to remove lumberjack log type log filter`, + f.StringVar(&cli.StringVar{ + Name: "override-filter", + Target: &c.flagOverrideFilter, + Hidden: true, + Usage: `Override lumberjack log filter, when it is used, it will be ` + + `the only filter used to tail logs`, }) f.BoolVar(&cli.BoolVar{ - Name: "validate-with-additional-check", - Target: &c.flagValidateWithAdditionalCheck, + Name: "additional-check", + Target: &c.flagAdditionalCheck, Default: false, - Usage: `Turn on for lumberjack log validation with additional ` + - `lumberjack specific checks on log labels.`, + Usage: `Use it with -validate flag to validate logs tailed with ` + + `additional lumberjack specific checks on log labels.`, }) return set @@ -168,13 +171,13 @@ func (c *TailCommand) Run(ctx context.Context, args []string) error { return fmt.Errorf("unexpected arguments: %q", args) } - if c.flagResource == "" { - return fmt.Errorf("resource is required") + if c.flagScope == "" { + return fmt.Errorf("scope is required") } // Request with negative and greater than 1000 (log count limit) is rejected. if c.flagMaxNum <= 0 || c.flagMaxNum > 1000 { - return fmt.Errorf("max number must be greater than 0 and less than 1000") + return fmt.Errorf("--max-num must be greater than 0 and less than 1000") } // Tail logs. @@ -183,15 +186,16 @@ func (c *TailCommand) Run(ctx context.Context, args []string) error { return err } if len(ls) == 0 { - c.Outf("Log not found") + c.Outf("No logs found.") return nil } - // Output results. var extra []validation.Validator - if c.flagValidateWithAdditionalCheck { + if c.flagAdditionalCheck { extra = append(extra, validation.ValidateLabels) } + + // Output results. var retErr error for _, l := range ls { js, err := protojson.Marshal(l) @@ -200,18 +204,18 @@ func (c *TailCommand) Run(ctx context.Context, args []string) error { continue } - // Output log entry in JSON format if validation is not enabled. - if !c.flagValidate && !c.flagValidateWithAdditionalCheck { - c.Outf(string(js)) - continue - } + // Output tailed log. + c.Outf(string(js)) // Output validation result if validation is enabled. - if err := validation.Validate(string(js), extra...); err != nil { - retErr = errors.Join(retErr, fmt.Errorf("failed to validate log (InsertId: %q): %w", l.InsertId, err)) - } else { - c.Outf("Successfully validated log (InsertId: %q)", l.InsertId) + if c.flagValidate { + if err := validation.Validate(string(js), extra...); err != nil { + retErr = errors.Join(retErr, fmt.Errorf("failed to validate log (InsertId: %q): %w", l.InsertId, err)) + } else { + c.Outf("Successfully validated log (InsertId: %q)", l.InsertId) + } } + c.Outf("\n") } return retErr @@ -226,10 +230,10 @@ func (c *TailCommand) tail(ctx context.Context) ([]*loggingpb.LogEntry, error) { if err != nil { return nil, fmt.Errorf("failed to create logging client: %w", err) } - p = cloudlogging.NewPuller(ctx, logClient, c.flagResource) + p = cloudlogging.NewPuller(ctx, logClient, c.flagScope) } - ls, err := p.Pull(ctx, c.getFilter(), c.flagMaxNum) + ls, err := p.Pull(ctx, c.queryFilter(), c.flagMaxNum) if err != nil { return nil, fmt.Errorf("failed to pull logs: %w", err) } @@ -237,18 +241,17 @@ func (c *TailCommand) tail(ctx context.Context) ([]*loggingpb.LogEntry, error) { return ls, nil } -func (c *TailCommand) getFilter() string { - cutoff := fmt.Sprintf("timestamp >= %q", time.Now().UTC().Add(-c.flagDuration).Format(time.RFC3339)) - - var f string - if c.flagRemoveLumberjackLogType { - f = cutoff - } else { - f = fmt.Sprintf("%s AND %s", logType, cutoff) +func (c *TailCommand) queryFilter() string { + // When override filter is set, use it only to query logs. + if c.flagOverrideFilter != "" { + return c.flagOverrideFilter } - if c.flagCustomQuery == "" { + cutoff := fmt.Sprintf("timestamp >= %q", time.Now().UTC().Add(-c.flagDuration).Format(time.RFC3339)) + f := fmt.Sprintf("%s AND %s", logType, cutoff) + + if c.flagAdditionalFilter == "" { return f } - return fmt.Sprintf("%s AND %s", f, c.flagCustomQuery) + return fmt.Sprintf("%s AND %s", f, c.flagAdditionalFilter) } diff --git a/pkg/cli/tail_test.go b/pkg/cli/tail_test.go index 46e163b5..a8da1c33 100644 --- a/pkg/cli/tail_test.go +++ b/pkg/cli/tail_test.go @@ -43,7 +43,7 @@ func TestTailCommand(t *testing.T) { }{ { name: "success_tail", - args: []string{"-resource", "projects/foo"}, + args: []string{"-scope", "projects/foo"}, puller: &fakePuller{ logEntries: []*loggingpb.LogEntry{{}}, }, @@ -54,7 +54,7 @@ func TestTailCommand(t *testing.T) { `LOG_ID("audit.abcxyz/consent") OR `+ `LOG_ID("audit.abcxyz/system_event") `+ `AND timestamp >= %q`, - ct.Add(-24*time.Hour).Format(time.RFC3339), + ct.Add(-2*time.Hour).Format(time.RFC3339), ), expMaxNum: 1, expOut: `{}`, @@ -62,9 +62,9 @@ func TestTailCommand(t *testing.T) { { name: "success_validate", args: []string{ - "-resource", "projects/foo", - "-duration", "2h", - "-query", `resource.type = "gae_app" AND severity = ERROR`, + "-scope", "projects/foo", + "-duration", "4h", + "-additional-filter", `resource.type = "gae_app" AND severity = ERROR`, "-validate", "-max-num", "2", }, @@ -97,16 +97,23 @@ func TestTailCommand(t *testing.T) { `LOG_ID("audit.abcxyz/system_event") `+ `AND timestamp >= %q AND resource.type = "gae_app" `+ `AND severity = ERROR`, - ct.Add(-2*time.Hour).Format(time.RFC3339), + ct.Add(-4*time.Hour).Format(time.RFC3339), ), expMaxNum: 2, - expOut: `Successfully validated log (InsertId: "test-log")`, + expOut: `{"jsonPayload":{"authentication_info":{"principal_email":"foo@bet.com"}, ` + + `"method_name":"foo_method", ` + + `"resource_name":"foo_resource", ` + + `"service_name":"foo_service"}, ` + + `"insertId":"test-log"} +Successfully validated log (InsertId: "test-log") + +`, }, { name: "success_validate_with_additional_check", args: []string{ - "-resource", "projects/foo", - "-validate-with-additional-check", + "-scope", "projects/foo", + "-validate", "-additional-check", }, puller: &fakePuller{ logEntries: []*loggingpb.LogEntry{ @@ -137,40 +144,45 @@ func TestTailCommand(t *testing.T) { `LOG_ID("audit.abcxyz/consent") OR `+ `LOG_ID("audit.abcxyz/system_event") `+ `AND timestamp >= %q`, - ct.Add(-24*time.Hour).Format(time.RFC3339), + ct.Add(-2*time.Hour).Format(time.RFC3339), ), expMaxNum: 1, - expOut: `Successfully validated log (InsertId: "test-log")`, + expOut: `{"jsonPayload":{"authentication_info":{"principal_email":"foo@bet.com"}, ` + + `"method_name":"foo_method", ` + + `"resource_name":"foo_resource", ` + + `"service_name":"foo_service"}, ` + + `"insertId":"test-log", ` + + `"labels":{"accessing_process_name":"foo_apn", "environment":"dev"}} +Successfully validated log (InsertId: "test-log") + +`, }, { name: "validate_fail", args: []string{ - "-resource", "projects/foo", - "-remove-lumberjack-log-type", + "-scope", "projects/foo", + "-override-filter", "test-filter", "-v", }, puller: &fakePuller{ logEntries: []*loggingpb.LogEntry{{InsertId: "test"}}, }, - expFilter: fmt.Sprintf( - `timestamp >= %q`, ct.Add(-24*time.Hour).Format(time.RFC3339), - ), + expFilter: "test-filter", expMaxNum: 1, + expOut: `{"insertId":"test"}`, expErrSubstr: "failed to validate log", }, { name: "tail_fail", args: []string{ - "-resource", "projects/foo", - "-remove-lumberjack-log-type", + "-scope", "projects/foo", + "-override-filter", "test-filter", }, puller: &fakePuller{ logEntries: []*loggingpb.LogEntry{{InsertId: "test"}}, injectErr: fmt.Errorf("injected error"), }, - expFilter: fmt.Sprintf( - `timestamp >= %q`, ct.Add(-24*time.Hour).Format(time.RFC3339), - ), + expFilter: "test-filter", expMaxNum: 1, expErrSubstr: "injected error", }, From 1558c276ed04736a4b11e597b39c5a46059c33ca Mon Sep 17 00:00:00 2001 From: Suhong Qin Date: Fri, 11 Aug 2023 01:53:27 +0000 Subject: [PATCH 6/8] address comments --- pkg/cli/tail.go | 34 ++++++----- pkg/cli/tail_test.go | 131 ++++++++++++++++++++++--------------------- 2 files changed, 82 insertions(+), 83 deletions(-) diff --git a/pkg/cli/tail.go b/pkg/cli/tail.go index 3eb51462..18e80019 100644 --- a/pkg/cli/tail.go +++ b/pkg/cli/tail.go @@ -16,7 +16,6 @@ package cli import ( "context" - "errors" "fmt" "time" @@ -75,19 +74,15 @@ Usage: {{ COMMAND }} [options] Tails and validates the latest lumberjack log in the last 2 hours in the scope: - {{ COMMAND }} -scope "project/foo" -validate + {{ COMMAND }} -scope "projects/foo" -validate Tails the latest lumberjack log filtered by additional custom log filter: - {{ COMMAND }} -scope "project/foo" -additional-filter "resource.type = \"foo\"" + {{ COMMAND }} -scope "projects/foo" -additional-filter "resource.type = \"foo\"" Tails and validates (with additional check) the latest 10 lumberjack log in the last 4 hours in the scope: - {{ COMMAND }} -scope "project/foo" -max-num 10 -duration 4h -validate -additional-check - -Tails and validates the latest log using override log filter only: - - {{ COMMAND }} -scope "project/foo" -override-filter "YOUR_FILTER" + {{ COMMAND }} -scope "projects/foo" -max-num 10 -duration 4h -validate -additional-check ` } @@ -120,7 +115,7 @@ func (c *TailCommand) Flags() *cli.FlagSet { Aliases: []string{"n"}, Target: &c.flagMaxNum, Default: 1, - Usage: `Maximum number of most recent logs to validate, default is 1`, + Usage: `Maximum number of most recent logs to validate`, }) f.DurationVar(&cli.DurationVar{ @@ -130,7 +125,7 @@ func (c *TailCommand) Flags() *cli.FlagSet { Example: "4h", Default: 2 * time.Hour, Usage: `Log filter that determines how far back to search for log ` + - `entries, default is 2 hours`, + `entries`, }) f.StringVar(&cli.StringVar{ @@ -177,7 +172,7 @@ func (c *TailCommand) Run(ctx context.Context, args []string) error { // Request with negative and greater than 1000 (log count limit) is rejected. if c.flagMaxNum <= 0 || c.flagMaxNum > 1000 { - return fmt.Errorf("--max-num must be greater than 0 and less than 1000") + return fmt.Errorf("-max-num must be greater than 0 and less than 1000") } // Tail logs. @@ -196,11 +191,12 @@ func (c *TailCommand) Run(ctx context.Context, args []string) error { } // Output results. - var retErr error + var failCount int for _, l := range ls { js, err := protojson.Marshal(l) if err != nil { - retErr = errors.Join(retErr, fmt.Errorf("failed to marshal log to json (InsertId: %q): %w", l.InsertId, err)) + failCount++ + c.Errf("failed to marshal log to json (InsertId: %q): %w", l.InsertId, err) continue } @@ -210,15 +206,17 @@ func (c *TailCommand) Run(ctx context.Context, args []string) error { // Output validation result if validation is enabled. if c.flagValidate { if err := validation.Validate(string(js), extra...); err != nil { - retErr = errors.Join(retErr, fmt.Errorf("failed to validate log (InsertId: %q): %w", l.InsertId, err)) + failCount++ + c.Errf("failed to validate log (InsertId: %q): %w\n", l.InsertId, err) } else { - c.Outf("Successfully validated log (InsertId: %q)", l.InsertId) + c.Outf("Successfully validated log (InsertId: %q)\n", l.InsertId) } } - c.Outf("\n") } - - return retErr + if c.flagValidate { + c.Outf("Validation failed for %d logs (out of %d)", failCount, len(ls)) + } + return nil } func (c *TailCommand) tail(ctx context.Context) ([]*loggingpb.LogEntry, error) { diff --git a/pkg/cli/tail_test.go b/pkg/cli/tail_test.go index a8da1c33..6f7d3658 100644 --- a/pkg/cli/tail_test.go +++ b/pkg/cli/tail_test.go @@ -24,6 +24,7 @@ import ( "cloud.google.com/go/logging/apiv2/loggingpb" "github.com/abcxyz/pkg/testutil" "github.com/google/go-cmp/cmp" + "google.golang.org/protobuf/encoding/protojson" "google.golang.org/protobuf/types/known/structpb" ) @@ -32,14 +33,39 @@ func TestTailCommand(t *testing.T) { ct := time.Now().UTC() + validLog := &loggingpb.LogEntry{ + InsertId: "test-log", + Payload: &loggingpb.LogEntry_JsonPayload{ + JsonPayload: &structpb.Struct{ + Fields: map[string]*structpb.Value{ + "service_name": structpb.NewStringValue("foo_service"), + "method_name": structpb.NewStringValue("foo_method"), + "resource_name": structpb.NewStringValue("foo_resource"), + "authentication_info": structpb.NewStructValue(&structpb.Struct{ + Fields: map[string]*structpb.Value{ + "principal_email": structpb.NewStringValue("foo@bet.com"), + }, + }), + }, + }, + }, + Labels: map[string]string{"environment": "dev", "accessing_process_name": "foo_apn"}, + } + + validLogJSON, err := protojson.Marshal(validLog) + if err != nil { + t.Fatalf("failed to mashal log to JSON: %v", err) + } + cases := []struct { - name string - args []string - puller *fakePuller - expFilter string - expMaxNum int - expOut string - expErrSubstr string + name string + args []string + puller *fakePuller + expFilter string + expMaxNum int + expOut string + expErrSubstr string + expStderrSubstr string }{ { name: "success_tail", @@ -69,25 +95,7 @@ func TestTailCommand(t *testing.T) { "-max-num", "2", }, puller: &fakePuller{ - logEntries: []*loggingpb.LogEntry{ - { - InsertId: "test-log", - Payload: &loggingpb.LogEntry_JsonPayload{ - JsonPayload: &structpb.Struct{ - Fields: map[string]*structpb.Value{ - "service_name": structpb.NewStringValue("foo_service"), - "method_name": structpb.NewStringValue("foo_method"), - "resource_name": structpb.NewStringValue("foo_resource"), - "authentication_info": structpb.NewStructValue(&structpb.Struct{ - Fields: map[string]*structpb.Value{ - "principal_email": structpb.NewStringValue("foo@bet.com"), - }, - }), - }, - }, - }, - }, - }, + logEntries: []*loggingpb.LogEntry{validLog}, }, expFilter: fmt.Sprintf( `LOG_ID("audit.abcxyz/unspecified") OR `+ @@ -100,14 +108,11 @@ func TestTailCommand(t *testing.T) { ct.Add(-4*time.Hour).Format(time.RFC3339), ), expMaxNum: 2, - expOut: `{"jsonPayload":{"authentication_info":{"principal_email":"foo@bet.com"}, ` + - `"method_name":"foo_method", ` + - `"resource_name":"foo_resource", ` + - `"service_name":"foo_service"}, ` + - `"insertId":"test-log"} + expOut: fmt.Sprintf(`%s Successfully validated log (InsertId: "test-log") -`, +Validation failed for 0 logs (out of 1) +`, validLogJSON), }, { name: "success_validate_with_additional_check", @@ -116,26 +121,7 @@ Successfully validated log (InsertId: "test-log") "-validate", "-additional-check", }, puller: &fakePuller{ - logEntries: []*loggingpb.LogEntry{ - { - InsertId: "test-log", - Payload: &loggingpb.LogEntry_JsonPayload{ - JsonPayload: &structpb.Struct{ - Fields: map[string]*structpb.Value{ - "service_name": structpb.NewStringValue("foo_service"), - "method_name": structpb.NewStringValue("foo_method"), - "resource_name": structpb.NewStringValue("foo_resource"), - "authentication_info": structpb.NewStructValue(&structpb.Struct{ - Fields: map[string]*structpb.Value{ - "principal_email": structpb.NewStringValue("foo@bet.com"), - }, - }), - }, - }, - }, - Labels: map[string]string{"environment": "dev", "accessing_process_name": "foo_apn"}, - }, - }, + logEntries: []*loggingpb.LogEntry{validLog}, }, expFilter: fmt.Sprintf( `LOG_ID("audit.abcxyz/unspecified") OR `+ @@ -147,15 +133,11 @@ Successfully validated log (InsertId: "test-log") ct.Add(-2*time.Hour).Format(time.RFC3339), ), expMaxNum: 1, - expOut: `{"jsonPayload":{"authentication_info":{"principal_email":"foo@bet.com"}, ` + - `"method_name":"foo_method", ` + - `"resource_name":"foo_resource", ` + - `"service_name":"foo_service"}, ` + - `"insertId":"test-log", ` + - `"labels":{"accessing_process_name":"foo_apn", "environment":"dev"}} + expOut: fmt.Sprintf(`%s Successfully validated log (InsertId: "test-log") -`, +Validation failed for 0 logs (out of 1) +`, validLogJSON), }, { name: "validate_fail", @@ -165,12 +147,21 @@ Successfully validated log (InsertId: "test-log") "-v", }, puller: &fakePuller{ - logEntries: []*loggingpb.LogEntry{{InsertId: "test"}}, + logEntries: []*loggingpb.LogEntry{ + {InsertId: "test"}, + validLog, + }, }, - expFilter: "test-filter", - expMaxNum: 1, - expOut: `{"insertId":"test"}`, - expErrSubstr: "failed to validate log", + expFilter: "test-filter", + expMaxNum: 1, + expOut: fmt.Sprintf(` +{"insertId":"test"} +%s +Successfully validated log (InsertId: "test-log") + +Validation failed for 1 logs (out of 2) +`, validLogJSON), + expStderrSubstr: `failed to validate log (InsertId: "test")`, }, { name: "tail_fail", @@ -198,12 +189,15 @@ Successfully validated log (InsertId: "test-log") var cmd TailCommand cmd.testPuller = tc.puller - _, stdout, _ := cmd.Pipe() + _, stdout, stderr := cmd.Pipe() err := cmd.Run(ctx, tc.args) if diff := testutil.DiffErrString(err, tc.expErrSubstr); diff != "" { t.Errorf("Process(%+v) got error diff (-want, +got):\n%s", tc.name, diff) } + if !errContainSubstring(stderr.String(), tc.expStderrSubstr) { + t.Errorf("Process(%+v) got stderr: %s, but want substring: %s", tc.name, stderr.String(), tc.expStderrSubstr) + } if diff := cmp.Diff(strings.TrimSpace(tc.expOut), strings.TrimSpace(stdout.String())); diff != "" { t.Errorf("Process(%+v) got output diff (-want, +got):\n%s", tc.name, diff) } @@ -217,6 +211,13 @@ Successfully validated log (InsertId: "test-log") } } +func errContainSubstring(gotErr, wantErr string) bool { + if wantErr == "" { + return gotErr == "" + } + return strings.Contains(gotErr, wantErr) +} + type fakePuller struct { injectErr error gotFilter string From 0209780047c8e9ade0b26213caed3cfb00709e82 Mon Sep 17 00:00:00 2001 From: Suhong Qin Date: Fri, 11 Aug 2023 20:21:27 +0000 Subject: [PATCH 7/8] fix potential unit test flakiness --- pkg/cli/tail.go | 7 +++++-- pkg/cli/tail_test.go | 3 ++- 2 files changed, 7 insertions(+), 3 deletions(-) diff --git a/pkg/cli/tail.go b/pkg/cli/tail.go index 18e80019..889922de 100644 --- a/pkg/cli/tail.go +++ b/pkg/cli/tail.go @@ -17,6 +17,7 @@ package cli import ( "context" "fmt" + "strings" "time" "cloud.google.com/go/logging/apiv2/loggingpb" @@ -200,8 +201,10 @@ func (c *TailCommand) Run(ctx context.Context, args []string) error { continue } - // Output tailed log. - c.Outf(string(js)) + // Output tailed log, all spaces are stripped to reduce unit test flakiness + // as protojson.Marshal can produce inconsistent output. See issue + // https://github.com/golang/protobuf/issues/1121. + c.Outf(strings.Replace(string(js), " ", "", -1)) // Output validation result if validation is enabled. if c.flagValidate { diff --git a/pkg/cli/tail_test.go b/pkg/cli/tail_test.go index 6f7d3658..bd1427b8 100644 --- a/pkg/cli/tail_test.go +++ b/pkg/cli/tail_test.go @@ -52,10 +52,11 @@ func TestTailCommand(t *testing.T) { Labels: map[string]string{"environment": "dev", "accessing_process_name": "foo_apn"}, } - validLogJSON, err := protojson.Marshal(validLog) + bs, err := protojson.Marshal(validLog) if err != nil { t.Fatalf("failed to mashal log to JSON: %v", err) } + validLogJSON := strings.Replace(string(bs), " ", "", -1) cases := []struct { name string From dfdc941e26f3e8a4937177ff13e31a47999655bf Mon Sep 17 00:00:00 2001 From: Suhong Qin Date: Fri, 11 Aug 2023 20:41:16 +0000 Subject: [PATCH 8/8] fix comments --- pkg/cli/tail.go | 6 +++++- pkg/cli/tail_test.go | 13 ++++++------- 2 files changed, 11 insertions(+), 8 deletions(-) diff --git a/pkg/cli/tail.go b/pkg/cli/tail.go index 889922de..3c299340 100644 --- a/pkg/cli/tail.go +++ b/pkg/cli/tail.go @@ -204,7 +204,7 @@ func (c *TailCommand) Run(ctx context.Context, args []string) error { // Output tailed log, all spaces are stripped to reduce unit test flakiness // as protojson.Marshal can produce inconsistent output. See issue // https://github.com/golang/protobuf/issues/1121. - c.Outf(strings.Replace(string(js), " ", "", -1)) + c.Outf(stripSpaces(string(js))) // Output validation result if validation is enabled. if c.flagValidate { @@ -256,3 +256,7 @@ func (c *TailCommand) queryFilter() string { } return fmt.Sprintf("%s AND %s", f, c.flagAdditionalFilter) } + +func stripSpaces(s string) string { + return strings.Replace(s, " ", "", -1) +} diff --git a/pkg/cli/tail_test.go b/pkg/cli/tail_test.go index bd1427b8..810840d9 100644 --- a/pkg/cli/tail_test.go +++ b/pkg/cli/tail_test.go @@ -23,7 +23,6 @@ import ( "cloud.google.com/go/logging/apiv2/loggingpb" "github.com/abcxyz/pkg/testutil" - "github.com/google/go-cmp/cmp" "google.golang.org/protobuf/encoding/protojson" "google.golang.org/protobuf/types/known/structpb" ) @@ -56,7 +55,7 @@ func TestTailCommand(t *testing.T) { if err != nil { t.Fatalf("failed to mashal log to JSON: %v", err) } - validLogJSON := strings.Replace(string(bs), " ", "", -1) + validLogJSON := stripSpaces(string(bs)) cases := []struct { name string @@ -197,13 +196,13 @@ Validation failed for 1 logs (out of 2) t.Errorf("Process(%+v) got error diff (-want, +got):\n%s", tc.name, diff) } if !errContainSubstring(stderr.String(), tc.expStderrSubstr) { - t.Errorf("Process(%+v) got stderr: %s, but want substring: %s", tc.name, stderr.String(), tc.expStderrSubstr) + t.Errorf("Process(%+v) got stderr: %q, but want substring: %q", tc.name, stderr.String(), tc.expStderrSubstr) } - if diff := cmp.Diff(strings.TrimSpace(tc.expOut), strings.TrimSpace(stdout.String())); diff != "" { - t.Errorf("Process(%+v) got output diff (-want, +got):\n%s", tc.name, diff) + if strings.TrimSpace(tc.expOut) != strings.TrimSpace(stdout.String()) { + t.Errorf("Process(%+v) got output: %q, but want output: %q", tc.name, stdout.String(), tc.expOut) } - if diff := cmp.Diff(tc.expFilter, tc.puller.gotFilter); diff != "" { - t.Errorf("Process(%+v) got filter diff (-want, +got):\n%s", tc.name, diff) + if strings.TrimSpace(tc.expFilter) != strings.TrimSpace(tc.puller.gotFilter) { + t.Errorf("Process(%+v) got filter: %q, but want output: %q", tc.name, tc.puller.gotFilter, tc.expFilter) } if tc.expMaxNum != tc.puller.gotMaxNum { t.Errorf("Process(%+v) want max number %q but got %q", tc.name, tc.expMaxNum, tc.puller.gotMaxNum)