Enhance logging (#233)

Signed-off-by: thepetk <thepetk@gmail.com>

go/README.md

@@ -91,6 +91,15 @@ $ ./alizer analyze <path>
 $ ./alizer devfile <path>
 ```
 
+#### CLI Arguments
+
+##### log
+Sets the logging level of the CLI. The arg accepts only 3 values [`debug`, `info`, `warning`]. The default value is `warning` and the logging level is `ErrorLevel`. Example usage
+
+```
+$ ./alizer analyze --log debug <path>
+```
+
 #### Outputs
 Example of `analyze` command:
 ```json

go/go.mod

@@ -4,14 +4,17 @@ go 1.19
 
 require (
 	github.com/go-git/go-git/v5 v5.5.1
+	github.com/go-logr/logr v1.2.4
 	github.com/moby/buildkit v0.10.6
 	github.com/pkg/errors v0.9.1
 	github.com/sabhiram/go-gitignore v0.0.0-20210923224102-525f6e181f06
 	github.com/spf13/cobra v1.7.0
 	github.com/spf13/pflag v1.0.5
 	github.com/stretchr/testify v1.8.1
+	go.uber.org/zap v1.24.0
 	golang.org/x/mod v0.10.0
 	gopkg.in/yaml.v3 v3.0.1
+	sigs.k8s.io/controller-runtime v0.15.0
 )
 
 require (
@@ -24,23 +27,37 @@ require (
 	github.com/emirpasic/gods v1.18.1 // indirect
 	github.com/go-git/gcfg v1.5.0 // indirect
 	github.com/go-git/go-billy/v5 v5.4.1 // indirect
+	github.com/go-logr/zapr v1.2.4 // indirect
 	github.com/gogo/protobuf v1.3.2 // indirect
 	github.com/golang/protobuf v1.5.3 // indirect
+	github.com/google/gofuzz v1.1.0 // indirect
 	github.com/imdario/mergo v0.3.15 // indirect
 	github.com/inconshreveable/mousetrap v1.1.0 // indirect
 	github.com/jbenet/go-context v0.0.0-20150711004518-d14ea06fba99 // indirect
+	github.com/json-iterator/go v1.1.12 // indirect
 	github.com/kevinburke/ssh_config v1.2.0 // indirect
-	github.com/kr/pretty v0.3.0 // indirect
+	github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect
+	github.com/modern-go/reflect2 v1.0.2 // indirect
 	github.com/pjbgf/sha1cd v0.2.3 // indirect
 	github.com/pmezard/go-difflib v1.0.0 // indirect
 	github.com/rogpeppe/go-internal v1.10.0 // indirect
 	github.com/sergi/go-diff v1.3.1 // indirect
 	github.com/skeema/knownhosts v1.1.0 // indirect
 	github.com/xanzy/ssh-agent v0.3.3 // indirect
+	go.uber.org/atomic v1.7.0 // indirect
+	go.uber.org/multierr v1.6.0 // indirect
 	golang.org/x/crypto v0.8.0 // indirect
-	golang.org/x/net v0.9.0 // indirect
-	golang.org/x/sys v0.7.0 // indirect
-	golang.org/x/tools v0.8.0 // indirect
+	golang.org/x/net v0.10.0 // indirect
+	golang.org/x/sys v0.8.0 // indirect
+	golang.org/x/text v0.9.0 // indirect
+	golang.org/x/tools v0.9.1 // indirect
 	google.golang.org/protobuf v1.30.0 // indirect
+	gopkg.in/inf.v0 v0.9.1 // indirect
 	gopkg.in/warnings.v0 v0.1.2 // indirect
+	gopkg.in/yaml.v2 v2.4.0 // indirect
+	k8s.io/apimachinery v0.27.2 // indirect
+	k8s.io/klog/v2 v2.90.1 // indirect
+	k8s.io/utils v0.0.0-20230209194617-a36077c30491 // indirect
+	sigs.k8s.io/json v0.0.0-20221116044647-bc3834ca7abd // indirect
+	sigs.k8s.io/structured-merge-diff/v4 v4.2.3 // indirect
 )

go/pkg/apis/recognizer/component_recognizer.go

@@ -16,6 +16,7 @@ package recognizer
 import (
 	"context"
 	"errors"
+	"fmt"
 	"io/fs"
 	"path/filepath"
 	"regexp"
@@ -82,14 +83,19 @@ func DetectComponentsWithSettings(settings model.DetectionSettings) ([]model.Com
 }
 
 func detectComponentsWithSettings(settings model.DetectionSettings, ctx *context.Context) ([]model.Component, error) {
+	alizerLogger := utils.GetOrCreateLogger()
+	alizerLogger.V(0).Info("Starting component with settings detection")
+	alizerLogger.V(0).Info("Getting cached filepaths from root")
 	files, err := utils.GetCachedFilePathsFromRoot(settings.BasePath, ctx)
 	if err != nil {
+		alizerLogger.V(0).Info("Not able to get cached file paths from root: exiting")
 		return []model.Component{}, err
 	}
 	components := DetectComponentsFromFilesList(files, settings, ctx)
 
 	// it may happen that a language has no a specific configuration file (e.g opposite to JAVA -> pom.xml and Nodejs -> package.json)
 	// we then rely on the language recognizer
+	alizerLogger.V(0).Info("Checking for components without configuration file")
 	directoriesNotBelongingToExistingComponent := getDirectoriesWithoutConfigFile(settings.BasePath, components)
 	components = append(components, getComponentsWithoutConfigFile(directoriesNotBelongingToExistingComponent, settings, ctx)...)
 
@@ -99,13 +105,19 @@ func detectComponentsWithSettings(settings model.DetectionSettings, ctx *context
 // getComponentsWithoutConfigFile retrieves the components which are written with a language that does not require a config file.
 // Uses the settings to perform detection on the list of directories to analyze.
 func getComponentsWithoutConfigFile(directories []string, settings model.DetectionSettings, ctx *context.Context) []model.Component {
+	alizerLogger := utils.GetOrCreateLogger()
 	var components []model.Component
 	for _, dir := range directories {
+		alizerLogger.V(1).Info(fmt.Sprintf("Accessing %s dir", dir))
 		component, _ := detectComponentByFolderAnalysis(dir, []string{}, settings, ctx)
 		if component.Path != "" && isLangForNoConfigComponent(component.Languages[0]) {
+			alizerLogger.V(1).Info(fmt.Sprintf("Component %s found for %s dir", component.Name, dir))
 			components = append(components, component)
+		} else {
+			alizerLogger.V(1).Info(fmt.Sprintf("No component found for %s dir", dir))
 		}
 	}
+	alizerLogger.V(0).Info(fmt.Sprintf("Found %d components without configuration file", len(components)))
 	return components
 }
 
@@ -178,18 +190,27 @@ func isFirstPathParentOfSecond(firstPath string, secondPath string) bool {
 // DetectComponentsFromFilesList detect components by analyzing all files.
 // Uses the settings to perform component detection on files.
 func DetectComponentsFromFilesList(files []string, settings model.DetectionSettings, ctx *context.Context) []model.Component {
+	alizerLogger := utils.GetOrCreateLogger()
+	alizerLogger.V(0).Info(fmt.Sprintf("Detecting components for %d fetched file paths", len(files)))
 	configurationPerLanguage := langfiles.Get().GetConfigurationPerLanguageMapping()
 	var components []model.Component
 	for _, file := range files {
+		alizerLogger.V(1).Info(fmt.Sprintf("Accessing %s", file))
 		languages, err := getLanguagesByConfigurationFile(configurationPerLanguage, file)
+
 		if err != nil {
+			alizerLogger.V(1).Info(err.Error())
 			continue
 		}
 
+		alizerLogger.V(0).Info(fmt.Sprintf("File %s detected as configuration file for %d languages", file, len(languages)))
+		alizerLogger.V(1).Info("Searching for components based on this configuration file")
 		component, err := detectComponentUsingConfigFile(file, languages, settings, ctx)
 		if err != nil {
+			alizerLogger.V(1).Info(err.Error())
 			continue
 		}
+		alizerLogger.V(0).Info(fmt.Sprintf("Component %s found", component.Name))
 		components = appendIfMissing(components, component)
 	}
 	return components
@@ -210,12 +231,14 @@ func getLanguagesByConfigurationFile(configurationPerLanguage map[string][]strin
 			return languages, nil
 		}
 	}
-	return nil, errors.New("no languages found for configuration file " + file)
+	return nil, errors.New("no languages found for file " + file)
 }
 
 // detectComponentByFolderAnalysis returns a Component if found.
 // Using settings, detection starts from root and uses configLanguages as a target.
 func detectComponentByFolderAnalysis(root string, configLanguages []string, settings model.DetectionSettings, ctx *context.Context) (model.Component, error) {
+	alizerLogger := utils.GetOrCreateLogger()
+	alizerLogger.V(0).Info("Detecting component by folder language analysis")
 	languages, err := analyze(root, ctx)
 	if err != nil {
 		return model.Component{}, err
@@ -231,13 +254,15 @@ func detectComponentByFolderAnalysis(root string, configLanguages []string, sett
 			return component, nil
 		}
 	}
-
+	alizerLogger.V(0).Info("No component detected")
 	return model.Component{}, errors.New("no component detected")
 
 }
 
 // detectComponentByAnalyzingConfigFile returns a Component if found.
 func detectComponentByAnalyzingConfigFile(file string, language string, settings model.DetectionSettings, ctx *context.Context) (model.Component, error) {
+	alizerLogger := utils.GetOrCreateLogger()
+	alizerLogger.V(1).Info("Analyzing config file for singe language or family of languages")
 	if !isConfigurationValid(language, file) {
 		return model.Component{}, errors.New("language not valid for component detection")
 	}

go/pkg/apis/recognizer/devfile_recognizer.go

@@ -26,12 +26,15 @@ import (
 )
 
 func SelectDevFilesFromTypes(path string, devFileTypes []model.DevFileType) ([]int, error) {
+	alizerLogger := utils.GetOrCreateLogger()
 	ctx := context.Background()
+	alizerLogger.V(0).Info("Applying component detection to match a devfile")
 	devFilesIndexes := selectDevFilesFromComponentsDetectedInPath(path, devFileTypes)
 	if len(devFilesIndexes) > 0 {
+		alizerLogger.V(0).Info(fmt.Sprintf("Found %d potential matches", len(devFilesIndexes)))
 		return devFilesIndexes, nil
 	}
-
+	alizerLogger.V(0).Info("No components found, applying language analysis for devfile matching")
 	languages, err := analyze(path, &ctx)
 	if err != nil {
 		return []int{}, err
@@ -75,9 +78,13 @@ func SelectDevFileFromTypes(path string, devFileTypes []model.DevFileType) (int,
 
 func SelectDevFilesUsingLanguagesFromTypes(languages []model.Language, devFileTypes []model.DevFileType) ([]int, error) {
 	var devFilesIndexes []int
+	alizerLogger := utils.GetOrCreateLogger()
+	alizerLogger.V(1).Info("Searching potential matches from detected languages")
 	for _, language := range languages {
+		alizerLogger.V(1).Info(fmt.Sprintf("Accessing %s language", language.Name))
 		devFiles, err := selectDevFilesByLanguage(language, devFileTypes)
 		if err == nil {
+			alizerLogger.V(1).Info(fmt.Sprintf("Found %d potential matches for language %s", len(devFiles), language.Name))
 			devFilesIndexes = append(devFilesIndexes, devFiles...)
 		}
 	}
@@ -96,11 +103,14 @@ func SelectDevFileUsingLanguagesFromTypes(languages []model.Language, devFileTyp
 }
 
 func SelectDevFilesFromRegistry(path string, url string) ([]model.DevFileType, error) {
+	alizerLogger := utils.GetOrCreateLogger()
+	alizerLogger.V(0).Info("Starting devfile matching")
+	alizerLogger.V(1).Info(fmt.Sprintf("Downloading devfiles from registry %s", url))
 	devFileTypesFromRegistry, err := downloadDevFileTypesFromRegistry(url)
 	if err != nil {
 		return []model.DevFileType{}, err
 	}
-
+	alizerLogger.V(1).Info(fmt.Sprintf("Fetched %d devfiles", len(devFileTypesFromRegistry)))
 	indexes, err := SelectDevFilesFromTypes(path, devFileTypesFromRegistry)
 	if err != nil {
 		return []model.DevFileType{}, err

go/pkg/apis/recognizer/language_recognizer.go

@@ -13,6 +13,7 @@ package recognizer
 
 import (
 	"context"
+	"fmt"
 	"path/filepath"
 	"sort"
 	"strings"
@@ -36,20 +37,29 @@ func Analyze(path string) ([]model.Language, error) {
 func analyze(path string, ctx *context.Context) ([]model.Language, error) {
 	languagesFile := langfile.Get()
 	languagesDetected := make(map[string]languageItem)
-
+	alizerLogger := utils.GetOrCreateLogger()
+	alizerLogger.V(1).Info("Searching for files in root")
 	paths, err := utils.GetCachedFilePathsFromRoot(path, ctx)
 	if err != nil {
 		return []model.Language{}, err
 	}
+	alizerLogger.V(0).Info(fmt.Sprintf("Found %d cached file paths from root", len(paths)))
+	alizerLogger.V(1).Info("Searching for language file extensions in given paths")
 	extensionsGrouped := extractExtensions(paths)
+	alizerLogger.V(0).Info(fmt.Sprintf("Found %d file extensions in given paths", len(extensionsGrouped)))
 	extensionHasProgrammingLanguage := false
 	totalProgrammingPoints := 0
 	for extension := range extensionsGrouped {
+		alizerLogger.V(1).Info(fmt.Sprintf("Checking extension %s", extension))
 		languages := languagesFile.GetLanguagesByExtension(extension)
 		if len(languages) == 0 {
+			alizerLogger.V(1).Info(fmt.Sprintf("Not able to match %s extension with any known language", extension))
 			continue
 		}
+		alizerLogger.V(1).Info(fmt.Sprintf("Found %d languages for extension %s", len(languages), extension))
+		alizerLogger.V(1).Info(fmt.Sprintf("Accessing languages for extension %s", extension))
 		for _, language := range languages {
+			alizerLogger.V(1).Info(fmt.Sprintf("Accessing %s language", language.Name))
 			if language.Kind == "programming" {
 				var languageFileItem langfile.LanguageItem
 				var err error
@@ -58,14 +68,18 @@ func analyze(path string, ctx *context.Context) ([]model.Language, error) {
 				} else {
 					languageFileItem, err = languagesFile.GetLanguageByName(language.Group)
 					if err != nil {
+						alizerLogger.V(1).Info(fmt.Sprintf("Cannot get language item for %s", language.Name))
 						continue
 					}
 				}
 				tmpLanguageItem := languageItem{languageFileItem, 0}
+				alizerLogger.V(1).Info(fmt.Sprintf("Extension %s was found %d times. Adding %s to detected languages", extension, extensionsGrouped[extension], language.Name))
 				weight := languagesDetected[tmpLanguageItem.item.Name].weight + extensionsGrouped[extension]
 				tmpLanguageItem.weight = weight
 				languagesDetected[tmpLanguageItem.item.Name] = tmpLanguageItem
 				extensionHasProgrammingLanguage = true
+			} else {
+				alizerLogger.V(1).Info(fmt.Sprintf("%s is not a programming language", language.Name))
 			}
 		}
 		if extensionHasProgrammingLanguage {
@@ -75,6 +89,11 @@ func analyze(path string, ctx *context.Context) ([]model.Language, error) {
 	}
 
 	var languagesFound []model.Language
+	if len(languagesDetected) > 0 {
+		alizerLogger.V(0).Info(fmt.Sprintf("Accessing %d detected programming languages", len(languagesDetected)))
+	} else {
+		alizerLogger.V(0).Info("No programming language was detected")
+	}
 	for name, item := range languagesDetected {
 		tmpWeight := float64(item.weight) / float64(totalProgrammingPoints)
 		tmpWeight = float64(int(tmpWeight*100)) / 100
@@ -90,6 +109,7 @@ func analyze(path string, ctx *context.Context) ([]model.Language, error) {
 			if langEnricher != nil {
 				langEnricher.DoEnrichLanguage(&tmpLanguage, &paths)
 			}
+			alizerLogger.V(0).Info(fmt.Sprintf("%s weight is %f. Detecting frameworks", tmpLanguage.Name, tmpLanguage.Weight))
 			languagesFound = append(languagesFound, tmpLanguage)
 		}
 	}

go/pkg/cli/analyze/analyze.go

@@ -6,6 +6,8 @@ import (
 	"github.com/spf13/cobra"
 )
 
+var logLevel string
+
 func NewCmdAnalyze() *cobra.Command {
 	analyzeCmd := &cobra.Command{
 		Use:     "analyze",
@@ -15,6 +17,8 @@ func NewCmdAnalyze() *cobra.Command {
 		Run:     doAnalyze,
 		Example: `  alizer analyze /your/local/project/path`,
 	}
+	analyzeCmd.Flags().StringVar(&logLevel, "log", "", "log level for alizer. Default value: error. Accepted values: [debug, info, warning]")
+
 	return analyzeCmd
 }
 
@@ -23,5 +27,10 @@ func doAnalyze(cmd *cobra.Command, args []string) {
 		utils.PrintNoArgsWarningMessage(cmd.Name())
 		return
 	}
+	err := utils.GenLogger(logLevel)
+	if err != nil {
+		utils.PrintWrongLoggingLevelMessage(cmd.Name())
+		return
+	}
 	utils.PrintPrettifyOutput(recognizer.Analyze(args[0]))
 }

go/pkg/cli/component/component.go

@@ -7,7 +7,10 @@ import (
 	"github.com/spf13/cobra"
 )
 
-var portDetectionAlgorithms []string
+var (
+	logLevel                string
+	portDetectionAlgorithms []string
+)
 
 func NewCmdComponent() *cobra.Command {
 	componentCmd := &cobra.Command{
@@ -19,6 +22,7 @@ Examples of components: API Backend, Web Frontend, Payment Backend`,
 		Run:     doDetection,
 		Example: `  alizer component /your/local/project/path`,
 	}
+	componentCmd.Flags().StringVar(&logLevel, "log", "", "log level for alizer. Default value: error. Accepted values: [debug, info, warning]")
 	componentCmd.Flags().StringSliceVarP(&portDetectionAlgorithms, "port-detection", "p", []string{}, "port detection strategy to use when detecting a port. Currently supported strategies are 'docker', 'compose' and 'source'. You can pass more strategies at the same time. They will be executed in order. By default Alizer will execute docker, compose and source.")
 	return componentCmd
 }
@@ -28,6 +32,11 @@ func doDetection(cmd *cobra.Command, args []string) {
 		utils.PrintNoArgsWarningMessage(cmd.Name())
 		return
 	}
+	err := utils.GenLogger(logLevel)
+	if err != nil {
+		utils.PrintWrongLoggingLevelMessage(cmd.Name())
+		return
+	}
 	utils.PrintPrettifyOutput(recognizer.DetectComponentsWithPathAndPortStartegy(args[0], getPortDetectionStrategy()))
 }
 

go/pkg/cli/devfile/devfile.go

@@ -6,7 +6,7 @@ import (
 	"github.com/spf13/cobra"
 )
 
-var registry string
+var logLevel, registry string
 
 func NewCmdDevfile() *cobra.Command {
 	devfileCmd := &cobra.Command{
@@ -16,6 +16,7 @@ func NewCmdDevfile() *cobra.Command {
 		Args:  cobra.MaximumNArgs(1),
 		Run:   doSelectDevfile,
 	}
+	devfileCmd.Flags().StringVar(&logLevel, "log", "", "log level for alizer. Default value: error. Accepted values: [debug, info, warning]")
 	devfileCmd.Flags().StringVarP(&registry, "registry", "r", "", "registry where to download the devfiles. Default value: https://registry.devfile.io")
 	return devfileCmd
 }
@@ -28,5 +29,10 @@ func doSelectDevfile(cmd *cobra.Command, args []string) {
 	if registry == "" {
 		registry = "https://registry.devfile.io/index"
 	}
+	err := utils.GenLogger(logLevel)
+	if err != nil {
+		utils.PrintWrongLoggingLevelMessage(cmd.Name())
+		return
+	}
 	utils.PrintPrettifyOutput(recognizer.SelectDevFilesFromRegistry(args[0], registry))
 }