gocommon/pkg/logger/logger.go

package logger

import (
	"fmt"
	"log"
	"os"
	"path/filepath"
	"strconv"
	"strings"
	"sync"
	"time"

	"git.shuncheng.lu/bigthing/gocommon/pkg/conf"
	"git.shuncheng.lu/bigthing/gocommon/pkg/internal/util"
)

type (
	Level int
)

const (
	LevelFatal = iota
	LevelError
	LevelWarning
	LevelInfo
	LevelDebug
)

var levelName = []string{
	LevelFatal:   "output",
	LevelDebug:   "debug",
	LevelInfo:    "info",
	LevelWarning: "warn",
	LevelError:   "error",
}

var _fileLogWriter Logger

// 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

	logSync     sync.RWMutex
	accessSync  sync.RWMutex
	monitorSync sync.RWMutex
	taskSync    sync.RWMutex
	thirdSync   sync.RWMutex

	// The opened file
	_logFile        map[Level]*os.File
	_accesslogFile  *os.File
	_monitorlogFile *os.File
	_tasklogFile    *os.File
	_thirdlogFile   *os.File

	// logs map cache
	_logs       map[Level]*logger
	_accesslog  *logger
	_monitorlog *logger
	_tasklog    *logger
	_thirdlog   *logger

	ThirdLogFile, TaskLogFile, AccessLogFile, MonitorLogFile, ProjectLogFile, LogFilePath string

	// Rotate daily
	Daily         bool `json:"daily"`
	dailyOpenDate int
	dailyOpenTime time.Time

	logFileTime map[Level]time.Time

	Rotate bool `json:"rotate"`

	Perm string `json:"perm"`

	RotatePerm string `json:"rotateperm"`

	_accesslogFileNameOnly, _accesslogSuffix   string // like "project.log", project is fileNameOnly and .log is suffix
	_monitorlogFileNameOnly, _monitorlogSuffix string // like "project.log", project is fileNameOnly and .log is suffix
	_tasklogFileNameOnly, _tasklogSuffix       string // like "project.log", project is fileNameOnly and .log is suffix
	_thirdlogFileNameOnly, _thirdlogSuffix     string // like "project.log", project is fileNameOnly and .log is suffix
	_projectLogFileNameOnly, _projectLogSuffix string // like "project.log", project is fileNameOnly and .log is suffix
}

// Logger defines the behavior of a log provider.
type Logger interface {
	Init() error
	Log(level Level) *logger
	Accesslog() *logger
	Monitorlog() *logger
	Tasklog() *logger
	Thirdlog() *logger
}

// 若没有配置 log.xxx_log 的位置和名称，则日志默认添加到运行时文件的目录里
func loadLogConfig(assertNil util.SetAndAssertNil) (map[string]string, error) {
	var (
		config = make(map[string]string)
	)
	if err := assertNil(config, "log", "project_log", "project_log.log"); err != nil {
		return nil, err
	}
	if err := assertNil(config, "log", "access_log", "access_log.log"); err != nil {
		return nil, err
	}
	if err := assertNil(config, "log", "task_log", "task_log.log"); err != nil {
		return nil, err
	}
	if err := assertNil(config, "log", "third_log", "third.log"); err != nil {
		return nil, err
	}
	if err := assertNil(config, "log", "monitor_log", "monitor_log.log"); err != nil {
		return nil, err
	}
	util.Debugf("Logger load config success, config=%+v.", config)
	return config, nil
}

// newFileWriter create a FileLogWriter returning as LoggerInterface.
func newFileWriter() (Logger, error) {
	config, err := loadLogConfig(conf.SetAndAssertNil)
	if err != nil {
		return nil, err
	}
	w := &fileLogWriter{
		Daily:          true,
		Rotate:         true,
		RotatePerm:     "0444",
		Perm:           "0664",
		_logs:          make(map[Level]*logger, 0),
		_logFile:       make(map[Level]*os.File, 0),
		logFileTime:    make(map[Level]time.Time, 0),
		AccessLogFile:  config["access_log"],
		MonitorLogFile: config["monitor_log"],
		TaskLogFile:    config["task_log"],
		ThirdLogFile:   config["third_log"],
		ProjectLogFile: config["project_log"],
	}
	return w, nil
}

