From 8e68760416cba19ce3f3073ade68914d1241a67b Mon Sep 17 00:00:00 2001 From: fatedier Date: Tue, 12 Mar 2024 11:43:17 +0800 Subject: [PATCH] add log package (#27) --- clock/clock.go | 22 +++ clock/testing/fake_clock.go | 36 +++++ go.mod | 17 ++- go.sum | 34 +++-- log/buffer.go | 44 ++++++ log/format.go | 62 ++++++++ log/global.go | 43 ++++++ log/level.go | 111 ++++++++++++++ log/log.go | 201 +++++++++++++++++++++++++ log/log_test.go | 42 ++++++ log/options.go | 51 +++++++ log/output_console.go | 78 ++++++++++ log/output_console_test.go | 54 +++++++ log/output_rotatefile.go | 276 ++++++++++++++++++++++++++++++++++ log/output_rotatefile_test.go | 74 +++++++++ 15 files changed, 1126 insertions(+), 19 deletions(-) create mode 100644 clock/clock.go create mode 100644 clock/testing/fake_clock.go create mode 100644 log/buffer.go create mode 100644 log/format.go create mode 100644 log/global.go create mode 100644 log/level.go create mode 100644 log/log.go create mode 100644 log/log_test.go create mode 100644 log/options.go create mode 100644 log/output_console.go create mode 100644 log/output_console_test.go create mode 100644 log/output_rotatefile.go create mode 100644 log/output_rotatefile_test.go diff --git a/clock/clock.go b/clock/clock.go new file mode 100644 index 0000000..22ffc3c --- /dev/null +++ b/clock/clock.go @@ -0,0 +1,22 @@ +package clock + +import "time" + +type Clock interface { + Now() time.Time + Since(time.Time) time.Duration +} + +var Real Clock = realClock{} + +type realClock struct{} + +// Now returns the current time. +func (realClock) Now() time.Time { + return time.Now() +} + +// Since returns time since the specified timestamp. +func (realClock) Since(ts time.Time) time.Duration { + return time.Since(ts) +} diff --git a/clock/testing/fake_clock.go b/clock/testing/fake_clock.go new file mode 100644 index 0000000..3d63273 --- /dev/null +++ b/clock/testing/fake_clock.go @@ -0,0 +1,36 @@ +package testing + +import ( + "sync" + "time" +) + +type FakeClock struct { + mu sync.RWMutex + t time.Time +} + +func NewFakeClock(t time.Time) *FakeClock { + return &FakeClock{t: t} +} + +// Now returns f's time. +func (f *FakeClock) Now() time.Time { + f.mu.RLock() + defer f.mu.RUnlock() + return f.t +} + +// Since returns time since the time in f. +func (f *FakeClock) Since(t time.Time) time.Duration { + f.mu.RLock() + defer f.mu.RUnlock() + return f.t.Sub(t) +} + +// SetTime sets the time on the FakeClock. +func (f *FakeClock) SetTime(t time.Time) { + f.mu.Lock() + defer f.mu.Unlock() + f.t = t +} diff --git a/go.mod b/go.mod index bb847ab..9e2e499 100644 --- a/go.mod +++ b/go.mod @@ -4,23 +4,26 @@ go 1.21 require ( github.com/Azure/go-ntlmssp v0.0.0-20200615164410-66371956d46c - github.com/davecgh/go-spew v1.1.1 // indirect github.com/golang/snappy v0.0.4 - github.com/klauspost/reedsolomon v1.12.0 // indirect - github.com/pkg/errors v0.9.1 // indirect - github.com/stretchr/testify v1.6.1 + github.com/stretchr/testify v1.8.4 github.com/xtaci/kcp-go/v5 v5.6.7 - golang.org/x/crypto v0.17.0 + golang.org/x/crypto v0.18.0 golang.org/x/net v0.19.0 ) require ( + github.com/davecgh/go-spew v1.1.1 // indirect github.com/klauspost/cpuid/v2 v2.2.6 // indirect + github.com/klauspost/reedsolomon v1.12.0 // indirect + github.com/kr/pretty v0.3.1 // indirect + github.com/pkg/errors v0.9.1 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect + github.com/rogpeppe/go-internal v1.10.0 // indirect github.com/templexxx/cpu v0.1.0 // indirect github.com/templexxx/xorsimd v0.4.2 // indirect github.com/tjfoc/gmsm v1.4.1 // indirect github.com/xtaci/lossyconn v0.0.0-20200209145036-adba10fffc37 // indirect - golang.org/x/sys v0.15.0 // indirect - gopkg.in/yaml.v3 v3.0.0 // indirect + golang.org/x/sys v0.16.0 // indirect + gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c // indirect + gopkg.in/yaml.v3 v3.0.1 // indirect ) diff --git a/go.sum b/go.sum index 8758acf..bd131bf 100644 --- a/go.sum +++ b/go.sum @@ -5,7 +5,7 @@ github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03 github.com/census-instrumentation/opencensus-proto v0.2.1/go.mod h1:f6KPmirojxKA12rnyqOA5BBL4O983OfeGPqjHWSTneU= github.com/client9/misspell v0.3.4/go.mod h1:qj6jICC3Q7zFZvVWo7KLAzC3yx5G7kyvSDkc90ppPyw= github.com/cncf/udpa/go v0.0.0-20191209042840-269d4d468f6f/go.mod h1:M8M6+tZqaGXZJjfX53e64911xZQV5JYwmTeXPW+k8Sc= -github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/envoyproxy/go-control-plane v0.9.0/go.mod h1:YTl/9mNaCwkRvm6d1a2C3ymFceY/DCBVvsKhRF0iEA4= @@ -32,14 +32,24 @@ github.com/klauspost/cpuid/v2 v2.2.6 h1:ndNyv040zDGIDh8thGkXYjnFtiN02M1PVVF+JE/4 github.com/klauspost/cpuid/v2 v2.2.6/go.mod h1:Lcz8mBdAVJIBVzewtcLocK12l3Y+JytZYpaMropDUws= github.com/klauspost/reedsolomon v1.12.0 h1:I5FEp3xSwVCcEh3F5A7dofEfhXdF/bWhQWPH+XwBFno= github.com/klauspost/reedsolomon v1.12.0/go.mod h1:EPLZJeh4l27pUGC3aXOjheaoh1I9yut7xTURiW3LQ9Y= +github.com/kr/pretty v0.2.1/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI= +github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE= +github.com/kr/pretty v0.3.1/go.mod h1:hoEshYVHaxMs3cyo3Yncou5ZscifuDolrwPKZanG3xk= +github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= +github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= +github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= +github.com/pkg/diff v0.0.0-20210226163009-20ebb0f2a09e/go.mod h1:pJLUxLENpZxwdsKMEsNbx1VGcRFpLqf3715MtcvvzbA= github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= -github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= -github.com/stretchr/testify v1.6.1 h1:hDPOHmpOpP40lSULcqw7IrRb/u7w6RpDC9399XyoNd0= -github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/rogpeppe/go-internal v1.9.0/go.mod h1:WtVeX8xhTBvf0smdhujwtBcq4Qrzq/fJaraNFVN+nFs= +github.com/rogpeppe/go-internal v1.10.0 h1:TMyTOH3F/DB16zRVcYyreMH6GnZZrwQVAoYjRBZyWFQ= +github.com/rogpeppe/go-internal v1.10.0/go.mod h1:UQnix2H7Ngw/k4C5ijL5+65zddjncjaFoBhdsK/akog= +github.com/stretchr/testify v1.8.4 h1:CcVxjf3Q8PM0mHUKJCdn+eZZtm5yQwehR5yeSVQQcUk= +github.com/stretchr/testify v1.8.4/go.mod h1:sz/lmYIOXD/1dqDmKjjqLyZ2RngseejIcXlSw2iwfAo= github.com/templexxx/cpu v0.1.0 h1:wVM+WIJP2nYaxVxqgHPD4wGA2aJ9rvrQRV8CvFzNb40= github.com/templexxx/cpu v0.1.0/go.mod h1:w7Tb+7qgcAlIyX4NhLuDKt78AHA5SzPmq0Wj6HiEnnk= github.com/templexxx/xorsimd v0.4.2 h1:ocZZ+Nvu65LGHmCLZ7OoCtg8Fx8jnHKK37SjvngUoVI= @@ -53,8 +63,8 @@ github.com/xtaci/lossyconn v0.0.0-20200209145036-adba10fffc37/go.mod h1:HpMP7DB2 golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto= golang.org/x/crypto v0.0.0-20201012173705-84dcc777aaee/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto= -golang.org/x/crypto v0.17.0 h1:r8bRNjWL3GshPW3gkd+RpvzWrZAwPS49OmTGZ/uhM4k= -golang.org/x/crypto v0.17.0/go.mod h1:gCAAfMLgwOJRpTjQ2zCCt2OcSfYMTeZVSRtQlPC7Nq4= +golang.org/x/crypto v0.18.0 h1:PGVlW0xEltQnzFZ55hkuX5+KLyrMYhHld1YHO4AKcdc= +golang.org/x/crypto v0.18.0/go.mod h1:R0j02AL6hcrfOiy9T4ZYp/rcWeMxM3L6QYxlOuEG1mg= golang.org/x/exp v0.0.0-20190121172915-509febef88a4/go.mod h1:CJ0aWSM057203Lf6IL+f9T1iT9GByDxfZKAQTCR3kQA= golang.org/x/lint v0.0.0-20181026193005-c67002cb31c3/go.mod h1:UVdnD1Gm6xHRNCYTkRU2/jEulfH38KcIWyp/GAMgvoE= golang.org/x/lint v0.0.0-20190227174305-5b3e6a55c961/go.mod h1:wehouNa3lNwaWXcvxsM5YxQ5yQlVC4a0KAMCusXpPoU= @@ -76,8 +86,8 @@ golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5h golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.15.0 h1:h48lPFYpsTvQJZF4EKyI4aLHaev3CxivZmv7yZig9pc= -golang.org/x/sys v0.15.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= +golang.org/x/sys v0.16.0 h1:xWw16ngr6ZMtmxDyKyIgsE93KNKz5HKmMa3b8ALHidU= +golang.org/x/sys v0.16.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= @@ -100,10 +110,10 @@ google.golang.org/protobuf v0.0.0-20200228230310-ab0ca4ff8a60/go.mod h1:cfTl7dwQ google.golang.org/protobuf v1.20.1-0.20200309200217-e05f789c0967/go.mod h1:A+miEFZTKqfCUM6K7xSMQL9OKL/b6hQv+e19PK+JZNE= google.golang.org/protobuf v1.21.0/go.mod h1:47Nbq4nVaFHyn7ilMalzfO3qCViNmqZ2kzikPIcrTAo= google.golang.org/protobuf v1.23.0/go.mod h1:EGpADcykh3NcUnDUJcl1+ZksZNG86OlYog2l/sGQquU= -gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= -gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= -gopkg.in/yaml.v3 v3.0.0 h1:hjy8E9ON/egN1tAYqKb61G10WtihqetD4sz2H+8nIeA= -gopkg.in/yaml.v3 v3.0.0/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q= +gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= honnef.co/go/tools v0.0.0-20190102054323-c2f93a96b099/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4= honnef.co/go/tools v0.0.0-20190523083050-ea95bdfd59fc/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4= diff --git a/log/buffer.go b/log/buffer.go new file mode 100644 index 0000000..cdf25b1 --- /dev/null +++ b/log/buffer.go @@ -0,0 +1,44 @@ +package log + +import ( + "bytes" + "sync" +) + +var bufferPool = sync.Pool{New: func() any { return new([]byte) }} + +func getBuffer() *[]byte { + p := bufferPool.Get().(*[]byte) + *p = (*p)[:0] + return p +} + +func putBuffer(p *[]byte) { + if cap(*p) > 64<<10 { + *p = nil + } + bufferPool.Put(p) +} + +var bytesBufferPool = sync.Pool{ + New: func() any { + return new(bytes.Buffer) + }, +} + +// Cheap integer to fixed-width decimal ASCII. Give a negative width to avoid zero-padding. +func itoa(buf *[]byte, i int, wid int) { + // Assemble decimal in reverse order. + var b [20]byte + bp := len(b) - 1 + for i >= 10 || wid > 1 { + wid-- + q := i / 10 + b[bp] = byte('0' + i - q*10) + bp-- + i = q + } + // i < 10 + b[bp] = byte('0' + i) + *buf = append(*buf, b[bp:]...) +} diff --git a/log/format.go b/log/format.go new file mode 100644 index 0000000..3c8d1bb --- /dev/null +++ b/log/format.go @@ -0,0 +1,62 @@ +package log + +import ( + "time" +) + +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` +) + +const logTimeFormat = "2006-01-02 15:04:05.000" + +func formatTimeHeader(when time.Time, buf []byte) (int, int) { + if len(buf) < 23 { + return 0, 0 + } + + y, mo, d := when.Date() + h, mi, s := when.Clock() + ns := when.Nanosecond() / 1000000 + // len("2006/01/02 15:04:05.000") == 23 + + 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] + + return d, h +} diff --git a/log/global.go b/log/global.go new file mode 100644 index 0000000..e3019c5 --- /dev/null +++ b/log/global.go @@ -0,0 +1,43 @@ +package log + +var DefaultLogger = New() + +func Trace(args ...interface{}) { + DefaultLogger.log(TraceLevel, "", args...) +} + +func Debug(args ...interface{}) { + DefaultLogger.log(DebugLevel, "", args...) +} + +func Info(args ...interface{}) { + DefaultLogger.log(InfoLevel, "", args...) +} + +func Warn(args ...interface{}) { + DefaultLogger.log(WarnLevel, "", args...) +} + +func Error(args ...interface{}) { + DefaultLogger.log(ErrorLevel, "", args...) +} + +func Tracef(msg string, args ...interface{}) { + DefaultLogger.log(TraceLevel, msg, args...) +} + +func Debugf(msg string, args ...interface{}) { + DefaultLogger.log(DebugLevel, msg, args...) +} + +func Infof(msg string, args ...interface{}) { + DefaultLogger.log(InfoLevel, msg, args...) +} + +func Warnf(msg string, args ...interface{}) { + DefaultLogger.log(WarnLevel, msg, args...) +} + +func Errorf(msg string, args ...interface{}) { + DefaultLogger.log(ErrorLevel, msg, args...) +} diff --git a/log/level.go b/log/level.go new file mode 100644 index 0000000..25304f7 --- /dev/null +++ b/log/level.go @@ -0,0 +1,111 @@ +package log + +import ( + "bytes" + "errors" + "fmt" +) + +var errUnmarshalNilLevel = errors.New("can't unmarshal a nil *Level") + +// A Level is a logging priority. Higher levels are more important. +type Level int8 + +const ( + TraceLevel Level = iota + 1 + DebugLevel + InfoLevel + WarnLevel + ErrorLevel +) + +// ParseLevel parses a level based on the lower-case or all-caps ASCII +// representation of the log level. If the provided ASCII representation is +// invalid an error is returned. +// +// This is particularly useful when dealing with text input to configure log +// levels. +func ParseLevel(text string) (Level, error) { + var level Level + err := level.UnmarshalText([]byte(text)) + return level, err +} + +// String returns a lower-case ASCII representation of the log level. +func (l Level) String() string { + switch l { + case TraceLevel: + return "trace" + case DebugLevel: + return "debug" + case InfoLevel: + return "info" + case WarnLevel: + return "warn" + case ErrorLevel: + return "error" + default: + return fmt.Sprintf("Level(%d)", l) + } +} + +func (l Level) LogPrefix() string { + switch l { + case TraceLevel: + return "[T]" + case DebugLevel: + return "[D]" + case InfoLevel: + return "[I]" + case WarnLevel: + return "[W]" + case ErrorLevel: + return "[E]" + default: + return "" + } +} + +// MarshalText marshals the Level to text. Note that the text representation +// drops the -Level suffix (see example). +func (l Level) MarshalText() ([]byte, error) { + return []byte(l.String()), nil +} + +// UnmarshalText unmarshals text to a level. Like MarshalText, UnmarshalText +// expects the text representation of a Level to drop the -Level suffix. +// +// In particular, this makes it easy to configure logging levels using YAML, +// TOML, or JSON files. +func (l *Level) UnmarshalText(text []byte) error { + if l == nil { + return errUnmarshalNilLevel + } + if !l.unmarshalText(text) && !l.unmarshalText(bytes.ToLower(text)) { + return fmt.Errorf("unrecognized level: %q", text) + } + return nil +} + +func (l *Level) unmarshalText(text []byte) bool { + switch string(text) { + case "trace", "TRACE": + *l = TraceLevel + case "debug", "DEBUG": + *l = DebugLevel + case "info", "INFO", "": // make the zero value useful + *l = InfoLevel + case "warn", "WARN": + *l = WarnLevel + case "error", "ERROR": + *l = ErrorLevel + default: + return false + } + return true +} + +// Enabled returns true if the given level is at or above this level. +func (l Level) Enabled(lvl Level) bool { + return lvl >= l +} diff --git a/log/log.go b/log/log.go new file mode 100644 index 0000000..c63c393 --- /dev/null +++ b/log/log.go @@ -0,0 +1,201 @@ +package log + +import ( + "bytes" + "fmt" + "io" + "os" + "runtime" + "strings" + "sync" + "time" + + "github.com/fatedier/golib/clock" +) + +type LogWriter interface { + WriteLog([]byte, Level, time.Time) (n int, err error) +} + +var DefaultWriter = os.Stdout + +type Logger struct { + outMu sync.Mutex + out io.Writer + + level Level + callerEnabled bool + callerSkip int + clock clock.Clock +} + +func New(opts ...Option) *Logger { + l := &Logger{} + for _, opt := range opts { + opt.apply(l) + } + if l.out == nil { + l.out = DefaultWriter + } + if l.level == 0 { + l.level = InfoLevel + } + if l.clock == nil { + l.clock = clock.Real + } + return l +} + +// WithOptions returns a new Logger with the given Options. +// It does not modify the original Logger. +func (l *Logger) WithOptions(opts ...Option) *Logger { + c := l.clone() + for _, opt := range opts { + opt.apply(c) + } + return c +} + +func (l *Logger) clone() *Logger { + clone := &Logger{ + out: l.out, + level: l.level, + callerEnabled: l.callerEnabled, + callerSkip: l.callerSkip, + clock: l.clock, + } + return clone +} + +func (l *Logger) Trace(args ...interface{}) { + l.log(TraceLevel, "", args...) +} + +func (l *Logger) Debug(args ...interface{}) { + l.log(DebugLevel, "", args...) +} + +func (l *Logger) Info(args ...interface{}) { + l.log(InfoLevel, "", args...) +} + +func (l *Logger) Warn(args ...interface{}) { + l.log(WarnLevel, "", args...) +} + +func (l *Logger) Error(args ...interface{}) { + l.log(ErrorLevel, "", args...) +} + +func (l *Logger) Tracef(msg string, args ...interface{}) { + l.log(TraceLevel, msg, args...) +} + +func (l *Logger) Debugf(msg string, args ...interface{}) { + l.log(DebugLevel, msg, args...) +} + +func (l *Logger) Infof(msg string, args ...interface{}) { + l.log(InfoLevel, msg, args...) +} + +func (l *Logger) Warnf(msg string, args ...interface{}) { + l.log(WarnLevel, msg, args...) +} + +func (l *Logger) Errorf(msg string, args ...interface{}) { + l.log(ErrorLevel, msg, args...) +} + +func (l *Logger) log(level Level, msg string, args ...interface{}) { + if !l.level.Enabled(level) { + return + } + + when := l.clock.Now() + + buffer := bytesBufferPool.Get().(*bytes.Buffer) + defer func() { + buffer.Reset() + bytesBufferPool.Put(buffer) + }() + + timeHeaderBuf := make([]byte, 23) + _, _ = formatTimeHeader(when, timeHeaderBuf) + + buffer.Write(timeHeaderBuf) + buffer.WriteByte(' ') + buffer.WriteString(level.LogPrefix()) + buffer.WriteByte(' ') + + if l.callerEnabled { + buffer.WriteString(getCallerPrefix(3 + l.callerSkip)) + buffer.WriteByte(' ') + } + + buffer.WriteString(getMessage(msg, args)) + buffer.WriteByte('\n') + + if lw, ok := l.out.(LogWriter); ok { + l.outMu.Lock() + defer l.outMu.Unlock() + _, _ = lw.WriteLog(buffer.Bytes(), level, when) + return + } + l.outMu.Lock() + defer l.outMu.Unlock() + l.out.Write(buffer.Bytes()) +} + +func getMessage(template string, fmtArgs []interface{}) string { + if len(fmtArgs) == 0 { + return template + } + + if template != "" { + return fmt.Sprintf(template, fmtArgs...) + } + + if len(fmtArgs) == 1 { + if str, ok := fmtArgs[0].(string); ok { + return str + } + } + return fmt.Sprint(fmtArgs...) +} + +func getCallerPrefix(skip int) string { + _, file, line, ok := runtime.Caller(skip) + if !ok { + file = "???" + line = 0 + } + return "[" + trimmedPath(file, line) + "]" +} + +func fullPath(path string, line int) string { + buf := getBuffer() + defer putBuffer(buf) + *buf = append(*buf, path...) + *buf = append(*buf, ':') + itoa(buf, line, -1) + return string(*buf) +} + +func trimmedPath(path string, line int) string { + idx := strings.LastIndexByte(path, '/') + if idx == -1 { + return fullPath(path, line) + } + // Find the penultimate separator. + idx = strings.LastIndexByte(path[:idx], '/') + if idx == -1 { + return fullPath(path, line) + } + buf := getBuffer() + defer putBuffer(buf) + *buf = append(*buf, path[idx+1:]...) + *buf = append(*buf, ':') + itoa(buf, line, -1) + return string(*buf) +} diff --git a/log/log_test.go b/log/log_test.go new file mode 100644 index 0000000..395d35b --- /dev/null +++ b/log/log_test.go @@ -0,0 +1,42 @@ +package log + +import ( + "bytes" + "fmt" + "io" + "testing" + "time" + + "github.com/stretchr/testify/require" +) + +// Caller path involves line numbers, when the line number for logging in this function changes, +// it needs to be synchronized. +func TestLogWithCaller(t *testing.T) { + require := require.New(t) + + testBuffer := bytes.NewBuffer(nil) + logger := New( + WithLevel(DebugLevel), + WithCaller(true), + WithOutput(testBuffer), + ) + logger.Debug("test") + + require.Contains(testBuffer.String(), "log/log_test.go:24") +} + +func testLogFormat(t time.Time, level Level, msg string) string { + return fmt.Sprintf("%s %s %s\n", t.Format(logTimeFormat), level.LogPrefix(), msg) +} + +func BenchmarkLog(b *testing.B) { + logger := New( + WithLevel(DebugLevel), + WithCaller(true), + WithOutput(io.Discard), + ) + for i := 0; i < b.N; i++ { + logger.Debugf("debug %d", i) + } +} diff --git a/log/options.go b/log/options.go new file mode 100644 index 0000000..5d6fdd4 --- /dev/null +++ b/log/options.go @@ -0,0 +1,51 @@ +package log + +import ( + "io" + + "github.com/fatedier/golib/clock" +) + +// An Option configures a Logger. +type Option interface { + apply(*Logger) +} + +// optionFunc wraps a func so it satisfies the Option interface. +type optionFunc func(*Logger) + +func (f optionFunc) apply(log *Logger) { + f(log) +} + +func WithOutput(w io.Writer) Option { + return optionFunc(func(log *Logger) { + log.out = w + }) +} + +func WithLevel(l Level) Option { + return optionFunc(func(log *Logger) { + log.level = l + }) +} + +func AddCallerSkip(skip int) Option { + return optionFunc(func(log *Logger) { + log.callerSkip += skip + }) +} + +func WithCaller(enabled bool) Option { + return optionFunc(func(log *Logger) { + log.callerEnabled = enabled + }) +} + +// WithClock specifies the clock used by the logger to determine the current +// time for logged entries. Defaults to the system clock with time.Now. +func WithClock(clock clock.Clock) Option { + return optionFunc(func(log *Logger) { + log.clock = clock + }) +} diff --git a/log/output_console.go b/log/output_console.go new file mode 100644 index 0000000..d302db1 --- /dev/null +++ b/log/output_console.go @@ -0,0 +1,78 @@ +package log + +import ( + "io" + "os" + "time" +) + +// brush is a color join function +type brush func(string) string + +// newBrush returns a fix color Brush +func newBrush(color string) brush { + pre := "\033[" + reset := "\033[0m" + return func(text string) string { + return pre + color + "m" + text + reset + } +} + +func emptyBrush(text string) string { + return text +} + +var colors = []brush{ + emptyBrush, // Trace No Color + newBrush("1;36"), // Debug Light Cyan + newBrush("1;34"), // Info Blue + newBrush("1;33"), // Warn Yellow + newBrush("1;31"), // Error Red +} + +func colorBrushByLevel(level Level) brush { + switch level { + case TraceLevel: + return colors[0] + case DebugLevel: + return colors[1] + case InfoLevel: + return colors[2] + case WarnLevel: + return colors[3] + case ErrorLevel: + return colors[4] + default: + return colors[2] + } +} + +var _ io.Writer = (*ConsoleWriter)(nil) + +type ConsoleConfig struct { + Colorful bool +} + +type ConsoleWriter struct { + w io.Writer +} + +func NewConsoleWriter(cfg ConsoleConfig, out io.Writer) io.Writer { + if !cfg.Colorful { + return out + } + if out == nil { + out = os.Stdout + } + return &ConsoleWriter{ + w: out, + } +} + +func (cw *ConsoleWriter) Write(p []byte) (n int, err error) { + return cw.w.Write(p) +} + +func (cw *ConsoleWriter) WriteLog(p []byte, level Level, when time.Time) (n int, err error) { + return cw.w.Write([]byte(colorBrushByLevel(level)(string(p)))) +} diff --git a/log/output_console_test.go b/log/output_console_test.go new file mode 100644 index 0000000..e66cca6 --- /dev/null +++ b/log/output_console_test.go @@ -0,0 +1,54 @@ +package log + +import ( + "bytes" + "testing" + "time" + + testingclock "github.com/fatedier/golib/clock/testing" + "github.com/stretchr/testify/require" +) + +func TestConsoleWriter(t *testing.T) { + require := require.New(t) + + now := time.Now() + fakeClock := testingclock.NewFakeClock(now) + + // no color + testBuffer := bytes.NewBuffer(nil) + w := NewConsoleWriter(ConsoleConfig{Colorful: false}, testBuffer) + logger := New(WithOutput(w), WithLevel(TraceLevel), WithClock(fakeClock)) + logger.Trace("trace") + logger.Debug("debug") + logger.Info("info") + logger.Warn("warn") + logger.Error("error") + + expect := testLogFormat(now, TraceLevel, "trace") + expect += testLogFormat(now, DebugLevel, "debug") + expect += testLogFormat(now, InfoLevel, "info") + expect += testLogFormat(now, WarnLevel, "warn") + expect += testLogFormat(now, ErrorLevel, "error") + + require.Equal(expect, testBuffer.String()) + + // with color + testBuffer.Reset() + w = NewConsoleWriter(ConsoleConfig{Colorful: true}, testBuffer) + logger = New(WithOutput(w), WithLevel(TraceLevel), WithClock(fakeClock)) + logger.Trace("trace") + logger.Debug("debug") + logger.Info("info") + logger.Warn("warn") + logger.Error("error") + + expect = "" + expect += colorBrushByLevel(TraceLevel)(testLogFormat(now, TraceLevel, "trace")) + expect += colorBrushByLevel(DebugLevel)(testLogFormat(now, DebugLevel, "debug")) + expect += colorBrushByLevel(InfoLevel)(testLogFormat(now, InfoLevel, "info")) + expect += colorBrushByLevel(WarnLevel)(testLogFormat(now, WarnLevel, "warn")) + expect += colorBrushByLevel(ErrorLevel)(testLogFormat(now, ErrorLevel, "error")) + + require.Equal(expect, testBuffer.String()) +} diff --git a/log/output_rotatefile.go b/log/output_rotatefile.go new file mode 100644 index 0000000..93ee6f3 --- /dev/null +++ b/log/output_rotatefile.go @@ -0,0 +1,276 @@ +package log + +import ( + "errors" + "fmt" + "io" + "io/ioutil" + "os" + "path/filepath" + "slices" + "strings" + "sync" + "time" + + "github.com/fatedier/golib/clock" +) + +var defaultLogFileName = "default.log" + +type RotateFileMode string + +const ( + RotateFileModeNone RotateFileMode = "" + RotateFileModeDaily RotateFileMode = "daily" +) + +var _ io.WriteCloser = (*RotateFileWriter)(nil) + +type RotateFileConfig struct { + FileName string + Mode RotateFileMode + MaxDays int + + Clock clock.Clock +} + +type RotateFileWriter struct { + cfg RotateFileConfig + + mu sync.Mutex + file *os.File + clock clock.Clock + done chan struct{} +} + +func NewRotateFileWriter(cfg RotateFileConfig) *RotateFileWriter { + if cfg.FileName == "" { + cfg.FileName = defaultLogFileName + } + if cfg.Clock == nil { + cfg.Clock = clock.Real + } + fw := &RotateFileWriter{ + cfg: cfg, + clock: cfg.Clock, + done: make(chan struct{}), + } + return fw +} + +func (fw *RotateFileWriter) Init() { + fw.mu.Lock() + defer fw.mu.Unlock() + if fw.done != nil { + close(fw.done) + } + fw.done = make(chan struct{}) + if fw.cfg.Mode == RotateFileModeDaily { + go fw.dailyRotate() + } +} + +func (fw *RotateFileWriter) Write(p []byte) (n int, err error) { + return fw.WriteLog(p, InfoLevel) +} + +func (fw *RotateFileWriter) WriteLog(p []byte, _ Level) (int, error) { + fw.mu.Lock() + defer fw.mu.Unlock() + + if fw.file == nil { + if err := fw.openExistingOrNew(); err != nil { + return 0, err + } + } + + n, err := fw.file.Write(p) + return n, err +} + +func (fw *RotateFileWriter) Rotate() error { + fw.mu.Lock() + defer fw.mu.Unlock() + return fw.rotate() +} + +func (fw *RotateFileWriter) rotate() error { + if err := fw.close(); err != nil { + return err + } + if err := fw.openNew(); err != nil { + return err + } + _ = fw.clearFiles() + return nil +} + +func (fw *RotateFileWriter) openExistingOrNew() error { + _, err := os.Stat(fw.cfg.FileName) + if os.IsNotExist(err) { + return fw.openNew() + } + if err != nil { + return fmt.Errorf("get stat of logfile error: %s", err) + } + + file, err := os.OpenFile(fw.cfg.FileName, os.O_APPEND|os.O_WRONLY, 0644) + if err != nil { + return fw.openNew() + } + fw.file = file + return nil +} + +func (fw *RotateFileWriter) openNew() error { + err := os.MkdirAll(fw.dir(), 0755) + if err != nil { + return fmt.Errorf("mkdir directories [%s] for new logfile error: %s", fw.dir(), err) + } + + mode := os.FileMode(0600) + info, err := os.Stat(fw.cfg.FileName) + if err == nil { + mode = info.Mode() + newName := fw.backupName(fw.cfg.FileName, fw.clock.Now()) + if err := os.Rename(fw.cfg.FileName, newName); err != nil { + return fmt.Errorf("rename logfile error: %s", err) + } + } + + f, err := os.OpenFile(fw.cfg.FileName, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, mode) + if err != nil { + return fmt.Errorf("open new logfile error: %s", err) + } + fw.file = f + return nil +} + +var backupTimeFormat = "20060102-150405" + +func (fw *RotateFileWriter) backupName(name string, t time.Time) string { + dir := filepath.Dir(name) + filename := filepath.Base(name) + ext := filepath.Ext(filename) + prefix := filename[:len(filename)-len(ext)] + + timestamp := t.Format(backupTimeFormat) + return filepath.Join(dir, fmt.Sprintf("%s.%s%s", prefix, timestamp, ext)) +} + +func (fw *RotateFileWriter) parseTimeFromBackupName(filename, prefix, ext string) (time.Time, error) { + if !strings.HasPrefix(filename, prefix) { + return time.Time{}, errors.New("missmatched prefix") + } + if !strings.HasSuffix(filename, ext) { + return time.Time{}, errors.New("missmatched ext") + } + if len(prefix) >= len(filename)-len(ext) { + return time.Time{}, errors.New("missmatched prefix and ext") + } + timestamp := filename[len(prefix) : len(filename)-len(ext)] + return time.ParseInLocation(backupTimeFormat, timestamp, time.Local) +} + +func (fw *RotateFileWriter) dir() string { + return filepath.Dir(fw.cfg.FileName) +} + +func (fw *RotateFileWriter) dailyRotate() { + fw.mu.Lock() + doneCh := fw.done + fw.mu.Unlock() + for { + now := fw.clock.Now() + y, m, d := now.Add(24 * time.Hour).Date() + nextDay := time.Date(y, m, d, 0, 0, 0, 0, now.Location()) + tm := time.NewTimer(time.Duration(nextDay.UnixNano()-now.UnixNano()) + time.Millisecond) + select { + case <-tm.C: + fw.Rotate() + case <-doneCh: + tm.Stop() + return + } + } +} + +type logFileInfo struct { + info os.FileInfo + t time.Time +} + +func (fw *RotateFileWriter) oldLogFiles() ([]logFileInfo, error) { + files, err := ioutil.ReadDir(fw.dir()) + if err != nil { + return nil, fmt.Errorf("read log file directory error: %s", err) + } + fileInfos := make([]logFileInfo, 0) + + filename := filepath.Base(fw.cfg.FileName) + ext := filepath.Ext(filename) + prefix := filename[:len(filename)-len(ext)] + "." + + for _, f := range files { + if f.IsDir() { + continue + } + if t, err := fw.parseTimeFromBackupName(f.Name(), prefix, ext); err == nil { + fileInfos = append(fileInfos, logFileInfo{info: f, t: t}) + continue + } + } + + slices.SortFunc(fileInfos, func(a, b logFileInfo) int { + return a.t.Compare(b.t) + }) + return fileInfos, nil +} + +func (fw *RotateFileWriter) clearFiles() error { + if fw.cfg.Mode == RotateFileModeNone { + return nil + } + if fw.cfg.Mode == RotateFileModeDaily && fw.cfg.MaxDays <= 0 { + return nil + } + + files, err := fw.oldLogFiles() + if err != nil { + return err + } + + var toRemove []logFileInfo + if fw.cfg.Mode == RotateFileModeDaily { + cutoff := fw.clock.Now().Add(-time.Duration(fw.cfg.MaxDays) * time.Duration(24) * time.Hour).Add(5 * time.Millisecond) + for _, f := range files { + if f.t.Before(cutoff) { + toRemove = append(toRemove, f) + } + } + } + + for _, f := range toRemove { + _ = os.Remove(filepath.Join(fw.dir(), f.info.Name())) + } + return nil +} + +func (fw *RotateFileWriter) Close() error { + fw.mu.Lock() + defer fw.mu.Unlock() + return fw.close() +} + +func (fw *RotateFileWriter) close() error { + if fw.file == nil { + return nil + } + if fw.done != nil { + close(fw.done) + fw.done = nil + } + err := fw.file.Close() + fw.file = nil + return err +} diff --git a/log/output_rotatefile_test.go b/log/output_rotatefile_test.go new file mode 100644 index 0000000..3796294 --- /dev/null +++ b/log/output_rotatefile_test.go @@ -0,0 +1,74 @@ +package log + +import ( + "os" + "path/filepath" + "testing" + "time" + + testingclock "github.com/fatedier/golib/clock/testing" + "github.com/stretchr/testify/require" +) + +func TestRotateFileWriter_RotateDaily(t *testing.T) { + require := require.New(t) + + now := time.Now() + nextDayTime := now.Add(24 * time.Hour) + nextDay := time.Date(nextDayTime.Year(), nextDayTime.Month(), nextDayTime.Day(), 0, 0, 0, 0, now.Location()) + nextDay = nextDay.Add(time.Millisecond) + + rotateClock := testingclock.NewFakeClock(now) + + tmpDir := t.TempDir() + // Don't call Init to start DailyRotate goroutine. + // Call Rotate manually. + w := NewRotateFileWriter(RotateFileConfig{ + FileName: filepath.Join(tmpDir, "rotate_daily", "test.log"), + Mode: RotateFileModeDaily, + MaxDays: 2, + Clock: rotateClock, + }) + t.Cleanup(func() { + w.Close() + os.RemoveAll(filepath.Join(tmpDir, "rotate_daily")) + }) + + getLogFileName := func(t time.Time) string { + return "test." + t.Format(backupTimeFormat) + ".log" + } + + logClock := testingclock.NewFakeClock(now) + logger := New(WithOutput(w), WithLevel(TraceLevel), WithClock(logClock)) + + logger.Info("test1") + + day1 := nextDay + rotateClock.SetTime(day1) + require.NoError(w.Rotate()) + require.EqualValues([]string{getLogFileName(day1)}, rorateLogFiles(w)) + + logger.Info("test2") + day2 := nextDay.Add(24 * time.Hour) + rotateClock.SetTime(day2) + require.NoError(w.Rotate()) + require.EqualValues([]string{getLogFileName(day1), getLogFileName(day2)}, rorateLogFiles(w)) + + logger.Info("test3") + day3 := nextDay.Add(2 * 24 * time.Hour) + rotateClock.SetTime(day3) + require.NoError(w.Rotate()) + require.EqualValues([]string{getLogFileName(day2), getLogFileName(day3)}, rorateLogFiles(w)) +} + +func rorateLogFiles(w *RotateFileWriter) []string { + files, err := w.oldLogFiles() + if err != nil { + return nil + } + out := make([]string, 0, len(files)) + for _, f := range files { + out = append(out, f.info.Name()) + } + return out +}