From 931bba0c525b074f1495e7bb103550d984119c26 Mon Sep 17 00:00:00 2001 From: anishnaik Date: Tue, 22 Aug 2023 17:54:11 -0400 Subject: [PATCH] Multi-channel and multi-error log support (#180) --- cmd/root.go | 10 +- fuzzing/fuzzer.go | 14 +- logging/init.go | 16 ++ logging/logger.go | 467 ++++++++++++++++++++++++++--------------- logging/logger_test.go | 47 +++++ 5 files changed, 375 insertions(+), 179 deletions(-) create mode 100644 logging/init.go create mode 100644 logging/logger_test.go diff --git a/cmd/root.go b/cmd/root.go index 9ec81398..37b1e941 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -4,7 +4,7 @@ import ( "github.com/crytic/medusa/logging" "github.com/rs/zerolog" "github.com/spf13/cobra" - "io" + "os" ) const version = "0.1.1" @@ -18,11 +18,13 @@ var rootCmd = &cobra.Command{ } // cmdLogger is the logger that will be used for the cmd package -var cmdLogger = logging.NewLogger(zerolog.InfoLevel, true, make([]io.Writer, 0)...) +var cmdLogger = logging.NewLogger(zerolog.InfoLevel) -// Execute provides an exportable function to invoke the CLI. -// Returns an error if one was encountered. +// Execute provides an exportable function to invoke the CLI. Returns an error if one was encountered. func Execute() error { + // Add stdout as an unstructured, colorized output stream for the command logger + cmdLogger.AddWriter(os.Stdout, logging.UNSTRUCTURED, true) + rootCmd.CompletionOptions.DisableDefaultCmd = true return rootCmd.Execute() } diff --git a/fuzzing/fuzzer.go b/fuzzing/fuzzer.go index be0fd598..7571448a 100644 --- a/fuzzing/fuzzer.go +++ b/fuzzing/fuzzer.go @@ -3,9 +3,9 @@ package fuzzing import ( "context" "fmt" - "io" "math/big" "math/rand" + "os" "path/filepath" "runtime" "sort" @@ -18,7 +18,6 @@ import ( "github.com/crytic/medusa/logging" "github.com/crytic/medusa/logging/colors" "github.com/rs/zerolog" - "github.com/rs/zerolog/pkgerrors" "github.com/crytic/medusa/fuzzing/calls" "github.com/crytic/medusa/utils/randomutils" @@ -90,12 +89,11 @@ type Fuzzer struct { // NewFuzzer returns an instance of a new Fuzzer provided a project configuration, or an error if one is encountered // while initializing the code. func NewFuzzer(config config.ProjectConfig) (*Fuzzer, error) { - // Create the global logger, set some global logging parameters, and enable terminal coloring - logging.GlobalLogger = logging.NewLogger(config.Logging.Level, true, make([]io.Writer, 0)...) - zerolog.ErrorStackMarshaler = pkgerrors.MarshalStack - zerolog.TimeFieldFormat = zerolog.TimeFormatUnix + // Create the global logger and add stdout as an unstructured, colored output stream + logging.GlobalLogger = logging.NewLogger(config.Logging.Level) + logging.GlobalLogger.AddWriter(os.Stdout, logging.UNSTRUCTURED, true) - // If the log directory is a non-empty string, create a file for file logging + // If the log directory is a non-empty string, create a file for unstructured, un-colorized file logging if config.Logging.LogDirectory != "" { // Filename will be the "log-current_unix_timestamp.log" filename := "log-" + strconv.FormatInt(time.Now().Unix(), 10) + ".log" @@ -105,7 +103,7 @@ func NewFuzzer(config config.ProjectConfig) (*Fuzzer, error) { logging.GlobalLogger.Error("Failed to create log file", err) return nil, err } - logging.GlobalLogger.AddWriter(file, logging.UNSTRUCTURED) + logging.GlobalLogger.AddWriter(file, logging.UNSTRUCTURED, false) } // Get the fuzzer's custom sub-logger diff --git a/logging/init.go b/logging/init.go new file mode 100644 index 00000000..0f47cf81 --- /dev/null +++ b/logging/init.go @@ -0,0 +1,16 @@ +package logging + +import ( + "github.com/rs/zerolog" + "github.com/rs/zerolog/pkgerrors" +) + +// init will instantiate the global logger and set up some global parameters from the zerolog package. +func init() { + // Instantiate the global logger + GlobalLogger = NewLogger(zerolog.Disabled) + + // Setup stack trace support and set the timestamp format to UNIX + zerolog.ErrorStackMarshaler = pkgerrors.MarshalStack + zerolog.TimeFieldFormat = zerolog.TimeFormatUnix +} diff --git a/logging/logger.go b/logging/logger.go index 6385d182..48d5c539 100644 --- a/logging/logger.go +++ b/logging/logger.go @@ -11,25 +11,31 @@ import ( // GlobalLogger describes a Logger that is disabled by default and is instantiated when the fuzzer is created. Each module/package // should create its own sub-logger. This allows to create unique logging instances depending on the use case. -var GlobalLogger = NewLogger(zerolog.Disabled, false, nil) +var GlobalLogger *Logger -// Logger describes a custom logging object that can log events to any arbitrary channel and can handle specialized -// output to console as well +// Logger describes a custom logging object that can log events to any arbitrary channel in structured, unstructured with colors, +// and unstructured formats. type Logger struct { // level describes the log level level zerolog.Level - // multiLogger describes a logger that will be used to output logs to any arbitrary channel(s) in either structured - // or unstructured format. - multiLogger zerolog.Logger + // structuredLogger describes a logger that will be used to output structured logs to any arbitrary channel. + structuredLogger zerolog.Logger - // consoleLogger describes a logger that will be used to output unstructured output to console. - // We are creating a separate logger for console so that we can support specialized formatting / custom coloring. - consoleLogger zerolog.Logger + // structuredWriters describes the various channels that the output from the structuredLogger will go to. + structuredWriters []io.Writer - // writers describes a list of io.Writer objects where log output will go. This writers list can be appended to / - // removed from. - writers []io.Writer + // unstructuredLogger describes a logger that will be used to stream un-colorized, unstructured output to any arbitrary channel. + unstructuredLogger zerolog.Logger + + // unstructuredWriters describes the various channels that the output from the unstructuredLogger will go to. + unstructuredWriters []io.Writer + + // unstructuredColorLogger describes a logger that will be used to stream colorized, unstructured output to any arbitrary channel. + unstructuredColorLogger zerolog.Logger + + // unstructuredColorWriters describes the various channels that the output from the unstructuredColoredLogger will go to. + unstructuredColorWriters []io.Writer } // LogFormat describes what format to log in @@ -45,73 +51,144 @@ const ( // StructuredLogInfo describes a key-value mapping that can be used to log structured data type StructuredLogInfo map[string]any -// NewLogger will create a new Logger object with a specific log level. The Logger can output to console, if enabled, -// and output logs to any number of arbitrary io.Writer channels -func NewLogger(level zerolog.Level, consoleEnabled bool, writers ...io.Writer) *Logger { - // The two base loggers are effectively loggers that are disabled - // We are creating instances of them so that we do not get nil pointer dereferences down the line - baseMultiLogger := zerolog.New(os.Stdout).Level(zerolog.Disabled) - baseConsoleLogger := zerolog.New(os.Stdout).Level(zerolog.Disabled) - - // If we are provided a list of writers, update the multi logger - if len(writers) > 0 { - baseMultiLogger = zerolog.New(zerolog.MultiLevelWriter(writers...)).Level(level).With().Timestamp().Logger() - } - - // If console logging is enabled, update the console logger - if consoleEnabled { - consoleWriter := setupDefaultFormatting(zerolog.ConsoleWriter{Out: os.Stdout}, level) - baseConsoleLogger = zerolog.New(consoleWriter).Level(level) - } - +// NewLogger will create a new Logger object with a specific log level. By default, a logger that is instantiated +// with this function is not usable until a log channel is added. To add or remove channels that the logger +// streams logs to, call the Logger.AddWriter and Logger.RemoveWriter functions. +func NewLogger(level zerolog.Level) *Logger { return &Logger{ - level: level, - multiLogger: baseMultiLogger, - consoleLogger: baseConsoleLogger, - writers: writers, + level: level, + structuredLogger: zerolog.New(os.Stdout).Level(zerolog.Disabled), + structuredWriters: make([]io.Writer, 0), + unstructuredLogger: zerolog.New(os.Stdout).Level(zerolog.Disabled), + unstructuredWriters: make([]io.Writer, 0), + unstructuredColorLogger: zerolog.New(os.Stdout).Level(zerolog.Disabled), + unstructuredColorWriters: make([]io.Writer, 0), } } // NewSubLogger will create a new Logger with unique context in the form of a key-value pair. The expected use of this -// function is for each package to have their own unique logger so that parsing of logs is "grep-able" based on some key +// is for each module or component of the system to create their own contextualized logs. The key can be used to search +// for logs from a specific module or component. func (l *Logger) NewSubLogger(key string, value string) *Logger { - subFileLogger := l.multiLogger.With().Str(key, value).Logger() - subConsoleLonger := l.consoleLogger.With().Str(key, value).Logger() + // Create the sub-loggers with the new key-value context + subStructuredLogger := l.structuredLogger.With().Str(key, value).Logger() + subUnstructuredColoredLogger := l.unstructuredColorLogger.With().Str(key, value).Logger() + subUnstructuredLogger := l.unstructuredLogger.With().Str(key, value).Logger() + + // Create new slices for the writers since we want to make a deep copy for each one + subStructuredWriters := make([]io.Writer, len(l.structuredWriters)) + copy(subStructuredWriters, l.structuredWriters) + + subUnstructuredColorWriters := make([]io.Writer, len(l.unstructuredColorWriters)) + copy(subUnstructuredColorWriters, l.unstructuredColorWriters) + + subUnstructuredWriters := make([]io.Writer, len(l.unstructuredWriters)) + copy(subUnstructuredWriters, l.unstructuredWriters) + + // Return a new logger return &Logger{ - level: l.level, - multiLogger: subFileLogger, - consoleLogger: subConsoleLonger, - writers: l.writers, + level: l.level, + structuredLogger: subStructuredLogger, + structuredWriters: subStructuredWriters, + unstructuredColorLogger: subUnstructuredColoredLogger, + unstructuredColorWriters: subUnstructuredColorWriters, + unstructuredLogger: subUnstructuredLogger, + unstructuredWriters: subUnstructuredWriters, } } -// AddWriter will add a writer to the list of channels where log output will be sent. -func (l *Logger) AddWriter(writer io.Writer, format LogFormat) { - // Check to see if the writer is already in the array of writers - for _, w := range l.writers { - if writer == w { - return +// AddWriter will add a writer to which log output will go to. If the format is structured then the writer will get +// structured output. If the writer is unstructured, then the writer has the choice to either receive colored or un-colored +// output. Note that unstructured writers will be converted into a zerolog.ConsoleWriter to maintain the same format +// across all unstructured output streams. +func (l *Logger) AddWriter(writer io.Writer, format LogFormat, colored bool) { + // First, try to add the writer to the list of channels that want structured logs + if format == STRUCTURED { + for _, w := range l.structuredWriters { + if w == writer { + // Writer already exists, return + return + } } + // Add the writer and recreate the logger + l.structuredWriters = append(l.structuredWriters, writer) + l.structuredLogger = zerolog.New(zerolog.MultiLevelWriter(l.structuredWriters...)).Level(l.level).With().Timestamp().Logger() + return } - // If we want unstructured output, wrap the base writer object into a console writer so that we get unstructured output with no ANSI coloring - if format == UNSTRUCTURED { - writer = zerolog.ConsoleWriter{Out: writer, NoColor: true} + // Now that we know we are going to create an unstructured writer, we will create an unstructured writer with(out) coloring + // using zerolog's console writer object. + unstructuredWriter := formatUnstructuredWriter(writer, l.level, colored) + + // Now, try to add the writer to the list of channels that want unstructured, colored logs + if format == UNSTRUCTURED && colored { + for _, w := range l.unstructuredColorWriters { + // We must convert the writer to a console writer to correctly check for existence within the list + if w.(zerolog.ConsoleWriter).Out == writer { + // Writer already exists, return + return + } + } + // Add the unstructured writer and recreate the logger + l.unstructuredColorWriters = append(l.unstructuredColorWriters, unstructuredWriter) + l.unstructuredColorLogger = zerolog.New(zerolog.MultiLevelWriter(l.unstructuredColorWriters...)).Level(l.level).With().Timestamp().Logger() } - // Add it to the list of writers and update the multi logger - l.writers = append(l.writers, writer) - l.multiLogger = zerolog.New(zerolog.MultiLevelWriter(l.writers...)).Level(l.level).With().Timestamp().Logger() + // Otherwise, try to add the writer to the list of channels that want unstructured, un-colored logs + if format == UNSTRUCTURED && !colored { + for _, w := range l.unstructuredWriters { + // We must convert the writer to a console writer to correctly check for existence within the list + if w.(zerolog.ConsoleWriter).Out == writer { + // Writer already exists, return + return + } + } + // Add the unstructured writer and recreate the logger + l.unstructuredWriters = append(l.unstructuredWriters, unstructuredWriter) + l.unstructuredLogger = zerolog.New(zerolog.MultiLevelWriter(l.unstructuredWriters...)).Level(l.level).With().Timestamp().Logger() + } } -// RemoveWriter will remove a writer from the list of writers that the logger manages. If the writer does not exist, this -// function is a no-op -func (l *Logger) RemoveWriter(writer io.Writer) { - // Iterate through the writers - for i, w := range l.writers { - if writer == w { - // Create a new slice without the writer at index i - l.writers = append(l.writers[:i], l.writers[i+1]) +// RemoveWriter will remove a writer from the list of writers that the logger manages. The writer will be either removed +// from the list of structured, unstructured and colored, or unstructured and un-colored writers. If the same writer +// is receiving multiple types of log output (e.g. structured and unstructured with color) then this function must be called +// multiple times. If the writer does not exist in any list, then this function is a no-op. +func (l *Logger) RemoveWriter(writer io.Writer, format LogFormat, colored bool) { + // First, try to remove the writer from the list of structured writers + if format == STRUCTURED { + // Check for writer existence + for i, w := range l.structuredWriters { + if w == writer { + // Remove the writer and recreate the logger + l.structuredWriters = append(l.structuredWriters[:i], l.structuredWriters[i+1:]...) + l.structuredLogger = zerolog.New(zerolog.MultiLevelWriter(l.structuredWriters...)).Level(l.level).With().Timestamp().Logger() + } + } + } + + // Now, try to remove the writer from the list of unstructured, colored writers + if format == UNSTRUCTURED && colored { + // Check for writer existence + for i, w := range l.unstructuredColorWriters { + // We must convert the writer to a console writer to correctly check for existence within the list + if w.(zerolog.ConsoleWriter).Out == writer { + // Remove the writer and recreate the logger + l.unstructuredColorWriters = append(l.unstructuredColorWriters[:i], l.unstructuredColorWriters[i+1:]...) + l.unstructuredColorLogger = zerolog.New(zerolog.MultiLevelWriter(l.unstructuredColorWriters...)).Level(l.level).With().Timestamp().Logger() + } + } + } + + // Otherwise, try to remove the writer from the list of unstructured, un-colored writers + if format == UNSTRUCTURED && !colored { + // Check for writer existence + for i, w := range l.unstructuredWriters { + // We must convert the writer to a console writer to correctly check for existence within the list + if w.(zerolog.ConsoleWriter).Out == writer { + // Remove the writer and recreate the logger + l.unstructuredWriters = append(l.unstructuredWriters[:i], l.unstructuredWriters[i+1:]...) + l.unstructuredLogger = zerolog.New(zerolog.MultiLevelWriter(l.unstructuredWriters...)).Level(l.level).With().Timestamp().Logger() + } } } } @@ -124,111 +201,104 @@ func (l *Logger) Level() zerolog.Level { // SetLevel will update the log level of the Logger func (l *Logger) SetLevel(level zerolog.Level) { l.level = level - l.multiLogger = l.multiLogger.Level(level) - l.consoleLogger = l.consoleLogger.Level(level) + + // Update the level of each underlying logger + l.structuredLogger = l.structuredLogger.Level(level) + l.unstructuredColorLogger = l.unstructuredColorLogger.Level(level) + l.unstructuredLogger = l.unstructuredLogger.Level(level) } // Trace is a wrapper function that will log a trace event func (l *Logger) Trace(args ...any) { - // Build the messages and retrieve any error or associated structured log info - consoleMsg, multiMsg, err, info := buildMsgs(args...) + // Build the messages and retrieve any errors or associated structured log info + colorMsg, noColorMsg, errs, info := buildMsgs(args...) // Instantiate log events - consoleLog := l.consoleLogger.Trace() - multiLog := l.multiLogger.Trace() - - // Chain the error - chainError(consoleLog, multiLog, err, l.level <= zerolog.DebugLevel) + structuredLog := l.structuredLogger.Trace() + unstructuredColoredLog := l.unstructuredColorLogger.Trace() + unstructuredLog := l.unstructuredLogger.Trace() - // Chain the structured log info and messages and send off the logs - chainStructuredLogInfoAndMsgs(consoleLog, multiLog, info, consoleMsg, multiMsg) + // Chain the structured log info, errors, and messages and send off the logs + chainStructuredLogInfoErrorsAndMsgs(structuredLog, unstructuredColoredLog, unstructuredLog, info, errs, colorMsg, noColorMsg) } // Debug is a wrapper function that will log a debug event func (l *Logger) Debug(args ...any) { - // Build the messages and retrieve any error or associated structured log info - consoleMsg, multiMsg, err, info := buildMsgs(args...) + // Build the messages and retrieve any errors or associated structured log info + colorMsg, noColorMsg, errs, info := buildMsgs(args...) // Instantiate log events - consoleLog := l.consoleLogger.Debug() - multiLog := l.multiLogger.Debug() + structuredLog := l.structuredLogger.Debug() + unstructuredColoredLog := l.unstructuredColorLogger.Debug() + unstructuredLog := l.unstructuredLogger.Debug() - // Chain the error - chainError(consoleLog, multiLog, err, l.level <= zerolog.DebugLevel) - - // Chain the structured log info and messages and send off the logs - chainStructuredLogInfoAndMsgs(consoleLog, multiLog, info, consoleMsg, multiMsg) + // Chain the structured log info, errors, and messages and send off the logs + chainStructuredLogInfoErrorsAndMsgs(structuredLog, unstructuredColoredLog, unstructuredLog, info, errs, colorMsg, noColorMsg) } // Info is a wrapper function that will log an info event func (l *Logger) Info(args ...any) { - // Build the messages and retrieve any error or associated structured log info - consoleMsg, multiMsg, err, info := buildMsgs(args...) + // Build the messages and retrieve any errors or associated structured log info + colorMsg, noColorMsg, errs, info := buildMsgs(args...) // Instantiate log events - consoleLog := l.consoleLogger.Info() - multiLog := l.multiLogger.Info() - - // Chain the error - chainError(consoleLog, multiLog, err, l.level <= zerolog.DebugLevel) + structuredLog := l.structuredLogger.Info() + unstructuredColoredLog := l.unstructuredColorLogger.Info() + unstructuredLog := l.unstructuredLogger.Info() - // Chain the structured log info and messages and send off the logs - chainStructuredLogInfoAndMsgs(consoleLog, multiLog, info, consoleMsg, multiMsg) + // Chain the structured log info, errors, and messages and send off the logs + chainStructuredLogInfoErrorsAndMsgs(structuredLog, unstructuredColoredLog, unstructuredLog, info, errs, colorMsg, noColorMsg) } // Warn is a wrapper function that will log a warning event both on console func (l *Logger) Warn(args ...any) { - // Build the messages and retrieve any error or associated structured log info - consoleMsg, multiMsg, err, info := buildMsgs(args...) + // Build the messages and retrieve any errors or associated structured log info + colorMsg, noColorMsg, errs, info := buildMsgs(args...) // Instantiate log events - consoleLog := l.consoleLogger.Warn() - multiLog := l.multiLogger.Warn() - - // Chain the error - chainError(consoleLog, multiLog, err, l.level <= zerolog.DebugLevel) + structuredLog := l.structuredLogger.Warn() + unstructuredColoredLog := l.unstructuredColorLogger.Warn() + unstructuredLog := l.unstructuredLogger.Warn() - // Chain the structured log info and messages and send off the logs - chainStructuredLogInfoAndMsgs(consoleLog, multiLog, info, consoleMsg, multiMsg) + // Chain the structured log info, errors, and messages and send off the logs + chainStructuredLogInfoErrorsAndMsgs(structuredLog, unstructuredColoredLog, unstructuredLog, info, errs, colorMsg, noColorMsg) } // Error is a wrapper function that will log an error event. func (l *Logger) Error(args ...any) { - // Build the messages and retrieve any error or associated structured log info - consoleMsg, multiMsg, err, info := buildMsgs(args...) + // Build the messages and retrieve any errors or associated structured log info + colorMsg, noColorMsg, errs, info := buildMsgs(args...) // Instantiate log events - consoleLog := l.consoleLogger.Error() - multiLog := l.multiLogger.Error() + structuredLog := l.structuredLogger.Error() + unstructuredColoredLog := l.unstructuredColorLogger.Error() + unstructuredLog := l.unstructuredLogger.Error() - // Chain the error - chainError(consoleLog, multiLog, err, l.level <= zerolog.DebugLevel) - - // Chain the structured log info and messages and send off the logs - chainStructuredLogInfoAndMsgs(consoleLog, multiLog, info, consoleMsg, multiMsg) + // Chain the structured log info, errors, and messages and send off the logs + chainStructuredLogInfoErrorsAndMsgs(structuredLog, unstructuredColoredLog, unstructuredLog, info, errs, colorMsg, noColorMsg) } // Panic is a wrapper function that will log a panic event func (l *Logger) Panic(args ...any) { - // Build the messages and retrieve any error or associated structured log info - consoleMsg, multiMsg, err, info := buildMsgs(args...) + // Build the messages and retrieve any errors or associated structured log info + colorMsg, noColorMsg, errs, info := buildMsgs(args...) // Instantiate log events - consoleLog := l.consoleLogger.Panic() - multiLog := l.multiLogger.Panic() - - // Chain the error - chainError(consoleLog, multiLog, err, true) + structuredLog := l.structuredLogger.Panic() + unstructuredColoredLog := l.unstructuredColorLogger.Panic() + unstructuredLog := l.unstructuredLogger.Panic() - // Chain the structured log info and messages and send off the logs - chainStructuredLogInfoAndMsgs(consoleLog, multiLog, info, consoleMsg, multiMsg) + // Chain the structured log info, errors, and messages and send off the logs + chainStructuredLogInfoErrorsAndMsgs(structuredLog, unstructuredColoredLog, unstructuredLog, info, errs, colorMsg, noColorMsg) } // buildMsgs describes a function that takes in a variadic list of arguments of any type and returns two strings and, -// optionally, an error and a StructuredLogInfo object. The first string will be a colorized-string that can be used for -// console logging while the second string will be a non-colorized one that can be used for file/structured logging. -// The error and the StructuredLogInfo can be used to add additional context to log messages -func buildMsgs(args ...any) (string, string, error, StructuredLogInfo) { +// optionally, a list of errors and a StructuredLogInfo object. The first string will be a colorized-message while the +// second string will be a non-colorized one. Colors are applied if one or more of the input arguments are of type +// colors.ColorFunc. The colorized message can be used for channels that request unstructured, colorized log output +// while the non-colorized one can be used for structured streams and unstructured streams that don't want color. The +// errors and the StructuredLogInfo can be used to add additional context to log messages. +func buildMsgs(args ...any) (string, string, []error, StructuredLogInfo) { // Guard clause if len(args) == 0 { return "", "", nil, nil @@ -236,10 +306,10 @@ func buildMsgs(args ...any) (string, string, error, StructuredLogInfo) { // Initialize the base color context, the string buffers and the structured log info object colorCtx := colors.Reset - consoleOutput := make([]string, 0) - fileOutput := make([]string, 0) + colorMsg := make([]string, 0) + noColorMsg := make([]string, 0) + errs := make([]error, 0) var info StructuredLogInfo - var err error // Iterate through each argument in the list and switch on type for _, arg := range args { @@ -251,86 +321,154 @@ func buildMsgs(args ...any) (string, string, error, StructuredLogInfo) { // Note that only one structured log info can be provided for each log message info = t case error: - // Note that only one error can be provided for each log message - err = t + // Append error to the list of errors + errs = append(errs, t) default: - // In the base case, append the object to the two string buffers. The console string buffer will have the + // In the base case, append the object to the two string buffers. The colored string buffer will have the // current color context applied to it. - consoleOutput = append(consoleOutput, colorCtx(t)) - fileOutput = append(fileOutput, fmt.Sprintf("%v", t)) + colorMsg = append(colorMsg, colorCtx(t)) + noColorMsg = append(noColorMsg, fmt.Sprintf("%v", t)) } } - return strings.Join(consoleOutput, ""), strings.Join(fileOutput, ""), err, info + return strings.Join(colorMsg, ""), strings.Join(noColorMsg, ""), errs, info } -// chainError is a helper function that takes in a *zerolog.Event for console and multi-log output and chains an error -// to both events. If debug is true, then a stack trace is added to both events as well. -func chainError(consoleLog *zerolog.Event, multiLog *zerolog.Event, err error, debug bool) { - // First append the errors to each event. Note that even if err is nil, there will not be a panic here - consoleLog.Err(err) - multiLog.Err(err) - - // If we are in debug mode or below, then we will add the stack traces as well for debugging - if debug { - consoleLog.Stack() - multiLog.Stack() +// chainStructuredLogInfoErrorsAndMsgs describes a function that takes in a *zerolog.Event for the structured, unstructured +// with color, and unstructured without colors log streams, chains any StructuredLogInfo and errors provided to it, +// adds the associated messages, and sends out the logs to their respective channels. Note that the StructuredLogInfo object +// is only appended to the structured log event and not to the unstructured ones. Additionally, note that errors are appended as a +// formatted bulleted list for unstructured logging while for the structured logger they get appended as a key-value pair. +func chainStructuredLogInfoErrorsAndMsgs(structuredLog *zerolog.Event, unstructuredColoredLog *zerolog.Event, unstructuredLog *zerolog.Event, info StructuredLogInfo, errs []error, colorMsg string, noColorMsg string) { + // First, we need to create a formatted error string for unstructured output + var errStr string + for _, err := range errs { + // To make the formatting a little nicer, we will add a tab after each new line in the error so that + // errors can be better differentiated on unstructured channels + lines := make([]string, 0) + for i, line := range strings.Split(err.Error(), "\n") { + // Add a tab to the line only after the first new line in the error message + if i != 0 { + line = "\t" + line + } + lines = append(lines, line) + } + + // Update the error string to be based on the tabbed lines array + if len(lines) > 0 { + err = fmt.Errorf("%v", strings.Join(lines, "\n")) + } + + // Append a bullet point and the formatted error to the error string + errStr += "\n" + colors.BULLET_POINT + " " + err.Error() + } + + // Add structured error element to the multi-log output and append the error string to the console message + // TODO: Add support for stack traces in the future + if len(errs) != 0 { + structuredLog.Errs("errors", errs) + } + + // The structured message will be the one without any potential errors appended to it since the errors will be provided + // as a key-value pair + structuredMsg := noColorMsg + + // Add the colorized and non-colorized version of the error string to the colorized and non-colorized messages, respectively. + if len(errStr) > 0 { + colorMsg += colors.Red(errStr) + noColorMsg += errStr } -} -// chainStructuredLogInfoAndMsgs is a helper function that takes in a *zerolog.Event for console and multi-log output, -// chains any StructuredLogInfo provided to it, adds the associated messages, and sends out the logs to their respective -// channels. -func chainStructuredLogInfoAndMsgs(consoleLog *zerolog.Event, multiLog *zerolog.Event, info StructuredLogInfo, consoleMsg string, multiMsg string) { - // If we are provided a structured log info object, add that as a key-value pair to the events + // If we are provided a structured log info object, add that as a key-value pair to the structured log event if info != nil { - consoleLog.Any("info", info) - multiLog.Any("info", info) + structuredLog.Any("info", info) } // Append the messages to each event. This will also result in the log events being sent out to their respective - // streams. Note that we are deferring the msg to multi logger in case we are logging a panic and want to make sure that - // all channels receive the panic log - defer multiLog.Msg(multiMsg) - consoleLog.Msg(consoleMsg) + // streams. Note that we are deferring the message to two of the three loggers multi logger in case we are logging a panic + // and want to make sure that all channels receive the panic log. + defer func() { + structuredLog.Msg(structuredMsg) + unstructuredLog.Msg(noColorMsg) + }() + unstructuredColoredLog.Msg(colorMsg) } -// setupDefaultFormatting will update the console logger's formatting to the medusa standard -func setupDefaultFormatting(writer zerolog.ConsoleWriter, level zerolog.Level) zerolog.ConsoleWriter { - // Get rid of the timestamp for console output - writer.FormatTimestamp = func(i interface{}) string { +// formatUnstructuredWriter will create a custom-formatted zerolog.ConsoleWriter from an arbitrary io.Writer. A zerolog.ConsoleWriter is +// what is used under-the-hood to support unstructured log output. Custom formatting is applied to specific fields, +// timestamps, and the log level strings. If requested, coloring may be applied to the log level strings. +func formatUnstructuredWriter(writer io.Writer, level zerolog.Level, colored bool) zerolog.ConsoleWriter { + // Create the console writer + consoleWriter := zerolog.ConsoleWriter{Out: writer, NoColor: !colored} + + // Get rid of the timestamp for unstructured output + consoleWriter.FormatTimestamp = func(i interface{}) string { return "" } - // We will define a custom format for each level - writer.FormatLevel = func(i any) string { + // If we are above debug level, we want to get rid of the `module` component when logging to unstructured streams + if level > zerolog.DebugLevel { + consoleWriter.FieldsExclude = []string{"module"} + } + + // If coloring is enabled, we will return a custom, colored string for each log severity level + // Otherwise, we will just return a non-colorized string for each log severity level + consoleWriter.FormatLevel = func(i any) string { // Create a level object for better switch logic level, err := zerolog.ParseLevel(i.(string)) if err != nil { panic(fmt.Sprintf("unable to parse the log level: %v", err)) } - // Switch on the level and return a custom, colored string + // Switch on the level switch level { case zerolog.TraceLevel: + if !colored { + // No coloring for "trace" string + return zerolog.LevelTraceValue + } // Return a bold, cyan "trace" string return colors.CyanBold(zerolog.LevelTraceValue) case zerolog.DebugLevel: + if !colored { + // No coloring for "debug" string + return zerolog.LevelDebugValue + } // Return a bold, blue "debug" string return colors.BlueBold(zerolog.LevelDebugValue) case zerolog.InfoLevel: + if !colored { + // Return a left arrow without any coloring + return colors.LEFT_ARROW + } // Return a bold, green left arrow return colors.GreenBold(colors.LEFT_ARROW) case zerolog.WarnLevel: + if !colored { + // No coloring for "warn" string + return zerolog.LevelWarnValue + } // Return a bold, yellow "warn" string return colors.YellowBold(zerolog.LevelWarnValue) case zerolog.ErrorLevel: + if !colored { + // No coloring for "err" string + return zerolog.LevelErrorValue + } // Return a bold, red "err" string return colors.RedBold(zerolog.LevelErrorValue) case zerolog.FatalLevel: + if !colored { + // No coloring for "fatal" string + return zerolog.LevelFatalValue + } // Return a bold, red "fatal" string return colors.RedBold(zerolog.LevelFatalValue) case zerolog.PanicLevel: + if !colored { + // No coloring for "panic" string + return zerolog.LevelPanicValue + } // Return a bold, red "panic" string return colors.RedBold(zerolog.LevelPanicValue) default: @@ -338,10 +476,5 @@ func setupDefaultFormatting(writer zerolog.ConsoleWriter, level zerolog.Level) z } } - // If we are above debug level, we want to get rid of the `module` component when logging to console - if level > zerolog.DebugLevel { - writer.FieldsExclude = []string{"module"} - } - - return writer + return consoleWriter } diff --git a/logging/logger_test.go b/logging/logger_test.go new file mode 100644 index 00000000..15404b83 --- /dev/null +++ b/logging/logger_test.go @@ -0,0 +1,47 @@ +package logging + +import ( + "github.com/rs/zerolog" + "github.com/stretchr/testify/assert" + "os" + "testing" +) + +// TestAddAndRemoveWriter will test to Logger.AddWriter and Logger.RemoveWriter functions to ensure that they work as expected. +func TestAddAndRemoveWriter(t *testing.T) { + // Create a base logger + logger := NewLogger(zerolog.InfoLevel) + + // Add three types of writers + // 1. Unstructured and colorized output to stdout + logger.AddWriter(os.Stdout, UNSTRUCTURED, true) + // 2. Unstructured and non-colorized output to stderr + logger.AddWriter(os.Stderr, UNSTRUCTURED, false) + // 3. Structured output to stdin + logger.AddWriter(os.Stdin, STRUCTURED, false) + + // We should expect the underlying data structures are correctly updated + assert.Equal(t, len(logger.unstructuredWriters), 1) + assert.Equal(t, len(logger.unstructuredColorWriters), 1) + assert.Equal(t, len(logger.structuredWriters), 1) + + // Try to add duplicate writers + logger.AddWriter(os.Stdout, UNSTRUCTURED, true) + logger.AddWriter(os.Stderr, UNSTRUCTURED, false) + logger.AddWriter(os.Stdin, STRUCTURED, false) + + // Ensure that the lengths of the lists have not changed + assert.Equal(t, len(logger.unstructuredWriters), 1) + assert.Equal(t, len(logger.unstructuredColorWriters), 1) + assert.Equal(t, len(logger.structuredWriters), 1) + + // Remove each writer + logger.RemoveWriter(os.Stdout, UNSTRUCTURED, true) + logger.RemoveWriter(os.Stderr, UNSTRUCTURED, false) + logger.RemoveWriter(os.Stdin, STRUCTURED, false) + + // We should expect the underlying data structures are correctly updated + assert.Equal(t, len(logger.unstructuredWriters), 0) + assert.Equal(t, len(logger.unstructuredColorWriters), 0) + assert.Equal(t, len(logger.structuredWriters), 0) +}