func (w *fileLogWriter) Monitorlog() *logger {
	w.monitorSync.RLock()
	defer w.monitorSync.RUnlock()
	return w._monitorlog
}

func (w *fileLogWriter) Accesslog() *logger {
	w.accessSync.RLock()
	defer w.accessSync.RUnlock()
	return w._accesslog
}

func (w *fileLogWriter) Tasklog() *logger {
	w.taskSync.RLock()
	defer w.taskSync.RUnlock()
	return w._tasklog
}

func (w *fileLogWriter) Thirdlog() *logger {
	w.thirdSync.RLock()
	defer w.thirdSync.RUnlock()
	return w._thirdlog
}

func (w *fileLogWriter) Log(level Level) *logger {
	w.logSync.Lock()
	defer w.logSync.Unlock()
	if w._logs[level] == nil || w.checkLogNeedRotate(level) {
		err := w.createLogFile(level)
		if err != nil {
			fmt.Printf("err %#v", err.Error())
		}
	}

	return w._logs[level]
}

func (w *fileLogWriter) checkLogNeedRotate(level Level) bool {
	if time.Now().Hour() != w.logFileTime[level].Hour() {
		return true
	}
	return false
}

func (w *fileLogWriter) Init() error {
	w._accesslogSuffix = filepath.Ext(w.AccessLogFile)
	w._accesslogFileNameOnly = strings.TrimSuffix(w.AccessLogFile, w._accesslogSuffix)
	if w._accesslogSuffix == "" {
		w._accesslogSuffix = ".log"
	}

	w._monitorlogSuffix = filepath.Ext(w.MonitorLogFile)
	w._monitorlogFileNameOnly = strings.TrimSuffix(w.MonitorLogFile, w._monitorlogSuffix)
	if w._monitorlogSuffix == "" {
		w._monitorlogSuffix = ".log"
	}

	w._tasklogSuffix = filepath.Ext(w.TaskLogFile)
	w._tasklogFileNameOnly = strings.TrimSuffix(w.TaskLogFile, w._tasklogSuffix)
	if w._tasklogSuffix == "" {
		w._tasklogSuffix = ".log"
	}

	w._thirdlogSuffix = filepath.Ext(w.ThirdLogFile)
	w._thirdlogFileNameOnly = strings.TrimSuffix(w.ThirdLogFile, w._thirdlogSuffix)
	if w._thirdlogSuffix == "" {
		w._thirdlogSuffix = ".log"
	}

	w._projectLogSuffix = filepath.Ext(w.ProjectLogFile)
	w._projectLogFileNameOnly = strings.TrimSuffix(w.ProjectLogFile, w._projectLogSuffix)
	if w._projectLogSuffix == "" {
		w._projectLogSuffix = ".log"
	}
	err := w.startLogger()
	return err
}

// start file logger. create log file and set to locker-inside file writer.
func (w *fileLogWriter) startLogger() error {
	err := w.createAccessLogFile()
	if err != nil {
		return err
	}
	err = w.createMonitorLogFile()
	if err != nil {
		return err
	}
	err = w.createTaskLogFile()
	if err != nil {
		return err
	}
	err = w.createThirdLogFile()
	if err != nil {
		return err
	}
	return w.initFd()
}

func (w *fileLogWriter) initFd() error {
	_, err := w._accesslogFile.Stat()
	if err != nil {
		return err
	}

	_, err = w._monitorlogFile.Stat()
	if err != nil {
		return err
	}

	_, err = w._tasklogFile.Stat()
	if err != nil {
		return err
	}

	_, err = w._thirdlogFile.Stat()
	if err != nil {
		return err
	}

	w.dailyOpenTime = time.Now()
	w.dailyOpenDate = w.dailyOpenTime.Day()
	if w.Daily {
		go w.dailyRotate(w.dailyOpenTime)
	}

	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(time.Now().Day()) {
		if err := w.doRotate(time.Now()); err != nil {
			fmt.Fprintf(os.Stderr, "FileLogWriter: %s\n", err)
		}
	}
	w.Unlock()
}

