diff --git a/cmd/config_logging.go b/cmd/config_logging.go index df6b0b7..a670cba 100644 --- a/cmd/config_logging.go +++ b/cmd/config_logging.go @@ -13,7 +13,7 @@ import ( ) type LoggingConfig struct { - Outlets logger.Outlets + Outlets *logger.Outlets } type MetadataFlags int64 @@ -26,10 +26,21 @@ const ( MetadataAll MetadataFlags = ^0 ) +func LoggerErrorOutlet() logger.Outlet { + + formatter := &HumanFormatter{} + writer := os.Stderr + formatter.SetMetadataFlags(MetadataAll) + return WriterOutlet{ + formatter, writer, + } +} + func parseLogging(i interface{}) (c *LoggingConfig, err error) { c = &LoggingConfig{} - c.Outlets = logger.NewOutlets() + + c.Outlets = logger.NewOutlets(LoggerErrorOutlet()) var asList []interface{} if err = mapstructure.Decode(i, &asList); err != nil { diff --git a/cmd/test.go b/cmd/test.go index 148719b..6258b67 100644 --- a/cmd/test.go +++ b/cmd/test.go @@ -65,7 +65,7 @@ func init() { func testCmdGlobalInit(cmd *cobra.Command, args []string) { - out := logger.NewOutlets() + out := logger.NewOutlets(WriterOutlet{&NoFormatter{}, os.Stderr}) out.Add(WriterOutlet{&NoFormatter{}, os.Stdout}, logger.Info) log := logger.NewLogger(out, 1*time.Second) testCmdGlobal.log = log diff --git a/logger/datastructures.go b/logger/datastructures.go index f78da7b..b3bad8c 100644 --- a/logger/datastructures.go +++ b/logger/datastructures.go @@ -78,14 +78,28 @@ type Outlet interface { WriteEntry(ctx context.Context, entry Entry) error } -type Outlets map[Level][]Outlet - -func NewOutlets() Outlets { - return make(Outlets, len(AllLevels)) +type Outlets struct { + reg map[Level][]Outlet + e Outlet } -func (os Outlets) Add(outlet Outlet, minLevel Level) { - for _, l := range AllLevels[minLevel:] { - os[l] = append(os[l], outlet) +func NewOutlets(loggerErrorOutlet Outlet) *Outlets { + return &Outlets{ + make(map[Level][]Outlet, len(AllLevels)), + loggerErrorOutlet, } } + +func (os *Outlets) Add(outlet Outlet, minLevel Level) { + for _, l := range AllLevels[minLevel:] { + os.reg[l] = append(os.reg[l], outlet) + } +} + +func (os *Outlets) Get(level Level) []Outlet { + return os.reg[level] +} + +func (os *Outlets) GetLoggerErrorOutlet() Outlet { + return os.e +} diff --git a/logger/logger.go b/logger/logger.go index b0a7689..10da381 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -3,7 +3,6 @@ package logger import ( "context" "fmt" - "os" "runtime/debug" "sync" "time" @@ -15,17 +14,16 @@ const ( ) const DefaultUserFieldCapacity = 5 -const InternalErrorPrefix = "github.com/zrepl/zrepl/logger: " type Logger struct { fields Fields - outlets Outlets + outlets *Outlets outletTimeout time.Duration mtx *sync.Mutex } -func NewLogger(outlets Outlets, outletTimeout time.Duration) *Logger { +func NewLogger(outlets *Outlets, outletTimeout time.Duration) *Logger { return &Logger{ make(Fields, DefaultUserFieldCapacity), outlets, @@ -34,6 +32,29 @@ func NewLogger(outlets Outlets, outletTimeout time.Duration) *Logger { } } +type outletResult struct { + Outlet Outlet + Error error +} + +func (l *Logger) logInternalError(outlet Outlet, err string) { + fields := Fields{} + if outlet != nil { + if _, ok := outlet.(fmt.Stringer); ok { + fields["outlet"] = fmt.Sprintf("%s", outlet) + } + fields["outlet_type"] = fmt.Sprintf("%T", outlet) + } + fields[FieldError] = err + entry := Entry{ + Error, + "outlet error", + time.Now(), + fields, + } + l.outlets.GetLoggerErrorOutlet().WriteEntry(context.Background(), entry) +} + func (l *Logger) log(level Level, msg string) { l.mtx.Lock() @@ -42,24 +63,24 @@ func (l *Logger) log(level Level, msg string) { entry := Entry{level, msg, time.Now(), l.fields} ctx, cancel := context.WithDeadline(context.Background(), time.Now().Add(l.outletTimeout)) - ech := make(chan error) + ech := make(chan outletResult) - louts := l.outlets[level] + louts := l.outlets.Get(level) for i := range louts { go func(ctx context.Context, outlet Outlet, entry Entry) { - ech <- outlet.WriteEntry(ctx, entry) + ech <- outletResult{outlet, outlet.WriteEntry(ctx, entry)} }(ctx, louts[i], entry) } for fin := 0; fin < len(louts); fin++ { select { - case err := <-ech: - if err != nil { - fmt.Fprintf(os.Stderr, "%s outlet error: %s\n", InternalErrorPrefix, err) + case res := <-ech: + if res.Error != nil { + l.logInternalError(res.Outlet, res.Error.Error()) } case <-ctx.Done(): if ctx.Err() == context.DeadlineExceeded { - fmt.Fprintf(os.Stderr, "%s outlets exceeded deadline, keep waiting anyways", InternalErrorPrefix) + l.logInternalError(nil, "one or more outlets exceeded timeout but will keep waiting anyways") } } } @@ -74,7 +95,8 @@ func (l *Logger) WithField(field string, val interface{}) *Logger { defer l.mtx.Unlock() if _, ok := l.fields[field]; ok { - fmt.Fprintf(os.Stderr, "%s caller overwrites field '%s'. Stack:\n%s\n", InternalErrorPrefix, field, string(debug.Stack())) + l.logInternalError(nil, + fmt.Sprintf("caller overwrites field '%s'. Stack: %s", field, string(debug.Stack()))) } child := &Logger{