Golang optimization Path — Build your own log wheel
As far as I can see, very few people are logging using Golang’s native log package. Today I’ll show you how to wrap a fully functional logging package in 200 lines of code.
- Writing in the front
- Logs are printed and controlled by log level
- Log files are automatically split
- Asynchronous output of logs
- The log line number
- Thread safety
- The last
- reference
Writing in the front
Golang’s log package doesn’t have much content, and to be honest, it’s a little easy to use for log development directly. Some features are missing:
- Print and control logs by log level.
- Automatic log file segmentation;
- Logs are generated asynchronously.
Logs are printed and controlled by log level
Our implementation of the logging module will support four levels:
const (
LevelError = iota
LevelWarning
LevelInformational
LevelDebug
)
Copy the codeDefine a log structure:
type Logger struct { level int l *log.Logger } func (ll *Logger) Error(format string, v ... interface{}) { if LevelError > ll.level { return } msg := fmt.Sprintf("[E] "+format, v...) ll.l.Printf(msg) }Copy the codeThis allows the log level to control the output and append a flag to the print, as in the example above, where the Error level is appended [E].
This implementation is fine, but there is still room for optimization. For example, the append [E] is printed using string addition. String addition allocates new memory and is not very performance optimized. We need to optimize with character arrays.
But I’m not going to optimize it that way. If you look at the log API, you can see that the native package supports setting prefixes:
func (l *Logger) SetPrefix(prefix string)
Copy the codeLet’s look at the implementation:
func (l *Logger) formatHeader(buf *[]byte, t time.Time, file string, line int) {
*buf = append(*buf, l.prefix...)
Copy the codeNative packages use []byte for log prefixes to improve performance. Since they’ve already provided it, let’s not build it ourselves. So the problem is that setting the prefix is set when you initialize it, and it’s printed automatically. A log.logger object can only have one prefix, and we need four levels of prefix. How to print this?
type Logger struct {
level int
err *log.Logger
warn *log.Logger
info *log.Logger
debug *log.Logger
}
Copy the codeWe can simply apply for four log objects. To ensure that all levels are printed in the same file, set it to the same IO.Writer during initialization.
logger := new(LcLogger)
logger.err = log.New(w, "[E] ", flag)
logger.warn = log.New(w, "[W] ", flag)
logger.info = log.New(w, "[I] ", flag)
logger.debug = log.New(w, "[D] ", flag)
Copy the codeTo set the log level:
func (ll *Logger) SetLevel(l int) {
ll.level = l
}
Copy the codeThe output is controlled according to the log level. Tell me about a pit I met. There was once too much log printing, and the disk was full, so I tried to adjust the log level to reduce the print content. After setting the log level to Error, it still does not work. Finally, I look at the code and find that the log level of the problem is Error. Type the Error logs as little as possible.)
func (ll *Logger) Error(format string, v ... interface{}) { if LevelError > ll.level { return } ll.err.Printf(format, v...) }Copy the codeLog files are automatically split
Log files need to be automatically split. Otherwise, a file is too large and cannot be cleaned up when the disk is cleaned because the log is still printed.
Log segmentation I think simple to size segmentation is good.
So how does the log partition function access the log module we implement above? The key lies in IO.Writer.
type Writer interface {
Write(p []byte) (n int, err error)
}
Copy the codeThe Writer interface has only one method, as simple as that. The native package prints logs to os.Stderr by default, which is a variable of type os.File that implements Writer.
func (f *File) Write(b []byte) (n int, err error)
Copy the codeWhen logging is written, the log package automatically calls the Write method. We can implement a Writer by ourselves. During Write, calculate the size of the current log file after writing this line of logs. If the size exceeds the preset value, split the log file once. This is also the time to split the log by day.
Recommended gopkg. In/natefinch lumberjack. V2 this package to do log segmentation, function is very powerful.
jack := &lumberjack.Logger{
Filename: lfn,
MaxSize: maxsize, // megabytes
}
Copy the codeThe Jack object is a Writer and can be copied directly to the Logger.
Asynchronous output of logs
Association in fibers is the whole package: github.com/ivpusic/grpool. The coroutine pool will not be expanded, but you can look at the implementation of the package if you are interested.
The log structure is updated again:
type Logger struct {
level int
err *log.Logger
warn *log.Logger
info *log.Logger
debug *log.Logger
p *grpool.Pool
}
Copy the codeInitialization:
logger.p = grpool.NewPool(numWorkers, jobQueueLen)
Copy the codeLog output:
func (ll *Logger) Error(format string, v ...interface{}) {
if LevelError > ll.level {
return
}
ll.p.JobQueue <- func() {
ll.err.Printf(format, v...)
}
}
Copy the codeThe log line number
If you do this step by step and set the print log to Lshortfile to show the flower of the line number, you may find that the line number printed at this time is not correct. The runtime stack is used to print logs, and since we have encapsulated a layer, the printed stack depth varies. Simply put, it’s a layer deeper.
The native log package provides func (L *Logger) Output(callDepth int, s string) error to control the log stack depth Output, and again we adjust the code.
type Logger struct {
level int
err *log.Logger
warn *log.Logger
info *log.Logger
debug *log.Logger
p *grpool.Pool
depth int
}
func (ll *Logger) Error(format string, v ...interface{}) {
if LevelError > ll.level {
return
}
ll.p.JobQueue <- func() {
ll.err.Output(ll.depth, fmt.Sprintf(format, v...))
}
}
Copy the codeWe’re only encapsulating one layer, so a depth of 3 is fine.
Thread safety
Native package printing logs is thread-safe:
func (l *Logger) Output(calldepth int, S string) error {now := time.now () // get this early. Var file string var line int l.mlock () // defer l.mu.Unlock() if l.flag&(Lshortfile|Llongfile) ! = 0 { // release lock while getting caller info - it's expensive. l.mu.Unlock() var ok bool _, file, line, ok = runtime.Caller(calldepth) if ! ok { file = "???" line = 0 } l.mu.Lock() } l.buf = l.buf[:0] l.formatHeader(&l.buf, now, file, line) l.buf = append(l.buf, s...) if len(s) == 0 || s[len(s)-1] ! = '\n' { l.buf = append(l.buf, '\n') } _, err := l.out.Write(l.buf) return err }Copy the codeWith this guarantee, we don’t need to worry about thread safety either.
Is FMT package logging thread-safe? Is println safe? Where do FMT and Println print logs go? Interested can leave a message to discuss together.
The last
Log printing will use something like fmt.sprintf, which will be implemented using reflection. Reflection affects performance, but the code is gross without reflection.
The complete code is posted on GitHub, address.
The logging described above is only for output to a file. If you want to export mail, ElasticSearch, etc., don’t do it with complicated configuration parameters at initialization.
Here’s what I said:
NewLogger("es", ...)
NewLogger("smtp", ...)
Copy the codeThe problem with this is that I can only use the good stuff you provide and can only modify the log package if I want to extend it. If the package is a third party package, how can someone extend it? And this implementation is not Golang’s implementation style.
In fact, if you look at the native packages, many of them are connected through interfaces. The native log package, which you can think of as a process service, concatenates the content to be printed, including line number, time, etc., to ensure thread safety, and then calls Writer to print. If we want to print logs to ES, we implement an ESWriter. This is golang-style code.
reference
- [1] Go Language Combat
Golang optimization road — build a log wheel!
– EOF –