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

* [ORCA-393] Add basic stats.

* Fmt.

cmd/server.go

@@ -76,6 +76,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"
@@ -112,6 +113,7 @@ const (
 	DefaultGitlabHostname   = "gitlab.com"
 	DefaultLogLevel         = "info"
 	DefaultParallelPoolSize = 15
+	DefaultStatsNamespace   = "atlantis"
 	DefaultPort             = 4141
 	DefaultTFDownloadURL    = "https://releases.hashicorp.com"
 	DefaultTFEHostname      = "app.terraform.io"
@@ -229,6 +231,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.",
 	},
@@ -603,6 +609,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

@@ -84,6 +84,7 @@ var testFlags = map[string]interface{}{
 	GitlabUserFlag:             "gitlab-user",
 	GitlabWebhookSecretFlag:    "gitlab-secret",
 	LogLevelFlag:               "debug",
+	StatsNamespace:             "atlantis",
 	AllowDraftPRs:              true,
 	PortFlag:                   8181,
 	ParallelPoolSize:           100,

server/controllers/events/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"
 	events_controllers "github.com/runatlantis/atlantis/server/controllers/events"
@@ -724,6 +725,8 @@ func setupE2E(t *testing.T, repoDir string) (events_controllers.VCSEventsControl
 		WorkingDir:            workingDir,
 		PreWorkflowHookRunner: mockPreWorkflowHookRunner,
 	}
+	statsScope := stats.NewStore(stats.NewNullSink(), false)
+
 	projectCommandBuilder := events.NewProjectCommandBuilder(
 		userConfig.EnablePolicyChecksFlag,
 		parser,
@@ -737,6 +740,8 @@ func setupE2E(t *testing.T, repoDir string) (events_controllers.VCSEventsControl
 		false,
 		false,
 		"**/*.tf,**/*.tfvars,**/*.tfvars.json,**/terragrunt.hcl",
+		statsScope,
+		logger,
 	)
 
 	showStepRunner, err := runtime.NewShowStepRunner(terraformClient, defaultTFVersion)
@@ -871,6 +876,7 @@ func setupE2E(t *testing.T, repoDir string) (events_controllers.VCSEventsControl
 		GithubPullGetter:              e2eGithubGetter,
 		GitlabMergeRequestGetter:      e2eGitlabGetter,
 		Logger:                        logger,
+		StatsScope:                    statsScope,
 		AllowForkPRs:                  allowForkPRs,
 		AllowForkPRsFlag:              "allow-fork-prs",
 		CommentCommandRunnerByCmd:     commentCommandRunnerByCmd,

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.SimpleLogging
+	User  models.User
+	Log   logging.SimpleLogging
+	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

@@ -18,8 +18,10 @@ import (
 	"strconv"
 
 	"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"
@@ -95,6 +97,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
@@ -134,9 +137,14 @@ func (c *DefaultCommandRunner) RunAutoplanCommand(baseRepo models.Repo, headRepo
 		log.Err("Unable to fetch pull status, this is likely a bug.", err)
 	}
 
+	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,
 		PullStatus: status,
@@ -177,6 +185,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
@@ -195,6 +211,7 @@ func (c *DefaultCommandRunner) RunCommentCommand(baseRepo models.Repo, maybeHead
 		PullStatus: status,
 		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"
@@ -173,6 +174,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,
@@ -181,6 +184,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.SimpleLogging
+}
+
+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

@@ -25,6 +25,7 @@ import (
 	"time"
 
 	"github.com/hashicorp/go-version"
+	stats "github.com/lyft/gostats"
 	"github.com/runatlantis/atlantis/server/logging"
 
 	"github.com/pkg/errors"
@@ -364,6 +365,8 @@ type ProjectCommandContext struct {
 	HeadRepo Repo
 	// Log is a logger that's been set up for this context.
 	Log logging.SimpleLogging
+	// 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
 	// CurrentProjectPlanStatus is the status of the current project prior to this command.
@@ -402,6 +405,12 @@ type ProjectCommandContext struct {
 	DeleteSourceBranchOnMerge bool
 }
 
+// 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"
@@ -42,7 +44,9 @@ func NewProjectCommandBuilder(
 	skipCloneNoChanges bool,
 	EnableRegExpCmd bool,
 	AutoplanFileList string,
-) *DefaultProjectCommandBuilder {
+	scope stats.Scope,
+	logger logging.SimpleLogging,
+) ProjectCommandBuilder {
 	projectCommandBuilder := &DefaultProjectCommandBuilder{
 		ParserValidator:    parserValidator,
 		ProjectFinder:      projectFinder,
@@ -57,10 +61,14 @@ func NewProjectCommandBuilder(
 		ProjectCommandContextBuilder: NewProjectCommandContextBulder(
 			policyChecksSupported,
 			commentBuilder,
+			scope,
 		),
 	}
 
-	return projectCommandBuilder
+	return &InstrumentedProjectCommandBuilder{
+		ProjectCommandBuilder: projectCommandBuilder,
+		Logger:                logger,
+	}
 }
 
 type ProjectPlanCommandBuilder interface {