v0.0.8 is 30% faster version

FUTURE.md

@@ -1,5 +1,14 @@
 ## ✒ 未来版本的新特性 (Features in future version)
 
+### v0.0.9
+* 支持日志输出为 Json 形式，通过增加 JSON 日志处理器实现
+* 支持日志输出函数，日志信息可以是一个返回 string 的函数
+
+### v0.0.8
+* 进行第一次性能优化，性能相比之前版本提升 30%
+* 取消占位符功能，由于这个功能的实现需要对类型进行反射检测，非常消耗性能
+* 取消 fmt 包的使用，经过性能检测，发现 fmt 包中存在大量使用反射的耗时行为
+
 ### v0.0.7
 * 重构日志输出的模块，抛弃了标准库的 log 设计
 * 增加日志处理器模块，支持用户自定义日志处理逻辑，大大地提高了扩展能力

HISTORY.md

@@ -1,5 +1,11 @@
 ## ✒ 历史版本的特性介绍 (Features in old version)
 
+### v0.0.8
+> 此版本发布于 2020-03-08
+* 进行第一次性能优化，性能相比之前版本提升 30%
+* 取消占位符功能，由于这个功能的实现需要对类型进行反射检测，非常消耗性能
+* 取消 fmt 包的使用，经过性能检测，发现 fmt 包中存在大量使用反射的耗时行为
+
 ### v0.0.7
 > 此版本发布于 2020-03-06
 * 重构日志输出的模块，抛弃了标准库的 log 设计

README.en.md

@@ -38,7 +38,7 @@ module your_project_name
 go 1.14
 
 require (
- github.com/FishGoddess/logit v0.0.7
+ github.com/FishGoddess/logit v0.0.8
 )
 ```
 
@@ -68,8 +68,9 @@ func main() {
  // Change logger level.
  logit.ChangeLevelTo(logit.DebugLevel)
 
- // If you want format your message, just add arguments!
- logit.Info("format info message! id = %d, content = %s", 1, "info!")
+ // If you want to output log with file info, try this:
+ logit.EnableFileInfo()
+ logit.Info("Show file info!")
 }
 ```
 
@@ -93,19 +94,25 @@ $ go test -v ./_examples/benchmarks_test.go -bench=. -benchtime=20s
 
 > Benchmark file：[_examples/benchmarks_test.go](./_examples/benchmarks_test.go)
 
-| test case | times ran (large is better) | ns/op (small is better) | B/op (small is better) | allocs/op (small is better) |
+| test case | times ran (large is better) | ns/op (small is better) | features | extension |
 | -----------|--------|-------------|-------------|-------------|
-| **logit** |   8617952 | 2807 ns/op |   352 B/op | 20 allocs/op |
-| logrus |   2990408 | 7991 ns/op | 1633 B/op | 52 allocs/op |
-| Golang log |   5308578 | 4539 ns/op |   920 B/op | 12 allocs/op |
-| Golog | 15536137 | 1556 ns/op |   232 B/op | 16 allocs/op |
+| **logit** | 12448242 | 2161 ns/op | powerful | high |
+| logrus |   2990408 | 7991 ns/op | normal | normal |
+| Golog | 15536137 | 1556 ns/op | normal | normal |
+| Golang log | 25268450 |   945 ns/op | not good | none |
 
 > Environment：I7-6700HQ CPU @ 2.6 GHZ, 16 GB RAM
 
-**Notice that fetch file info will call runtime.Caller, which is expensive.**
+**Notice:**
+
+**1. Fetching file info will call runtime.Caller, which is expensive.**
 **However, we think file info is useful in check errors,**
 **so we keep this feature, and provide a switch to turn off it for high-performance.**
 
+**2. For now logit uses some functions of fmt, and these functions is expensive**
+**because of reflect (for judging the parameter v interface{}). Actually, these judgements**
+**are redundant in a logger. The more effective output will be used in v0.0.8 and higher versions.**
+
 ### 👥 Contributing
 
 If you find that something is not working as expected please open an _**issue**_.

README.md

@@ -38,7 +38,7 @@ module your_project_name
 go 1.14
 
 require (
- github.com/FishGoddess/logit v0.0.7
+ github.com/FishGoddess/logit v0.0.8
 )
 ```
 
@@ -68,8 +68,9 @@ func main() {
  // Change logger level.
  logit.ChangeLevelTo(logit.DebugLevel)
 
- // If you want format your message, just add arguments!
- logit.Info("format info message! id = %d, content = %s", 1, "info!")
+ // If you want to output log with file info, try this:
+ logit.EnableFileInfo()
+ logit.Info("Show file info!")
 }
 ```
 
