[ORCA-393] Add basic stats. (#26)

* [ORCA-393] Add basic stats.

* Fmt.

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
 	}

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,

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

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) {

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,

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
+
+}

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
+
+}

server/events/metrics/common.go

@@ -0,0 +1,8 @@
+package metrics
+
+const (
+	ExecutionTimeMetric    = "execution_time"
+	ExecutionSuccessMetric = "execution_success"
+	ExecutionErrorMetric   = "execution_error"
+	ExecutionFailureMetric = "execution_failure"
+)

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 == "" {

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 {