overall/logging: new trace log level

- new root flag '--trace' with precedence over '--verbose'
- some new trace logs
- migrated some debug logs to trace logs to reduce debug verbosity

cmd/cluster/clusterCreate.go

@@ -315,7 +315,7 @@ func parseCreateClusterCmd(cmd *cobra.Command, args []string, createClusterOpts
 		}
 	}
 
-	log.Debugf("PortFilterMap: %+v", portFilterMap)
+	log.Tracef("PortFilterMap: %+v", portFilterMap)
 
 	/********************
 	 *									*

cmd/root.go

@@ -45,6 +45,7 @@ import (
 // RootFlags describes a struct that holds flags that can be set on root level of the command
 type RootFlags struct {
 	debugLogging bool
+	traceLogging bool
 	version      bool
 }
 
@@ -98,6 +99,7 @@ func init() {
 	// add persistent flags (present to all subcommands)
 	// rootCmd.PersistentFlags().StringVar(&cfgFile, "config", "", "config file (default is $HOME/.k3d/config.yaml)")
 	rootCmd.PersistentFlags().BoolVar(&flags.debugLogging, "verbose", false, "Enable verbose output (debug logging)")
+	rootCmd.PersistentFlags().BoolVar(&flags.traceLogging, "trace", false, "Enable super verbose output (trace logging)")
 
 	// add local flags
 	rootCmd.Flags().BoolVar(&flags.version, "version", false, "Show k3d and default k3s version")
@@ -121,10 +123,14 @@ func init() {
 
 // initLogging initializes the logger
 func initLogging() {
-	if flags.debugLogging {
+	if flags.traceLogging {
+		log.SetLevel(log.TraceLevel)
+	} else if flags.debugLogging {
 		log.SetLevel(log.DebugLevel)
 	} else {
 		switch logLevel := strings.ToUpper(os.Getenv("LOG_LEVEL")); logLevel {
+		case "TRACE":
+			log.SetLevel(log.TraceLevel)
 		case "DEBUG":
 			log.SetLevel(log.DebugLevel)
 		case "WARN":
@@ -150,6 +156,7 @@ func initLogging() {
 		LogLevels: []log.Level{
 			log.InfoLevel,
 			log.DebugLevel,
+			log.TraceLevel,
 		},
 	})
 	log.SetFormatter(&log.TextFormatter{

pkg/cluster/cluster.go

@@ -277,7 +277,6 @@ func ClusterCreate(ctx context.Context, runtime k3drt.Runtime, cluster *k3d.Clus
 			servers := ""
 			for _, node := range cluster.Nodes {
 				if node.Role == k3d.ServerRole {
-					log.Debugf("Node NAME: %s", node.Name)
 					if servers == "" {
 						servers = node.Name
 					} else {

pkg/cluster/host.go

@@ -44,7 +44,7 @@ func GetHostIP(ctx context.Context, rtime rt.Runtime, cluster *k3d.Cluster) (net
 	// Docker Runtime
 	if rtime == rt.Docker {
 
-		log.Debugf("Runtime GOOS: %s", runtime.GOOS)
+		log.Tracef("Runtime GOOS: %s", runtime.GOOS)
 
 		// "native" Docker on Linux
 		if runtime.GOOS == "linux" {
@@ -81,11 +81,14 @@ func resolveHostnameFromInside(ctx context.Context, rtime rt.Runtime, node *k3d.
 	submatches := map[string]string{}
 	scanner := bufio.NewScanner(logreader)
 	for scanner.Scan() {
+		log.Tracef("Scanning Log Line '%s'", scanner.Text())
 		match := nsLookupAddressRegexp.FindStringSubmatch(scanner.Text())
 		if len(match) == 0 {
 			continue
 		}
+		log.Tracef("-> Match(es): '%+v'", match)
 		submatches = util.MapSubexpNames(nsLookupAddressRegexp.SubexpNames(), match)
+		log.Tracef(" -> Submatch(es): %+v", submatches)
 		break
 	}
 	if _, ok := submatches["ip"]; !ok {

pkg/cluster/kubeconfig.go

@@ -194,7 +194,7 @@ func KubeconfigGet(ctx context.Context, runtime runtimes.Runtime, cluster *k3d.C
 	// set current-context to new context name
 	kc.CurrentContext = newContextName
 
-	log.Debugf("Modified Kubeconfig: %+v", kc)
+	log.Tracef("Modified Kubeconfig: %+v", kc)
 
 	return kc, nil
 }
@@ -237,7 +237,7 @@ func KubeconfigWriteToPath(ctx context.Context, kubeconfig *clientcmdapi.Config,
 // KubeconfigMerge merges a new kubeconfig into an existing kubeconfig and returns the result
 func KubeconfigMerge(ctx context.Context, newKubeConfig *clientcmdapi.Config, existingKubeConfig *clientcmdapi.Config, outPath string, overwriteConflicting bool, updateCurrentContext bool) error {
 
-	log.Debugf("Merging new KubeConfig:\n%+v\n>>> into existing KubeConfig:\n%+v", newKubeConfig, existingKubeConfig)
+	log.Tracef("Merging new Kubeconfig:\n%+v\n>>> into existing Kubeconfig:\n%+v", newKubeConfig, existingKubeConfig)
 
 	// Overwrite values in existing kubeconfig
 	for k, v := range newKubeConfig.Clusters {
@@ -276,7 +276,12 @@ func KubeconfigMerge(ctx context.Context, newKubeConfig *clientcmdapi.Config, ex
 		existingKubeConfig.CurrentContext = newKubeConfig.CurrentContext
 	}
 
-	log.Debugf("Merged KubeConfig:\n%+v", existingKubeConfig)
+	kubeconfigYaml, err := clientcmd.Write(*existingKubeConfig)
+	if err != nil {
+		log.Debugf("Merged Kubeconfig:\n%+v", existingKubeConfig)
+	} else {
+		log.Tracef("Merged Kubeconfig:\n%s", kubeconfigYaml)
+	}
 
 	return KubeconfigWrite(ctx, existingKubeConfig, outPath)
 }

pkg/cluster/node.go

@@ -207,7 +207,7 @@ func NodeCreateMulti(ctx context.Context, runtime runtimes.Runtime, nodes []*k3d
 
 // NodeCreate creates a new containerized k3s node
 func NodeCreate(ctx context.Context, runtime runtimes.Runtime, node *k3d.Node, createNodeOpts k3d.NodeCreateOpts) error {
-	log.Debugf("Creating node from spec\n%+v", node)
+	log.Tracef("Creating node from spec\n%+v", node)
 
 	/*
 	 * CONFIGURATION

pkg/runtimes/docker/container.go

@@ -40,7 +40,7 @@ import (
 // createContainer creates a new docker container from translated specs
 func createContainer(ctx context.Context, dockerNode *NodeInDocker, name string) error {
 
-	log.Debugf("Creating docker container with translated config\n%+v\n", dockerNode) // TODO: remove?
+	log.Tracef("Creating docker container with translated config\n%+v\n", dockerNode)
 
 	// initialize docker client
 	docker, err := client.NewClientWithOpts(client.FromEnv, client.WithAPIVersionNegotiation())
@@ -65,7 +65,7 @@ func createContainer(ctx context.Context, dockerNode *NodeInDocker, name string)
 			log.Errorf("Failed to create container '%s'", name)
 			return err
 		}
-		log.Debugln("Created container", resp.ID)
+		log.Debugf("Created container %s (ID: %s)", name, resp.ID)
 		break
 	}
 

pkg/runtimes/docker/kubeconfig.go

@@ -45,7 +45,7 @@ func (d Docker) GetKubeconfig(ctx context.Context, node *k3d.Node) (io.ReadClose
 		return nil, err
 	}
 
-	log.Debugf("Container Details: %+v", container)
+	log.Tracef("Container Details: %+v", container)
 
 	reader, _, err := docker.CopyFromContainer(ctx, container.ID, "/output/kubeconfig.yaml")
 	if err != nil {

pkg/runtimes/docker/node.go

@@ -373,7 +373,7 @@ func executeInNode(ctx context.Context, node *k3d.Node, cmd []string) (*types.Hi
 
 		// if still running, continue loop
 		if execInfo.Running {
-			log.Debugf("Exec process '%+v' still running in node '%s'.. sleeping for 1 second...", cmd, node.Name)
+			log.Tracef("Exec process '%+v' still running in node '%s'.. sleeping for 1 second...", cmd, node.Name)
 			time.Sleep(1 * time.Second)
 			continue
 		}

pkg/runtimes/docker/translate.go

@@ -80,7 +80,6 @@ func TranslateNodeToContainer(node *k3d.Node) (*NodeInDocker, error) {
 	hostConfig.Privileged = true
 
 	/* Volumes */
-	log.Debugf("Volumes: %+v", node.Volumes)
 	hostConfig.Binds = node.Volumes
 	// containerConfig.Volumes = map[string]struct{}{} // TODO: do we need this? We only used binds before