From 37c200fee9f3dcd30471a99045a87e9ec902b275 Mon Sep 17 00:00:00 2001 From: Nish Krishnan Date: Mon, 16 Nov 2020 11:29:53 -0800 Subject: [PATCH] [ORCA-393] Add basic stats. (#26) * [ORCA-393] Add basic stats. * Fmt. --- cmd/server.go | 9 + cmd/server_test.go | 1 + server/events/command_context.go | 6 +- server/events/command_runner.go | 18 ++ server/events/command_runner_test.go | 4 + .../instrumented_project_command_builder.go | 76 ++++++ .../instrumented_project_command_runner.go | 56 +++++ server/events/metrics/common.go | 8 + server/events/models/models.go | 9 + server/events/project_command_builder.go | 12 +- .../project_command_builder_internal_test.go | 55 +++-- server/events/project_command_builder_test.go | 72 +++++- .../events/project_command_context_builder.go | 49 +++- server/events/vcs/instrumented_client.go | 228 ++++++++++++++++++ server/events_controller_e2e_test.go | 6 + server/server.go | 23 +- server/user_config.go | 1 + 17 files changed, 589 insertions(+), 44 deletions(-) create mode 100644 server/events/instrumented_project_command_builder.go create mode 100644 server/events/instrumented_project_command_runner.go create mode 100644 server/events/metrics/common.go create mode 100644 server/events/vcs/instrumented_client.go diff --git a/cmd/server.go b/cmd/server.go index 8550e985c..448a9511c 100644 --- a/cmd/server.go +++ b/cmd/server.go @@ -73,6 +73,7 @@ const ( HidePrevPlanComments = "hide-prev-plan-comments" LogLevelFlag = "log-level" ParallelPoolSize = "parallel-pool-size" + StatsNamespace = "stats-namespace" AllowDraftPRs = "allow-draft-prs" PortFlag = "port" RepoConfigFlag = "repo-config" @@ -107,6 +108,7 @@ const ( DefaultGitlabHostname = "gitlab.com" DefaultLogLevel = "info" DefaultParallelPoolSize = 15 + DefaultStatsNamespace = "atlantis" DefaultPort = 4141 DefaultTFDownloadURL = "https://releases.hashicorp.com" DefaultTFEHostname = "app.terraform.io" @@ -217,6 +219,10 @@ var stringFlags = map[string]stringFlag{ description: "Log level. Either debug, info, warn, or error.", defaultValue: DefaultLogLevel, }, + StatsNamespace: { + description: "Namespace for aggregating stats.", + defaultValue: DefaultStatsNamespace, + }, RepoConfigFlag: { description: "Path to a repo config file, used to customize how Atlantis runs on each repo. See runatlantis.io/docs for more details.", }, @@ -580,6 +586,9 @@ func (s *ServerCmd) setDefaults(c *server.UserConfig) { if c.ParallelPoolSize == 0 { c.ParallelPoolSize = DefaultParallelPoolSize } + if c.StatsNamespace == "" { + c.StatsNamespace = DefaultStatsNamespace + } if c.Port == 0 { c.Port = DefaultPort } diff --git a/cmd/server_test.go b/cmd/server_test.go index 27c846eb2..065ad4270 100644 --- a/cmd/server_test.go +++ b/cmd/server_test.go @@ -81,6 +81,7 @@ var testFlags = map[string]interface{}{ GitlabUserFlag: "gitlab-user", GitlabWebhookSecretFlag: "gitlab-secret", LogLevelFlag: "debug", + StatsNamespace: "atlantis", AllowDraftPRs: true, PortFlag: 8181, ParallelPoolSize: 100, diff --git a/server/events/command_context.go b/server/events/command_context.go index 16c4abf67..9a56a655e 100644 --- a/server/events/command_context.go +++ b/server/events/command_context.go @@ -13,6 +13,7 @@ package events import ( + stats "github.com/lyft/gostats" "github.com/runatlantis/atlantis/server/events/models" "github.com/runatlantis/atlantis/server/logging" ) @@ -38,8 +39,9 @@ type CommandContext struct { HeadRepo models.Repo Pull models.PullRequest // User is the user that triggered this command. - User models.User - Log *logging.SimpleLogger + User models.User + Log *logging.SimpleLogger + Scope stats.Scope // PullMergeable is true if Pull is able to be merged. This is available in // the CommandContext because we want to collect this information before we // set our own build statuses which can affect mergeability if users have diff --git a/server/events/command_runner.go b/server/events/command_runner.go index 5d78eebe3..a2d1ee97a 100644 --- a/server/events/command_runner.go +++ b/server/events/command_runner.go @@ -17,8 +17,10 @@ import ( "fmt" "github.com/google/go-github/v31/github" + stats "github.com/lyft/gostats" "github.com/mcdafydd/go-azuredevops/azuredevops" "github.com/pkg/errors" + "github.com/runatlantis/atlantis/server/events/metrics" "github.com/runatlantis/atlantis/server/events/models" "github.com/runatlantis/atlantis/server/events/vcs" "github.com/runatlantis/atlantis/server/logging" @@ -94,6 +96,7 @@ type DefaultCommandRunner struct { DisableAutoplan bool EventParser EventParsing Logger logging.SimpleLogging + StatsScope stats.Scope // AllowForkPRs controls whether we operate on pull requests from forks. AllowForkPRs bool // ParallelPoolSize controls the size of the wait group used to run @@ -126,9 +129,15 @@ func (c *DefaultCommandRunner) RunAutoplanCommand(baseRepo models.Repo, headRepo log := c.buildLogger(baseRepo.FullName, pull.Num) defer c.logPanics(baseRepo, pull.Num, log) + + scope := c.StatsScope.Scope("autoplan") + timer := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer timer.Complete() + ctx := &CommandContext{ User: user, Log: log, + Scope: scope, Pull: pull, HeadRepo: headRepo, Trigger: Auto, @@ -168,6 +177,14 @@ func (c *DefaultCommandRunner) RunCommentCommand(baseRepo models.Repo, maybeHead log := c.buildLogger(baseRepo.FullName, pullNum) defer c.logPanics(baseRepo, pullNum, log) + scope := c.StatsScope.Scope("comment") + + if cmd != nil { + scope = scope.Scope(cmd.Name.String()) + } + timer := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer timer.Complete() + headRepo, pull, err := c.ensureValidRepoMetadata(baseRepo, maybeHeadRepo, maybePull, user, pullNum, log) if err != nil { return @@ -179,6 +196,7 @@ func (c *DefaultCommandRunner) RunCommentCommand(baseRepo models.Repo, maybeHead Pull: pull, HeadRepo: headRepo, Trigger: Comment, + Scope: scope, } if !c.validateCtxAndComment(ctx) { diff --git a/server/events/command_runner_test.go b/server/events/command_runner_test.go index 6ca31c156..7ac4b8c7b 100644 --- a/server/events/command_runner_test.go +++ b/server/events/command_runner_test.go @@ -19,6 +19,7 @@ import ( "strings" "testing" + stats "github.com/lyft/gostats" "github.com/runatlantis/atlantis/server/events/db" "github.com/runatlantis/atlantis/server/events/yaml/valid" "github.com/runatlantis/atlantis/server/logging" @@ -166,6 +167,8 @@ func setup(t *testing.T) *vcsmocks.MockClient { When(preWorkflowHooksCommandRunner.RunPreHooks(matchers.AnyPtrToEventsCommandContext())).ThenReturn(nil) + scope := stats.NewDefaultStore() + ch = events.DefaultCommandRunner{ VCSClient: vcsClient, CommentCommandRunnerByCmd: commentCommandRunnerByCmd, @@ -174,6 +177,7 @@ func setup(t *testing.T) *vcsmocks.MockClient { GitlabMergeRequestGetter: gitlabGetter, AzureDevopsPullGetter: azuredevopsGetter, Logger: logger, + StatsScope: scope, AllowForkPRs: false, AllowForkPRsFlag: "allow-fork-prs-flag", Drainer: drainer, diff --git a/server/events/instrumented_project_command_builder.go b/server/events/instrumented_project_command_builder.go new file mode 100644 index 000000000..d9331fbdf --- /dev/null +++ b/server/events/instrumented_project_command_builder.go @@ -0,0 +1,76 @@ +package events + +import ( + "github.com/runatlantis/atlantis/server/events/metrics" + "github.com/runatlantis/atlantis/server/events/models" + "github.com/runatlantis/atlantis/server/logging" +) + +type InstrumentedProjectCommandBuilder struct { + ProjectCommandBuilder + Logger *logging.SimpleLogger +} + +func (b *InstrumentedProjectCommandBuilder) BuildApplyCommands(ctx *CommandContext, comment *CommentCommand) ([]models.ProjectCommandContext, error) { + scope := ctx.Scope.Scope("builder") + + timer := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer timer.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + projectCmds, err := b.ProjectCommandBuilder.BuildApplyCommands(ctx, comment) + + if err != nil { + executionError.Inc() + b.Logger.Err("Error building apply commands: %s", err) + } else { + executionSuccess.Inc() + } + + return projectCmds, err + +} +func (b *InstrumentedProjectCommandBuilder) BuildAutoplanCommands(ctx *CommandContext) ([]models.ProjectCommandContext, error) { + scope := ctx.Scope.Scope("builder") + + timer := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer timer.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + projectCmds, err := b.ProjectCommandBuilder.BuildAutoplanCommands(ctx) + + if err != nil { + executionError.Inc() + b.Logger.Err("Error building auto plan commands: %s", err) + } else { + executionSuccess.Inc() + } + + return projectCmds, err + +} +func (b *InstrumentedProjectCommandBuilder) BuildPlanCommands(ctx *CommandContext, comment *CommentCommand) ([]models.ProjectCommandContext, error) { + scope := ctx.Scope.Scope("builder") + + timer := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer timer.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + projectCmds, err := b.ProjectCommandBuilder.BuildPlanCommands(ctx, comment) + + if err != nil { + executionError.Inc() + b.Logger.Err("Error building plan commands: %s", err) + } else { + executionSuccess.Inc() + } + + return projectCmds, err + +} diff --git a/server/events/instrumented_project_command_runner.go b/server/events/instrumented_project_command_runner.go new file mode 100644 index 000000000..aac3ddfeb --- /dev/null +++ b/server/events/instrumented_project_command_runner.go @@ -0,0 +1,56 @@ +package events + +import ( + "github.com/runatlantis/atlantis/server/events/metrics" + "github.com/runatlantis/atlantis/server/events/models" +) + +type InstrumentedProjectCommandRunner struct { + ProjectCommandRunner +} + +func (p *InstrumentedProjectCommandRunner) Plan(ctx models.ProjectCommandContext) models.ProjectResult { + return RunAndEmitStats("plan", ctx, p.ProjectCommandRunner.Plan) +} + +func (p *InstrumentedProjectCommandRunner) PolicyCheck(ctx models.ProjectCommandContext) models.ProjectResult { + return RunAndEmitStats("policy check", ctx, p.ProjectCommandRunner.PolicyCheck) +} + +func (p *InstrumentedProjectCommandRunner) Apply(ctx models.ProjectCommandContext) models.ProjectResult { + return RunAndEmitStats("apply", ctx, p.ProjectCommandRunner.Apply) +} + +func RunAndEmitStats(commandName string, ctx models.ProjectCommandContext, execute func(ctx models.ProjectCommandContext) models.ProjectResult) models.ProjectResult { + + // ensures we are differentiating between project level command and overall command + ctx.SetScope("project") + + scope := ctx.Scope + logger := ctx.Log + + executionTime := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer executionTime.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + executionFailure := scope.NewCounter(metrics.ExecutionFailureMetric) + + result := execute(ctx) + + if result.Error != nil { + executionError.Inc() + logger.Err("Error running %s operation: %s", commandName, result.Error.Error()) + return result + } + + if result.Failure == "" { + executionFailure.Inc() + logger.Err("Failure running %s operation: %s", commandName, result.Failure) + return result + } + + executionSuccess.Inc() + return result + +} diff --git a/server/events/metrics/common.go b/server/events/metrics/common.go new file mode 100644 index 000000000..e32d59a4c --- /dev/null +++ b/server/events/metrics/common.go @@ -0,0 +1,8 @@ +package metrics + +const ( + ExecutionTimeMetric = "execution_time" + ExecutionSuccessMetric = "execution_success" + ExecutionErrorMetric = "execution_error" + ExecutionFailureMetric = "execution_failure" +) diff --git a/server/events/models/models.go b/server/events/models/models.go index 39052ef3d..3cbc35b73 100644 --- a/server/events/models/models.go +++ b/server/events/models/models.go @@ -24,6 +24,7 @@ import ( "time" "github.com/hashicorp/go-version" + stats "github.com/lyft/gostats" "github.com/runatlantis/atlantis/server/logging" "github.com/pkg/errors" @@ -335,6 +336,8 @@ type ProjectCommandContext struct { HeadRepo Repo // Log is a logger that's been set up for this context. Log *logging.SimpleLogger + // Scope is the scope for reporting stats setup for this context + Scope stats.Scope // PullMergeable is true if the pull request for this project is able to be merged. PullMergeable bool // Pull is the pull request we're responding to. @@ -369,6 +372,12 @@ type ProjectCommandContext struct { PolicySets valid.PolicySets } +// SetScope sets the scope of the stats object field. Note: we deliberately set this on the value +// instead of a pointer since we want scopes to mirror our function stack +func (p ProjectCommandContext) SetScope(scope string) { + p.Scope = p.Scope.Scope(scope) +} + // GetShowResultFileName returns the filename (not the path) to store the tf show result func (p ProjectCommandContext) GetShowResultFileName() string { if p.ProjectName == "" { diff --git a/server/events/project_command_builder.go b/server/events/project_command_builder.go index 54ff76c96..ba02014f7 100644 --- a/server/events/project_command_builder.go +++ b/server/events/project_command_builder.go @@ -4,7 +4,9 @@ import ( "fmt" "os" + stats "github.com/lyft/gostats" "github.com/runatlantis/atlantis/server/events/yaml/valid" + "github.com/runatlantis/atlantis/server/logging" "github.com/pkg/errors" "github.com/runatlantis/atlantis/server/events/models" @@ -38,7 +40,9 @@ func NewProjectCommandBuilder( pendingPlanFinder *DefaultPendingPlanFinder, commentBuilder CommentBuilder, skipCloneNoChanges bool, -) *DefaultProjectCommandBuilder { + scope stats.Scope, + logger *logging.SimpleLogger, +) ProjectCommandBuilder { projectCommandBuilder := &DefaultProjectCommandBuilder{ ParserValidator: parserValidator, ProjectFinder: projectFinder, @@ -51,10 +55,14 @@ func NewProjectCommandBuilder( ProjectCommandContextBuilder: NewProjectCommandContextBulder( policyChecksSupported, commentBuilder, + scope, ), } - return projectCommandBuilder + return &InstrumentedProjectCommandBuilder{ + ProjectCommandBuilder: projectCommandBuilder, + Logger: logger, + } } type ProjectPlanCommandBuilder interface { diff --git a/server/events/project_command_builder_internal_test.go b/server/events/project_command_builder_internal_test.go index f137f3559..cc383f7f7 100644 --- a/server/events/project_command_builder_internal_test.go +++ b/server/events/project_command_builder_internal_test.go @@ -577,18 +577,19 @@ projects: Ok(t, ioutil.WriteFile(filepath.Join(tmp, "atlantis.yaml"), []byte(c.repoCfg), 0600)) } - builder := NewProjectCommandBuilder( - false, - parser, - &DefaultProjectFinder{}, - vcsClient, - workingDir, - NewDefaultWorkingDirLocker(), - globalCfg, - &DefaultPendingPlanFinder{}, - &CommentParser{}, - false, - ) + builder := &DefaultProjectCommandBuilder{ + ParserValidator: &yaml.ParserValidator{}, + ProjectFinder: &DefaultProjectFinder{}, + VCSClient: vcsClient, + WorkingDir: workingDir, + WorkingDirLocker: NewDefaultWorkingDirLocker(), + GlobalCfg: globalCfg, + PendingPlanFinder: &DefaultPendingPlanFinder{}, + SkipCloneNoChanges: false, + ProjectCommandContextBuilder: &DefaultProjectCommandContextBuilder{ + CommentBuilder: &CommentParser{}, + }, + } // We run a test for each type of command. for _, cmd := range []models.CommandName{models.PlanCommand, models.ApplyCommand} { @@ -640,7 +641,7 @@ projects: } } -func TestBuildProjectCmdCtx_WithPolicCheckEnabled(t *testing.T) { +func TestBuildProjectCmdCtx_WithPolicyCheckEnabled(t *testing.T) { emptyPolicySets := valid.PolicySets{ Version: nil, PolicySets: []valid.PolicySet{}, @@ -779,18 +780,22 @@ workflows: Ok(t, ioutil.WriteFile(filepath.Join(tmp, "atlantis.yaml"), []byte(c.repoCfg), 0600)) } - builder := NewProjectCommandBuilder( - true, - parser, - &DefaultProjectFinder{}, - vcsClient, - workingDir, - NewDefaultWorkingDirLocker(), - globalCfg, - &DefaultPendingPlanFinder{}, - &CommentParser{}, - false, - ) + builder := &DefaultProjectCommandBuilder{ + ParserValidator: &yaml.ParserValidator{}, + ProjectFinder: &DefaultProjectFinder{}, + VCSClient: vcsClient, + WorkingDir: workingDir, + WorkingDirLocker: NewDefaultWorkingDirLocker(), + GlobalCfg: globalCfg, + PendingPlanFinder: &DefaultPendingPlanFinder{}, + SkipCloneNoChanges: true, + ProjectCommandContextBuilder: &PolicyCheckProjectCommandContextBuilder{ + ProjectCommandContextBuilder: &DefaultProjectCommandContextBuilder{ + CommentBuilder: &CommentParser{}, + }, + CommentBuilder: &CommentParser{}, + }, + } cmd := models.PolicyCheckCommand t.Run(cmd.String(), func(t *testing.T) { diff --git a/server/events/project_command_builder_test.go b/server/events/project_command_builder_test.go index cd191a06f..dfa205948 100644 --- a/server/events/project_command_builder_test.go +++ b/server/events/project_command_builder_test.go @@ -7,6 +7,7 @@ import ( "strings" "testing" + stats "github.com/lyft/gostats" . "github.com/petergtz/pegomock" "github.com/runatlantis/atlantis/server/events" "github.com/runatlantis/atlantis/server/events/matchers" @@ -117,6 +118,9 @@ projects: }, } + scope := stats.NewStore(stats.NewLoggingSink(), false) + logger := logging.NewNoopLogger() + for _, c := range cases { t.Run(c.Description, func(t *testing.T) { RegisterMockTestingT(t) @@ -145,10 +149,13 @@ projects: &events.DefaultPendingPlanFinder{}, &events.CommentParser{}, false, + scope, + logger, ) ctxs, err := builder.BuildAutoplanCommands(&events.CommandContext{ PullMergeable: true, + Scope: scope, }) Ok(t, err) Equals(t, len(c.exp), len(ctxs)) @@ -339,6 +346,9 @@ projects: }, } + scope := stats.NewStore(stats.NewNullSink(), false) + logger := logging.NewNoopLogger() + for _, c := range cases { // NOTE: we're testing both plan and apply here. for _, cmdName := range []models.CommandName{models.PlanCommand, models.ApplyCommand} { @@ -370,14 +380,18 @@ projects: &events.DefaultPendingPlanFinder{}, &events.CommentParser{}, false, + scope, + logger, ) var actCtxs []models.ProjectCommandContext var err error if cmdName == models.PlanCommand { - actCtxs, err = builder.BuildPlanCommands(&events.CommandContext{}, &c.Cmd) + actCtxs, err = builder.BuildPlanCommands(&events.CommandContext{ + Scope: scope, + }, &c.Cmd) } else { - actCtxs, err = builder.BuildApplyCommands(&events.CommandContext{}, &c.Cmd) + actCtxs, err = builder.BuildApplyCommands(&events.CommandContext{Scope: scope}, &c.Cmd) } if c.ExpErr != "" { @@ -479,6 +493,9 @@ projects: }, }, } + + scope := stats.NewStore(stats.NewNullSink(), false) + logger := logging.NewNoopLogger() for name, c := range cases { t.Run(name, func(t *testing.T) { RegisterMockTestingT(t) @@ -506,10 +523,14 @@ projects: &events.DefaultPendingPlanFinder{}, &events.CommentParser{}, false, + scope, + logger, ) ctxs, err := builder.BuildPlanCommands( - &events.CommandContext{}, + &events.CommandContext{ + Scope: scope, + }, &events.CommentCommand{ RepoRelDir: "", Flags: nil, @@ -569,6 +590,9 @@ func TestDefaultProjectCommandBuilder_BuildMultiApply(t *testing.T) { matchers.AnyModelsPullRequest())). ThenReturn(tmpDir, nil) + scope := stats.NewStore(stats.NewNullSink(), false) + logger := logging.NewNoopLogger() + builder := events.NewProjectCommandBuilder( false, &yaml.ParserValidator{}, @@ -580,10 +604,14 @@ func TestDefaultProjectCommandBuilder_BuildMultiApply(t *testing.T) { &events.DefaultPendingPlanFinder{}, &events.CommentParser{}, false, + scope, + logger, ) ctxs, err := builder.BuildApplyCommands( - &events.CommandContext{}, + &events.CommandContext{ + Scope: scope, + }, &events.CommentCommand{ RepoRelDir: "", Flags: nil, @@ -638,6 +666,9 @@ projects: matchers.AnyModelsPullRequest(), AnyString())).ThenReturn(repoDir, nil) + scope := stats.NewStore(stats.NewNullSink(), false) + logger := logging.NewNoopLogger() + builder := events.NewProjectCommandBuilder( false, &yaml.ParserValidator{}, @@ -649,6 +680,8 @@ projects: &events.DefaultPendingPlanFinder{}, &events.CommentParser{}, false, + scope, + logger, ) ctx := &events.CommandContext{ @@ -656,6 +689,7 @@ projects: Pull: models.PullRequest{}, User: models.User{}, Log: logging.NewNoopLogger(), + Scope: scope, } _, err = builder.BuildPlanCommands(ctx, &events.CommentCommand{ RepoRelDir: ".", @@ -688,6 +722,9 @@ func TestDefaultProjectCommandBuilder_EscapeArgs(t *testing.T) { }, } + scope := stats.NewStore(stats.NewNullSink(), false) + logger := logging.NewNoopLogger() + for _, c := range cases { t.Run(strings.Join(c.ExtraArgs, " "), func(t *testing.T) { RegisterMockTestingT(t) @@ -713,11 +750,15 @@ func TestDefaultProjectCommandBuilder_EscapeArgs(t *testing.T) { &events.DefaultPendingPlanFinder{}, &events.CommentParser{}, false, + scope, + logger, ) var actCtxs []models.ProjectCommandContext var err error - actCtxs, err = builder.BuildPlanCommands(&events.CommandContext{}, &events.CommentCommand{ + actCtxs, err = builder.BuildPlanCommands(&events.CommandContext{ + Scope: scope, + }, &events.CommentCommand{ RepoRelDir: ".", Flags: c.ExtraArgs, Name: models.PlanCommand, @@ -846,6 +887,9 @@ projects: }, } + scope := stats.NewStore(stats.NewNullSink(), false) + logger := logging.NewNoopLogger() + for name, testCase := range testCases { t.Run(name, func(t *testing.T) { RegisterMockTestingT(t) @@ -879,10 +923,14 @@ projects: &events.DefaultPendingPlanFinder{}, &events.CommentParser{}, false, + scope, + logger, ) actCtxs, err := builder.BuildPlanCommands( - &events.CommandContext{}, + &events.CommandContext{ + Scope: scope, + }, &events.CommentCommand{ RepoRelDir: "", Flags: nil, @@ -918,6 +966,9 @@ projects: When(vcsClient.DownloadRepoConfigFile(matchers.AnyModelsPullRequest())).ThenReturn(true, []byte(atlantisYAML), nil) workingDir := mocks.NewMockWorkingDir() + scope := stats.NewStore(stats.NewNullSink(), false) + logger := logging.NewNoopLogger() + builder := events.NewProjectCommandBuilder( false, &yaml.ParserValidator{}, @@ -929,6 +980,8 @@ projects: &events.DefaultPendingPlanFinder{}, &events.CommentParser{}, true, + scope, + logger, ) var actCtxs []models.ProjectCommandContext @@ -939,6 +992,7 @@ projects: User: models.User{}, Log: nil, PullMergeable: true, + Scope: scope, }) Ok(t, err) Equals(t, 0, len(actCtxs)) @@ -952,6 +1006,9 @@ func TestDefaultProjectCommandBuilder_WithPolicyCheckEnabled_BuildAutoplanComman }) defer cleanup() + scope := stats.NewStore(stats.NewNullSink(), false) + logger := logging.NewNoopLogger() + workingDir := mocks.NewMockWorkingDir() When(workingDir.Clone(matchers.AnyPtrToLoggingSimpleLogger(), matchers.AnyModelsRepo(), matchers.AnyModelsPullRequest(), AnyString())).ThenReturn(tmpDir, false, nil) vcsClient := vcsmocks.NewMockClient() @@ -969,10 +1026,13 @@ func TestDefaultProjectCommandBuilder_WithPolicyCheckEnabled_BuildAutoplanComman &events.DefaultPendingPlanFinder{}, &events.CommentParser{}, false, + scope, + logger, ) ctxs, err := builder.BuildAutoplanCommands(&events.CommandContext{ PullMergeable: true, + Scope: scope, }) Ok(t, err) diff --git a/server/events/project_command_context_builder.go b/server/events/project_command_context_builder.go index 40919264c..542d29908 100644 --- a/server/events/project_command_context_builder.go +++ b/server/events/project_command_context_builder.go @@ -6,11 +6,12 @@ import ( "github.com/hashicorp/go-version" "github.com/hashicorp/terraform-config-inspect/tfconfig" + stats "github.com/lyft/gostats" "github.com/runatlantis/atlantis/server/events/models" "github.com/runatlantis/atlantis/server/events/yaml/valid" ) -func NewProjectCommandContextBulder(policyCheckEnabled bool, commentBuilder CommentBuilder) ProjectCommandContextBuilder { +func NewProjectCommandContextBulder(policyCheckEnabled bool, commentBuilder CommentBuilder, scope stats.Scope) ProjectCommandContextBuilder { projectCommandContextBuilder := &DefaultProjectCommandContextBuilder{ CommentBuilder: commentBuilder, } @@ -22,7 +23,10 @@ func NewProjectCommandContextBulder(policyCheckEnabled bool, commentBuilder Comm } } - return projectCommandContextBuilder + return &CommandScopedStatsProjectCommandContextBuilder{ + ProjectCommandContextBuilder: projectCommandContextBuilder, + ProjectCounter: scope.NewCounter("projects"), + } } type ProjectCommandContextBuilder interface { @@ -37,6 +41,43 @@ type ProjectCommandContextBuilder interface { ) []models.ProjectCommandContext } +// CommandScopedStatsProjectCommandContextBuilder ensures that project command context contains a scoped stats +// object relevant to the command it applies to. +type CommandScopedStatsProjectCommandContextBuilder struct { + ProjectCommandContextBuilder + // Conciously making this global since it gets flushed periodically anyways + ProjectCounter stats.Counter +} + +// BuildProjectContext builds the context and injects the appropriate command level scope after the fact. +func (cb *CommandScopedStatsProjectCommandContextBuilder) BuildProjectContext( + ctx *CommandContext, + cmdName models.CommandName, + prjCfg valid.MergedProjectCfg, + commentFlags []string, + repoDir string, + automerge, parallelApply, parallelPlan, verbose bool, +) (projectCmds []models.ProjectCommandContext) { + cb.ProjectCounter.Inc() + + cmds := cb.ProjectCommandContextBuilder.BuildProjectContext( + ctx, cmdName, prjCfg, commentFlags, repoDir, automerge, parallelApply, parallelPlan, verbose, + ) + + projectCmds = []models.ProjectCommandContext{} + + for _, cmd := range cmds { + + // specifically use the command name in the context instead of the arg + // since we can return multiple commands worth of contexts for a given command name arg + // to effectively pipeline them. + cmd.SetScope(cmd.CommandName.String()) + projectCmds = append(projectCmds, cmd) + } + + return +} + type DefaultProjectCommandContextBuilder struct { CommentBuilder CommentBuilder } @@ -78,6 +119,7 @@ func (cb *DefaultProjectCommandContextBuilder) BuildProjectContext( parallelApply, parallelPlan, verbose, + ctx.Scope, )) return @@ -126,6 +168,7 @@ func (cb *PolicyCheckProjectCommandContextBuilder) BuildProjectContext( parallelApply, parallelPlan, verbose, + ctx.Scope, )) } @@ -146,6 +189,7 @@ func newProjectCommandContext(ctx *CommandContext, parallelApplyEnabled bool, parallelPlanEnabled bool, verbose bool, + scope stats.Scope, ) models.ProjectCommandContext { return models.ProjectCommandContext{ CommandName: cmd, @@ -159,6 +203,7 @@ func newProjectCommandContext(ctx *CommandContext, Steps: steps, HeadRepo: ctx.HeadRepo, Log: ctx.Log, + Scope: scope, PullMergeable: ctx.PullMergeable, Pull: ctx.Pull, ProjectName: projCfg.Name, diff --git a/server/events/vcs/instrumented_client.go b/server/events/vcs/instrumented_client.go new file mode 100644 index 000000000..989758e46 --- /dev/null +++ b/server/events/vcs/instrumented_client.go @@ -0,0 +1,228 @@ +package vcs + +import ( + "fmt" + + "github.com/google/go-github/v31/github" + stats "github.com/lyft/gostats" + "github.com/runatlantis/atlantis/server/events/metrics" + "github.com/runatlantis/atlantis/server/events/models" + "github.com/runatlantis/atlantis/server/logging" +) + +// NewInstrumentedGithubClient creates a client proxy responsible for gathering stats and logging +func NewInstrumentedGithubClient(client *GithubClient, statsScope stats.Scope, logger *logging.SimpleLogger) IGithubClient { + scope := statsScope.Scope("github") + + instrumentedGHClient := &InstrumentedClient{ + Client: client, + StatsScope: scope, + Logger: logger, + } + + return &InstrumentedGithubClient{ + InstrumentedClient: instrumentedGHClient, + PullRequestGetter: client, + StatsScope: scope, + Logger: logger, + } +} + +type GithubPullRequestGetter interface { + GetPullRequest(repo models.Repo, pullNum int) (*github.PullRequest, error) +} + +// IGithubClient exists to bridge the gap between GithubPullRequestGetter and Client interface to allow +// for a single instrumented client +type IGithubClient interface { + Client + GithubPullRequestGetter +} + +// InstrumentedGithubClient should delegate to the underlying InstrumentedClient for vcs provider-agnostic +// methods and implement soley any github specific interfaces. +type InstrumentedGithubClient struct { + *InstrumentedClient + PullRequestGetter GithubPullRequestGetter + StatsScope stats.Scope + Logger *logging.SimpleLogger +} + +func (c *InstrumentedGithubClient) GetPullRequest(repo models.Repo, pullNum int) (*github.PullRequest, error) { + scope := c.StatsScope.Scope("get_pull_request") + logger := c.Logger.NewLogger(fmtLogSrc(repo, pullNum), true, c.Logger.GetLevel()) + + executionTime := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer executionTime.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + pull, err := c.PullRequestGetter.GetPullRequest(repo, pullNum) + + if err != nil { + executionError.Inc() + logger.Err("Unable to get pull number for repo, error: %s", err.Error()) + } else { + executionSuccess.Inc() + } + + return pull, err + +} + +type InstrumentedClient struct { + Client + StatsScope stats.Scope + Logger *logging.SimpleLogger +} + +func (c *InstrumentedClient) GetModifiedFiles(repo models.Repo, pull models.PullRequest) ([]string, error) { + scope := c.StatsScope.Scope("get_modified_files") + logger := c.Logger.NewLogger(fmtLogSrc(repo, pull.Num), true, c.Logger.GetLevel()) + + executionTime := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer executionTime.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + files, err := c.Client.GetModifiedFiles(repo, pull) + + if err != nil { + executionError.Inc() + logger.Err("Unable to get modified files, error: %s", err.Error()) + } else { + executionSuccess.Inc() + } + + return files, err + +} +func (c *InstrumentedClient) CreateComment(repo models.Repo, pullNum int, comment string, command string) error { + scope := c.StatsScope.Scope("create_comment") + logger := c.Logger.NewLogger(fmtLogSrc(repo, pullNum), true, c.Logger.GetLevel()) + + executionTime := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer executionTime.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + if err := c.Client.CreateComment(repo, pullNum, comment, command); err != nil { + executionError.Inc() + logger.Err("Unable to create comment for command %s, error: %s", command, err.Error()) + return err + } + + executionSuccess.Inc() + return nil +} +func (c *InstrumentedClient) HidePrevPlanComments(repo models.Repo, pullNum int) error { + scope := c.StatsScope.Scope("hide_prev_plan_comments") + logger := c.Logger.NewLogger(fmtLogSrc(repo, pullNum), true, c.Logger.GetLevel()) + + executionTime := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer executionTime.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + if err := c.Client.HidePrevPlanComments(repo, pullNum); err != nil { + executionError.Inc() + logger.Err("Unable to hide previous plan comments, error: %s", err.Error()) + return err + } + + executionSuccess.Inc() + return nil + +} +func (c *InstrumentedClient) PullIsApproved(repo models.Repo, pull models.PullRequest) (bool, error) { + scope := c.StatsScope.Scope("pull_is_approved") + logger := c.Logger.NewLogger(fmtLogSrc(repo, pull.Num), true, c.Logger.GetLevel()) + + executionTime := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer executionTime.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + approved, err := c.Client.PullIsApproved(repo, pull) + + if err != nil { + executionError.Inc() + logger.Err("Unable to check pull approval status, error: %s", err.Error()) + } else { + executionSuccess.Inc() + } + + return approved, err + +} +func (c *InstrumentedClient) PullIsMergeable(repo models.Repo, pull models.PullRequest) (bool, error) { + scope := c.StatsScope.Scope("pull_is_mergeable") + logger := c.Logger.NewLogger(fmtLogSrc(repo, pull.Num), true, c.Logger.GetLevel()) + + executionTime := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer executionTime.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + mergeable, err := c.Client.PullIsMergeable(repo, pull) + + if err != nil { + executionError.Inc() + logger.Err("Unable to check pull mergeable status, error: %s", err.Error()) + } else { + executionSuccess.Inc() + } + + return mergeable, err +} + +func (c *InstrumentedClient) UpdateStatus(repo models.Repo, pull models.PullRequest, state models.CommitStatus, src string, description string, url string) error { + scope := c.StatsScope.Scope("update_status") + logger := c.Logger.NewLogger(fmtLogSrc(repo, pull.Num), true, c.Logger.GetLevel()) + + executionTime := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer executionTime.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + if err := c.Client.UpdateStatus(repo, pull, state, src, description, url); err != nil { + executionError.Inc() + logger.Err("Unable to update status at url: %s, error: %s", url, err.Error()) + return err + } + + executionSuccess.Inc() + return nil + +} +func (c *InstrumentedClient) MergePull(pull models.PullRequest) error { + scope := c.StatsScope.Scope("merge_pull") + logger := c.Logger.NewLogger(fmt.Sprintf("#%d", pull.Num), true, c.Logger.GetLevel()) + + executionTime := scope.NewTimer(metrics.ExecutionTimeMetric).AllocateSpan() + defer executionTime.Complete() + + executionSuccess := scope.NewCounter(metrics.ExecutionSuccessMetric) + executionError := scope.NewCounter(metrics.ExecutionErrorMetric) + + if err := c.Client.MergePull(pull); err != nil { + executionError.Inc() + logger.Err("Unable to merge pull, error: %s", err.Error()) + } + + executionSuccess.Inc() + return nil + +} + +// taken from other parts of the code, would be great to have this in a shared spot +func fmtLogSrc(repo models.Repo, pullNum int) string { + return fmt.Sprintf("%s#%d", repo.FullName, pullNum) +} diff --git a/server/events_controller_e2e_test.go b/server/events_controller_e2e_test.go index 861e5d272..67d9bbcf5 100644 --- a/server/events_controller_e2e_test.go +++ b/server/events_controller_e2e_test.go @@ -16,6 +16,7 @@ import ( "github.com/google/go-github/v31/github" "github.com/hashicorp/go-getter" "github.com/hashicorp/go-version" + stats "github.com/lyft/gostats" . "github.com/petergtz/pegomock" "github.com/runatlantis/atlantis/server" "github.com/runatlantis/atlantis/server/events" @@ -629,6 +630,8 @@ func setupE2E(t *testing.T, repoDir string, policyChecksEnabled bool) (server.Ev WorkingDir: workingDir, PreWorkflowHookRunner: mockPreWorkflowHookRunner, } + statsScope := stats.NewStore(stats.NewNullSink(), false) + projectCommandBuilder := events.NewProjectCommandBuilder( policyChecksEnabled, parser, @@ -640,6 +643,8 @@ func setupE2E(t *testing.T, repoDir string, policyChecksEnabled bool) (server.Ev &events.DefaultPendingPlanFinder{}, commentParser, false, + statsScope, + logger, ) showStepRunner, err := runtime.NewShowStepRunner(terraformClient, defaultTFVersion) @@ -765,6 +770,7 @@ func setupE2E(t *testing.T, repoDir string, policyChecksEnabled bool) (server.Ev GithubPullGetter: e2eGithubGetter, GitlabMergeRequestGetter: e2eGitlabGetter, Logger: logger, + StatsScope: statsScope, AllowForkPRs: allowForkPRs, AllowForkPRsFlag: "allow-fork-prs", CommentCommandRunnerByCmd: commentCommandRunnerByCmd, diff --git a/server/server.go b/server/server.go index 8aab7bbf0..9b2819b43 100644 --- a/server/server.go +++ b/server/server.go @@ -128,11 +128,11 @@ type WebhookConfig struct { func NewServer(userConfig UserConfig, config Config) (*Server, error) { logger := logging.NewSimpleLogger("server", false, userConfig.ToLogLevel()) - statsScope := stats.NewDefaultStore().Scope("atlantis") + statsScope := stats.NewDefaultStore().Scope(userConfig.StatsNamespace) statsScope.Store().AddStatGenerator(stats.NewRuntimeStats(statsScope.Scope("go"))) var supportedVCSHosts []models.VCSHostType - var githubClient *vcs.GithubClient + var githubClient vcs.IGithubClient var githubAppEnabled bool var githubCredentials vcs.GithubCredentials var gitlabClient *vcs.GitlabClient @@ -164,10 +164,12 @@ func NewServer(userConfig UserConfig, config Config) (*Server, error) { } var err error - githubClient, err = vcs.NewGithubClient(userConfig.GithubHostname, githubCredentials, logger) + rawGithubClient, err := vcs.NewGithubClient(userConfig.GithubHostname, githubCredentials, logger) if err != nil { return nil, err } + + githubClient = vcs.NewInstrumentedGithubClient(rawGithubClient, statsScope, logger) } if userConfig.GitlabUser != "" { supportedVCSHosts = append(supportedVCSHosts, models.Gitlab) @@ -418,6 +420,8 @@ func NewServer(userConfig UserConfig, config Config) (*Server, error) { pendingPlanFinder, commentParser, userConfig.SkipCloneNoChanges, + statsScope, + logger, ) showStepRunner, err := runtime.NewShowStepRunner(terraformClient, defaultTfVersion) @@ -480,11 +484,15 @@ func NewServer(userConfig UserConfig, config Config) (*Server, error) { GlobalAutomerge: userConfig.Automerge, } + instrumentedProjectCmdRunner := &events.InstrumentedProjectCommandRunner{ + ProjectCommandRunner: projectCommandRunner, + } + policyCheckCommandRunner := events.NewPolicyCheckCommandRunner( dbUpdater, pullUpdater, commitStatusUpdater, - projectCommandRunner, + instrumentedProjectCmdRunner, userConfig.ParallelPoolSize, ) @@ -495,7 +503,7 @@ func NewServer(userConfig UserConfig, config Config) (*Server, error) { workingDir, commitStatusUpdater, projectCommandBuilder, - projectCommandRunner, + instrumentedProjectCmdRunner, dbUpdater, pullUpdater, policyCheckCommandRunner, @@ -509,7 +517,7 @@ func NewServer(userConfig UserConfig, config Config) (*Server, error) { userConfig.DisableApply, commitStatusUpdater, projectCommandBuilder, - projectCommandRunner, + instrumentedProjectCmdRunner, autoMerger, pullUpdater, dbUpdater, @@ -520,7 +528,7 @@ func NewServer(userConfig UserConfig, config Config) (*Server, error) { approvePoliciesCommandRunner := events.NewApprovePoliciesCommandRunner( commitStatusUpdater, projectCommandBuilder, - projectCommandRunner, + instrumentedProjectCmdRunner, pullUpdater, dbUpdater, ) @@ -545,6 +553,7 @@ func NewServer(userConfig UserConfig, config Config) (*Server, error) { CommentCommandRunnerByCmd: commentCommandRunnerByCmd, EventParser: eventParser, Logger: logger, + StatsScope: statsScope.Scope("cmd"), AllowForkPRs: userConfig.AllowForkPRs, AllowForkPRsFlag: config.AllowForkPRsFlag, SilenceForkPRErrors: userConfig.SilenceForkPRErrors, diff --git a/server/user_config.go b/server/user_config.go index 81a3eeee8..e6bba3582 100644 --- a/server/user_config.go +++ b/server/user_config.go @@ -43,6 +43,7 @@ type UserConfig struct { HidePrevPlanComments bool `mapstructure:"hide-prev-plan-comments"` LogLevel string `mapstructure:"log-level"` ParallelPoolSize int `mapstructure:"parallel-pool-size"` + StatsNamespace string `mapstructure:"stats-namespace"` PlanDrafts bool `mapstructure:"allow-draft-prs"` Port int `mapstructure:"port"` RepoConfig string `mapstructure:"repo-config"`