feat(log): Working on log library

log/hooks/file/config.go

@@ -0,0 +1,42 @@
+package file
+
+import (
+	"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"`
+}
+
+// IsValid will check that the File configuration is valid.
+func (c *ConfigStruct) IsValid() error {
+
+	if c.Filename == "" {
+		return errors.NotValidf("Path is empty in File configuration")
+	} else if isValid, _ := govalidator.IsFilePath(c.Filename); !isValid {
+		return errors.NotValidf("Path is invalid 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"
+	}
+}

log/hooks/file/file.go

@@ -0,0 +1,354 @@
+// 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
+}

log/hooks/file/hook.go

@@ -0,0 +1,110 @@
+// Based on https://github.com/gogap/logrus_mate under License Apache License 2.0
+package file
+
+import (
+	"bytes"
+	"fmt"
+	"os"
+	"path/filepath"
+	"strings"
+	"time"
+
+	"github.com/juju/errors"
+	"github.com/sirupsen/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)
+
+	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)
+		}
+	}
+	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)
+
+		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))
+
+		message = message + fmt.Sprintf("%v", buf.String())
+	}
+
+	return
+}