From 4e49672758bd354f7d1f88c934d0334045d03878 Mon Sep 17 00:00:00 2001 From: Matthieu 'JP' DERASSE Date: Tue, 6 Dec 2022 21:45:50 +0000 Subject: [PATCH] feat(log): Implement text logger to files --- go.mod | 7 +- go.sum | 12 +- log/hooks/file/config.go | 66 +++++-- log/hooks/file/file.go | 354 ------------------------------------ log/hooks/file/file_hook.go | 168 +++++++++++++++++ log/hooks/file/hook.go | 127 +++++-------- log/log.go | 2 +- 7 files changed, 275 insertions(+), 461 deletions(-) delete mode 100644 log/hooks/file/file.go create mode 100644 log/hooks/file/file_hook.go diff --git a/go.mod b/go.mod index f86b56b..522b4a8 100644 --- a/go.mod +++ b/go.mod @@ -4,13 +4,16 @@ go 1.19 require ( github.com/asaskevich/govalidator v0.0.0-20210307081110-f21760c49a8d + github.com/gemnasium/logrus-graylog-hook/v3 v3.1.0 github.com/juju/errors v1.0.0 + github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible github.com/sirupsen/logrus v1.9.0 gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c ) require ( - github.com/gemnasium/logrus-graylog-hook/v3 v3.1.0 // indirect - github.com/pkg/errors v0.8.1 // indirect + github.com/jonboulle/clockwork v0.3.0 // indirect + github.com/lestrrat-go/strftime v1.0.6 // indirect + github.com/pkg/errors v0.9.1 // indirect golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8 // indirect ) diff --git a/go.sum b/go.sum index 765f4df..51b16e7 100644 --- a/go.sum +++ b/go.sum @@ -5,13 +5,22 @@ github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/gemnasium/logrus-graylog-hook/v3 v3.1.0 h1:SLtCnpI5ZZaz4l7RSatEhppB1BBhUEu+DqGANJzJdEA= github.com/gemnasium/logrus-graylog-hook/v3 v3.1.0/go.mod h1:wi1zWv9tIvyLSMLCAzgRP+YR24oLVQVBHfPPKjtht44= +github.com/jonboulle/clockwork v0.3.0 h1:9BSCMi8C+0qdApAp4auwX0RkLGUjs956h0EkuQymUhg= +github.com/jonboulle/clockwork v0.3.0/go.mod h1:Pkfl5aHPm1nk2H9h0bjmnJD/BcgbGXUBGnn1kMkgxc8= github.com/juju/errors v1.0.0 h1:yiq7kjCLll1BiaRuNY53MGI0+EQ3rF6GB+wvboZDefM= github.com/juju/errors v1.0.0/go.mod h1:B5x9thDqx0wIMH3+aLIMP9HjItInYWObRovoCFM5Qe8= github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ= github.com/kr/pretty v0.2.1 h1:Fmg33tUaq4/8ym9TJN1x7sLJnHVwhP33CNkpYV/7rwI= github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= -github.com/pkg/errors v0.8.1 h1:iURUrRGxPUNPdy5/HRSm+Yj6okJ6UtLINN0Q9M4+h3I= +github.com/lestrrat-go/envload v0.0.0-20180220234015-a3eb8ddeffcc h1:RKf14vYWi2ttpEmkA4aQ3j4u9dStX2t4M8UM6qqNsG8= +github.com/lestrrat-go/envload v0.0.0-20180220234015-a3eb8ddeffcc/go.mod h1:kopuH9ugFRkIXf3YoqHKyrJ9YfUFsckUU9S7B+XP+is= +github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible h1:Y6sqxHMyB1D2YSzWkLibYKgg+SwmyFU9dF2hn6MdTj4= +github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible/go.mod h1:ZQnN8lSECaebrkQytbHj4xNgtg8CR7RYXnPok8e0EHA= +github.com/lestrrat-go/strftime v1.0.6 h1:CFGsDEt1pOpFNU+TJB0nhz9jl+K0hZSLE205AhTIGQQ= +github.com/lestrrat-go/strftime v1.0.6/go.mod h1:f7jQKgV5nnJpYgdEasS+/y7EsTb8ykN2z68n3TtcTaw= github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/sirupsen/logrus v1.3.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPxbbu5VWo= @@ -20,6 +29,7 @@ github.com/sirupsen/logrus v1.9.0/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVs github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= +github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY= github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= diff --git a/log/hooks/file/config.go b/log/hooks/file/config.go index 4799fdd..f7c61a2 100644 --- a/log/hooks/file/config.go +++ b/log/hooks/file/config.go @@ -1,20 +1,22 @@ package file import ( + "io/fs" + "os" + "path/filepath" + "time" + "github.com/asaskevich/govalidator" "github.com/juju/errors" ) // ConfigStruct is the configuration for File Provider. type ConfigStruct struct { - Filename string `yaml:"filename"` - MaxLines int `yaml:"max_lines"` - MaxSize int `yaml:"max_size"` - Daily bool `yaml:"daily"` - MaxDays int `yaml:"max_days"` - Rotate bool `yaml:"rotate"` - Perm string `yaml:"perm"` - RotatePerm string `yaml:"rotate_perm"` + Filename string `yaml:"filename"` + Rotate bool `yaml:"rotate"` + RotateTime *string `yaml:"rotate_time"` + RotateMaxAge *string `yaml:"rotate_max_age"` + RotateMaxFile *int `yaml:"rotate_max_file"` } // IsValid will check that the File configuration is valid. @@ -26,17 +28,41 @@ func (c *ConfigStruct) IsValid() error { return errors.NotValidf("Path is invalid in File configuration") } + dir := filepath.Dir(c.Filename) + + if _, err := os.Stat(dir); err != nil { + if errors.Is(err, fs.ErrPermission) { + return errors.NewForbidden(err, "Filename directory is not readeable in File configuration") + } else if errors.Is(err, fs.ErrNotExist) { + return errors.NewNotFound(err, "Filename directory does not exist in File configuration") + } else { + return errors.Trace(err) + } + } + + if c.Rotate { + + if c.RotateTime == nil || *c.RotateTime == "" { + return errors.NotValidf("rotate_time cannot be null or an empty string in File configuration") + } else if _, err := time.ParseDuration(*c.RotateTime); err != nil { + return errors.NewNotValid(err, "rotate_time contain an invalid duration in File configuration") + } + + if c.RotateMaxFile != nil && *c.RotateMaxFile <= 0 { + return errors.NotValidf("rotate_max_file cannot be negative or 0 in File configuration") + } + + if c.RotateMaxAge != nil && *c.RotateMaxAge == "" { + return errors.NotValidf("rotate_max_age cannot be an empty string in File configuration") + } else if c.RotateMaxAge != nil { + if _, err := time.ParseDuration(*c.RotateMaxAge); err != nil { + return errors.NewNotValid(err, "rotate_max_age contain an invalid duration in File configuration") + } + } + + if c.RotateMaxFile != nil && c.RotateMaxAge != nil { + return errors.NotValidf("rotate_max_age and rotate_max_file cannot be defined at the same time in File configuration") + } + } return nil } - -// ApplyDefault will check config and apply default on mandatory values. -func (c *ConfigStruct) ApplyDefault() { - - if c.Perm == "" { - c.Perm = "0660" - } - - if c.RotatePerm == "" { - c.RotatePerm = "0440" - } -} diff --git a/log/hooks/file/file.go b/log/hooks/file/file.go deleted file mode 100644 index 327ab39..0000000 --- a/log/hooks/file/file.go +++ /dev/null @@ -1,354 +0,0 @@ -// Based on https://github.com/gogap/logrus_mate under License Apache License 2.0 -package file - -import ( - "bytes" - "fmt" - "io" - "os" - "path/filepath" - "strconv" - "strings" - "sync" - "time" -) - -// RFC5424 log message levels. -const ( - LevelError = iota - LevelWarn - LevelInfo - LevelDebug -) - -const ( - y1 = `0123456789` - y2 = `0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789` - y3 = `0000000000111111111122222222223333333333444444444455555555556666666666777777777788888888889999999999` - y4 = `0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789` - mo1 = `000000000111` - mo2 = `123456789012` - d1 = `0000000001111111111222222222233` - d2 = `1234567890123456789012345678901` - h1 = `000000000011111111112222` - h2 = `012345678901234567890123` - mi1 = `000000000011111111112222222222333333333344444444445555555555` - mi2 = `012345678901234567890123456789012345678901234567890123456789` - s1 = `000000000011111111112222222222333333333344444444445555555555` - s2 = `012345678901234567890123456789012345678901234567890123456789` - ns1 = `0123456789` -) - -// fileLogWriter implements LoggerInterface. -// It writes messages by lines limit, file size limit, or time frequency. -type fileLogWriter struct { - sync.RWMutex // write log order by order and atomic incr maxLinesCurLines and maxSizeCurSize - // The opened file - Filename string - fileWriter *os.File - - // Rotate at line - MaxLines int - maxLinesCurLines int - - // Rotate at size - MaxSize int - maxSizeCurSize int - - // Rotate daily - Daily bool - MaxDays int - dailyOpenDate int - dailyOpenTime time.Time - - Rotate bool - Perm string - RotatePerm string - - fileNameOnly, suffix string // like "project.log", project is fileNameOnly and .log is suffix -} - -func InitFileLogWriter(c *ConfigStruct) (*fileLogWriter, error) { - - w := fileLogWriter{ - Filename: c.Filename, - MaxLines: c.MaxLines, - MaxSize: c.MaxSize, - Daily: c.Daily, - MaxDays: c.MaxDays, - Rotate: c.Rotate, - Perm: c.Perm, - RotatePerm: c.RotatePerm, - } - - w.suffix = filepath.Ext(w.Filename) - w.fileNameOnly = strings.TrimSuffix(w.Filename, w.suffix) - if w.suffix == "" { - w.suffix = ".log" - } - err := w.startLogger() - return &w, err -} - -// start file logger. create log file and set to locker-inside file writer. -func (w *fileLogWriter) startLogger() error { - file, err := w.createLogFile() - if err != nil { - return err - } - if w.fileWriter != nil { - w.fileWriter.Close() - } - w.fileWriter = file - return w.initFd() -} - -func (w *fileLogWriter) needRotate(size int, day int) bool { - return (w.MaxLines > 0 && w.maxLinesCurLines >= w.MaxLines) || - (w.MaxSize > 0 && w.maxSizeCurSize >= w.MaxSize) || - (w.Daily && day != w.dailyOpenDate) - -} - -// WriteMsg write logger message into file. -func (w *fileLogWriter) WriteMsg(when time.Time, msg string, level int) error { - h, d := formatTimeHeader(when) - msg = string(h) + msg + "\n" - if w.Rotate { - w.RLock() - if w.needRotate(len(msg), d) { - w.RUnlock() - w.Lock() - if w.needRotate(len(msg), d) { - if err := w.doRotate(when); err != nil { - fmt.Fprintf(os.Stderr, "FileLogWriter(%q): %s\n", w.Filename, err) - } - } - w.Unlock() - } else { - w.RUnlock() - } - } - - w.Lock() - _, err := w.fileWriter.Write([]byte(msg)) - if err == nil { - w.maxLinesCurLines++ - w.maxSizeCurSize += len(msg) - } - w.Unlock() - return err -} - -func (w *fileLogWriter) createLogFile() (*os.File, error) { - // Open the log file - perm, err := strconv.ParseInt(w.Perm, 8, 64) - if err != nil { - return nil, err - } - fd, err := os.OpenFile(w.Filename, os.O_WRONLY|os.O_APPEND|os.O_CREATE, os.FileMode(perm)) - if err == nil { - // Make sure file perm is user set perm cause of `os.OpenFile` will obey umask - os.Chmod(w.Filename, os.FileMode(perm)) - } - return fd, err -} - -func (w *fileLogWriter) initFd() error { - fd := w.fileWriter - fInfo, err := fd.Stat() - if err != nil { - return fmt.Errorf("get stat err: %s", err) - } - w.maxSizeCurSize = int(fInfo.Size()) - w.dailyOpenTime = time.Now() - w.dailyOpenDate = w.dailyOpenTime.Day() - w.maxLinesCurLines = 0 - if w.Rotate { - if w.Daily { - go w.dailyRotate(w.dailyOpenTime) - } - if fInfo.Size() > 0 && w.MaxLines > 0 { - count, err := w.lines() - if err != nil { - return err - } - w.maxLinesCurLines = count - } - } - return nil -} - -func (w *fileLogWriter) dailyRotate(openTime time.Time) { - y, m, d := openTime.Add(24 * time.Hour).Date() - nextDay := time.Date(y, m, d, 0, 0, 0, 0, openTime.Location()) - tm := time.NewTimer(time.Duration(nextDay.UnixNano() - openTime.UnixNano() + 100)) - <-tm.C - w.Lock() - if w.needRotate(0, time.Now().Day()) { - if err := w.doRotate(time.Now()); err != nil { - fmt.Fprintf(os.Stderr, "FileLogWriter(%q): %s\n", w.Filename, err) - } - } - w.Unlock() -} - -func (w *fileLogWriter) lines() (int, error) { - fd, err := os.Open(w.Filename) - if err != nil { - return 0, err - } - defer fd.Close() - - buf := make([]byte, 32768) // 32k - count := 0 - lineSep := []byte{'\n'} - - for { - c, err := fd.Read(buf) - if err != nil && err != io.EOF { - return count, err - } - - count += bytes.Count(buf[:c], lineSep) - - if err == io.EOF { - break - } - } - - return count, nil -} - -// DoRotate means it need to write file in new file. -// new file name like xx.2013-01-01.log (daily) or xx.001.log (by line or size) -func (w *fileLogWriter) doRotate(logTime time.Time) error { - // file exists - // Find the next available number - num := 1 - fName := "" - rotatePerm, err := strconv.ParseInt(w.RotatePerm, 8, 64) - if err != nil { - return err - } - - _, err = os.Lstat(w.Filename) - if err != nil { - //even if the file is not exist or other ,we should RESTART the logger - goto RESTART_LOGGER - } - - if w.MaxLines > 0 || w.MaxSize > 0 { - for ; err == nil && num <= 999; num++ { - fName = w.fileNameOnly + fmt.Sprintf(".%s.%03d%s", logTime.Format("2006-01-02"), num, w.suffix) - _, err = os.Lstat(fName) - } - } else { - fName = fmt.Sprintf("%s.%s%s", w.fileNameOnly, w.dailyOpenTime.Format("2006-01-02"), w.suffix) - _, err = os.Lstat(fName) - for ; err == nil && num <= 999; num++ { - fName = w.fileNameOnly + fmt.Sprintf(".%s.%03d%s", w.dailyOpenTime.Format("2006-01-02"), num, w.suffix) - _, err = os.Lstat(fName) - } - } - // return error if the last file checked still existed - if err == nil { - return fmt.Errorf("Rotate: Cannot find free log number to rename %s", w.Filename) - } - - // close fileWriter before rename - w.fileWriter.Close() - - // Rename the file to its new found name - // even if occurs error,we MUST guarantee to restart new logger - err = os.Rename(w.Filename, fName) - if err != nil { - goto RESTART_LOGGER - } - - err = os.Chmod(fName, os.FileMode(rotatePerm)) - -RESTART_LOGGER: - - startLoggerErr := w.startLogger() - go w.deleteOldLog() - - if startLoggerErr != nil { - return fmt.Errorf("Rotate StartLogger: %s", startLoggerErr) - } - if err != nil { - return fmt.Errorf("Rotate: %s", err) - } - return nil -} - -func (w *fileLogWriter) deleteOldLog() { - dir := filepath.Dir(w.Filename) - filepath.Walk(dir, func(path string, info os.FileInfo, err error) (returnErr error) { - defer func() { - if r := recover(); r != nil { - fmt.Fprintf(os.Stderr, "Unable to delete old log '%s', error: %v\n", path, r) - } - }() - - if info == nil { - return - } - - if !info.IsDir() && info.ModTime().Add(24*time.Hour*time.Duration(w.MaxDays)).Before(time.Now()) { - if strings.HasPrefix(filepath.Base(path), filepath.Base(w.fileNameOnly)) && - strings.HasSuffix(filepath.Base(path), w.suffix) { - os.Remove(path) - } - } - return - }) -} - -// Destroy close the file description, close file writer. -func (w *fileLogWriter) Destroy() { - w.fileWriter.Close() -} - -// Flush flush file logger. -// there are no buffering messages in file logger in memory. -// flush file means sync file from disk. -func (w *fileLogWriter) Flush() { - w.fileWriter.Sync() -} - -func formatTimeHeader(when time.Time) ([]byte, int) { - y, mo, d := when.Date() - h, mi, s := when.Clock() - ns := when.Nanosecond() / 1000000 - //len("2006/01/02 15:04:05.123 ")==24 - var buf [24]byte - - buf[0] = y1[y/1000%10] - buf[1] = y2[y/100] - buf[2] = y3[y-y/100*100] - buf[3] = y4[y-y/100*100] - buf[4] = '/' - buf[5] = mo1[mo-1] - buf[6] = mo2[mo-1] - buf[7] = '/' - buf[8] = d1[d-1] - buf[9] = d2[d-1] - buf[10] = ' ' - buf[11] = h1[h] - buf[12] = h2[h] - buf[13] = ':' - buf[14] = mi1[mi] - buf[15] = mi2[mi] - buf[16] = ':' - buf[17] = s1[s] - buf[18] = s2[s] - buf[19] = '.' - buf[20] = ns1[ns/100] - buf[21] = ns1[ns%100/10] - buf[22] = ns1[ns%10] - - buf[23] = ' ' - - return buf[0:], d -} diff --git a/log/hooks/file/file_hook.go b/log/hooks/file/file_hook.go new file mode 100644 index 0000000..0162b90 --- /dev/null +++ b/log/hooks/file/file_hook.go @@ -0,0 +1,168 @@ +package file + +import ( + "bytes" + "fmt" + "io" + "os" + "strings" + "sync" + "time" + + "github.com/sirupsen/logrus" +) + +// BufSize is the number of log that can be put in buffer before make it full +// BufSize= _before_ calling NewFileHook +// Once the buffer is full, logging will start blocking, waiting for slots to +// be available in the queue. +var BufSize uint = 8192 + +// Hook will write logs to a file. +type Hook struct { + Level logrus.Level + w io.Writer + buf chan logrus.Entry + wg sync.WaitGroup + mu sync.RWMutex + synchronous bool +} + +// NewFileHook creates a hook to be added to an instance of logger. +func NewFileHook(w io.Writer) *Hook { + if w == nil { + logrus.Error("Can't create File Hook with an empty writer") + return nil + } + + hook := &Hook{ + Level: logrus.DebugLevel, + synchronous: true, + w: w, + } + + return hook +} + +// NewAsyncFileHook creates a hook to be added to an instance of logger. +// The hook created will be asynchronous, and it's the responsibility of the user to call the Flush method +// before exiting to empty the log queue. +func NewAsyncFileHook(w io.Writer) *Hook { + if w == nil { + logrus.Error("Can't create File Hook with an empty writer") + return nil + } + + hook := &Hook{ + Level: logrus.DebugLevel, + buf: make(chan logrus.Entry, BufSize), + w: w, + } + go hook.fire() // Log in background + + return hook +} + +// Flush waits for the log queue to be empty. +// This func is meant to be used when the hook was created with NewAsyncFileHook. +func (hook *Hook) Flush() { + if hook.synchronous { + logrus.Error("Can't call Flush on a File Hook in synchronous execution") + } + + hook.mu.Lock() // claim the mutex as a Lock - we want exclusive access to it + defer hook.mu.Unlock() + + hook.wg.Wait() +} + +// Fire is called when a log event is fired. +// We assume the entry will be altered by another hook, +// otherwise we might be logging something wrong to Graylog. +func (hook *Hook) Fire(entry *logrus.Entry) error { + hook.mu.RLock() // Claim the mutex as a RLock - allowing multiple go routines to log simultaneously + defer hook.mu.RUnlock() + + if hook.synchronous { + hook.writeEntry(entry) + } else { + hook.wg.Add(1) + hook.buf <- *entry + } + + return nil +} + +// fire will loop on the 'buf' channel, and write entries to the writer. +func (hook *Hook) fire() { + for { + entry := <-hook.buf // receive new entry on channel + hook.writeEntry(&entry) + hook.wg.Done() + } +} + +// writeEntry write an entry to a file synchronously. +func (hook *Hook) writeEntry(entry *logrus.Entry) { + if hook.w == nil { + fmt.Println("Can't write to a file without a writer") + return + } + + message := constructMessage(entry) + _, err := hook.w.Write([]byte(fmt.Sprintf("%s\n", message))) + if err != nil { + fmt.Fprintf(os.Stderr, "Failed to write in log file. Error: %s\nLog Line: %s", err, message) + } +} + +// Levels returns the available logging levels. +func (hook *Hook) Levels() []logrus.Level { + levels := []logrus.Level{} + for _, level := range logrus.AllLevels { + if level <= hook.Level { + levels = append(levels, level) + } + } + return levels +} + +func constructMessage(entry *logrus.Entry) string { + var messageParts []string + + // handle time + messageParts = append(messageParts, fmt.Sprintf("time=\"%s\"", entry.Time.UTC().Format(time.RFC3339))) + + // handle log level + messageParts = append(messageParts, fmt.Sprintf("level=%s", entry.Level.String())) + + // handle actual message + messageParts = append(messageParts, fmt.Sprintf("msg=\"%s\"", string(bytes.TrimSpace([]byte(entry.Message))))) + + // add extra data except err_* + for k, v := range entry.Data { + if !strings.HasPrefix(k, "err_") { + messageParts = append(messageParts, fmt.Sprintf("%s=\"%s\"", k, v)) + } + } + + message := strings.Join(messageParts, " ") + + // handle error stack + // XXX: Is that really how it work ?? I doubt but let see + if _, exist := entry.Data["err_code"]; exist { + + // get error infos + //ns := entry.Data["err_ns"] + ctx := entry.Data["err_ctx"] + //id := entry.Data["err_id"] + + // get stack and clean it a bit + tSt := entry.Data["err_stack"] + st := strings.Replace(tSt.(string), "\n", "\n\t\t", -1) + + message = fmt.Sprintf("%s\nerror:\n\tcontext:%s\n\tstacktrace:\n\t\t%s", message, ctx, st) + } + + return message +} diff --git a/log/hooks/file/hook.go b/log/hooks/file/hook.go index 7a29ae6..e84fb3b 100644 --- a/log/hooks/file/hook.go +++ b/log/hooks/file/hook.go @@ -1,110 +1,71 @@ -// Based on https://github.com/gogap/logrus_mate under License Apache License 2.0 package file import ( - "bytes" "fmt" + "io" "os" "path/filepath" - "strings" "time" "github.com/juju/errors" "github.com/sirupsen/logrus" + + rotatelogs "github.com/lestrrat-go/file-rotatelogs" ) +// NewHook will create a File Hook for logrus. func NewHook(c *ConfigStruct) (logrus.Hook, error) { - c.ApplyDefault() - err := c.IsValid() if err != nil { return nil, errors.Trace(err) } - dir := filepath.Dir(c.Filename) + var w io.Writer + if c.Rotate { + rotateTime, _ := time.ParseDuration(*c.RotateTime) - err = os.MkdirAll(dir, 0755) - if err != nil { - return nil, nil - } - - w, err := InitFileLogWriter(c) - if err != nil { - return nil, errors.Trace(err) - } - - return &FileHook{W: w}, nil -} - -type FileHook struct { - W *fileLogWriter -} - -func (p *FileHook) Fire(entry *logrus.Entry) (err error) { - message, err := getMessage(entry) - - if err != nil { - fmt.Fprintf(os.Stderr, "Unable to read entry, %v", err) - return err - } - - now := time.Now() - - switch entry.Level { - case logrus.PanicLevel: - fallthrough - case logrus.FatalLevel: - fallthrough - case logrus.ErrorLevel: - return p.W.WriteMsg(now, fmt.Sprintf("[ERROR] %s", message), LevelError) - case logrus.WarnLevel: - return p.W.WriteMsg(now, fmt.Sprintf("[WARN] %s", message), LevelWarn) - case logrus.InfoLevel: - return p.W.WriteMsg(now, fmt.Sprintf("[INFO] %s", message), LevelInfo) - case logrus.DebugLevel: - return p.W.WriteMsg(now, fmt.Sprintf("[DEBUG] %s", message), LevelDebug) - default: - return nil - } - - return -} - -func (p *FileHook) Levels() []logrus.Level { - return []logrus.Level{ - logrus.PanicLevel, - logrus.FatalLevel, - logrus.ErrorLevel, - logrus.WarnLevel, - logrus.InfoLevel, - logrus.DebugLevel, - } -} - -func getMessage(entry *logrus.Entry) (message string, err error) { - message = message + fmt.Sprintf("%s", entry.Message) - for k, v := range entry.Data { - if !strings.HasPrefix(k, "err_") { - message = message + fmt.Sprintf("\n%v:%v", k, v) + // let's construct log rotator options + rotateOptions := []rotatelogs.Option{ + rotatelogs.WithLinkName(c.Filename), + rotatelogs.WithRotationTime(rotateTime), } - } - if errCode, exist := entry.Data["err_code"]; exist { - ns, _ := entry.Data["err_ns"] - ctx, _ := entry.Data["err_ctx"] - id, _ := entry.Data["err_id"] - tSt, _ := entry.Data["err_stack"] - st, _ := tSt.(string) - st = strings.Replace(st, "\n", "\n\t\t", -1) + if c.RotateMaxAge != nil { + rotateMaxAge, _ := time.ParseDuration(*c.RotateMaxAge) + rotateOptions = append(rotateOptions, rotatelogs.WithMaxAge(rotateMaxAge)) + } else if c.RotateMaxFile != nil { + rotateOptions = append( + rotateOptions, + rotatelogs.WithRotationCount(uint(*c.RotateMaxFile)), + rotatelogs.WithMaxAge(-1), + ) + } - buf := bytes.NewBuffer(nil) - buf.WriteString(fmt.Sprintf("\tid:\n\t\t%s#%d:%s\n", ns, errCode, id)) - buf.WriteString(fmt.Sprintf("\tcontext:\n\t\t%s\n", ctx)) - buf.WriteString(fmt.Sprintf("\tstacktrace:\n\t\t%s", st)) + w, err = rotatelogs.New( + fmt.Sprintf("%s.%%Y%%m%%d%%H%%M", c.Filename), + rotateOptions..., + ) + if err != nil { + return nil, errors.Trace(err) + } - message = message + fmt.Sprintf("%v", buf.String()) + } else { + dirname := filepath.Dir(c.Filename) + if err := os.MkdirAll(dirname, 0750); err != nil { + return nil, errors.NewNotSupported(err, fmt.Sprintf("failed to create directory %s", dirname)) + } + + // if we got here, then we need to create a file + fh, err := os.OpenFile(c.Filename, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0600) + if err != nil { + return nil, errors.NewNotSupported(err, fmt.Sprintf("failed to open file %s", c.Filename)) + } + + w = fh } - return + h := NewAsyncFileHook(w) + + return h, nil } diff --git a/log/log.go b/log/log.go index c648773..af80a25 100644 --- a/log/log.go +++ b/log/log.go @@ -98,7 +98,7 @@ func InitLogFromCustomConfig(c *ConfigStruct) error { default: } - for i := 0; i < 50; i++ { + for i := 0; i < 500; i++ { log.Infof("Test %d", i) time.Sleep(1 * time.Second) }