func (w *fileLogWriter) cuttingLog(fileName, fileNameOnly, suffix string, rotatePerm int64, file *os.File) error {
	//fmt.Printf("fileName: %s, fileNameOnly: %s, suffix: %s \n", fileName, fileNameOnly, suffix)
	num := 1
	logfName := ""

	_, err := os.Lstat(fileName)
	if err != nil {
		//even if the file is not exist or other ,we should RESTART the logger
		return err
	}

	logfName = fmt.Sprintf("%s%s.%s", fileNameOnly, suffix, w.dailyOpenTime.Format("2006-01-02"))
	_, err = os.Lstat(logfName)
	for ; err == nil && num <= 10000; num++ {
		logfName = fileNameOnly +
			fmt.Sprintf(".%03d%s.%s", num, suffix, w.dailyOpenTime.Format("2006-01-02"))
		_, err = os.Lstat(logfName)
	}

	// return error if the last file checked still existed
	if err == nil {
		return err
	}

	// close fileWriter before rename
	//file.Close()

	// Rename the file to its new found name
	// even if occurs error,we MUST guarantee to  restart new logger
	err = os.Rename(fileName, logfName)
	if err != nil {
		return err
	}

	err = os.Chmod(logfName, os.FileMode(rotatePerm))
	if err != nil {
		return err
	}

	return 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

	rotatePerm, err := strconv.ParseInt(w.RotatePerm, 8, 64)
	if err != nil {
		return err
	}

	//accessLogFile
	err1 := w.cuttingLog(w.AccessLogFile, w._accesslogFileNameOnly, w._accesslogSuffix, rotatePerm, w._accesslogFile)
	if err1 != nil {
		fmt.Fprintf(os.Stderr, "doRotate err: %s", err1.Error())
		goto RESTART_LOGGER
	}

	//monitorLogFile
	err1 = w.cuttingLog(w.MonitorLogFile, w._monitorlogFileNameOnly, w._monitorlogSuffix, rotatePerm, w._monitorlogFile)
	if err1 != nil {
		fmt.Fprintf(os.Stderr, "doRotate err: %s", err1.Error())
		goto RESTART_LOGGER
	}

	//taskLogFile
	err1 = w.cuttingLog(w.TaskLogFile, w._tasklogFileNameOnly, w._tasklogSuffix, rotatePerm, w._tasklogFile)
	if err1 != nil {
		fmt.Fprintf(os.Stderr, "doRotate err: %s", err1.Error())
		goto RESTART_LOGGER
	}

	//thirdLogFile
	err1 = w.cuttingLog(w.ThirdLogFile, w._thirdlogFileNameOnly, w._thirdlogSuffix, rotatePerm, w._thirdlogFile)
	if err1 != nil {
		fmt.Fprintf(os.Stderr, "doRotate err: %s", err1.Error())
		goto RESTART_LOGGER
	}

RESTART_LOGGER:

	startLoggerErr := w.startLogger()

	if startLoggerErr != nil {
		return startLoggerErr
	}

	return nil
}

func (w *fileLogWriter) needRotate(day int) bool {
	return (w.Daily && day != w.dailyOpenDate)
}

func (w *fileLogWriter) createLogFile(level Level) error {
	//basePath := w.LogFilePath
	t := time.Now()
	year, month, day := t.Date()
	//if !strings.HasSuffix(basePath, "/") {
	//	basePath += "/"
	//}
	perm, err := strconv.ParseInt(w.Perm, 8, 64)
	if err != nil {
		return err
	}
	hour := t.Hour()
	fileName := fmt.Sprintf("%s-%04d-%02d-%02d-%02d-%s.log", w._projectLogFileNameOnly, year, month, day, hour, levelName[level])
	//fname := filepath.Join(basePath, fileName)
	//正常日志
	logFileFd, err := os.OpenFile(fileName, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0666)
	if err != nil {
		return err
	}

	// Make sure file perm is user set perm cause of `os.OpenFile` will obey umask
	os.Chmod(fileName, os.FileMode(perm))

	w.logFileTime[level] = t

	//close the old file
	if w._logFile[level] != nil {
		w._logFile[level].Close()
	}
	w._logFile[level] = logFileFd

	if w._logs[level] != nil {
		w._logs[level]._log.SetOutput(logFileFd)
	} else {
		w._logs[level] = &logger{_log: log.New(logFileFd, "", log.Lshortfile|log.LstdFlags), logLevel: LevelDebug}
	}

	return nil
}

