Change default logging level to Info (gruntwork-io#1541)

* Change default logging level to Info

Recent PR (gruntwork-io#1510) changed logging, and also introduced default logging
level. While it seemed like a good idea, it also introduced a lot of
confusion, because in logrus `Println()` is an alias to `Info()`
loglevel - so lots of messages were lost.

This change restores previous behavior in logging output.

Related: gruntwork-io#1529
Related: gruntwork-io#1530
Related: gruntwork-io#1531
Related: gruntwork-io#1532

* Use `Infof()` instead of `Printf()`

`Printf()` is an alias, so this does not change any functionality - just
makes logging more explicit.

* Update log levels according to PR reviews

* Some minor fixes after PR review

* Use same default logLevel across different modules

This also updates integration tests to catch this error.

* Log both prompt and a assume message for better visibility

cli/args.go

@@ -123,7 +123,7 @@ func parseTerragruntOptionsFromArgs(terragruntVersion string, args []string, wri
 	strictInclude := parseBooleanArg(args, OPT_TERRAGRUNT_STRICT_INCLUDE, false)
 
 	// Those correspond to logrus levels
-	logLevel, err := parseStringArg(args, OPT_TERRAGRUNT_LOGLEVEL, logrus.WarnLevel.String())
+	logLevel, err := parseStringArg(args, OPT_TERRAGRUNT_LOGLEVEL, util.DEFAULT_LOG_LEVEL.String())
 	if err != nil {
 		return nil, err
 	}

cli/cli_app.go

@@ -534,18 +534,18 @@ func processHooks(hooks []config.Hook, terragruntOptions *options.TerragruntOpti
 
 	errorsOccurred := []error{}
 
-	terragruntOptions.Logger.Printf("Detected %d Hooks", len(hooks))
+	terragruntOptions.Logger.Debugf("Detected %d Hooks", len(hooks))
 
 	for _, curHook := range hooks {
 		allPreviousErrors := append(previousExecError, errorsOccurred...)
 		if shouldRunHook(curHook, terragruntOptions, allPreviousErrors...) {
-			terragruntOptions.Logger.Printf("Executing hook: %s", curHook.Name)
+			terragruntOptions.Logger.Infof("Executing hook: %s", curHook.Name)
 			actionToExecute := curHook.Execute[0]
 			actionParams := curHook.Execute[1:]
 			possibleError := shell.RunShellCommand(terragruntOptions, actionToExecute, actionParams...)
 
 			if possibleError != nil {
-				terragruntOptions.Logger.Printf("Error running hook %s with message: %s", curHook.Name, possibleError.Error())
+				terragruntOptions.Logger.Errorf("Error running hook %s with message: %s", curHook.Name, possibleError.Error())
 				errorsOccurred = append(errorsOccurred, possibleError)
 			}
 
@@ -674,7 +674,7 @@ func runActionWithHooks(description string, terragruntOptions *options.Terragrun
 	if beforeHookErrors == nil {
 		actionErrors = action()
 	} else {
-		terragruntOptions.Logger.Printf("Errors encountered running before_hooks. Not running '%s'.", description)
+		terragruntOptions.Logger.Errorf("Errors encountered running before_hooks. Not running '%s'.", description)
 	}
 
 	postHookErrors := processHooks(terragruntConfig.Terraform.GetAfterHooks(), terragruntOptions, beforeHookErrors, actionErrors)
@@ -708,7 +708,7 @@ func runTerraformWithRetry(terragruntOptions *options.TerragruntOptions) error {
 	for i := 0; i < terragruntOptions.MaxRetryAttempts; i++ {
 		if out, tferr := shell.RunTerraformCommandWithOutput(terragruntOptions, terragruntOptions.TerraformCliArgs...); tferr != nil {
 			if out != nil && isRetryable(out.Stderr, tferr, terragruntOptions) {
-				terragruntOptions.Logger.Printf("Encountered an error eligible for retrying. Sleeping %v before retrying.\n", terragruntOptions.Sleep)
+				terragruntOptions.Logger.Infof("Encountered an error eligible for retrying. Sleeping %v before retrying.\n", terragruntOptions.Sleep)
 				time.Sleep(terragruntOptions.Sleep)
 			} else {
 				return tferr

cli/download_source.go

@@ -33,14 +33,14 @@ func downloadTerraformSource(source string, terragruntOptions *options.Terragrun
 		return nil, err
 	}
 
-	terragruntOptions.Logger.Printf("Copying files from %s into %s", terragruntOptions.WorkingDir, terraformSource.WorkingDir)
+	terragruntOptions.Logger.Debugf("Copying files from %s into %s", terragruntOptions.WorkingDir, terraformSource.WorkingDir)
 	if err := util.CopyFolderContents(terragruntOptions.WorkingDir, terraformSource.WorkingDir, MODULE_MANIFEST_NAME); err != nil {
 		return nil, err
 	}
 
 	updatedTerragruntOptions := terragruntOptions.Clone(terragruntOptions.TerragruntConfigPath)
 
-	terragruntOptions.Logger.Printf("Setting working directory to %s", terraformSource.WorkingDir)
+	terragruntOptions.Logger.Debugf("Setting working directory to %s", terraformSource.WorkingDir)
 	updatedTerragruntOptions.WorkingDir = terraformSource.WorkingDir
 
 	return updatedTerragruntOptions, nil
@@ -49,7 +49,7 @@ func downloadTerraformSource(source string, terragruntOptions *options.Terragrun
 // Download the specified TerraformSource if the latest code hasn't already been downloaded.
 func downloadTerraformSourceIfNecessary(terraformSource *tfsource.TerraformSource, terragruntOptions *options.TerragruntOptions, terragruntConfig *config.TerragruntConfig) error {
 	if terragruntOptions.SourceUpdate {
-		terragruntOptions.Logger.Printf("The --%s flag is set, so deleting the temporary folder %s before downloading source.", OPT_TERRAGRUNT_SOURCE_UPDATE, terraformSource.DownloadDir)
+		terragruntOptions.Logger.Debugf("The --%s flag is set, so deleting the temporary folder %s before downloading source.", OPT_TERRAGRUNT_SOURCE_UPDATE, terraformSource.DownloadDir)
 		if err := os.RemoveAll(terraformSource.DownloadDir); err != nil {
 			return errors.WithStackTrace(err)
 		}
@@ -61,7 +61,7 @@ func downloadTerraformSourceIfNecessary(terraformSource *tfsource.TerraformSourc
 	}
 
 	if alreadyLatest {
-		terragruntOptions.Logger.Printf("Terraform files in %s are up to date. Will not download again.", terraformSource.WorkingDir)
+		terragruntOptions.Logger.Debugf("Terraform files in %s are up to date. Will not download again.", terraformSource.WorkingDir)
 		return nil
 	}
 
@@ -104,7 +104,7 @@ func alreadyHaveLatestCode(terraformSource *tfsource.TerraformSource, terragrunt
 	}
 
 	if len(tfFiles) == 0 {
-		terragruntOptions.Logger.Printf("Working dir %s exists but contains no Terraform files, so assuming code needs to be downloaded again.", terraformSource.WorkingDir)
+		terragruntOptions.Logger.Debugf("Working dir %s exists but contains no Terraform files, so assuming code needs to be downloaded again.", terraformSource.WorkingDir)
 		return false, nil
 	}
 
@@ -146,7 +146,7 @@ var copyFiles = func(client *getter.Client) error {
 
 // Download the code from the Canonical Source URL into the Download Folder using the go-getter library
 func downloadSource(terraformSource *tfsource.TerraformSource, terragruntOptions *options.TerragruntOptions, terragruntConfig *config.TerragruntConfig) error {
-	terragruntOptions.Logger.Printf("Downloading Terraform configurations from %s into %s", terraformSource.CanonicalSourceURL, terraformSource.DownloadDir)
+	terragruntOptions.Logger.Debugf("Downloading Terraform configurations from %s into %s", terraformSource.CanonicalSourceURL, terraformSource.DownloadDir)
 
 	if err := getter.GetAny(terraformSource.DownloadDir, terraformSource.CanonicalSourceURL.String(), copyFiles); err != nil {
 		return errors.WithStackTrace(err)

cli/hclfmt.go

@@ -29,11 +29,11 @@ func runHCLFmt(terragruntOptions *options.TerragruntOptions) error {
 		if !filepath.IsAbs(targetFile) {
 			targetFile = util.JoinPath(workingDir, targetFile)
 		}
-		terragruntOptions.Logger.Printf("Formatting terragrunt.hcl file at: %s.", targetFile)
+		terragruntOptions.Logger.Infof("Formatting terragrunt.hcl file at: %s.", targetFile)
 		return formatTgHCL(terragruntOptions, targetFile)
 	}
 
-	terragruntOptions.Logger.Printf("Formatting terragrunt.hcl files from the directory tree %s.", terragruntOptions.WorkingDir)
+	terragruntOptions.Logger.Infof("Formatting terragrunt.hcl files from the directory tree %s.", terragruntOptions.WorkingDir)
 	// zglob normalizes paths to "/"
 	tgHclFiles, err := zglob.Glob(util.JoinPath(workingDir, "**", "*.hcl"))
 	if err != nil {
@@ -66,24 +66,24 @@ func runHCLFmt(terragruntOptions *options.TerragruntOptions) error {
 // formatTgHCL uses the hcl2 library to format the terragrunt.hcl file. This will attempt to parse the HCL file first to
 // ensure that there are no syntax errors, before attempting to format it.
 func formatTgHCL(terragruntOptions *options.TerragruntOptions, tgHclFile string) error {
-	terragruntOptions.Logger.Printf("Formatting %s", tgHclFile)
+	terragruntOptions.Logger.Infof("Formatting %s", tgHclFile)
 
 	info, err := os.Stat(tgHclFile)
 	if err != nil {
-		terragruntOptions.Logger.Printf("Error retrieving file info of %s", tgHclFile)
+		terragruntOptions.Logger.Errorf("Error retrieving file info of %s", tgHclFile)
 		return err
 	}
 
 	contentsStr, err := util.ReadFileAsString(tgHclFile)
 	if err != nil {
-		terragruntOptions.Logger.Printf("Error reading %s", tgHclFile)
+		terragruntOptions.Logger.Errorf("Error reading %s", tgHclFile)
 		return err
 	}
 	contents := []byte(contentsStr)
 
 	err = checkErrors(contents, tgHclFile)
 	if err != nil {
-		terragruntOptions.Logger.Printf("Error parsing %s", tgHclFile)
+		terragruntOptions.Logger.Errorf("Error parsing %s", tgHclFile)
 		return err
 	}
 

cli/version_check.go

@@ -47,7 +47,7 @@ func PopulateTerraformVersion(terragruntOptions *options.TerragruntOptions) erro
 	}
 
 	terragruntOptions.TerraformVersion = terraformVersion
-	terragruntOptions.Logger.Printf("Terraform version: %s", terraformVersion)
+	terragruntOptions.Logger.Debugf("Terraform version: %s", terraformVersion)
 	return nil
 }
 

config/dependency.go

@@ -469,7 +469,7 @@ func terragruntAlreadyInit(terragruntOptions *options.TerragruntOptions, configP
 func getTerragruntOutputJsonFromInitFolder(terragruntOptions *options.TerragruntOptions, terraformWorkingDir string, iamRole string) ([]byte, error) {
 	targetConfig := terragruntOptions.TerragruntConfigPath
 
-	terragruntOptions.Logger.Infof("Detected module %s is already init-ed. Retrieving outputs directly from working directory.", targetConfig)
+	terragruntOptions.Logger.Debugf("Detected module %s is already init-ed. Retrieving outputs directly from working directory.", targetConfig)
 
 	targetTGOptions, err := setupTerragruntOptionsForBareTerraform(terragruntOptions, terraformWorkingDir, targetConfig, iamRole)
 	if err != nil {

configstack/running_module.go

@@ -249,7 +249,7 @@ func (module *runningModule) moduleFinished(moduleErr error) {
 	if moduleErr == nil {
 		module.Module.TerragruntOptions.Logger.Debugf("Module %s has finished successfully!", module.Module.Path)
 	} else {
-		module.Module.TerragruntOptions.Logger.Printf("Module %s has finished with an error: %v", module.Module.Path, moduleErr)
+		module.Module.TerragruntOptions.Logger.Errorf("Module %s has finished with an error: %v", module.Module.Path, moduleErr)
 	}
 
 	module.Status = Finished

configstack/stack.go

@@ -81,14 +81,14 @@ func (stack *Stack) Run(terragruntOptions *options.TerragruntOptions) error {
 func (stack *Stack) summarizePlanAllErrors(terragruntOptions *options.TerragruntOptions, errorStreams []bytes.Buffer) {
 	for i, errorStream := range errorStreams {
 		output := errorStream.String()
-		terragruntOptions.Logger.Println(output)
+		terragruntOptions.Logger.Infoln(output)
 		if strings.Contains(output, "Error running plan:") {
 			if strings.Contains(output, ": Resource 'data.terraform_remote_state.") {
 				var dependenciesMsg string
 				if len(stack.Modules[i].Dependencies) > 0 {
 					dependenciesMsg = fmt.Sprintf(" contains dependencies to %v and", stack.Modules[i].Config.Dependencies.Paths)
 				}
-				terragruntOptions.Logger.Printf("%v%v refers to remote state "+
+				terragruntOptions.Logger.Infof("%v%v refers to remote state "+
 					"you may have to apply your changes in the dependencies prior running terragrunt plan-all.\n",
 					stack.Modules[i].Path,
 					dependenciesMsg,

docs/_docs/04_reference/cli-options.md

@@ -561,8 +561,8 @@ When passed it, sets logging level for terragrunt. All supported levels are:
 * panic
 * fatal
 * error
-* warn (this is the default)
-* info
+* warn
+* info (this is the default)
 * debug
 * trace
 

dynamodb/dynamo_lock_table.go

@@ -44,7 +44,7 @@ func CreateLockTableIfNecessary(tableName string, tags map[string]string, client
 	}
 
 	if !tableExists {
-		terragruntOptions.Logger.Printf("Lock table %s does not exist in DynamoDB. Will need to create it just this first time.", tableName)
+		terragruntOptions.Logger.Debugf("Lock table %s does not exist in DynamoDB. Will need to create it just this first time.", tableName)
 		return CreateLockTable(tableName, tags, client, terragruntOptions)
 	}
 
@@ -81,7 +81,7 @@ func CreateLockTable(tableName string, tags map[string]string, client *dynamodb.
 	tableCreateDeleteSemaphore.Acquire()
 	defer tableCreateDeleteSemaphore.Release()
 
-	terragruntOptions.Logger.Printf("Creating table %s in DynamoDB", tableName)
+	terragruntOptions.Logger.Debugf("Creating table %s in DynamoDB", tableName)
 
 	attributeDefinitions := []*dynamodb.AttributeDefinition{
 		{AttributeName: aws.String(ATTR_LOCK_ID), AttributeType: aws.String(dynamodb.ScalarAttributeTypeS)},
@@ -100,7 +100,7 @@ func CreateLockTable(tableName string, tags map[string]string, client *dynamodb.
 
 	if err != nil {
 		if isTableAlreadyBeingCreatedOrUpdatedError(err) {
-			terragruntOptions.Logger.Printf("Looks like someone created table %s at the same time. Will wait for it to be in active state.", tableName)
+			terragruntOptions.Logger.Debugf("Looks like someone created table %s at the same time. Will wait for it to be in active state.", tableName)
 		} else {
 			return errors.WithStackTrace(err)
 		}
@@ -128,12 +128,12 @@ func CreateLockTable(tableName string, tags map[string]string, client *dynamodb.
 func tagTableIfTagsGiven(tags map[string]string, tableArn *string, client *dynamodb.DynamoDB, terragruntOptions *options.TerragruntOptions) error {
 
 	if tags == nil || len(tags) == 0 {
-		terragruntOptions.Logger.Printf("No tags for lock table given.")
+		terragruntOptions.Logger.Debugf("No tags for lock table given.")
 		return nil
 	}
 
 	// we were able to create the table successfully, now add tags
-	terragruntOptions.Logger.Printf("Adding tags to lock table: %s", tags)
+	terragruntOptions.Logger.Debugf("Adding tags to lock table: %s", tags)
 
 	var tagsConverted []*dynamodb.Tag
 
@@ -183,12 +183,12 @@ func waitForTableToBeActiveWithRandomSleep(tableName string, client *dynamodb.Dy
 		}
 
 		if tableReady {
-			terragruntOptions.Logger.Printf("Success! Table %s is now in active state.", tableName)
+			terragruntOptions.Logger.Debugf("Success! Table %s is now in active state.", tableName)
 			return nil
 		}
 
 		sleepBetweenRetries := util.GetRandomTime(sleepBetweenRetriesMin, sleepBetweenRetriesMax)
-		terragruntOptions.Logger.Printf("Table %s is not yet in active state. Will check again after %s.", tableName, sleepBetweenRetries)
+		terragruntOptions.Logger.Debugf("Table %s is not yet in active state. Will check again after %s.", tableName, sleepBetweenRetries)
 		time.Sleep(sleepBetweenRetries)
 	}
 
@@ -203,14 +203,14 @@ func UpdateLockTableSetSSEncryptionOnIfNecessary(tableName string, client *dynam
 	}
 
 	if tableSSEncrypted {
-		terragruntOptions.Logger.Printf("Table %s already has encryption enabled", tableName)
+		terragruntOptions.Logger.Debugf("Table %s already has encryption enabled", tableName)
 		return nil
 	}
 
 	tableCreateDeleteSemaphore.Acquire()
 	defer tableCreateDeleteSemaphore.Release()
 
-	terragruntOptions.Logger.Printf("Enabling server-side encryption on table %s in AWS DynamoDB", tableName)
+	terragruntOptions.Logger.Debugf("Enabling server-side encryption on table %s in AWS DynamoDB", tableName)
 
 	input := &dynamodb.UpdateTableInput{
 		SSESpecification: &dynamodb.SSESpecification{
@@ -222,7 +222,7 @@ func UpdateLockTableSetSSEncryptionOnIfNecessary(tableName string, client *dynam
 
 	if _, err := client.UpdateTable(input); err != nil {
 		if isTableAlreadyBeingCreatedOrUpdatedError(err) {
-			terragruntOptions.Logger.Printf("Looks like someone is already updating table %s at the same time. Will wait for that update to complete.", tableName)
+			terragruntOptions.Logger.Debugf("Looks like someone is already updating table %s at the same time. Will wait for that update to complete.", tableName)
 		} else {
 			return errors.WithStackTrace(err)
 		}
@@ -240,7 +240,7 @@ func waitForEncryptionToBeEnabled(tableName string, client *dynamodb.DynamoDB, t
 	maxRetries := 15
 	sleepBetweenRetries := 20 * time.Second
 
-	terragruntOptions.Logger.Printf("Waiting for encryption to be enabled on table %s", tableName)
+	terragruntOptions.Logger.Debugf("Waiting for encryption to be enabled on table %s", tableName)
 
 	for i := 0; i < maxRetries; i++ {
 		tableSSEncrypted, err := LockTableCheckSSEncryptionIsOn(tableName, client)
@@ -249,11 +249,11 @@ func waitForEncryptionToBeEnabled(tableName string, client *dynamodb.DynamoDB, t
 		}
 
 		if tableSSEncrypted {
-			terragruntOptions.Logger.Printf("Encryption is now enabled for table %s!", tableName)
+			terragruntOptions.Logger.Debugf("Encryption is now enabled for table %s!", tableName)
 			return nil
 		}
 
-		terragruntOptions.Logger.Printf("Encryption is still not enabled for table %s. Will sleep for %v and try again.", tableName, sleepBetweenRetries)
+		terragruntOptions.Logger.Debugf("Encryption is still not enabled for table %s. Will sleep for %v and try again.", tableName, sleepBetweenRetries)
 		time.Sleep(sleepBetweenRetries)
 	}
 

options/options.go

@@ -227,7 +227,7 @@ func NewTerragruntOptionsForTest(terragruntConfigPath string) (*TerragruntOption
 
 	if err != nil {
 		logger := util.CreateLogEntry("", DEFAULT_LOG_LEVEL)
-		logger.Printf("error: %v\n", errors.WithStackTrace(err))
+		logger.Errorf("%v\n", errors.WithStackTrace(err))
 		return nil, err
 	}
 

remote/remote_state.go

@@ -64,7 +64,7 @@ func (remoteState *RemoteState) Validate() error {
 // Perform any actions necessary to initialize the remote state before it's used for storage. For example, if you're
 // using S3 or GCS for remote state storage, this may create the bucket if it doesn't exist already.
 func (remoteState *RemoteState) Initialize(terragruntOptions *options.TerragruntOptions) error {
-	terragruntOptions.Logger.Printf("Initializing remote state for the %s backend", remoteState.Backend)
+	terragruntOptions.Logger.Debugf("Initializing remote state for the %s backend", remoteState.Backend)
 	initializer, hasInitializer := remoteStateInitializers[remoteState.Backend]
 	if hasInitializer {
 		return initializer.Initialize(remoteState, terragruntOptions)
@@ -116,7 +116,7 @@ func (remoteState *RemoteState) differsFrom(existingBackend *TerraformBackend, t
 		return true
 	}
 
-	terragruntOptions.Logger.Printf("Backend %s has not changed.", existingBackend.Type)
+	terragruntOptions.Logger.Debugf("Backend %s has not changed.", existingBackend.Type)
 	return false
 }