fog.go

Documentation: edge-infra.dev/pkg/lib/fog

     1  package fog
     2  
     3  import (
     4  	"fmt"
     5  	"strings"
     6  
     7  	"github.com/go-logr/logr"
     8  	"go.uber.org/zap"
     9  	"go.uber.org/zap/zapcore"
    10  )
    11  
    12  // TODO(aw185176): Invert level again on the actual log message so that it
    13  // corresponds to logr V()? Would need to be careful with error logs if stick
    14  // with using Zap error level as a internal sentinel.
    15  
    16  // TODO: how to handle Error vs Critical/Alert/Emergency, since those are all
    17  // just additional severities?
    18  // - dont log errors below certain levels based on verbosity of logger?
    19  // TODO: DPanic -> Alert/Critical?
    20  
    21  // fogr is a logr.Logger that uses Zap under the covers, with custom encoders
    22  // to leverage GCP structure logging features: https://cloud.google.com/logging/docs/structured-logging#special-payload-fields
    23  type fogr struct {
    24  	l *zap.Logger
    25  }
    26  
    27  func New(opts ...Option) logr.Logger {
    28  	o := makeOptions(opts...)
    29  
    30  	c := zapcore.NewCore(
    31  		newEncoder(zapcore.EncoderConfig{
    32  			LevelKey:       LevelKey,
    33  			TimeKey:        TimeKey,
    34  			MessageKey:     MessageKey,
    35  			StacktraceKey:  StacktraceKey,
    36  			NameKey:        "logger",
    37  			EncodeTime:     zapcore.RFC3339TimeEncoder,
    38  			EncodeDuration: zapcore.MillisDurationEncoder,
    39  			EncodeLevel:    encodeLevel(),
    40  		}),
    41  		zapcore.Lock(zapcore.AddSync(o.dest)),
    42  		zap.NewAtomicLevelAt(zapcore.Level(o.lvl)),
    43  	)
    44  	zopts := []zap.Option{
    45  		zap.AddCaller(),
    46  		zap.AddCallerSkip(1),
    47  	}
    48  
    49  	if o.development {
    50  		zopts = append(zopts, zap.Development())
    51  	}
    52  
    53  	return logr.New(&fogr{zap.New(c, zopts...)})
    54  }
    55  
    56  // Assert that fogr implements logr interfaces.
    57  var _ logr.LogSink = (*fogr)(nil)
    58  var _ logr.CallDepthLogSink = (*fogr)(nil)
    59  
    60  // Init receives optional information about the logr library for LogSink
    61  // implementations that need it.
    62  func (f *fogr) Init(ri logr.RuntimeInfo) {
    63  	f.l = f.l.WithOptions(zap.AddCallerSkip(ri.CallDepth))
    64  }
    65  
    66  // Enabled returns true if the provided log level is enabled.
    67  func (f *fogr) Enabled(lvl int) bool {
    68  	return f.l.Core().Enabled(toZapLevel(lvl))
    69  }
    70  
    71  // Info logs a non-error message with the given key/value pairs as context.
    72  // This method will only be called when Enabled(lvl) is true. See
    73  // logr.Logger.Info for more details.
    74  func (f *fogr) Info(lvl int, msg string, keysAndVals ...interface{}) {
    75  	if checkedEntry := f.l.Check(toZapLevel(lvl), msg); checkedEntry != nil {
    76  		checkedEntry.Write(f.handleFields(lvl, keysAndVals)...)
    77  	}
    78  }
    79  
    80  // Error logs an error, with the given message and key/value pairs as context.
    81  // See logr.Logger.Error for more details.
    82  func (f *fogr) Error(err error, msg string, keysAndVals ...interface{}) {
    83  	f.l.Error(msg, f.handleFields(int(zap.ErrorLevel), keysAndVals, zap.NamedError(errorKey, err))...)
    84  }
    85  
    86  // WithValues returns a new LogSink with additional key/value pairs.
    87  func (f *fogr) WithValues(keysAndValues ...interface{}) logr.LogSink {
    88  	newLogger := *f
    89  	newLogger.l = f.l.With(f.handleFields(-1, keysAndValues)...)
    90  	return &newLogger
    91  }
    92  
    93  // WithName returns a new LogSink with the specified name appended.
    94  func (f *fogr) WithName(name string) logr.LogSink {
    95  	newLogger := *f
    96  	newLogger.l = f.l.Named(name)
    97  	return &newLogger
    98  }
    99  
   100  // WithCallDepth returns a new LogSink with a call stack offset by depth.
   101  func (f *fogr) WithCallDepth(depth int) logr.LogSink {
   102  	newLogger := *f
   103  	newLogger.l = f.l.WithOptions(zap.AddCallerSkip(depth))
   104  	return &newLogger
   105  }
   106  
   107  // WithLabels decorates the input logger with string key/values pairs so that
   108  // they are added as log labels in Google Cloud, by prefixing the label keys with
   109  // an internal identifier that indicates they should be processed differently
   110  // than standard logger decorations done via WithValues. It narrows the standard
   111  // interface{} input to strings in order to align with the required data type
   112  // per the Google Cloud logging API: https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#FIELDS.labels
   113  //
   114  // If an odd number of keys and values are provided, we attempt to cast the logger
   115  // to our implementation. If successful, we log a DPanic so that uneven keysAndValues
   116  // are handled consistently with normal logging operations (Info(), Error()).
   117  //
   118  // Example usage:
   119  //
   120  //	log = fog.WithLabels(log, "cmd", "my_app")
   121  func WithLabels(l logr.Logger, keysAndValues ...string) logr.Logger {
   122  	if len(keysAndValues)%2 != 0 {
   123  		// if the logr we were given is our implementation, leverage the zap logger
   124  		// to log development panic
   125  		if f, ok := l.GetSink().(*fogr); ok {
   126  			f.l.WithOptions(zap.AddCallerSkip(1)).DPanic(
   127  				"odd number of arguments passed as key-value pairs for logging labels",
   128  				zapIt("ignored", keysAndValues),
   129  			)
   130  		}
   131  		// return logger unmodified
   132  		return l
   133  	}
   134  
   135  	// prefix all keys with the internal identifier that indicates the label should
   136  	// be hoisted to the GCP logging label key
   137  	for i := 0; i < len(keysAndValues); {
   138  		keysAndValues[i] = fmt.Sprintf("%s%s", gcpLabelKey, keysAndValues[i])
   139  		i += 2
   140  	}
   141  
   142  	// cast to looser type
   143  	modifiedKeysAndValues := make([]interface{}, len(keysAndValues))
   144  	for i := range keysAndValues {
   145  		modifiedKeysAndValues[i] = keysAndValues[i]
   146  	}
   147  
   148  	// return decorated logger
   149  	return l.WithValues(modifiedKeysAndValues...)
   150  }
   151  
   152  // zap levels are int8 - make sure we stay in bounds. logr itself should
   153  // ensure we never get negative values.
   154  func toZapLevel(lvl int) zapcore.Level {
   155  	if lvl > 127 {
   156  		lvl = 127
   157  	}
   158  	// zap levels are inverted.
   159  	return 0 - zapcore.Level(lvl) /* #nosec G115 */
   160  }
   161  
   162  // handleFields converts a bunch of arbitrary key-value pairs into Zap fields.
   163  // It takes additional pre-converted Zap fields, for use with automatically
   164  // attached fields, like `error`.
   165  func (f *fogr) handleFields(lvl int, args []interface{}, additional ...zap.Field) []zap.Field {
   166  	injectNumericLevel := lvl < 0
   167  	// a slightly modified version of zap.SugaredLogger.sweetenFields
   168  	if len(args) == 0 {
   169  		// if log level is below 0, don't add
   170  		if injectNumericLevel {
   171  			return additional
   172  		}
   173  		// fast-return if we have no sweetened fields
   174  		return append(additional, zap.Int(lvlKey, lvl))
   175  	}
   176  
   177  	// unlike Zap, we can be pretty sure users aren't passing structured
   178  	// fields (since logr has no concept of that), so guess that we need a
   179  	// little less space.
   180  	// add additional field for V() level
   181  	numFields := len(args)/2 + len(additional)
   182  	if injectNumericLevel {
   183  		numFields++
   184  	}
   185  	fields := make([]zap.Field, 0, numFields)
   186  	if injectNumericLevel {
   187  		fields = append(fields, zap.Int(lvlKey, lvl))
   188  	}
   189  
   190  	// map where we will accumulate all keys that should be hoisted to Google Cloud
   191  	// log labels
   192  	var googleLabels map[string]string
   193  
   194  	// iterate through all of the arguments
   195  	for i := 0; i < len(args); {
   196  		// make sure this isn't a mismatched key for all other labels; a directly passed
   197  		// key should have a value following it, this checks for the proper number of args
   198  		if i == len(args)-1 {
   199  			f.l.WithOptions(zap.AddCallerSkip(1)).DPanic(
   200  				"odd number of arguments passed as key-value pairs for logging",
   201  				zapIt("ignored key", args[i]),
   202  			)
   203  			break
   204  		}
   205  
   206  		// process input that is passed directly and convert into key/value pair,
   207  		// ensuring that the key is a string; for key/value pairs passed directly
   208  		// that aren't meant for cloud logging
   209  		key, val := args[i], args[i+1]
   210  		keyStr, isString := key.(string)
   211  		if !isString {
   212  			// TODO: handle DPanic stuff
   213  			// if the key isn't a string, DPanic and stop logging
   214  			f.l.WithOptions(zap.AddCallerSkip(1)).DPanic(
   215  				"non-string key argument passed to logging, ignoring all later arguments",
   216  				zapIt("invalid key", key),
   217  			)
   218  			break
   219  		}
   220  		if strings.HasPrefix(keyStr, gcpLabelKey) {
   221  			if googleLabels == nil {
   222  				googleLabels = make(map[string]string)
   223  			}
   224  			// because we validate in WithLabels, we can cast blindly here
   225  			googleLabels[strings.TrimPrefix(keyStr, gcpLabelKey)] = val.(string)
   226  		} else if strings.HasPrefix(keyStr, gcpOperationKey) {
   227  			keyStr = strings.TrimPrefix(keyStr, gcpOperationKey)
   228  			fields = append(fields, zapIt(operationKey, map[string]string{keyStr: val.(string)}))
   229  		} else {
   230  			fields = append(fields, zapIt(keyStr, val))
   231  		}
   232  		i += 2
   233  	}
   234  
   235  	// if we accumulated any google labels, add them now that we have finished
   236  	// processing all args
   237  	if googleLabels != nil {
   238  		fields = append(fields, zapIt(labelsKey, googleLabels))
   239  	}
   240  
   241  	return append(fields, additional...)
   242  }
   243  
   244  // zapIt converts a key-value pair into a Zap field
   245  func zapIt(field string, val interface{}) zap.Field {
   246  	// Handle types that implement logr.Marshaler: log the replacement
   247  	// object instead of the original one.
   248  	if marshaler, ok := val.(logr.Marshaler); ok {
   249  		field, val = invokeMarshaler(field, marshaler)
   250  	}
   251  	return zap.Any(field, val)
   252  }
   253  
   254  func invokeMarshaler(field string, m logr.Marshaler) (f string, ret interface{}) {
   255  	defer func() {
   256  		if r := recover(); r != nil {
   257  			ret = fmt.Sprintf("PANIC=%s", r)
   258  			f = field + "Error"
   259  		}
   260  	}()
   261  	return field, m.MarshalLog()
   262  }
   263
View as plain text