func (w *fileLogWriter) createAccessLogFile() error {
	// Open the log file
	perm, err := strconv.ParseInt(w.Perm, 8, 64)
	if err != nil {
		return err
	}

	w.accessSync.Lock()
	defer w.accessSync.Unlock()

	//accessLogFile
	accessLogFileFd, err := os.OpenFile(w.AccessLogFile, os.O_WRONLY|os.O_APPEND|os.O_CREATE, os.FileMode(perm))
	if err != nil {
		return err
	}

	os.Chmod(w.AccessLogFile, os.FileMode(perm))

	if w._accesslogFile != nil {
		w._accesslogFile.Close()
	}
	w._accesslogFile = accessLogFileFd

	if w._accesslog != nil {
		w._accesslog._log.SetOutput(accessLogFileFd)
	} else {
		w._accesslog = &logger{_log: log.New(accessLogFileFd, "", 0), logLevel: LevelDebug}
	}

	return nil
}

func (w *fileLogWriter) createMonitorLogFile() error {
	// Open the log file
	perm, err := strconv.ParseInt(w.Perm, 8, 64)
	if err != nil {
		return err
	}

	w.monitorSync.Lock()
	defer w.monitorSync.Unlock()

	//monitorLogFile
	monitorLogFileFd, err := os.OpenFile(w.MonitorLogFile, os.O_WRONLY|os.O_APPEND|os.O_CREATE, os.FileMode(perm))
	if err != nil {
		return err
	}

	os.Chmod(w.MonitorLogFile, os.FileMode(perm))

	if w._monitorlogFile != nil {
		w._monitorlogFile.Close()
	}
	w._monitorlogFile = monitorLogFileFd

	if w._monitorlog != nil {
		w._monitorlog._log.SetOutput(monitorLogFileFd)
	} else {
		w._monitorlog = &logger{_log: log.New(monitorLogFileFd, "", log.Lshortfile|log.LstdFlags), logLevel: LevelDebug}
	}

	return nil
}

func (w *fileLogWriter) createTaskLogFile() error {
	// Open the log file
	perm, err := strconv.ParseInt(w.Perm, 8, 64)
	if err != nil {
		return err
	}

	w.taskSync.Lock()
	defer w.taskSync.Unlock()

	//taskLogFile
	taskLogFileFd, err := os.OpenFile(w.TaskLogFile, os.O_WRONLY|os.O_APPEND|os.O_CREATE, os.FileMode(perm))
	if err != nil {
		return err
	}

	os.Chmod(w.TaskLogFile, os.FileMode(perm))

	if w._tasklogFile != nil {
		w._tasklogFile.Close()
	}
	w._tasklogFile = taskLogFileFd

	if w._tasklog != nil {
		w._tasklog._log.SetOutput(taskLogFileFd)
	} else {
		w._tasklog = &logger{_log: log.New(taskLogFileFd, "", log.LUTC), logLevel: LevelDebug}
	}

	return nil
}

func (w *fileLogWriter) createThirdLogFile() error {
	// Open the log file
	perm, err := strconv.ParseInt(w.Perm, 8, 64)
	if err != nil {
		return err
	}

	w.thirdSync.Lock()
	defer w.thirdSync.Unlock()

	//thirdLogFile
	thirdLogFileFd, err := os.OpenFile(w.ThirdLogFile, os.O_WRONLY|os.O_APPEND|os.O_CREATE, os.FileMode(perm))
	if err != nil {
		return err
	}

	os.Chmod(w.ThirdLogFile, os.FileMode(perm))

	if w._thirdlogFile != nil {
		w._thirdlogFile.Close()
	}
	w._thirdlogFile = thirdLogFileFd

	if w._thirdlog != nil {
		w._thirdlog._log.SetOutput(thirdLogFileFd)
	} else {
		w._thirdlog = &logger{_log: log.New(thirdLogFileFd, "", log.LUTC), logLevel: LevelDebug}
	}

	return nil
}

func Init() error {
	writer, err := newFileWriter()
	if err != nil {
		return err
	}
	_fileLogWriter = writer
	return writer.Init()
}

type logger struct {
	_log *log.Logger
	//小于等于该级别的level才会被记录
	logLevel Level
}

// 输出无格式的
func (l *logger) RawOutput(s string) error {
	return l._log.Output(0, s)
}