@@ -93,19 +94,25 @@ $ go test -v ./_examples/benchmarks_test.go -bench=. -benchtime=20s
 
 > 测试文件：[_examples/benchmarks_test.go](./_examples/benchmarks_test.go)
 
-| 测试 | 单位时间内运行次数 (large is better) | ns/op (small is better) | B/op (small is better) | allocs/op (small is better) |
+| 测试 | 单位时间内运行次数 (越大越好) | 每个操作消耗时间 (越小越好) | 功能性 | 扩展性 |
 | -----------|--------|-------------|-------------|-------------|
-| **logit** |   8617952 | 2807 ns/op |   352 B/op | 20 allocs/op |
-| logrus |   2990408 | 7991 ns/op | 1633 B/op | 52 allocs/op |
-| Golang log |   5308578 | 4539 ns/op |   920 B/op | 12 allocs/op |
-| Golog | 15536137 | 1556 ns/op |   232 B/op | 16 allocs/op |
+| **logit** | 12448242 | 2161 ns/op | 强大 | 高 |
+| logrus |   2990408 | 7991 ns/op | 正常 | 正常 |
+| Golog | 15536137 | 1556 ns/op | 正常 | 正常 |
+| Golang log | 25268450 |   945 ns/op | 一般 | 无 |
 
 > 测试环境：I7-6700HQ CPU @ 2.6 GHZ，16 GB RAM
 
-**注意：输出文件信息会有运行时操作（runtime.Caller 方法），非常影响性能，**
+**注意：**
+
+**1. 输出文件信息会有运行时操作（runtime.Caller 方法），非常影响性能，**
 **但是这个功能感觉还是比较实用的，尤其是在查找错误的时候，所以我们还是加了这个功能！**
 **如果你更在乎性能，那我们也提供了一个选项可以关闭文件信息的查询！**
 
+**2. 目前的日志输出使用了 fmt 包的一些方法，经过性能检测发现这些方法存在大量使用反射的**
+**行为，主要体现在对参数 v interface{} 进行类型检测的逻辑上，而日志输出都是字符串，这一个**
+**判断是可以省略的，可以减少很多运行时操作时间！v0.0.8 版本开始使用了更有效率的输出方式！**
+
 ### 👥 贡献者
 
 如果您觉得 logit 缺少您需要的功能，请不要犹豫，马上参与进来，发起一个 _**issue**_。

_examples/basic.go

