From e9d929dc2ff937740205ef7af90cf647ecf5cc8e Mon Sep 17 00:00:00 2001 From: Evan Lezar Date: Thu, 5 May 2022 17:27:36 +0200 Subject: [PATCH] Support runc logging command line options This change processes and supports runc logging command line arguments. This allows for better integration into container engines such as docker. Signed-off-by: Evan Lezar --- cmd/nvidia-container-runtime/logger.go | 213 +++++++++++++++--- cmd/nvidia-container-runtime/main.go | 22 +- .../modifier/experimental.go | 2 +- 3 files changed, 186 insertions(+), 51 deletions(-) diff --git a/cmd/nvidia-container-runtime/logger.go b/cmd/nvidia-container-runtime/logger.go index 803a1d35..f39f8421 100644 --- a/cmd/nvidia-container-runtime/logger.go +++ b/cmd/nvidia-container-runtime/logger.go @@ -20,60 +20,205 @@ import ( "fmt" "io" "os" + "path/filepath" + "runtime" + "strconv" + "strings" "github.com/sirupsen/logrus" - "github.com/tsaikd/KDGoLib/logrusutil" ) // Logger adds a way to manage output to a log file to a logrus.Logger type Logger struct { *logrus.Logger - previousOutput io.Writer - logFile *os.File + previousLogger *logrus.Logger + logFiles []*os.File } -// NewLogger constructs a Logger with a preddefined formatter +// NewLogger creates an empty logger func NewLogger() *Logger { - logrusLogger := logrus.New() - - formatter := &logrusutil.ConsoleLogFormatter{ - TimestampFormat: "2006/01/02 15:04:07", - Flag: logrusutil.Ltime, + return &Logger{ + Logger: logrus.New(), } - - logger := &Logger{ - Logger: logrusLogger, - } - logger.SetFormatter(formatter) - - return logger } -// LogToFile opens the specified file for appending and sets the logger to -// output to the opened file. A reference to the file pointer is stored to -// allow this to be closed. -func (l *Logger) LogToFile(filename string) error { - logFile, err := os.OpenFile(filename, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) +// UpdateLogger constructs a Logger with a preddefined formatter +func UpdateLogger(filename string, logLevel string, argv []string) (*Logger, error) { + configFromArgs := parseArgs(argv) + + level, logLevelError := configFromArgs.getLevel(logLevel) + + var logFiles []*os.File + + configLogFile, err := createLogFile(filename) if err != nil { - return fmt.Errorf("error opening debug log file: %v", err) + return logger, fmt.Errorf("error opening debug log file: %v", err) + } + if configLogFile != nil { + logFiles = append(logFiles, configLogFile) } - l.logFile = logFile - l.previousOutput = l.Out - l.SetOutput(logFile) + argLogFile, argLogFileError := createLogFile(configFromArgs.file) + if argLogFile != nil { + logFiles = append(logFiles, argLogFile) + } - return nil + l := &Logger{ + Logger: logrus.New(), + previousLogger: logger.Logger, + logFiles: logFiles, + } + + if len(logFiles) == 0 { + l.SetOutput(io.Discard) + } else if len(logFiles) == 1 { + l.SetOutput(logFiles[0]) + } else { + var writers []io.Writer + for _, f := range logFiles { + writers = append(writers, f) + } + l.SetOutput(io.MultiWriter(writers...)) + } + + l.SetLevel(level) + if level == logrus.DebugLevel { + logrus.SetReportCaller(true) + // Shorten function and file names reported by the logger, by + // trimming common "github.com/opencontainers/runc" prefix. + // This is only done for text formatter. + _, file, _, _ := runtime.Caller(0) + prefix := filepath.Dir(file) + "/" + logrus.SetFormatter(&logrus.TextFormatter{ + CallerPrettyfier: func(f *runtime.Frame) (string, string) { + function := strings.TrimPrefix(f.Function, prefix) + "()" + fileLine := strings.TrimPrefix(f.File, prefix) + ":" + strconv.Itoa(f.Line) + return function, fileLine + }, + }) + } + + if configFromArgs.format == "json" { + l.SetFormatter(new(logrus.JSONFormatter)) + } + + if logLevelError != nil { + l.Warn(logLevelError) + } + + if argLogFileError != nil { + l.Warnf("Failed to open log file: %v", argLogFileError) + } + + return l, nil } // CloseFile closes the log file (if any) and resets the logger output to what it -// was before LogToFile was called. +// was before UpdateLogger was called. func (l *Logger) CloseFile() error { - if l.logFile == nil { - return nil - } - logFile := l.logFile - l.SetOutput(l.previousOutput) - l.logFile = nil + defer func() { + previous := l.previousLogger + if previous == nil { + previous = logrus.New() + } + logger = &Logger{Logger: previous} + }() - return logFile.Close() + var errs []error + for _, f := range l.logFiles { + err := f.Close() + if err != nil { + errs = append(errs, err) + } + } + + var err error + for _, e := range errs { + if err == nil { + err = e + continue + } + return fmt.Errorf("%v; %w", e, err) + } + + return err +} + +func createLogFile(filename string) (*os.File, error) { + if filename != "" && filename != os.DevNull { + return os.OpenFile(filename, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) + } + + return nil, nil +} + +type loggerConfig struct { + file string + format string + debug bool +} + +func (c loggerConfig) getLevel(logLevel string) (logrus.Level, error) { + if c.debug { + return logrus.DebugLevel, nil + } + + if logLevel, err := logrus.ParseLevel(logLevel); err == nil { + return logLevel, nil + } + + return logrus.InfoLevel, fmt.Errorf("invalid log-level '%v'", logLevel) +} + +// Informed by Taken from https://github.com/opencontainers/runc/blob/7fd8b57001f5bfa102e89cb434d96bf71f7c1d35/main.go#L182 +func parseArgs(args []string) loggerConfig { + c := loggerConfig{} + + expected := map[string]*string{ + "log-format": &c.format, + "log": &c.file, + } + + found := make(map[string]bool) + + for i := 0; i < len(args); i++ { + if len(found) == 3 { + break + } + + param := args[i] + + parts := strings.SplitN(param, "=", 2) + trimmed := strings.TrimPrefix(parts[0], "--") + if !strings.HasPrefix(parts[0], "--") { + continue + } + + // Check the debug flag + if trimmed == "debug" { + c.debug = true + found["debug"] = true + continue + } + + destination, exists := expected[trimmed] + if !exists { + continue + } + + var value string + if len(parts) == 2 { + value = parts[2] + } else if i+1 < len(args) { + value = args[i+1] + i++ + } else { + continue + } + + *destination = value + found[trimmed] = true + } + + return c } diff --git a/cmd/nvidia-container-runtime/main.go b/cmd/nvidia-container-runtime/main.go index be9054d7..0f3f59cb 100644 --- a/cmd/nvidia-container-runtime/main.go +++ b/cmd/nvidia-container-runtime/main.go @@ -5,7 +5,6 @@ import ( "os" "github.com/NVIDIA/nvidia-container-toolkit/internal/config" - "github.com/sirupsen/logrus" ) var logger = NewLogger() @@ -26,22 +25,13 @@ func run(argv []string) (rerr error) { return fmt.Errorf("error loading config: %v", err) } - err = logger.LogToFile(cfg.NVIDIAContainerRuntimeConfig.DebugFilePath) + logger, err = UpdateLogger( + cfg.NVIDIAContainerRuntimeConfig.DebugFilePath, + cfg.NVIDIAContainerRuntimeConfig.LogLevel, + argv, + ) if err != nil { - return fmt.Errorf("error opening debug log file: %v", err) - } - defer func() { - // We capture and log a returning error before closing the log file. - if rerr != nil { - logger.Errorf("%v", rerr) - } - logger.CloseFile() - }() - - if logLevel, err := logrus.ParseLevel(cfg.NVIDIAContainerRuntimeConfig.LogLevel); err == nil { - logger.SetLevel(logLevel) - } else { - logger.Warnf("Invalid log-level '%v'; using '%v'", cfg.NVIDIAContainerRuntimeConfig.LogLevel, logger.Level.String()) + return fmt.Errorf("failed to set up logger: %v", err) } logger.Debugf("Command line arguments: %v", argv) diff --git a/cmd/nvidia-container-runtime/modifier/experimental.go b/cmd/nvidia-container-runtime/modifier/experimental.go index 0bf73bd8..b220f9eb 100644 --- a/cmd/nvidia-container-runtime/modifier/experimental.go +++ b/cmd/nvidia-container-runtime/modifier/experimental.go @@ -61,7 +61,7 @@ func NewExperimentalModifier(logger *logrus.Logger, cfg *config.Config, ociSpec logger.Infof("No modification required: %v=%v (exists=%v)", visibleDevicesEnvvar, visibleDevices, exists) return nil, nil } - logger.Infof("Constructing modifier from config: %+v", cfg) + logger.Infof("Constructing modifier from config: %+v", *cfg) config := &discover.Config{ Root: cfg.NVIDIAContainerCLIConfig.Root,