func (l *logger) Output(level Level, s string) error {
	if l.logLevel < level {
		return nil
	}
	formatStr := "[UNKNOWN] " + s
	switch level {
	case LevelFatal:
		formatStr = "\033[35m[FATAL]\033[0m " + s
	case LevelError:
		formatStr = "\033[31m[ERROR]\033[0m " + s
	case LevelWarning:
		formatStr = "\033[33m[WARN]\033[0m " + s
	case LevelInfo:
		formatStr = "\033[32m[INFO]\033[0m " + s
	case LevelDebug:
		formatStr = "\033[36m[DEBUG]\033[0m " + s
	}
	return l._log.Output(3, formatStr)
}

func (l *logger) Fatal(s string) {
	err := l.Output(LevelFatal, s)
	if err != nil {
		fmt.Fprintf(os.Stderr, "write Fatal log to file fail, err: %s", err.Error())
	}
	os.Exit(1)
}

func (l *logger) Fatalf(format string, v ...interface{}) {
	err := l.Output(LevelFatal, fmt.Sprintf(format, v...))
	if err != nil {
		fmt.Fprintf(os.Stderr, "write Fatalf log to file fail, err: %s", err.Error())
	}
	os.Exit(1)
}

func (l *logger) Error(s string) {
	err := l.Output(LevelError, s)
	if err != nil {
		fmt.Fprintf(os.Stderr, "write Error log to file fail, err: %s", err.Error())
	}
}

func (l *logger) Errorf(format string, v ...interface{}) {
	err := l.Output(LevelError, fmt.Sprintf(format, v...))
	if err != nil {
		panic("Errorf")
		fmt.Fprintf(os.Stderr, "write Errorf log to file fail, err: %s", err.Error())
	}
}

func (l *logger) Warn(s string) {
	err := l.Output(LevelWarning, s)
	if err != nil {
		fmt.Fprintf(os.Stderr, "write Warn log to file fail, err: %s", err.Error())
	}
}

func (l *logger) Warnf(format string, v ...interface{}) {
	err := l.Output(LevelWarning, fmt.Sprintf(format, v...))
	if err != nil {
		fmt.Fprintf(os.Stderr, "write Warnf log to file fail, err: %s", err.Error())
	}
}

func (l *logger) Info(s string) {
	err := l.Output(LevelInfo, s)
	if err != nil {
		fmt.Fprintf(os.Stderr, "write Info log to file fail, err: %s", err.Error())
	}
}

func (l *logger) Infof(format string, v ...interface{}) {
	err := l.Output(LevelInfo, fmt.Sprintf(format, v...))
	if err != nil {
		panic("Errorf")
		fmt.Fprintf(os.Stderr, "write Infof log to file fail, err: %s", err.Error())
	}
}

func (l *logger) Debug(s string) {
	err := l.Output(LevelDebug, s)
	if err != nil {
		fmt.Fprintf(os.Stderr, "write Debug log to file fail, err: %s", err.Error())
	}
}

func (l *logger) Debugf(format string, v ...interface{}) {
	err := l.Output(LevelDebug, fmt.Sprintf(format, v...))
	if err != nil {
		fmt.Fprintf(os.Stderr, "write Debugf log to file fail, err: %s", err.Error())
	}
}

func (l *logger) SetLogLevel(level Level) {
	l.logLevel = level
}

func (l *logger) taskOutput(level Level, s string) error {
	var cstSh, _ = time.LoadLocation("Asia/Shanghai") //时区上海
	//时间前缀  毫秒级别，默认的点换句号
	formatStr := strings.Replace(time.Now().In(cstSh).Format("2006-01-02 15:04:05.000"), ".", ",", -1)
	switch level {
	case LevelError:
		formatStr += " ERROR - " + s
	case LevelWarning:
		formatStr += " WARN - " + s
	case LevelInfo:
		formatStr += " INFO - " + s
	}
	return l._log.Output(3, formatStr)
}

func (l *logger) thirdOutput(s string) error {
	var cstSh, _ = time.LoadLocation("Asia/Shanghai") //时区上海
	//时间前缀  毫秒级别，默认的.替换为:
	formatStr := strings.Replace(time.Now().In(cstSh).Format("2006-01-02 15:04:05.000"), ".", ":", -1)
	formatStr += s
	return l._log.Output(3, formatStr)
}