Reduce logging for the NVIDIA Container runtime

This change moves most of the logging for the NVIDIA Container runtime
from Info to Debug or Trace -- especially in the case where no
modifications are requried.

This removes execessive logging.

Signed-off-by: Evan Lezar <elezar@nvidia.com>

internal/oci/runtime_low_level.go

@@ -31,8 +31,6 @@ func NewLowLevelRuntime(logger logger.Interface, candidates []string) (Runtime,
 	if err != nil {
 		return nil, fmt.Errorf("error locating runtime: %v", err)
 	}
-
-	logger.Infof("Using low-level runtime %v", runtimePath)
 	return NewRuntimeForPath(logger, runtimePath)
 }
 
@@ -45,13 +43,12 @@ func findRuntime(logger logger.Interface, candidates []string) (string, error) {
 
 	locator := lookup.NewExecutableLocator(logger, "/")
 	for _, candidate := range candidates {
-		logger.Debugf("Looking for runtime binary '%v'", candidate)
+		logger.Tracef("Looking for runtime binary '%v'", candidate)
 		targets, err := locator.Locate(candidate)
 		if err == nil && len(targets) > 0 {
-			logger.Debugf("Found runtime binary '%v'", targets)
+			logger.Tracef("Found runtime binary '%v'", targets)
 			return targets[0], nil
 		}
-		logger.Debugf("Runtime binary '%v' not found: %v (targets=%v)", candidate, err, targets)
 	}
 
 	return "", fmt.Errorf("no runtime binary found from candidate list: %v", candidates)

internal/oci/runtime_modifier.go

@@ -35,7 +35,7 @@ var _ Runtime = (*modifyingRuntimeWrapper)(nil)
 // before invoking the wrapped runtime. If the modifier is nil, the input runtime is returned.
 func NewModifyingRuntimeWrapper(logger logger.Interface, runtime Runtime, spec Spec, modifier SpecModifier) Runtime {
 	if modifier == nil {
-		logger.Infof("Using low-level runtime with no modification")
+		logger.Tracef("Using low-level runtime with no modification")
 		return runtime
 	}
 
@@ -52,16 +52,15 @@ func NewModifyingRuntimeWrapper(logger logger.Interface, runtime Runtime, spec S
 // into the wrapped runtime.
 func (r *modifyingRuntimeWrapper) Exec(args []string) error {
 	if HasCreateSubcommand(args) {
+		r.logger.Debugf("Create command detected; applying OCI specification modifications")
 		err := r.modify()
 		if err != nil {
-			return fmt.Errorf("could not apply required modification to OCI specification: %v", err)
+			return fmt.Errorf("could not apply required modification to OCI specification: %w", err)
 		}
-		r.logger.Infof("Applied required modification to OCI specification")
+		r.logger.Debugf("Applied required modification to OCI specification")
-	} else {
-		r.logger.Infof("No modification of OCI specification required")
 	}
 
-	r.logger.Infof("Forwarding command to runtime")
+	r.logger.Debugf("Forwarding command to runtime %v", r.runtime.String())
 	return r.runtime.Exec(args)
 }
 

internal/runtime/runtime.go

@@ -17,7 +17,6 @@
 package runtime
 
 import (
-	"encoding/json"
 	"errors"
 	"fmt"
 	"strings"
@@ -26,6 +25,7 @@ import (
 
 	"github.com/NVIDIA/nvidia-container-toolkit/internal/config"
 	"github.com/NVIDIA/nvidia-container-toolkit/internal/info"
+	"github.com/NVIDIA/nvidia-container-toolkit/internal/logger"
 	"github.com/NVIDIA/nvidia-container-toolkit/internal/lookup/root"
 )
 
@@ -67,23 +67,18 @@ func (r rt) Run(argv []string) (rerr error) {
 		cfg.NVIDIAContainerRuntimeConfig.Mode = r.modeOverride
 	}
 	//nolint:staticcheck  // TODO(elezar): We should swith the nvidia-container-runtime from using nvidia-ctk to using nvidia-cdi-hook.
-	cfg.NVIDIACTKConfig.Path = config.ResolveNVIDIACTKPath(r.logger, cfg.NVIDIACTKConfig.Path)
+	cfg.NVIDIACTKConfig.Path = config.ResolveNVIDIACTKPath(&logger.NullLogger{}, cfg.NVIDIACTKConfig.Path)
-	cfg.NVIDIAContainerRuntimeHookConfig.Path = config.ResolveNVIDIAContainerRuntimeHookPath(r.logger, cfg.NVIDIAContainerRuntimeHookConfig.Path)
+	cfg.NVIDIAContainerRuntimeHookConfig.Path = config.ResolveNVIDIAContainerRuntimeHookPath(&logger.NullLogger{}, cfg.NVIDIAContainerRuntimeHookConfig.Path)
 
-	// Print the config to the output.
+	// Log the config at Trace to allow for debugging if required.
-	configJSON, err := json.MarshalIndent(cfg, "", "  ")
+	r.logger.Tracef("Running with config: %+v", cfg)
-	if err == nil {
-		r.logger.Infof("Running with config:\n%v", string(configJSON))
-	} else {
-		r.logger.Infof("Running with config:\n%+v", cfg)
-	}
 
 	driver := root.New(
 		root.WithLogger(r.logger),
 		root.WithDriverRoot(cfg.NVIDIAContainerCLIConfig.Root),
 	)
 
-	r.logger.Debugf("Command line arguments: %v", argv)
+	r.logger.Tracef("Command line arguments: %v", argv)
 	runtime, err := newNVIDIAContainerRuntime(r.logger, cfg, argv, driver)
 	if err != nil {
 		return fmt.Errorf("failed to create NVIDIA Container Runtime: %v", err)

internal/runtime/runtime_factory.go

@@ -35,8 +35,9 @@ func newNVIDIAContainerRuntime(logger logger.Interface, cfg *config.Config, argv
 		return nil, fmt.Errorf("error constructing low-level runtime: %v", err)
 	}
 
+	logger.Tracef("Using low-level runtime %v", lowLevelRuntime.String())
 	if !oci.HasCreateSubcommand(argv) {
-		logger.Debugf("Skipping modifier for non-create subcommand")
+		logger.Tracef("Skipping modifier for non-create subcommand")
 		return lowLevelRuntime, nil
 	}
 
@@ -50,7 +51,7 @@ func newNVIDIAContainerRuntime(logger logger.Interface, cfg *config.Config, argv
 		return nil, fmt.Errorf("failed to construct OCI spec modifier: %v", err)
 	}
 
-	// Create the wrapping runtime with the specified modifier
+	// Create the wrapping runtime with the specified modifier.
 	r := oci.NewModifyingRuntimeWrapper(
 		logger,
 		lowLevelRuntime,