Tweak logging. Add timezone, use everywhere.

- Use logger for all warnings. Previously we were writing warnings from
cmd/server.go directly to stderr which bypassed our normal log format.
- Add the timezone to log output. This is just really nice to have if
you're looking at old logs.
- Change levels to all be 4 characters: DBUG, INFO, WARN, EROR. This
makes the logs easier to read because it lines up.
- Log when we first receive the request as well as when we send a
response. This makes it easier to see where the request starts and ends.

cmd/server.go

@@ -20,6 +20,8 @@ import (
 	"path/filepath"
 	"strings"
 
+	"github.com/runatlantis/atlantis/server/logging"
+
 	"github.com/mitchellh/go-homedir"
 	"github.com/pkg/errors"
 	"github.com/runatlantis/atlantis/server"
@@ -69,9 +71,6 @@ const (
 	DefaultPort             = 4141
 )
 
-const redTermStart = "\033[31m"
-const redTermEnd = "\033[39m"
-
 var stringFlags = []stringFlag{
 	{
 		name:        AtlantisURLFlag,
@@ -231,6 +230,7 @@ type ServerCmd struct {
 	// Useful for testing to keep the logs clean.
 	SilenceOutput   bool
 	AtlantisVersion string
+	Logger          *logging.SimpleLogger
 }
 
 // ServerCreator creates servers.
@@ -283,7 +283,7 @@ func (s *ServerCmd) Init() *cobra.Command {
 
 	// If a user passes in an invalid flag, tell them what the flag was.
 	c.SetFlagErrorFunc(func(c *cobra.Command, err error) error {
-		fmt.Fprintf(os.Stderr, "\033[31mError: %s\033[39m\n\n", err.Error())
+		s.printErr(err)
 		return err
 	})
 
@@ -334,6 +334,11 @@ func (s *ServerCmd) run() error {
 		return err
 	}
 	s.setDefaults(&userConfig)
+
+	// Now that we've parsed the config we can set our local logger to the
+	// right level.
+	s.Logger.SetLevel(userConfig.ToLogLevel())
+
 	if err := s.validate(userConfig); err != nil {
 		return err
 	}
@@ -471,26 +476,31 @@ func (s *ServerCmd) trimAtSymbolFromUsers(userConfig *server.UserConfig) {
 
 func (s *ServerCmd) securityWarnings(userConfig *server.UserConfig) {
 	if userConfig.GithubUser != "" && userConfig.GithubWebhookSecret == "" && !s.SilenceOutput {
-		fmt.Fprintf(os.Stderr, "%s[WARN] No GitHub webhook secret set. This could allow attackers to spoof requests from GitHub.%s\n", redTermStart, redTermEnd)
+		s.Logger.Warn("no GitHub webhook secret set. This could allow attackers to spoof requests from GitHub")
 	}
 	if userConfig.GitlabUser != "" && userConfig.GitlabWebhookSecret == "" && !s.SilenceOutput {
-		fmt.Fprintf(os.Stderr, "%s[WARN] No GitLab webhook secret set. This could allow attackers to spoof requests from GitLab.%s\n", redTermStart, redTermEnd)
+		s.Logger.Warn("no GitLab webhook secret set. This could allow attackers to spoof requests from GitLab")
 	}
 	if userConfig.BitbucketUser != "" && userConfig.BitbucketBaseURL != DefaultBitbucketBaseURL && userConfig.BitbucketWebhookSecret == "" && !s.SilenceOutput {
-		fmt.Fprintf(os.Stderr, "%s[WARN] No Bitbucket webhook secret set. This could allow attackers to spoof requests from Bitbucket.%s\n", redTermStart, redTermEnd)
+		s.Logger.Warn("no Bitbucket webhook secret set. This could allow attackers to spoof requests from Bitbucket")
 	}
 	if userConfig.BitbucketUser != "" && userConfig.BitbucketBaseURL == DefaultBitbucketBaseURL && !s.SilenceOutput {
-		fmt.Fprintf(os.Stderr, "%s[WARN] Bitbucket Cloud does not support webhook secrets. This could allow attackers to spoof requests from Bitbucket. Ensure you are whitelisting Bitbucket IPs.%s\n", redTermStart, redTermEnd)
+		s.Logger.Warn("Bitbucket Cloud does not support webhook secrets. This could allow attackers to spoof requests from Bitbucket. Ensure you are whitelisting Bitbucket IPs")
 	}
 }
 
-// withErrPrint prints out any errors to a terminal in red.
+// withErrPrint prints out any cmd errors to stderr.
 func (s *ServerCmd) withErrPrint(f func(*cobra.Command, []string) error) func(*cobra.Command, []string) error {
 	return func(cmd *cobra.Command, args []string) error {
 		err := f(cmd, args)
 		if err != nil && !s.SilenceOutput {
-			fmt.Fprintf(os.Stderr, "%s[ERROR] %s%s\n\n", redTermStart, err.Error(), redTermEnd)
+			s.printErr(err)
 		}
 		return err
 	}
 }
+
+// printErr prints err to stderr using a red terminal colour.
+func (s *ServerCmd) printErr(err error) {
+	fmt.Fprintf(os.Stderr, "%sError: %s%s\n", "\033[31m", err.Error(), "\033[39m")
+}

main.go

@@ -16,6 +16,7 @@ package main
 
 import (
 	"github.com/runatlantis/atlantis/cmd"
+	"github.com/runatlantis/atlantis/server/logging"
 	"github.com/spf13/viper"
 )
 
@@ -30,6 +31,7 @@ func main() {
 		ServerCreator:   &cmd.DefaultServerCreator{},
 		Viper:           v,
 		AtlantisVersion: atlantisVersion,
+		Logger:          logging.NewSimpleLogger("cmd", false, logging.Info),
 	}
 	version := &cmd.VersionCmd{AtlantisVersion: atlantisVersion}
 	testdrive := &cmd.TestdriveCmd{}

server/events/command_runner.go

@@ -74,6 +74,7 @@ type DefaultCommandRunner struct {
 // RunAutoplanCommand runs plan when a pull request is opened or updated.
 func (c *DefaultCommandRunner) RunAutoplanCommand(baseRepo models.Repo, headRepo models.Repo, pull models.PullRequest, user models.User) {
 	log := c.buildLogger(baseRepo.FullName, pull.Num)
+	defer c.logPanics(baseRepo, pull.Num, log)
 	ctx := &CommandContext{
 		User:     user,
 		Log:      log,
@@ -81,7 +82,6 @@ func (c *DefaultCommandRunner) RunAutoplanCommand(baseRepo models.Repo, headRepo
 		HeadRepo: headRepo,
 		BaseRepo: baseRepo,
 	}
-	defer c.logPanics(ctx)
 	if !c.validateCtxAndComment(ctx) {
 		return
 	}
@@ -113,6 +113,8 @@ func (c *DefaultCommandRunner) RunAutoplanCommand(baseRepo models.Repo, headRepo
 // wasteful) call to get the necessary data.
 func (c *DefaultCommandRunner) RunCommentCommand(baseRepo models.Repo, maybeHeadRepo *models.Repo, maybePull *models.PullRequest, user models.User, pullNum int, cmd *CommentCommand) {
 	log := c.buildLogger(baseRepo.FullName, pullNum)
+	defer c.logPanics(baseRepo, pullNum, log)
+
 	var headRepo models.Repo
 	if maybeHeadRepo != nil {
 		headRepo = *maybeHeadRepo
@@ -147,7 +149,6 @@ func (c *DefaultCommandRunner) RunCommentCommand(baseRepo models.Repo, maybeHead
 		HeadRepo: headRepo,
 		BaseRepo: baseRepo,
 	}
-	defer c.logPanics(ctx)
 	if !c.validateCtxAndComment(ctx) {
 		return
 	}
@@ -221,7 +222,7 @@ func (c *DefaultCommandRunner) getGitlabData(baseRepo models.Repo, pullNum int)
 
 func (c *DefaultCommandRunner) buildLogger(repoFullName string, pullNum int) *logging.SimpleLogger {
 	src := fmt.Sprintf("%s#%d", repoFullName, pullNum)
-	return logging.NewSimpleLogger(src, c.Logger.Underlying(), true, c.Logger.GetLevel())
+	return c.Logger.NewLogger(src, true, c.Logger.GetLevel())
 }
 
 func (c *DefaultCommandRunner) validateCtxAndComment(ctx *CommandContext) bool {
@@ -262,11 +263,16 @@ func (c *DefaultCommandRunner) updatePull(ctx *CommandContext, command PullComma
 }
 
 // logPanics logs and creates a comment on the pull request for panics.
-func (c *DefaultCommandRunner) logPanics(ctx *CommandContext) {
+func (c *DefaultCommandRunner) logPanics(baseRepo models.Repo, pullNum int, logger logging.SimpleLogging) {
 	if err := recover(); err != nil {
 		stack := recovery.Stack(3)
-		c.VCSClient.CreateComment(ctx.BaseRepo, ctx.Pull.Num, // nolint: errcheck
-			fmt.Sprintf("**Error: goroutine panic. This is a bug.**\n```\n%s\n%s```", err, stack))
-		ctx.Log.Err("PANIC: %s\n%s", err, stack)
+		logger.Err("PANIC: %s\n%s", err, stack)
+		if commentErr := c.VCSClient.CreateComment(
+			baseRepo,
+			pullNum,
+			fmt.Sprintf("**Error: goroutine panic. This is a bug.**\n```\n%s\n%s```", err, stack),
+		); commentErr != nil {
+			logger.Err("unable to comment: %s", commentErr)
+		}
 	}
 }

server/events/command_runner_test.go

@@ -14,12 +14,13 @@
 package events_test
 
 import (
-	"bytes"
 	"errors"
-	"log"
+	"fmt"
 	"strings"
 	"testing"
 
+	"github.com/runatlantis/atlantis/server/logging"
+
 	"github.com/google/go-github/github"
 	. "github.com/petergtz/pegomock"
 	"github.com/runatlantis/atlantis/server/events"
@@ -38,7 +39,7 @@ var ghStatus *mocks.MockCommitStatusUpdater
 var githubGetter *mocks.MockGithubPullGetter
 var gitlabGetter *mocks.MockGitlabMergeRequestGetter
 var ch events.DefaultCommandRunner
-var logBytes *bytes.Buffer
+var pullLogger *logging.SimpleLogger
 
 func setup(t *testing.T) *vcsmocks.MockClientProxy {
 	RegisterMockTestingT(t)
@@ -49,9 +50,11 @@ func setup(t *testing.T) *vcsmocks.MockClientProxy {
 	githubGetter = mocks.NewMockGithubPullGetter()
 	gitlabGetter = mocks.NewMockGitlabMergeRequestGetter()
 	logger := logmocks.NewMockSimpleLogging()
-	logBytes = new(bytes.Buffer)
+	pullLogger = logging.NewSimpleLogger("runatlantis/atlantis#1", true, logging.Info)
 	projectCommandRunner := mocks.NewMockProjectCommandRunner()
-	When(logger.Underlying()).ThenReturn(log.New(logBytes, "", 0))
+	When(logger.GetLevel()).ThenReturn(logging.Info)
+	When(logger.NewLogger("runatlantis/atlantis#1", true, logging.Info)).
+		ThenReturn(pullLogger)
 	ch = events.DefaultCommandRunner{
 		VCSClient:                vcsClient,
 		CommitStatusUpdater:      ghStatus,
@@ -71,12 +74,10 @@ func setup(t *testing.T) *vcsmocks.MockClientProxy {
 func TestRunCommentCommand_LogPanics(t *testing.T) {
 	t.Log("if there is a panic it is commented back on the pull request")
 	vcsClient := setup(t)
-	ch.AllowForkPRs = true // Lets us get to the panic code.
-	defer func() { ch.AllowForkPRs = false }()
-	When(ghStatus.Update(fixtures.GithubRepo, fixtures.Pull, models.PendingCommitStatus, events.PlanCommand)).ThenPanic("panic")
-	ch.RunCommentCommand(fixtures.GithubRepo, &fixtures.GithubRepo, nil, fixtures.User, 1, nil)
+	When(githubGetter.GetPullRequest(fixtures.GithubRepo, fixtures.Pull.Num)).ThenPanic("OMG PANIC!!!")
+	ch.RunCommentCommand(fixtures.GithubRepo, &fixtures.GithubRepo, nil, fixtures.User, 1, &events.CommentCommand{Name: events.PlanCommand})
 	_, _, comment := vcsClient.VerifyWasCalledOnce().CreateComment(matchers.AnyModelsRepo(), AnyInt(), AnyString()).GetCapturedArguments()
-	Assert(t, strings.Contains(comment, "Error: goroutine panic"), "comment should be about a goroutine panic")
+	Assert(t, strings.Contains(comment, "Error: goroutine panic"), fmt.Sprintf("comment should be about a goroutine panic but was %q", comment))
 }
 
 func TestRunCommentCommand_NoGithubPullGetter(t *testing.T) {
@@ -84,7 +85,7 @@ func TestRunCommentCommand_NoGithubPullGetter(t *testing.T) {
 	setup(t)
 	ch.GithubPullGetter = nil
 	ch.RunCommentCommand(fixtures.GithubRepo, &fixtures.GithubRepo, nil, fixtures.User, 1, nil)
-	Equals(t, "[ERROR] runatlantis/atlantis#1: Atlantis not configured to support GitHub\n", logBytes.String())
+	Equals(t, "[EROR] Atlantis not configured to support GitHub\n", pullLogger.History.String())
 }
 
 func TestRunCommentCommand_NoGitlabMergeGetter(t *testing.T) {
@@ -92,7 +93,7 @@ func TestRunCommentCommand_NoGitlabMergeGetter(t *testing.T) {
 	setup(t)
 	ch.GitlabMergeRequestGetter = nil
 	ch.RunCommentCommand(fixtures.GitlabRepo, &fixtures.GitlabRepo, nil, fixtures.User, 1, nil)
-	Equals(t, "[ERROR] runatlantis/atlantis#1: Atlantis not configured to support GitLab\n", logBytes.String())
+	Equals(t, "[EROR] Atlantis not configured to support GitLab\n", pullLogger.History.String())
 }
 
 func TestRunCommentCommand_GithubPullErr(t *testing.T) {

server/events_controller_e2e_test.go

@@ -260,7 +260,7 @@ func setupE2E(t *testing.T) (server.EventsController, *vcsmocks.MockClientProxy,
 	e2eGitlabGetter := mocks.NewMockGitlabMergeRequestGetter()
 
 	// Real dependencies.
-	logger := logging.NewSimpleLogger("server", nil, true, logging.Debug)
+	logger := logging.NewSimpleLogger("server", true, logging.Debug)
 	eventParser := &events.EventParser{
 		GithubUser:  "github-user",
 		GithubToken: "github-token",

server/logging/mocks/matchers/ptr_to_logging_simplelogger.go

@@ -0,0 +1,20 @@
+// Code generated by pegomock. DO NOT EDIT.
+package matchers
+
+import (
+	"reflect"
+	"github.com/petergtz/pegomock"
+	logging "github.com/runatlantis/atlantis/server/logging"
+)
+
+func AnyPtrToLoggingSimpleLogger() *logging.SimpleLogger {
+	pegomock.RegisterMatcher(pegomock.NewAnyMatcher(reflect.TypeOf((*(*logging.SimpleLogger))(nil)).Elem()))
+	var nullValue *logging.SimpleLogger
+	return nullValue
+}
+
+func EqPtrToLoggingSimpleLogger(value *logging.SimpleLogger) *logging.SimpleLogger {
+	pegomock.RegisterMatcher(&pegomock.EqMatcher{Value: value})
+	var nullValue *logging.SimpleLogger
+	return nullValue
+}

server/logging/mocks/mock_simple_logging.go

@@ -104,6 +104,21 @@ func (mock *MockSimpleLogging) GetLevel() logging.LogLevel {
 	return ret0
 }
 
+func (mock *MockSimpleLogging) NewLogger(_param0 string, _param1 bool, _param2 logging.LogLevel) *logging.SimpleLogger {
+	if mock == nil {
+		panic("mock must not be nil. Use myMock := NewMockSimpleLogging().")
+	}
+	params := []pegomock.Param{_param0, _param1, _param2}
+	result := pegomock.GetGenericMockFrom(mock).Invoke("NewLogger", params, []reflect.Type{reflect.TypeOf((**logging.SimpleLogger)(nil)).Elem()})
+	var ret0 *logging.SimpleLogger
+	if len(result) != 0 {
+		if result[0] != nil {
+			ret0 = result[0].(*logging.SimpleLogger)
+		}
+	}
+	return ret0
+}
+
 func (mock *MockSimpleLogging) VerifyWasCalledOnce() *VerifierSimpleLogging {
 	return &VerifierSimpleLogging{
 		mock:                   mock,
@@ -373,3 +388,38 @@ func (c *SimpleLogging_GetLevel_OngoingVerification) GetCapturedArguments() {
 
 func (c *SimpleLogging_GetLevel_OngoingVerification) GetAllCapturedArguments() {
 }
+
+func (verifier *VerifierSimpleLogging) NewLogger(_param0 string, _param1 bool, _param2 logging.LogLevel) *SimpleLogging_NewLogger_OngoingVerification {
+	params := []pegomock.Param{_param0, _param1, _param2}
+	methodInvocations := pegomock.GetGenericMockFrom(verifier.mock).Verify(verifier.inOrderContext, verifier.invocationCountMatcher, "NewLogger", params, verifier.timeout)
+	return &SimpleLogging_NewLogger_OngoingVerification{mock: verifier.mock, methodInvocations: methodInvocations}
+}
+
+type SimpleLogging_NewLogger_OngoingVerification struct {
+	mock              *MockSimpleLogging
+	methodInvocations []pegomock.MethodInvocation
+}
+
+func (c *SimpleLogging_NewLogger_OngoingVerification) GetCapturedArguments() (string, bool, logging.LogLevel) {
+	_param0, _param1, _param2 := c.GetAllCapturedArguments()
+	return _param0[len(_param0)-1], _param1[len(_param1)-1], _param2[len(_param2)-1]
+}
+
+func (c *SimpleLogging_NewLogger_OngoingVerification) GetAllCapturedArguments() (_param0 []string, _param1 []bool, _param2 []logging.LogLevel) {
+	params := pegomock.GetGenericMockFrom(c.mock).GetInvocationParams(c.methodInvocations)
+	if len(params) > 0 {
+		_param0 = make([]string, len(params[0]))
+		for u, param := range params[0] {
+			_param0[u] = param.(string)
+		}
+		_param1 = make([]bool, len(params[1]))
+		for u, param := range params[1] {
+			_param1[u] = param.(bool)
+		}
+		_param2 = make([]logging.LogLevel, len(params[2]))
+		for u, param := range params[2] {
+			_param2[u] = param.(logging.LogLevel)
+		}
+	}
+	return
+}

server/logging/simple_logger.go

@@ -20,6 +20,8 @@ import (
 	"io/ioutil"
 	"log"
 	"os"
+	"runtime"
+	"time"
 	"unicode"
 )
 
@@ -37,6 +39,7 @@ type SimpleLogging interface {
 	Underlying() *log.Logger
 	// GetLevel returns the current log level.
 	GetLevel() LogLevel
+	NewLogger(string, bool, LogLevel) *SimpleLogger
 }
 
 // SimpleLogger wraps the standard logger with leveled logging
@@ -68,24 +71,14 @@ const (
 // NewSimpleLogger creates a new logger.
 // source is added as a prefix to each log entry. It's useful if you want to
 // trace a log entry back to a specific context, for example a pull request id.
-// logger is the underlying logger. If nil will create a logger from stdlib.
 // keepHistory set to true will store all log entries written using this logger.
 // level will set the level at which logs >= than that level will be written.
 // If keepHistory is set to true, we'll store logs at all levels, regardless of
 // what level is set to.
-func NewSimpleLogger(source string, logger *log.Logger, keepHistory bool, level LogLevel) *SimpleLogger {
-	if logger == nil {
-		flags := log.LstdFlags
-		if level == Debug {
-			// If we're using debug logging, we also have the logger print the
-			// filename the log comes from with log.Lshortfile.
-			flags = flags | log.Lshortfile
-		}
-		logger = log.New(os.Stderr, "", flags)
-	}
+func NewSimpleLogger(source string, keepHistory bool, level LogLevel) *SimpleLogger {
 	return &SimpleLogger{
 		Source:      source,
-		Logger:      logger,
+		Logger:      log.New(os.Stderr, "", 0),
 		Level:       level,
 		KeepHistory: keepHistory,
 	}
@@ -104,20 +97,24 @@ func NewNoopLogger() *SimpleLogger {
 	}
 }
 
-// ToLogLevel converts a log level string to a valid LogLevel object.
-// If the string doesn't match a level, it will return Info.
-func ToLogLevel(levelStr string) LogLevel {
-	switch levelStr {
-	case "debug":
-		return Debug
-	case "info":
-		return Info
-	case "warn":
-		return Warn
-	case "error":
-		return Error
+// NewLogger returns a new logger that reuses the underlying logger.
+func (l *SimpleLogger) NewLogger(source string, keepHistory bool, lvl LogLevel) *SimpleLogger {
+	if l == nil {
+		return nil
+	}
+	return &SimpleLogger{
+		Source:      source,
+		Level:       lvl,
+		Logger:      l.Underlying(),
+		KeepHistory: keepHistory,
+	}
+}
+
+// SetLevel changes the level that this logger is writing at to lvl.
+func (l *SimpleLogger) SetLevel(lvl LogLevel) {
+	if l != nil {
+		l.Level = lvl
 	}
-	return Info
 }
 
 // Debug logs at debug level.
@@ -155,10 +152,13 @@ func (l *SimpleLogger) Log(level LogLevel, format string, a ...interface{}) {
 
 	// Only log this message if configured to log at this level.
 	if l.Level <= level {
-		// Calling .Output instead of Printf so we can change the calldepth
-		// param to 3. The default is 2 which would identify the log as coming
-		// from this file and line every time instead of our caller's.
-		l.Logger.Output(3, fmt.Sprintf("[%s] %s: %s\n", levelStr, l.Source, msg)) // nolint: errcheck
+		datetime := time.Now().Format("2006/01/02 15:04:05-0700")
+		var caller string
+		if l.Level <= Debug {
+			file, line := l.callSite(3)
+			caller = fmt.Sprintf(" %s:%d", file, line)
+		}
+		l.Logger.Printf("%s [%s]%s %s: %s\n", datetime, levelStr, caller, l.Source, msg) // noline: errcheck
 	}
 
 	// Keep history at all log levels.
@@ -190,13 +190,35 @@ func (l *SimpleLogger) capitalizeFirstLetter(s string) string {
 func (l *SimpleLogger) levelToString(level LogLevel) string {
 	switch level {
 	case Debug:
-		return "DEBUG"
+		return "DBUG"
 	case Info:
 		return "INFO"
 	case Warn:
 		return "WARN"
 	case Error:
-		return "ERROR"
+		return "EROR"
 	}
-	return "NOLEVEL"
+	return "????"
+}
+
+// callSite returns the location of the caller of this function via its
+// filename and line number. skip is the number of stack frames to skip.
+// nolint: unparam
+func (l *SimpleLogger) callSite(skip int) (string, int) {
+	_, file, line, ok := runtime.Caller(skip)
+	if !ok {
+		return "???", 0
+	}
+
+	// file is the full filepath but we just want the filename.
+	// NOTE: rather than calling path.Base we're using code from the stdlib
+	// logging package which I assume is optimized.
+	short := file
+	for i := len(file) - 1; i > 0; i-- {
+		if file[i] == '/' {
+			short = file[i+1:]
+			break
+		}
+	}
+	return short, line
 }

server/middleware.go

@@ -34,9 +34,15 @@ type RequestLogger struct {
 // ServeHTTP implements the middleware function. It logs a request at INFO
 // level unless it's a request to /static/*.
 func (l *RequestLogger) ServeHTTP(rw http.ResponseWriter, r *http.Request, next http.HandlerFunc) {
+	if l.shouldLog(r) {
+		l.logger.Info("%s %s – from %s", r.Method, r.URL.RequestURI(), r.RemoteAddr)
+	}
 	next(rw, r)
-	res := rw.(negroni.ResponseWriter)
-	if !strings.HasPrefix(r.URL.RequestURI(), "/static") {
-		l.logger.Info("%d | %s %s", res.Status(), r.Method, r.URL.RequestURI())
+	if l.shouldLog(r) {
+		l.logger.Info("%s %s – respond HTTP %d", r.Method, r.URL.RequestURI(), rw.(negroni.ResponseWriter).Status())
 	}
 }
+
+func (l *RequestLogger) shouldLog(r *http.Request) bool {
+	return !strings.HasPrefix(r.URL.RequestURI(), "/static")
+}

server/server.go

@@ -77,42 +77,6 @@ type Server struct {
 	SSLKeyFile         string
 }
 
-// UserConfig holds config values passed in by the user.
-// The mapstructure tags correspond to flags in cmd/server.go and are used when
-// the config is parsed from a YAML file.
-type UserConfig struct {
-	AllowForkPRs           bool   `mapstructure:"allow-fork-prs"`
-	AllowRepoConfig        bool   `mapstructure:"allow-repo-config"`
-	AtlantisURL            string `mapstructure:"atlantis-url"`
-	BitbucketBaseURL       string `mapstructure:"bitbucket-base-url"`
-	BitbucketToken         string `mapstructure:"bitbucket-token"`
-	BitbucketUser          string `mapstructure:"bitbucket-user"`
-	BitbucketWebhookSecret string `mapstructure:"bitbucket-webhook-secret"`
-	DataDir                string `mapstructure:"data-dir"`
-	GithubHostname         string `mapstructure:"gh-hostname"`
-	GithubToken            string `mapstructure:"gh-token"`
-	GithubUser             string `mapstructure:"gh-user"`
-	GithubWebhookSecret    string `mapstructure:"gh-webhook-secret"`
-	GitlabHostname         string `mapstructure:"gitlab-hostname"`
-	GitlabToken            string `mapstructure:"gitlab-token"`
-	GitlabUser             string `mapstructure:"gitlab-user"`
-	GitlabWebhookSecret    string `mapstructure:"gitlab-webhook-secret"`
-	LogLevel               string `mapstructure:"log-level"`
-	Port                   int    `mapstructure:"port"`
-	RepoWhitelist          string `mapstructure:"repo-whitelist"`
-	// RequireApproval is whether to require pull request approval before
-	// allowing terraform apply's to be run.
-	RequireApproval bool `mapstructure:"require-approval"`
-	// RequireMergeable is whether to require pull requests to be mergeable before
-	// allowing terraform apply's to run.
-	RequireMergeable       bool            `mapstructure:"require-mergeable"`
-	SilenceWhitelistErrors bool            `mapstructure:"silence-whitelist-errors"`
-	SlackToken             string          `mapstructure:"slack-token"`
-	SSLCertFile            string          `mapstructure:"ssl-cert-file"`
-	SSLKeyFile             string          `mapstructure:"ssl-key-file"`
-	Webhooks               []WebhookConfig `mapstructure:"webhooks"`
-}
-
 // Config holds config for server that isn't passed in by the user.
 type Config struct {
 	AllowForkPRsFlag    string
@@ -140,7 +104,7 @@ type WebhookConfig struct {
 // its dependencies an error will be returned. This is like the main() function
 // for the server CLI command because it injects all the dependencies.
 func NewServer(userConfig UserConfig, config Config) (*Server, error) {
-	logger := logging.NewSimpleLogger("server", nil, false, logging.ToLogLevel(userConfig.LogLevel))
+	logger := logging.NewSimpleLogger("server", false, userConfig.ToLogLevel())
 	var supportedVCSHosts []models.VCSHostType
 	var githubClient *vcs.GithubClient
 	var gitlabClient *vcs.GitlabClient
@@ -385,8 +349,7 @@ func (s *Server) Start() error {
 			err = server.ListenAndServe()
 		}
 
-		if err != nil {
-			// When shutdown safely, there will be no error.
+		if err != nil && err != http.ErrServerClosed {
 			s.Logger.Err(err.Error())
 		}
 	}()

server/user_config.go

@@ -0,0 +1,55 @@
+package server
+
+import "github.com/runatlantis/atlantis/server/logging"
+
+// UserConfig holds config values passed in by the user.
+// The mapstructure tags correspond to flags in cmd/server.go and are used when
+// the config is parsed from a YAML file.
+type UserConfig struct {
+	AllowForkPRs           bool   `mapstructure:"allow-fork-prs"`
+	AllowRepoConfig        bool   `mapstructure:"allow-repo-config"`
+	AtlantisURL            string `mapstructure:"atlantis-url"`
+	BitbucketBaseURL       string `mapstructure:"bitbucket-base-url"`
+	BitbucketToken         string `mapstructure:"bitbucket-token"`
+	BitbucketUser          string `mapstructure:"bitbucket-user"`
+	BitbucketWebhookSecret string `mapstructure:"bitbucket-webhook-secret"`
+	DataDir                string `mapstructure:"data-dir"`
+	GithubHostname         string `mapstructure:"gh-hostname"`
+	GithubToken            string `mapstructure:"gh-token"`
+	GithubUser             string `mapstructure:"gh-user"`
+	GithubWebhookSecret    string `mapstructure:"gh-webhook-secret"`
+	GitlabHostname         string `mapstructure:"gitlab-hostname"`
+	GitlabToken            string `mapstructure:"gitlab-token"`
+	GitlabUser             string `mapstructure:"gitlab-user"`
+	GitlabWebhookSecret    string `mapstructure:"gitlab-webhook-secret"`
+	LogLevel               string `mapstructure:"log-level"`
+	Port                   int    `mapstructure:"port"`
+	RepoWhitelist          string `mapstructure:"repo-whitelist"`
+	// RequireApproval is whether to require pull request approval before
+	// allowing terraform apply's to be run.
+	RequireApproval bool `mapstructure:"require-approval"`
+	// RequireMergeable is whether to require pull requests to be mergeable before
+	// allowing terraform apply's to run.
+	RequireMergeable       bool            `mapstructure:"require-mergeable"`
+	SilenceWhitelistErrors bool            `mapstructure:"silence-whitelist-errors"`
+	SlackToken             string          `mapstructure:"slack-token"`
+	SSLCertFile            string          `mapstructure:"ssl-cert-file"`
+	SSLKeyFile             string          `mapstructure:"ssl-key-file"`
+	Webhooks               []WebhookConfig `mapstructure:"webhooks"`
+}
+
+// ToLogLevel returns the LogLevel object corresponding to the user-passed
+// log level.
+func (u UserConfig) ToLogLevel() logging.LogLevel {
+	switch u.LogLevel {
+	case "debug":
+		return logging.Debug
+	case "info":
+		return logging.Info
+	case "warn":
+		return logging.Warn
+	case "error":
+		return logging.Error
+	}
+	return logging.Info
+}

server/user_config_test.go

@@ -0,0 +1,46 @@
+package server_test
+
+import (
+	"testing"
+
+	"github.com/runatlantis/atlantis/server"
+	"github.com/runatlantis/atlantis/server/logging"
+	. "github.com/runatlantis/atlantis/testing"
+)
+
+func TestUserConfig_ToLogLevel(t *testing.T) {
+	cases := []struct {
+		userLvl string
+		expLvl  logging.LogLevel
+	}{
+		{
+			"debug",
+			logging.Debug,
+		},
+		{
+			"info",
+			logging.Info,
+		},
+		{
+			"warn",
+			logging.Warn,
+		},
+		{
+			"error",
+			logging.Error,
+		},
+		{
+			"unknown",
+			logging.Info,
+		},
+	}
+
+	for _, c := range cases {
+		t.Run(c.userLvl, func(t *testing.T) {
+			u := server.UserConfig{
+				LogLevel: c.userLvl,
+			}
+			Equals(t, c.expLvl, u.ToLogLevel())
+		})
+	}
+}