From 4ceada4701331928923205d12fc60c696810548b Mon Sep 17 00:00:00 2001 From: bryanqiu Date: Wed, 13 Nov 2024 11:01:08 +0800 Subject: [PATCH] dev: improve log position --- log.go | 456 ++++++++++++++++++++++++++++++++++----------------------- 1 file changed, 271 insertions(+), 185 deletions(-) diff --git a/log.go b/log.go index f448f00..17d7d3e 100644 --- a/log.go +++ b/log.go @@ -3,244 +3,330 @@ package log import ( - "encoding/json" - "fmt" - "log" - "os" - "runtime/debug" - "strings" - "sync" - "time" + "encoding/json" + "fmt" + "log" + "os" + "runtime" + "runtime/debug" + "strings" + "sync" + "time" - "qoobing.com/gomod/str" + "qoobing.com/gomod/str" ) const ( - PANIC LogLevel = 0 - FATAL LogLevel = 1 - ERROR LogLevel = 2 - NOTICE LogLevel = 3 - WARNING LogLevel = 4 - INFO LogLevel = 5 - DEBUG LogLevel = 9 - ErrLogLevel = "~~~~~invalid loglevel~~~~~" - ErrLogPanic = "~~~~panic~~~~~~" + PANIC LogLevel = 0 + FATAL LogLevel = 1 + ERROR LogLevel = 2 + NOTICE LogLevel = 3 + WARNING LogLevel = 4 + INFO LogLevel = 5 + DEBUG LogLevel = 9 + ErrLogLevel = "~~~~~invalid loglevel~~~~~" + ErrLogPanic = "~~~~panic~~~~~~" ) var ( - mapStrToLevel = map[string]LogLevel{ - "PANIC": PANIC, - "FATAL": FATAL, - "ERROR": ERROR, - "NOTICE": NOTICE, - "WARNING": WARNING, - "INFO": INFO, - "DEBUG": DEBUG, - } - mapLevelToStr = map[LogLevel]string{ - PANIC: "PANIC", - FATAL: "FATAL", - ERROR: "ERROR", - NOTICE: "NOTICE", - WARNING: "WARNING", - INFO: "INFO", - DEBUG: "DEBUG", - } + mapStrToLevel = map[string]LogLevel{ + "PANIC": PANIC, + "FATAL": FATAL, + "ERROR": ERROR, + "NOTICE": NOTICE, + "WARNING": WARNING, + "INFO": INFO, + "DEBUG": DEBUG, + } + mapLevelToStr = map[LogLevel]string{ + PANIC: "PANIC", + FATAL: "FATAL", + ERROR: "ERROR", + NOTICE: "NOTICE", + WARNING: "WARNING", + INFO: "INFO", + DEBUG: "DEBUG", + } ) var ( - golog *log.Logger = nil - mylog *Logger = nil - logidCreator LogidCreator = nil - modulelogs map[string]*Logger = map[string]*Logger{} + golog *log.Logger = nil + mylog *Logger = nil + logidCreator LogidCreator = nil + modulelogs map[string]*Logger = map[string]*Logger{} ) type LogLevel int type Logger struct { - module string - golog *log.Logger - loglevel LogLevel + module string + golog *log.Logger + loglevel LogLevel } type LogidCreator interface { - Cleanup() - GetLogid() string - SetLogid(logid string) + Cleanup() + GetLogid() string + SetLogid(logid string) } func New(module string) *Logger { - if module == "" { - module = "undefine" - } - if _, ok := modulelogs[module]; ok { - return modulelogs[module] - } else { - modulelogs[module] = &Logger{ - module: module, - golog: golog, - loglevel: DEBUG, - } - return modulelogs[module] - } + if module == "" { + module = "undefine" + } + if _, ok := modulelogs[module]; ok { + return modulelogs[module] + } else { + modulelogs[module] = &Logger{ + module: module, + golog: golog, + loglevel: DEBUG, + } + return modulelogs[module] + } } // SetLogLevel set new log level func (log *Logger) SetLogLevel(newlv LogLevel) (oldlv LogLevel) { - oldlv = log.loglevel - log.loglevel = newlv - return oldlv + oldlv = log.loglevel + log.loglevel = newlv + return oldlv } // SetLogLevelByName set new log level by level name func (log *Logger) SetLogLevelByName(newlv string) (oldlv string) { - if newlevel, ok := mapStrToLevel[newlv]; ok { - oldlevel := log.loglevel - log.loglevel = newlevel - return mapLevelToStr[oldlevel] - } - return ErrLogLevel + if newlevel, ok := mapStrToLevel[newlv]; ok { + oldlevel := log.loglevel + log.loglevel = newlevel + return mapLevelToStr[oldlevel] + } + return ErrLogLevel } - func (log *Logger) Print(prefix string, v interface{}) { - var str = "" - if pkg, err := json.Marshal(v); err != nil { - str = err.Error() - } else { - str = string(pkg) - } - log.logwrite(DEBUG, 3, prefix+"%s\n", str) + var str = "" + if pkg, err := json.Marshal(v); err != nil { + str = err.Error() + } else { + str = string(pkg) + } + log.logwrite(DEBUG, 3, prefix+"%s\n", str) } func (log *Logger) PrintPretty(prefix string, v interface{}) { - var preety = "" - if pkg, err := json.MarshalIndent(v, "==", " "); err != nil { - preety = err.Error() - } else { - preety = string(pkg) - } - log.logwrite(DEBUG, 3, prefix+"%s\n", preety) + var preety = "" + if pkg, err := json.MarshalIndent(v, "==", " "); err != nil { + preety = err.Error() + } else { + preety = string(pkg) + } + log.logwrite(DEBUG, 3, prefix+"%s\n", preety) } func (log *Logger) Debugf(format string, v ...interface{}) { - log.logwrite(DEBUG, 3, format, v...) + log.logwrite(DEBUG, 3, format, v...) } func (log *Logger) DebugfWithDepth(calldepth int, format string, v ...interface{}) { - calldepth += 3 - log.logwrite(DEBUG, calldepth, format, v...) + calldepth += 3 + log.logwrite(DEBUG, calldepth, format, v...) } func (log *Logger) Noticef(format string, v ...interface{}) { - log.logwrite(NOTICE, 3, format, v...) + log.logwrite(NOTICE, 3, format, v...) } func (log *Logger) NoticefWithDepth(calldepth int, format string, v ...interface{}) { - calldepth += 3 - log.logwrite(NOTICE, calldepth, format, v...) + calldepth += 3 + log.logwrite(NOTICE, calldepth, format, v...) } func (log *Logger) Warningf(format string, v ...interface{}) { - log.logwrite(WARNING, 3, format, v...) + log.logwrite(WARNING, 3, format, v...) } func (log *Logger) Infof(format string, v ...interface{}) { - log.logwrite(INFO, 3, format, v...) + log.logwrite(INFO, 3, format, v...) } func (log *Logger) Errorf(format string, v ...interface{}) { - log.logwrite(ERROR, 3, format, v...) + log.logwrite(ERROR, 3, format, v...) } func (log *Logger) Fatalf(format string, v ...interface{}) { - log.logwrite(FATAL, 3, format, v...) + log.logwrite(FATAL, 3, format, v...) } func (log *Logger) Panicf(format string, v ...interface{}) { - log.logwrite(PANIC, 3, format, v...) + log.logwrite(PANIC, 3, format, v...) } -func (log *Logger) Fatal(v ...interface{}){ - log.logwrite(FATAL, 3, "%s", fmt.Sprintln(v...)) +func (log *Logger) Fatal(v ...interface{}) { + log.logwrite(FATAL, 3, "%s", fmt.Sprintln(v...)) } -func (log *Logger) Println(v ...interface{}){ - log.logwrite(DEBUG, 3, "%s", fmt.Sprintln(v...)) +func (log *Logger) Println(v ...interface{}) { + log.logwrite(DEBUG, 3, "%s", fmt.Sprintln(v...)) } - func (log *Logger) GetLogidStr(format string) string { - if logidCreator != nil { - return fmt.Sprintf(format, logidCreator.GetLogid()) - } - return "" + if logidCreator != nil { + return fmt.Sprintf(format, logidCreator.GetLogid()) + } + return "" } func (log *Logger) logwrite(typ LogLevel, calldepth int, format string, v ...interface{}) { - if typ > log.loglevel { - return - } + if typ > log.loglevel { + return + } - var ( - idstr = log.GetLogidStr("[%s] ") - prestr = idstr // + "[" + log.module + "] " - ) + var ( + idstr = log.GetLogidStr("[%s]") + prestr = formatHeader(calldepth) + "" + idstr + "$ " + ) - format = strings.Trim(format, "\n") - switch typ { - case PANIC: - log.golog.SetPrefix("\x1b[31m" + "PANI ") - case FATAL: - log.golog.SetPrefix("\x1b[31m" + "FATA ") - case WARNING: - log.golog.SetPrefix("\x1b[32m" + "WARN ") - case ERROR: - log.golog.SetPrefix("\x1b[33m" + "ERRO ") - case INFO: - log.golog.SetPrefix("INFO ") - case NOTICE: - log.golog.SetPrefix("NOTI ") - case DEBUG: - log.golog.SetPrefix("DBUG ") - default: - log.golog.SetPrefix("UNKN ") - } + format = strings.Trim(format, "\n") + switch typ { + case PANIC: + log.golog.SetPrefix("\x1b[31m" + "PANI ") + case FATAL: + log.golog.SetPrefix("\x1b[31m" + "FATA ") + case WARNING: + log.golog.SetPrefix("\x1b[32m" + "WARN ") + case ERROR: + log.golog.SetPrefix("\x1b[33m" + "ERRO ") + case INFO: + log.golog.SetPrefix("INFO ") + case NOTICE: + log.golog.SetPrefix("NOTI ") + case DEBUG: + log.golog.SetPrefix("DBUG ") + default: + log.golog.SetPrefix("UNKN ") + } - if mylog == log { - calldepth = calldepth + 1 - } + if mylog == log { + calldepth = calldepth + 1 + } - if typ == FATAL || typ == WARNING || typ == ERROR { - log.golog.Output(calldepth, prestr+fmt.Sprintf(format+"\x1b[0m\n", v...)) - } else if typ == NOTICE { - calldepth = calldepth + 2 - log.golog.Output(calldepth, prestr+fmt.Sprintf(format+"\n", v...)) - } else if typ == PANIC { - stack := strings.Replace(string(debug.Stack()), "\n", "\n== ", -1) - stack = str.SkipLine(stack, calldepth*2+1) - v = append(v, stack) - panicstr := fmt.Sprintf(prestr+format+"\x1b[0m. Panic stack:\n%s\n", v...) - log.golog.Output(calldepth, panicstr) - panic(ErrLogPanic) - } else { - log.golog.Output(calldepth, prestr+fmt.Sprintf(format+"\n", v...)) - } + if typ == FATAL || typ == WARNING || typ == ERROR { + log.golog.Output(calldepth, prestr+fmt.Sprintf(format+"\x1b[0m\n", v...)) + } else if typ == NOTICE { + calldepth = calldepth + 2 + log.golog.Output(calldepth, prestr+fmt.Sprintf(format+"\n", v...)) + } else if typ == PANIC { + stack := strings.Replace(string(debug.Stack()), "\n", "\n== ", -1) + stack = str.SkipLine(stack, calldepth*2+1) + v = append(v, stack) + panicstr := fmt.Sprintf(prestr+format+"\x1b[0m. Panic stack:\n%s\n", v...) + log.golog.Output(calldepth, panicstr) + panic(ErrLogPanic) + } else { + log.golog.Output(calldepth, prestr+fmt.Sprintf(format+"\n", v...)) + } +} + +func formatHeader(calldepth int) string { + const MAX_LENGTH = 35 /* + 22 */ + // log time + now := time.Now() + year, month, day := now.Date() + hour, min, sec := now.Clock() + nowstr := fmt.Sprintf("%4d%02d%02dT%02d:%02d:%02d.%03d ", + year, month, day, hour, min, sec, now.Nanosecond()/1e6) + + // log position + _, file, line, ok := runtime.Caller(calldepth + 1) + if !ok { + file = "???" + line = 0 + } + + // Case 1: too short path, return directly + i, header, linestr := 0, "", fmt.Sprintf("%d", line) + if len(file)+len(linestr) < MAX_LENGTH { + header = file + ":" + linestr + return nowstr + header + } + + // Case 2: filename long enough, just return filename + for i = len(file) - 1; i >= 0; i-- { + if file[i] == '/' { + header = file[i:] + ":" + linestr + i-- + break + } + } + if len(header) >= MAX_LENGTH && i > 0 { + header = "…" + header[:4] + "…" + header[len(header)-MAX_LENGTH+6:] + return nowstr + header + } else if len(header) >= MAX_LENGTH && i <= 0 { + header = header[:4] + "…" + header[len(header)-MAX_LENGTH+5:] + return nowstr + header + } + + // Case 3: try complex middle path with 'width=6' + tempheader := formatHeaderPath(file, i, 6) + header + if len(tempheader) > MAX_LENGTH { + tempheader = "…" + tempheader[len(tempheader)-MAX_LENGTH+1:] + return nowstr + tempheader + } + + // Case 4: try complex middle path with 'width=8' + tempheader = formatHeaderPath(file, i, 8) + header + if len(tempheader) > MAX_LENGTH { + tempheader = "…" + tempheader[len(tempheader)-MAX_LENGTH+1:] + return nowstr + tempheader + } + + // Case 5: try complex middle path with 'width=10' + tempheader = formatHeaderPath(file, i, 10) + header + if len(tempheader) > MAX_LENGTH { + tempheader = "…" + tempheader[len(tempheader)-MAX_LENGTH+1:] + return nowstr + tempheader + } + + // Case 6: fallback + return nowstr + tempheader +} + +func formatHeaderPath(file string, i, width int) (paths string) { + ii, iw := i, i + for i := ii; i >= 0; i-- { + if file[i] == '/' { + if iw-i > width { + // dirname lenght more then width + paths = file[i:i+width] + "." + paths + } else { + // dirname lenght less then width + paths = file[i:iw+1] + paths + } + //fmt.Println("w", iw-i, "width", width, "paths", paths) + if width > 2 { + // decrease width + width-- + } + iw = i - 1 + continue + } + } + return paths } func needWriteLogToFile() bool { - if cls, ok := os.LookupEnv("QOOLOG_CLOSE_FILELOG"); ok && cls != "N" && cls != "n" { - return false - } else if ink8s, ok := os.LookupEnv("KUBERNETES_PORT"); ok && ink8s != "" { - return false - } - return true + if cls, ok := os.LookupEnv("QOOLOG_CLOSE_FILELOG"); ok && cls != "N" && cls != "n" { + return false + } else if ink8s, ok := os.LookupEnv("KUBERNETES_PORT"); ok && ink8s != "" { + return false + } + return true } func needWriteLogToStdout() bool { - if cls, ok := os.LookupEnv("QOOLOG_CLOSE_STDLOG"); ok && (cls == "Y" || cls == "y") { - return false - } - return true + if cls, ok := os.LookupEnv("QOOLOG_CLOSE_STDLOG"); ok && (cls == "Y" || cls == "y") { + return false + } + return true } // ////////////////////////////////////////////////////////////////////////////////// @@ -250,38 +336,38 @@ var once sync.Once = sync.Once{} // init func init() { - once.Do(initlog) + once.Do(initlog) } // initlog func initlog() { - // Step 1. create base writer & cache writer for ALL log - var ( - logDir = "./logs/" - logName = getExeFilename() - logDirsOptional = []string{"./log", "/var/log"} - logSplitTag = "20060102" //20060102150405 - baseWriter = NewBaseWriter(nil, os.Stdout, nil) - gologFlags = log.Ldate | log.Lmicroseconds | log.Lshortfile - ) + // Step 1. create base writer & cache writer for ALL log + var ( + logDir = "./logs/" + logName = getExeFilename() + logDirsOptional = []string{"./log", "/var/log"} + logSplitTag = "20060102" //20060102150405 + baseWriter = NewBaseWriter(nil, os.Stdout, nil) + gologFlags = 0 /* log.Ldate | log.Lmicroseconds | log.Lshortfile */ + ) - // Step 2.1 add stdout to base writer if need - if needWriteLogToStdout() { - baseWriter.stdw = os.Stdout - } - // Step 2.2 rotate log(split log ) if need - if needWriteLogToFile() { - baseWriter.OpenLogFile(logDir, logName, logDirsOptional) - go func() { - for { - tag := time.Now().Local().Format(logSplitTag) - baseWriter.TryBackupLogFile(tag) - time.Sleep(2 * time.Minute) - } - }() - } + // Step 2.1 add stdout to base writer if need + if needWriteLogToStdout() { + baseWriter.stdw = os.Stdout + } + // Step 2.2 rotate log(split log ) if need + if needWriteLogToFile() { + baseWriter.OpenLogFile(logDir, logName, logDirsOptional) + go func() { + for { + tag := time.Now().Local().Format(logSplitTag) + baseWriter.TryBackupLogFile(tag) + time.Sleep(2 * time.Minute) + } + }() + } - // Step 3. init golog(golang std logger) & mylog(myself defined logger) - golog = log.New(NewCacheWriter(baseWriter), "", gologFlags) - mylog = New("system") + // Step 3. init golog(golang std logger) & mylog(myself defined logger) + golog = log.New(NewCacheWriter(baseWriter), "", gologFlags) + mylog = New("system") }