do not use logging before it's ready

Author: Massimiliano Pippi

cli/cli.go

@@ -118,7 +118,22 @@ func parseFormatString(arg string) (feedback.OutputFormat, bool) {
 }
 
 func preRun(cmd *cobra.Command, args []string) {
-	// before doing anything, decide whether we should log to stdout
+	//
+	// Prepare the configuration system
+	//
+	configPath := ""
+	if configFile != "" {
+		// override the config path if --config-file was passed
+		configPath = filepath.Dir(configFile)
+	}
+	configuration.Init(configPath)
+	configFile := viper.ConfigFileUsed()
+
+	//
+	// Prepare logging
+	//
+
+	// decide whether we should log to stdout
 	if verbose {
 		// if we print on stdout, do it in full colors
 		logrus.SetOutput(colorable.NewColorableStdout())
@@ -129,23 +144,14 @@ func preRun(cmd *cobra.Command, args []string) {
 		logrus.SetOutput(ioutil.Discard)
 	}
 
-	// setup the configuration system
-	configPath := ""
-	if configFile != "" {
-		// override the config path if --config-file was passed
-		configPath = filepath.Dir(configFile)
-	}
-	configuration.Init(configPath)
-
-	// normalize the format strings
-	outputFormat = strings.ToLower(outputFormat)
-	// configure the output package
-	output.OutputFormat = outputFormat
-	// configure log format
+	// set the Logger format
 	logFormat := strings.ToLower(viper.GetString("logging.format"))
+	if logFormat == "json" {
+		logrus.SetFormatter(&logrus.JSONFormatter{})
+	}
 
 	// should we log to file?
-	logFile := viper.GetString("log.file")
+	logFile := viper.GetString("logging.file")
 	if logFile != "" {
 		file, err := os.OpenFile(logFile, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
 		if err != nil {
@@ -169,11 +175,14 @@ func preRun(cmd *cobra.Command, args []string) {
 		logrus.SetLevel(lvl)
 	}
 
-	// set the Logger format
-	if logFormat == "json" {
-		logrus.SetFormatter(&logrus.JSONFormatter{})
-	}
+	//
+	// Prepare the Feedback system
+	//
 
+	// normalize the format strings
+	outputFormat = strings.ToLower(outputFormat)
+	// configure the output package
+	output.OutputFormat = outputFormat
 	// check the right output format was passed
 	format, found := parseFormatString(outputFormat)
 	if !found {
@@ -184,10 +193,18 @@ func preRun(cmd *cobra.Command, args []string) {
 	// use the output format to configure the Feedback
 	feedback.SetFormat(format)
 
-	logrus.Info(globals.VersionInfo.Application + "-" + globals.VersionInfo.VersionString)
-	logrus.Info("Starting root command preparation (`arduino`)")
+	//
+	// Print some status info and check command is consistent
+	//
+
+	if configFile != "" {
+		logrus.Infof("Using config file: %s", configFile)
+	} else {
+		logrus.Info("Config file not found, using default values")
+	}
+
+	logrus.Info(globals.VersionInfo.Application + " version " + globals.VersionInfo.VersionString)
 
-	logrus.Info("Formatter set")
 	if outputFormat != "text" {
 		cmd.SetHelpFunc(func(cmd *cobra.Command, args []string) {
 			logrus.Warn("Calling help on JSON format")

configuration/configuration.go

@@ -27,7 +27,9 @@ import (
 	"github.com/spf13/viper"
 )
 
-// Init initialize defaults and read the configuration file
+// Init initialize defaults and read the configuration file.
+// Please note the logging system hasn't been configured yet,
+// so logging shouldn't be used here.
 func Init(configPath string) {
 	// Config file metadata
 	viper.SetConfigName("arduino-cli")
@@ -38,7 +40,6 @@ func Init(configPath string) {
 	}
 
 	// Add paths where to search for a config file
-	logrus.Infof("Checking for config file in: %s", configPath)
 	viper.AddConfigPath(configPath)
 
 	// Bind env vars
@@ -67,9 +68,9 @@ func Init(configPath string) {
 
 	// Attempt to read config file
 	if err := viper.ReadInConfig(); err != nil {
-		if _, ok := err.(viper.ConfigFileNotFoundError); ok {
-			logrus.Info("Config file not found, using default values")
-		} else {
+		// ConfigFileNotFoundError is acceptable, anything else
+		// should be reported to the user
+		if _, ok := err.(viper.ConfigFileNotFoundError); !ok {
 			feedback.Errorf("Error reading config file: %v", err)
 		}
 	}
@@ -79,7 +80,7 @@ func Init(configPath string) {
 func getDefaultArduinoDataDir() string {
 	userHomeDir, err := os.UserHomeDir()
 	if err != nil {
-		logrus.Errorf("Unable to get user home dir: %v", err)
+		feedback.Errorf("Unable to get user home dir: %v", err)
 		return "."
 	}
 
@@ -91,7 +92,7 @@ func getDefaultArduinoDataDir() string {
 	case "windows":
 		localAppDataPath, err := win32.GetLocalAppDataFolder()
 		if err != nil {
-			logrus.Errorf("Unable to get Local App Data Folder: %v", err)
+			feedback.Errorf("Unable to get Local App Data Folder: %v", err)
 			return "."
 		}
 		return filepath.Join(localAppDataPath, "Arduino15")
@@ -104,7 +105,7 @@ func getDefaultArduinoDataDir() string {
 func getDefaultSketchbookDir() string {
 	userHomeDir, err := os.UserHomeDir()
 	if err != nil {
-		logrus.Errorf("Unable to get user home dir: %v", err)
+		feedback.Errorf("Unable to get user home dir: %v", err)
 		return "."
 	}
 
@@ -116,7 +117,7 @@ func getDefaultSketchbookDir() string {
 	case "windows":
 		documentsPath, err := win32.GetDocumentsFolder()
 		if err != nil {
-			logrus.Errorf("Unable to get Documents Folder: %v", err)
+			feedback.Errorf("Unable to get Documents Folder: %v", err)
 			return "."
 		}
 		return filepath.Join(documentsPath, "Arduino")
@@ -138,18 +139,17 @@ func IsBundledInDesktopIDE() bool {
 	logrus.Info("Checking if CLI is Bundled into the IDE")
 	executable, err := os.Executable()
 	if err != nil {
-		logrus.WithError(err).Warn("Cannot get executable path")
+		feedback.Errorf("Cannot get executable path: %v", err)
 		return viper.GetBool("IDE.Bundled")
 	}
 
 	executablePath, err := filepath.EvalSymlinks(executable)
 	if err != nil {
-		logrus.WithError(err).Warn("Cannot get executable path")
+		feedback.Errorf("Cannot get executable path: %v", err)
 		return viper.GetBool("IDE.Bundled")
 	}
 
 	ideDir := filepath.Dir(executablePath)
-	logrus.Info("Candidate IDE Directory: ", ideDir)
 
 	// We check an arbitrary number of folders that are part of the IDE
 	// install tree
@@ -166,7 +166,6 @@ func IsBundledInDesktopIDE() bool {
 		}
 
 		if test == "portable" {
-			logrus.Info("IDE is portable")
 			viper.Set("IDE.Portable", true)
 		}
 	}