@@ -33,9 +33,6 @@ func main() {
 
  // Also, you can create a new independent Logger to use. See logit.NewLogger.
 
- // If you want format your message, just add arguments!
- logit.Info("format info message! id = %d, content = %s", 1, "info!")
-
  // If you want to output log with file info, try this:
  logit.EnableFileInfo()
  logit.Info("Show file info!")

_examples/benchmarks_test.go

@@ -47,7 +47,7 @@ func BenchmarkLogitLogger(b *testing.B) {
 func BenchmarkLogLogger(b *testing.B) {
 
  // 测试用的日志记录器
- logger := log.New(&nopWriter{}, "", log.LstdFlags|log.Lshortfile)
+ logger := log.New(&nopWriter{}, "", log.LstdFlags)
 
  // 测试用的日志任务
  logTask := func() {

_examples/logger.go

@@ -41,9 +41,6 @@ func main() {
  // The second parameter "logit.DebugLevel" is the level of this Logger.
  logger = logit.NewLogger(os.Stdout, logit.DebugLevel)
 
- // If you want format your message, just add arguments!
- logger.Error("format info message! id = %d, content = %s", 1, "info!")
-
  // If you want format your time, try this:
  logger.SetFormatOfTime("2006/01/02 15:04:05")
  logger.Info("What time is it now?")

_examples/wrapper.go

@@ -39,7 +39,7 @@ func main() {
 
  // 2. SizeRollingFile is a file size sensitive file.
  sizeRollingFile := wrapper.NewSizeRollingFile(64*wrapper.KB, func(now time.Time) string {
- return "D:/" + now.Format("20060102150405.000") + ".log"
+ return "D:/" + now.Format("20060102150405.000") + ".txt"
  })
  defer sizeRollingFile.Close()
 

doc.go

@@ -31,9 +31,6 @@ Package logit provides an easy way to use foundation for your logging operations
 
  // Also, you can create a new independent Logger to use. See logit.NewLogger.
 
- // If you want format your message, just add arguments!
- logit.Info("format info message! id = %d, content = %s", 1, "info!")
-
  // If you want to output log with file info, try this:
  logit.EnableFileInfo()
  logit.Info("Show file info!")
@@ -55,9 +52,6 @@ Package logit provides an easy way to use foundation for your logging operations
  // The second parameter "logit.DebugLevel" is the level of this Logger.
  logger = logit.NewLogger(os.Stdout, logit.DebugLevel)
 
- // If you want format your message, just add arguments!
- logger.Info("format info message! id = %d, content = %s", 1, "info!")
-
  // If you want format your time, try this:
  logger.SetFormatOfTime("2006/01/02 15:04:05")
  logger.Info("What time is it now?")
@@ -165,4 +159,4 @@ Package logit provides an easy way to use foundation for your logging operations
 package logit // import "github.com/FishGoddess/logit"
 
 // Version is the version string representation of the "logit" package.
-const Version = "0.0.7"
+const Version = "0.0.8"

logger.go

@@ -19,9 +19,9 @@
 package logit
 
 import (
- "fmt"
  "io"
  "runtime"
+ "strconv"
  "sync"
  "time"
 )
@@ -223,33 +223,28 @@ func wrapMessageWithFileInfo(callDepth int, msg string) string {
  // 这个 callDepth 是 runtime.Caller 方法的参数，表示上面第几层调用者信息
  _, file, line, ok := runtime.Caller(callDepth)
  if !ok {
- return fmt.Sprintf("[unknown file:unknown line] %s", msg)
+ return "[unknown file:unknown line] " + msg
  }
 
- return fmt.Sprintf("[%s:%d] %s", file, line, msg)
-}
-
-// formatMessage returns the formatted message with given args
-func formatMessage(msg string, args ...interface{}) string {
- return fmt.Sprintf(msg, args...)
+ return "[" + file + ":" + strconv.Itoa(line) + "] " + msg
 }
 
 // Debug will output msg as a debug message.
-func (l *Logger) Debug(msg string, args ...interface{}) {
- l.log(callDepth, DebugLevel, formatMessage(msg, args...))
+func (l *Logger) Debug(msg string) {
+ l.log(callDepth, DebugLevel, msg)
 }
 
 // Info will output msg as an info message.
-func (l *Logger) Info(msg string, args ...interface{}) {
- l.log(callDepth, InfoLevel, formatMessage(msg, args...))
+func (l *Logger) Info(msg string) {
+ l.log(callDepth, InfoLevel, msg)
 }
 
 // Warn will output msg as a warn message.
-func (l *Logger) Warn(msg string, args ...interface{}) {
- l.log(callDepth, WarnLevel, formatMessage(msg, args...))
+func (l *Logger) Warn(msg string) {
+ l.log(callDepth, WarnLevel, msg)
 }
 
 // Error will output msg as an error message.
-func (l *Logger) Error(msg string, args ...interface{}) {
- l.log(callDepth, ErrorLevel, formatMessage(msg, args...))
+func (l *Logger) Error(msg string) {
+ l.log(callDepth, ErrorLevel, msg)
 }

logger_extension_test.go

@@ -19,6 +19,7 @@
 package logit
 
 import (
+ "strconv"
  "testing"
  "time"
 
@@ -43,7 +44,7 @@ func TestNewFileLogger(t *testing.T) {
 
  logger := NewFileLogger("Z:/test.log", DebugLevel)
  for i := 0; i < 100; i++ {
- logger.Info("我是第 %d 条日志！", i)
+ logger.Info("我是第 " + strconv.Itoa(i) + " 条日志！")
  }
 
  logger = NewFileLogger("https://test.io", DebugLevel)
@@ -54,30 +55,30 @@ func TestNewDurationRollingLogger(t *testing.T) {
 
  logger := NewDurationRollingLogger("Z:/", time.Second, DebugLevel)
  for i := 0; i < 10; i++ {
- logger.Info("1. info!!!!!!!!%d", time.Now().Unix())
+ logger.Info("1. info!!!!!!!! " + strconv.FormatInt(time.Now().Unix(), 10))
  time.Sleep(time.Second)
- logger.Info("2. info!!!!!!!!%d", time.Now().Unix())
+ logger.Info("2. info!!!!!!!! " + strconv.FormatInt(time.Now().Unix(), 10))
  }
 }
 
 // 测试按天自动划分日志文件的日志记录器
 func TestNewDayRollingLogger(t *testing.T) {
 
  logger := NewDayRollingLogger("Z:/", DebugLevel)
- logger.Info("1. info!!!!!!!!%d", time.Now().Unix())
+ logger.Info("1. info!!!!!!!! " + strconv.FormatInt(time.Now().Unix(), 10))
  time.Sleep(time.Second)
- logger.Info("2. info!!!!!!!!%d", time.Now().Unix())
+ logger.Info("2. info!!!!!!!! " + strconv.FormatInt(time.Now().Unix(), 10))
 }
 
 // 测试按照文件大小自动划分日志文件的日志记录器
 func TestNewSizeRollingLogger(t *testing.T) {
 
  logger := NewSizeRollingLogger("Z:/", 64*wrapper.KB, DebugLevel)
  for i := 0; i < 1000; i++ {
- logger.Debug("debug...%d", i)
- logger.Info("info...%d", i)
- logger.Warn("warn...%d", i)
- logger.Error("error...%d", i)
+ logger.Debug("debug...")
+ logger.Info("info...")
+ logger.Warn("warn...")
+ logger.Error("error...")
  }
 }
 
@@ -86,9 +87,9 @@ func TestNewDefaultSizeRollingLogger(t *testing.T) {
 
  logger := NewDefaultSizeRollingLogger("Z:/", DebugLevel)
  for i := 0; i < 1000; i++ {
- logger.Debug("debug...%d", i)
- logger.Info("info...%d", i)
- logger.Warn("warn...%d", i)
- logger.Error("error...%d", i)
+ logger.Debug("debug...")
+ logger.Info("info...")
+ logger.Warn("warn...")
+ logger.Error("error...")
  }
 }

logger_handler.go

@@ -19,7 +19,6 @@
 package logit
 
 import (
- "fmt"
  "time"
 )
 
@@ -40,6 +39,6 @@ func (lh LoggerHandler) handle(logger *Logger, level LoggerLevel, now time.Time,
 // The log handled by this handler will be like "[Info] [2020-03-06 16:10:44] msg".
 // If you want to customize, just code your own handler, then replace it!
 func DefaultLoggerHandler(logger *Logger, level LoggerLevel, now time.Time, msg string) bool {
- fmt.Fprintf(logger.Writer(), "[%s] [%s] %s\n", prefixOf(level), now.Format(logger.formatOfTime), msg)
+ logger.Writer().Write([]byte("[" + prefixOf(level) + "] [" + now.Format(logger.formatOfTime) + "] " + msg + "\n"))
  return true
 }

logger_test.go

@@ -19,6 +19,7 @@
 package logit
 
 import (
+ "fmt"
  "os"
  "testing"
  "time"
@@ -104,7 +105,7 @@ func TestLoggerEnableAndDisableFileInfo(t *testing.T) {
 // 测试增加处理器是否可用
 func TestLoggerAddHandlersAndSetHandlers(t *testing.T) {
  logger := NewLogger(os.Stdout, InfoLevel)
- logger.Info("当前的日志处理器：%v", logger.handlers)
+ logger.Info("当前的日志处理器：" + fmt.Sprintf("%v", logger.handlers))
 
  handlers1 := func(logger *Logger, level LoggerLevel, now time.Time, msg string) bool {
  logger.writer.Write([]byte("第一个日志处理器！\n"))
@@ -117,14 +118,14 @@ func TestLoggerAddHandlersAndSetHandlers(t *testing.T) {
  }
 
  logger.AddHandlers(handlers1, handlers2)
- logger.Info("当前的日志处理器：%v", logger.handlers)
+ logger.Info("当前的日志处理器：" + fmt.Sprintf("%v", logger.handlers))
 
  ok := logger.SetHandlers()
  if ok {
  t.Fatal("SetHandlers 应该返回 false！")
  }
  logger.SetHandlers(handlers1, handlers2)
- logger.Info("当前的日志处理器：%v", logger.handlers)
+ logger.Info("当前的日志处理器：" + fmt.Sprintf("%v", logger.handlers))
 }
 
 // 测试更改时间格式化标准的方法