From 9509bb6c9079d547da42b44809b38c2667c2b6e2 Mon Sep 17 00:00:00 2001 From: icey-yu <1186114839@qq.com> Date: Sat, 20 Jul 2024 18:01:16 +0800 Subject: [PATCH 1/3] Revert "Fix log (#107)" This reverts commit de5ae29cc3a6e81c275bb509b0d63caee6e2cb05. --- go.mod | 4 +- go.sum | 10 ++++- log/zap.go | 121 +++++++++++++++++------------------------------------ 3 files changed, 49 insertions(+), 86 deletions(-) diff --git a/go.mod b/go.mod index 9711dd9..239a322 100644 --- a/go.mod +++ b/go.mod @@ -30,6 +30,7 @@ require ( github.com/golang-jwt/jwt/v4 v4.5.0 github.com/google/uuid v1.6.0 github.com/jinzhu/copier v0.4.0 + github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible github.com/magefile/mage v1.15.0 github.com/minio/minio-go/v7 v7.0.69 github.com/openimsdk/protocol v0.0.69-alpha.4 @@ -45,7 +46,6 @@ require ( golang.org/x/image v0.15.0 google.golang.org/grpc v1.62.1 google.golang.org/protobuf v1.33.0 - gopkg.in/natefinch/lumberjack.v2 v2.2.1 gopkg.in/src-d/go-git.v4 v4.13.1 gopkg.in/yaml.v2 v2.4.0 gorm.io/gorm v1.25.8 @@ -66,6 +66,7 @@ require ( github.com/jcmturner/rpc/v2 v2.0.3 // indirect github.com/jinzhu/inflection v1.0.0 // indirect github.com/jinzhu/now v1.1.5 // indirect + github.com/jonboulle/clockwork v0.4.0 // indirect github.com/pierrec/lz4/v4 v4.1.21 // indirect github.com/rcrowley/go-metrics v0.0.0-20201227073835-cf1acfcdf475 // indirect github.com/rogpeppe/go-internal v1.11.0 // indirect @@ -101,6 +102,7 @@ require ( github.com/klauspost/cpuid/v2 v2.2.6 // indirect github.com/kr/pretty v0.3.1 // indirect github.com/leodido/go-urn v1.2.4 // indirect + github.com/lestrrat-go/strftime v1.0.6 // indirect github.com/mattn/go-isatty v0.0.19 // indirect github.com/minio/md5-simd v1.1.2 // indirect github.com/minio/sha256-simd v1.0.1 // indirect diff --git a/go.sum b/go.sum index a2d39a0..99e2c62 100644 --- a/go.sum +++ b/go.sum @@ -165,6 +165,8 @@ github.com/jinzhu/inflection v1.0.0 h1:K317FqzuhWc8YvSVlFMCCUb36O/S9MCKRDI7QkRKD github.com/jinzhu/inflection v1.0.0/go.mod h1:h+uFLlag+Qp1Va5pdKtLDYj+kHp5pxUVkryuEj+Srlc= github.com/jinzhu/now v1.1.5 h1:/o9tlHleP7gOFmsnYNz3RGnqzefHA47wQpKrrdTIwXQ= github.com/jinzhu/now v1.1.5/go.mod h1:d3SSVoowX0Lcu0IBviAWJpolVfI5UJVZZ7cO71lE/z8= +github.com/jonboulle/clockwork v0.4.0 h1:p4Cf1aMWXnXAUh8lVfewRBx1zaTSYKrKMF2g3ST4RZ4= +github.com/jonboulle/clockwork v0.4.0/go.mod h1:xgRqUGwRcjKCO1vbZUEtSLrqKoPSsUpK7fnezOII0kc= github.com/json-iterator/go v1.1.12 h1:PV8peI4a0ysnczrg+LtxykD8LfKY9ML6u2jnxaEnrnM= github.com/json-iterator/go v1.1.12/go.mod h1:e30LSqwooZae/UwlEbR2852Gd8hjQvJoHmT4TnhNGBo= github.com/kevinburke/ssh_config v0.0.0-20190725054713-01f96b0aa0cd h1:Coekwdh0v2wtGp9Gmz1Ze3eVRAWJMLokvN3QjdzCHLY= @@ -191,6 +193,12 @@ github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/leodido/go-urn v1.2.1/go.mod h1:zt4jvISO2HfUBqxjfIshjdMTYS56ZS/qv49ictyFfxY= github.com/leodido/go-urn v1.2.4 h1:XlAE/cm/ms7TE/VMVoduSpNBoyc2dOxHs5MZSwAN63Q= github.com/leodido/go-urn v1.2.4/go.mod h1:7ZrI8mTSeBSHl/UaRyKQW1qZeMgak41ANeCNaVckg+4= +github.com/lestrrat-go/envload v0.0.0-20180220234015-a3eb8ddeffcc h1:RKf14vYWi2ttpEmkA4aQ3j4u9dStX2t4M8UM6qqNsG8= +github.com/lestrrat-go/envload v0.0.0-20180220234015-a3eb8ddeffcc/go.mod h1:kopuH9ugFRkIXf3YoqHKyrJ9YfUFsckUU9S7B+XP+is= +github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible h1:Y6sqxHMyB1D2YSzWkLibYKgg+SwmyFU9dF2hn6MdTj4= +github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible/go.mod h1:ZQnN8lSECaebrkQytbHj4xNgtg8CR7RYXnPok8e0EHA= +github.com/lestrrat-go/strftime v1.0.6 h1:CFGsDEt1pOpFNU+TJB0nhz9jl+K0hZSLE205AhTIGQQ= +github.com/lestrrat-go/strftime v1.0.6/go.mod h1:f7jQKgV5nnJpYgdEasS+/y7EsTb8ykN2z68n3TtcTaw= github.com/magefile/mage v1.15.0 h1:BvGheCMAsG3bWUDbZ8AyXXpCNwU9u5CB6sM+HNb9HYg= github.com/magefile/mage v1.15.0/go.mod h1:z5UZb/iS3GoOSn0JgWuiw7dxlurVYTu+/jHXqQg881A= github.com/mattn/go-isatty v0.0.19 h1:JITubQf0MOLdlGRuRq+jtsDlekdYPia9ZFsB8h/APPA= @@ -409,8 +417,6 @@ gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EV gopkg.in/errgo.v2 v2.1.0/go.mod h1:hNsd1EY+bozCKY1Ytp96fpM3vjJbqLJn88ws8XvfDNI= gopkg.in/ini.v1 v1.67.0 h1:Dgnx+6+nfE+IfzjUEISNeydPJh9AXNNsWbGP9KzCsOA= gopkg.in/ini.v1 v1.67.0/go.mod h1:pNLf8WUiyNEtQjuu5G5vTm06TEv9tsIgeAvK8hOrP4k= -gopkg.in/natefinch/lumberjack.v2 v2.2.1 h1:bBRl1b0OH9s/DuPhuXpNl+VtCaJXFZ5/uEFST95x9zc= -gopkg.in/natefinch/lumberjack.v2 v2.2.1/go.mod h1:YD8tP3GAjkrDg1eZH7EGmyESg/lsYskCTPBJVb9jqSc= gopkg.in/src-d/go-billy.v4 v4.3.2 h1:0SQA1pRztfTFx2miS8sA97XvooFeNOmvUenF4o0EcVg= gopkg.in/src-d/go-billy.v4 v4.3.2/go.mod h1:nDjArDMp+XMs1aFAESLRjfGSgfvoYN0hDfzEk0GjC98= gopkg.in/src-d/go-git-fixtures.v3 v3.5.0 h1:ivZFOIltbce2Mo8IjzUHAFoq/IylO9WHhNOAJK+LsJg= diff --git a/log/zap.go b/log/zap.go index dd04972..0745273 100644 --- a/log/zap.go +++ b/log/zap.go @@ -18,11 +18,11 @@ import ( "context" "fmt" "github.com/openimsdk/tools/utils/stringutil" - "gopkg.in/natefinch/lumberjack.v2" "os" "path/filepath" "time" + rotatelogs "github.com/lestrrat-go/file-rotatelogs" "github.com/openimsdk/protocol/constant" "github.com/openimsdk/tools/mcontext" "go.uber.org/zap" @@ -54,27 +54,20 @@ func InitFromConfig( isStdout bool, isJson bool, logLocation string, - rotateTime uint, - maxBackups int, - maxSize int, - maxAge int, - compress bool, + rotateCount uint, + rotationTime uint, moduleVersion string, ) error { l, err := NewZapLogger(loggerPrefixName, moduleName, logLevel, isStdout, isJson, logLocation, - rotateTime, maxBackups, maxSize, maxAge, compress, moduleVersion) + rotateCount, rotationTime, moduleVersion) if err != nil { return err } - setPkgLogger(isJson, moduleName, l) - return nil -} - -func setPkgLogger(isJson bool, moduleName string, l *ZapLogger) { pkgLogger = l.WithCallDepth(callDepth) if isJson { pkgLogger = pkgLogger.WithName(moduleName) } + return nil } // InitConsoleLogger init osStdout and osStderr. @@ -134,12 +127,7 @@ type ZapLogger struct { moduleName string moduleVersion string loggerPrefixName string - logLocation string rotationTime time.Duration - maxBackups int - maxSize int - maxAge int - compress bool } func NewZapLogger( @@ -148,11 +136,8 @@ func NewZapLogger( isStdout bool, isJson bool, logLocation string, + rotateCount uint, rotationTime uint, - maxBackups int, - maxSize int, - maxAge int, - compress bool, moduleVersion string, ) (*ZapLogger, error) { zapConfig := zap.Config{ @@ -164,20 +149,12 @@ func NewZapLogger( } else { zapConfig.Encoding = "console" } - zl := &ZapLogger{ - level: logLevelMap[logLevel], - moduleName: moduleName, - moduleVersion: moduleVersion, - loggerPrefixName: loggerPrefixName, - logLocation: logLocation, - rotationTime: time.Duration(rotationTime) * time.Hour, - maxBackups: maxBackups, - maxSize: maxSize, - maxAge: maxAge, - compress: compress, - } - opts := zl.cores(isStdout, isJson) - + zl := &ZapLogger{level: logLevelMap[logLevel], moduleName: moduleName, loggerPrefixName: loggerPrefixName, + rotationTime: time.Duration(rotationTime) * time.Hour, moduleVersion: moduleVersion} + opts, err := zl.cores(isStdout, isJson, logLocation, rotateCount) + if err != nil { + return nil, err + } l, err := zapConfig.Build(opts) if err != nil { return nil, err @@ -202,8 +179,10 @@ func NewConsoleZapLogger( zapConfig.Encoding = "console" } zl := &ZapLogger{level: logLevelMap[logLevel], moduleName: moduleName, moduleVersion: moduleVersion} - opts := zl.consoleCores(outPut, isJson) - + opts, err := zl.consoleCores(outPut, isJson) + if err != nil { + return nil, err + } l, err := zapConfig.Build(opts) if err != nil { return nil, err @@ -211,8 +190,7 @@ func NewConsoleZapLogger( zl.zap = l.Sugar() return zl, nil } - -func (l *ZapLogger) cores(isStdout bool, isJson bool) zap.Option { +func (l *ZapLogger) cores(isStdout bool, isJson bool, logLocation string, rotateCount uint) (zap.Option, error) { c := zap.NewProductionEncoderConfig() c.EncodeTime = l.timeEncoder c.EncodeDuration = zapcore.SecondsDurationEncoder @@ -233,10 +211,12 @@ func (l *ZapLogger) cores(isStdout bool, isJson bool) zap.Option { fileEncoder = zapcore.NewConsoleEncoder(c) } fileEncoder = &alignEncoder{Encoder: fileEncoder} - writer := l.getWriter() - + writer, err := l.getWriter(logLocation, rotateCount) + if err != nil { + return nil, err + } var cores []zapcore.Core - if l.logLocation != "" { + if logLocation != "" { cores = []zapcore.Core{ zapcore.NewCore(fileEncoder, writer, zap.NewAtomicLevelAt(l.level)), } @@ -247,25 +227,10 @@ func (l *ZapLogger) cores(isStdout bool, isJson bool) zap.Option { } return zap.WrapCore(func(c zapcore.Core) zapcore.Core { return zapcore.NewTee(cores...) - }) + }), nil } -// setupLogRotation set to rotate according to l.rotationTime -func (l *ZapLogger) setupLogRotation(lumLogger *lumberjack.Logger) { - ticker := time.NewTicker(l.rotationTime) - go func() { - for range ticker.C { - fileName := l.getLogFileName() - lumLogger.Filename = fileName - err := lumLogger.Rotate() - if err != nil { - ZError(context.TODO(), "rotate log field", err) - } - } - }() -} - -func (l *ZapLogger) consoleCores(outPut *os.File, isJson bool) zap.Option { +func (l *ZapLogger) consoleCores(outPut *os.File, isJson bool) (zap.Option, error) { c := zap.NewProductionEncoderConfig() c.EncodeTime = l.timeEncoder c.EncodeDuration = zapcore.SecondsDurationEncoder @@ -290,7 +255,7 @@ func (l *ZapLogger) consoleCores(outPut *os.File, isJson bool) zap.Option { return zap.WrapCore(func(c zapcore.Core) zapcore.Core { return zapcore.NewTee(cores...) - }) + }), nil } func (l *ZapLogger) customCallerEncoder(caller zapcore.EntryCaller, enc zapcore.PrimitiveArrayEncoder) { @@ -313,33 +278,23 @@ func (l *ZapLogger) timeEncoder(t time.Time, enc zapcore.PrimitiveArrayEncoder) enc.AppendString(t.Format(layout)) } -func (l *ZapLogger) getWriter() zapcore.WriteSyncer { - fileName := l.getLogFileName() - lumberjackLogger := &lumberjack.Logger{ - Filename: fileName, // log file path - MaxSize: l.maxSize, // maximum size of each log file (in MB) - MaxBackups: l.maxBackups, // maximum number of retained old log files - MaxAge: l.maxAge, // maximum number of days to retain old log files - Compress: l.compress, // whether compress old log files - } - l.setupLogRotation(lumberjackLogger) // Set to rotate according to time - return zapcore.AddSync(lumberjackLogger) -} - -func (l *ZapLogger) getLogFileName() string { - var ( - now = time.Now() - timeStr string - ) - +func (l *ZapLogger) getWriter(logLocation string, rorateCount uint) (zapcore.WriteSyncer, error) { + var path string if l.rotationTime%(time.Hour*time.Duration(hoursPerDay)) == 0 { - timeStr = now.Format(".2006-01-02") + path = logLocation + sp + l.loggerPrefixName + ".%Y-%m-%d" } else if l.rotationTime%time.Hour == 0 { - timeStr = now.Format(".2006-01-02_15") + path = logLocation + sp + l.loggerPrefixName + ".%Y-%m-%d_%H" } else { - timeStr = now.Format(".2006-01-02_15_04_05") + path = logLocation + sp + l.loggerPrefixName + ".%Y-%m-%d_%H_%M_%S" + } + logf, err := rotatelogs.New(path, + rotatelogs.WithRotationCount(rorateCount), + rotatelogs.WithRotationTime(l.rotationTime), + ) + if err != nil { + return nil, err } - return l.logLocation + sp + l.loggerPrefixName + timeStr + return zapcore.AddSync(logf), nil } func (l *ZapLogger) capitalColorLevelEncoder(level zapcore.Level, enc zapcore.PrimitiveArrayEncoder) { From 6ed3dee5cf968753fd8141c9fe214391c0fb4e27 Mon Sep 17 00:00:00 2001 From: icey-yu <1186114839@qq.com> Date: Sat, 20 Jul 2024 18:10:04 +0800 Subject: [PATCH 2/3] feature: add log package --- go.mod | 1 + go.sum | 1 + log/file-rotatelogs/LICENSE | 20 + log/file-rotatelogs/README.md | 237 +++++++ log/file-rotatelogs/event.go | 17 + log/file-rotatelogs/example_test.go | 63 ++ log/file-rotatelogs/interface.go | 73 +++ .../internal/fileutil/fileutil.go | 58 ++ .../internal/fileutil/fileutil_test.go | 38 ++ log/file-rotatelogs/internal/option/option.go | 26 + log/file-rotatelogs/options.go | 88 +++ log/file-rotatelogs/rotatelogs.go | 386 ++++++++++++ log/file-rotatelogs/rotatelogs_test.go | 582 ++++++++++++++++++ 13 files changed, 1590 insertions(+) create mode 100644 log/file-rotatelogs/LICENSE create mode 100644 log/file-rotatelogs/README.md create mode 100644 log/file-rotatelogs/event.go create mode 100644 log/file-rotatelogs/example_test.go create mode 100644 log/file-rotatelogs/interface.go create mode 100644 log/file-rotatelogs/internal/fileutil/fileutil.go create mode 100644 log/file-rotatelogs/internal/fileutil/fileutil_test.go create mode 100644 log/file-rotatelogs/internal/option/option.go create mode 100644 log/file-rotatelogs/options.go create mode 100644 log/file-rotatelogs/rotatelogs.go create mode 100644 log/file-rotatelogs/rotatelogs_test.go diff --git a/go.mod b/go.mod index 239a322..a3d4cae 100644 --- a/go.mod +++ b/go.mod @@ -142,6 +142,7 @@ require ( google.golang.org/genproto v0.0.0-20240123012728-ef4313101c80 // indirect google.golang.org/genproto/googleapis/api v0.0.0-20240123012728-ef4313101c80 // indirect gopkg.in/ini.v1 v1.67.0 // indirect + gopkg.in/natefinch/lumberjack.v2 v2.2.1 // indirect gopkg.in/src-d/go-billy.v4 v4.3.2 // indirect gopkg.in/warnings.v0 v0.1.2 // indirect ) diff --git a/go.sum b/go.sum index 99e2c62..17c1691 100644 --- a/go.sum +++ b/go.sum @@ -417,6 +417,7 @@ gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EV gopkg.in/errgo.v2 v2.1.0/go.mod h1:hNsd1EY+bozCKY1Ytp96fpM3vjJbqLJn88ws8XvfDNI= gopkg.in/ini.v1 v1.67.0 h1:Dgnx+6+nfE+IfzjUEISNeydPJh9AXNNsWbGP9KzCsOA= gopkg.in/ini.v1 v1.67.0/go.mod h1:pNLf8WUiyNEtQjuu5G5vTm06TEv9tsIgeAvK8hOrP4k= +gopkg.in/natefinch/lumberjack.v2 v2.2.1/go.mod h1:YD8tP3GAjkrDg1eZH7EGmyESg/lsYskCTPBJVb9jqSc= gopkg.in/src-d/go-billy.v4 v4.3.2 h1:0SQA1pRztfTFx2miS8sA97XvooFeNOmvUenF4o0EcVg= gopkg.in/src-d/go-billy.v4 v4.3.2/go.mod h1:nDjArDMp+XMs1aFAESLRjfGSgfvoYN0hDfzEk0GjC98= gopkg.in/src-d/go-git-fixtures.v3 v3.5.0 h1:ivZFOIltbce2Mo8IjzUHAFoq/IylO9WHhNOAJK+LsJg= diff --git a/log/file-rotatelogs/LICENSE b/log/file-rotatelogs/LICENSE new file mode 100644 index 0000000..9a7f25b --- /dev/null +++ b/log/file-rotatelogs/LICENSE @@ -0,0 +1,20 @@ +The MIT License (MIT) + +Copyright (c) 2014 lestrrat + +Permission is hereby granted, free of charge, to any person obtaining a copy of +this software and associated documentation files (the "Software"), to deal in +the Software without restriction, including without limitation the rights to +use, copy, modify, merge, publish, distribute, sublicense, and/or sell copies of +the Software, and to permit persons to whom the Software is furnished to do so, +subject to the following conditions: + +The above copyright notice and this permission notice shall be included in all +copies or substantial portions of the Software. + +THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR +IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS +FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR +COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER +IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN +CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. diff --git a/log/file-rotatelogs/README.md b/log/file-rotatelogs/README.md new file mode 100644 index 0000000..8781dc1 --- /dev/null +++ b/log/file-rotatelogs/README.md @@ -0,0 +1,237 @@ +file-rotatelogs +================== + +Provide an `io.Writer` that periodically rotates log files from within the application. Port of [File::RotateLogs](https://metacpan.org/release/File-RotateLogs) from Perl to Go. + +[![Build Status](https://travis-ci.org/lestrrat-go/file-rotatelogs.png?branch=master)](https://travis-ci.org/lestrrat-go/file-rotatelogs) + +[![GoDoc](https://godoc.org/github.com/lestrrat-go/file-rotatelogs?status.svg)](https://godoc.org/github.com/lestrrat-go/file-rotatelogs) + +# WARNINGS + +THIS PROJECT HAS BEEN ARCHIVED. IT WILL NOT RECEIVE UPDATES, THE AUTHOR DOES NOT WISH TO MAINTAIN OR SUPPORT IT. +IN SHORT, DO NOT USE THIS PROJECT. + +# SYNOPSIS + +```go +import ( + "log" + "net/http" + + apachelog "github.com/lestrrat-go/apache-logformat" + rotatelogs "github.com/lestrrat-go/file-rotatelogs" +) + +func main() { + mux := http.NewServeMux() + mux.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) { ... }) + + logf, err := rotatelogs.New( + "/path/to/access_log.%Y%m%d%H%M", + rotatelogs.WithLinkName("/path/to/access_log"), + rotatelogs.WithMaxAge(24 * time.Hour), + rotatelogs.WithRotationTime(time.Hour), + ) + if err != nil { + log.Printf("failed to create rotatelogs: %s", err) + return + } + + // Now you must write to logf. apache-logformat library can create + // a http.Handler that only writes the approriate logs for the request + // to the given handle + http.ListenAndServe(":8080", apachelog.CombinedLog.Wrap(mux, logf)) +} +``` + +# DESCRIPTION + +When you integrate this to into your app, it automatically write to logs that +are rotated from within the app: No more disk-full alerts because you forgot +to setup logrotate! + +To install, simply issue a `go get`: + +``` +go get github.com/lestrrat-go/file-rotatelogs +``` + +It's normally expected that this library is used with some other +logging service, such as the built-in `log` library, or loggers +such as `github.com/lestrrat-go/apache-logformat`. + +```go +import( + "log" + "github.com/lestrrat-go/file-rotatelogs" +) + +func main() { + rl, _ := rotatelogs.New("/path/to/access_log.%Y%m%d%H%M") + + log.SetOutput(rl) + + /* elsewhere ... */ + log.Printf("Hello, World!") +} +``` + +OPTIONS +==== + +## Pattern (Required) + +The pattern used to generate actual log file names. You should use patterns +using the strftime (3) format. For example: + +```go + rotatelogs.New("/var/log/myapp/log.%Y%m%d") +``` + +## Clock (default: rotatelogs.Local) + +You may specify an object that implements the roatatelogs.Clock interface. +When this option is supplied, it's used to determine the current time to +base all of the calculations on. For example, if you want to base your +calculations in UTC, you may specify rotatelogs.UTC + +```go + rotatelogs.New( + "/var/log/myapp/log.%Y%m%d", + rotatelogs.WithClock(rotatelogs.UTC), + ) +``` + +## Location + +This is an alternative to the `WithClock` option. Instead of providing an +explicit clock, you can provide a location for you times. We will create +a Clock object that produces times in your specified location, and configure +the rotatelog to respect it. + +## LinkName (default: "") + +Path where a symlink for the actual log file is placed. This allows you to +always check at the same location for log files even if the logs were rotated + +```go + rotatelogs.New( + "/var/log/myapp/log.%Y%m%d", + rotatelogs.WithLinkName("/var/log/myapp/current"), + ) +``` + +``` + // Else where + $ tail -f /var/log/myapp/current +``` + +Links that share the same parent directory with the main log path will get a +special treatment: namely, linked paths will be *RELATIVE* to the main log file. + +| Main log file name | Link name | Linked path | +|---------------------|---------------------|-----------------------| +| /path/to/log.%Y%m%d | /path/to/log | log.YYYYMMDD | +| /path/to/log.%Y%m%d | /path/to/nested/log | ../log.YYYYMMDD | +| /path/to/log.%Y%m%d | /foo/bar/baz/log | /path/to/log.YYYYMMDD | + +If not provided, no link will be written. + +## RotationTime (default: 86400 sec) + +Interval between file rotation. By default logs are rotated every 86400 seconds. +Note: Remember to use time.Duration values. + +```go + // Rotate every hour + rotatelogs.New( + "/var/log/myapp/log.%Y%m%d", + rotatelogs.WithRotationTime(time.Hour), + ) +``` + +## MaxAge (default: 7 days) + +Time to wait until old logs are purged. By default no logs are purged, which +certainly isn't what you want. +Note: Remember to use time.Duration values. + +```go + // Purge logs older than 1 hour + rotatelogs.New( + "/var/log/myapp/log.%Y%m%d", + rotatelogs.WithMaxAge(time.Hour), + ) +``` + +## RotationCount (default: -1) + +The number of files should be kept. By default, this option is disabled. + +Note: MaxAge should be disabled by specifing `WithMaxAge(-1)` explicitly. + +```go + // Purge logs except latest 7 files + rotatelogs.New( + "/var/log/myapp/log.%Y%m%d", + rotatelogs.WithMaxAge(-1), + rotatelogs.WithRotationCount(7), + ) +``` + +## Handler (default: nil) + +Sets the event handler to receive event notifications from the RotateLogs +object. Currently only supported event type is FiledRotated + +```go + rotatelogs.New( + "/var/log/myapp/log.%Y%m%d", + rotatelogs.WithHandler(rotatelogs.HandlerFunc(func(e rotatelogs.Event) { + if e.Type() != rotatelogs.FileRotatedEventType { + return + } + + // Do what you want with the data. This is just an idea: + storeLogFileToRemoteStorage(e.(*rotatelogs.FileRotatedEvent).PreviousFile()) + })), + ) +``` + +## ForceNewFile + +Ensure a new file is created every time New() is called. If the base file name +already exists, an implicit rotation is performed. + +```go + rotatelogs.New( + "/var/log/myapp/log.%Y%m%d", + rotatelogs.ForceNewFile(), + ) +``` + +# Rotating files forcefully + +If you want to rotate files forcefully before the actual rotation time has reached, +you may use the `Rotate()` method. This method forcefully rotates the logs, but +if the generated file name clashes, then a numeric suffix is added so that +the new file will forcefully appear on disk. + +For example, suppose you had a pattern of '%Y.log' with a rotation time of +`86400` so that it only gets rotated every year, but for whatever reason you +wanted to rotate the logs now, you could install a signal handler to +trigger this rotation: + +```go +rl := rotatelogs.New(...) + +signal.Notify(ch, syscall.SIGHUP) + +go func(ch chan os.Signal) { + <-ch + rl.Rotate() +}() +``` + +And you will get a log file name in like `2018.log.1`, `2018.log.2`, etc. diff --git a/log/file-rotatelogs/event.go b/log/file-rotatelogs/event.go new file mode 100644 index 0000000..23047c4 --- /dev/null +++ b/log/file-rotatelogs/event.go @@ -0,0 +1,17 @@ +package rotatelogs + +func (h HandlerFunc) Handle(e Event) { + h(e) +} + +func (e *FileRotatedEvent) Type() EventType { + return FileRotatedEventType +} + +func (e *FileRotatedEvent) PreviousFile() string { + return e.prev +} + +func (e *FileRotatedEvent) CurrentFile() string { + return e.current +} diff --git a/log/file-rotatelogs/example_test.go b/log/file-rotatelogs/example_test.go new file mode 100644 index 0000000..6fb495b --- /dev/null +++ b/log/file-rotatelogs/example_test.go @@ -0,0 +1,63 @@ +package rotatelogs_test + +import ( + "fmt" + "io/ioutil" + "os" + + rotatelogs "github.com/lestrrat-go/file-rotatelogs" +) + +func ExampleForceNewFile() { + logDir, err := ioutil.TempDir("", "rotatelogs_test") + if err != nil { + fmt.Println("could not create log directory ", err) + + return + } + logPath := fmt.Sprintf("%s/test.log", logDir) + + for i := 0; i < 2; i++ { + writer, err := rotatelogs.New(logPath, + rotatelogs.ForceNewFile(), + ) + if err != nil { + fmt.Println("Could not open log file ", err) + + return + } + + n, err := writer.Write([]byte("test")) + if err != nil || n != 4 { + fmt.Println("Write failed ", err, " number written ", n) + + return + } + err = writer.Close() + if err != nil { + fmt.Println("Close failed ", err) + + return + } + } + + files, err := ioutil.ReadDir(logDir) + if err != nil { + fmt.Println("ReadDir failed ", err) + + return + } + for _, file := range files { + fmt.Println(file.Name(), file.Size()) + } + + err = os.RemoveAll(logDir) + if err != nil { + fmt.Println("RemoveAll failed ", err) + + return + } + // OUTPUT: + // test.log 4 + // test.log.1 4 +} diff --git a/log/file-rotatelogs/interface.go b/log/file-rotatelogs/interface.go new file mode 100644 index 0000000..9a04ab4 --- /dev/null +++ b/log/file-rotatelogs/interface.go @@ -0,0 +1,73 @@ +package rotatelogs + +import ( + "os" + "sync" + "time" + + strftime "github.com/lestrrat-go/strftime" +) + +type Handler interface { + Handle(Event) +} + +type HandlerFunc func(Event) + +type Event interface { + Type() EventType +} + +type EventType int + +const ( + InvalidEventType EventType = iota + FileRotatedEventType +) + +type FileRotatedEvent struct { + prev string // previous filename + current string // current, new filename +} + +// RotateLogs represents a log file that gets +// automatically rotated as you write to it. +type RotateLogs struct { + clock Clock + curFn string + curBaseFn string + globPattern string + generation int + linkName string + maxAge time.Duration + mutex sync.RWMutex + eventHandler Handler + outFh *os.File + pattern *strftime.Strftime + rotationTime time.Duration + rotationSize int64 + rotationCount uint + forceNewFile bool +} + +// Clock is the interface used by the RotateLogs +// object to determine the current time +type Clock interface { + Now() time.Time +} +type clockFn func() time.Time + +// UTC is an object satisfying the Clock interface, which +// returns the current time in UTC +var UTC = clockFn(func() time.Time { return time.Now().UTC() }) + +// Local is an object satisfying the Clock interface, which +// returns the current time in the local timezone +var Local = clockFn(time.Now) + +// Option is used to pass optional arguments to +// the RotateLogs constructor +type Option interface { + Name() string + Value() interface{} +} diff --git a/log/file-rotatelogs/internal/fileutil/fileutil.go b/log/file-rotatelogs/internal/fileutil/fileutil.go new file mode 100644 index 0000000..346f4fb --- /dev/null +++ b/log/file-rotatelogs/internal/fileutil/fileutil.go @@ -0,0 +1,58 @@ +package fileutil + +import ( + "os" + "path/filepath" + "time" + + "github.com/lestrrat-go/strftime" + "github.com/pkg/errors" +) + +// GenerateFn creates a file name based on the pattern, the current time, and the +// rotation time. +// +// The bsase time that is used to generate the filename is truncated based +// on the rotation time. +func GenerateFn(pattern *strftime.Strftime, clock interface{ Now() time.Time }, rotationTime time.Duration) string { + now := clock.Now() + + // XXX HACK: Truncate only happens in UTC semantics, apparently. + // observed values for truncating given time with 86400 secs: + // + // before truncation: 2018/06/01 03:54:54 2018-06-01T03:18:00+09:00 + // after truncation: 2018/06/01 03:54:54 2018-05-31T09:00:00+09:00 + // + // This is really annoying when we want to truncate in local time + // so we hack: we take the apparent local time in the local zone, + // and pretend that it's in UTC. do our math, and put it back to + // the local zone + var base time.Time + if now.Location() != time.UTC { + base = time.Date(now.Year(), now.Month(), now.Day(), now.Hour(), now.Minute(), now.Second(), now.Nanosecond(), time.UTC) + base = base.Truncate(rotationTime) + base = time.Date(base.Year(), base.Month(), base.Day(), base.Hour(), base.Minute(), base.Second(), base.Nanosecond(), base.Location()) + } else { + base = now.Truncate(rotationTime) + } + + return pattern.FormatString(base) +} + +// CreateFile creates a new file in the given path, creating parent directories +// as necessary +func CreateFile(filename string) (*os.File, error) { + // make sure the dir is existed, eg: + // ./foo/bar/baz/hello.log must make sure ./foo/bar/baz is existed + dirname := filepath.Dir(filename) + if err := os.MkdirAll(dirname, 0755); err != nil { + return nil, errors.Wrapf(err, "failed to create directory %s", dirname) + } + // if we got here, then we need to create a file + fh, err := os.OpenFile(filename, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0644) + if err != nil { + return nil, errors.Errorf("failed to open file %s: %s", filename, err) + } + + return fh, nil +} diff --git a/log/file-rotatelogs/internal/fileutil/fileutil_test.go b/log/file-rotatelogs/internal/fileutil/fileutil_test.go new file mode 100644 index 0000000..e0bd1d4 --- /dev/null +++ b/log/file-rotatelogs/internal/fileutil/fileutil_test.go @@ -0,0 +1,38 @@ +package fileutil_test + +import ( + "fmt" + "github.com/openimsdk/tools/log/file-rotatelogs/internal/fileutil" + "testing" + "time" + + "github.com/jonboulle/clockwork" + "github.com/lestrrat-go/strftime" + "github.com/stretchr/testify/assert" +) + +func TestGenerateFn(t *testing.T) { + // Mock time + ts := []time.Time{ + {}, + (time.Time{}).Add(24 * time.Hour), + } + + for _, xt := range ts { + pattern, err := strftime.New("/path/to/%Y/%m/%d") + if !assert.NoError(t, err, `strftime.New should succeed`) { + return + } + clock := clockwork.NewFakeClockAt(xt) + fn := fileutil.GenerateFn(pattern, clock, 24*time.Hour) + expected := fmt.Sprintf("/path/to/%04d/%02d/%02d", + xt.Year(), + xt.Month(), + xt.Day(), + ) + + if !assert.Equal(t, expected, fn) { + return + } + } +} diff --git a/log/file-rotatelogs/internal/option/option.go b/log/file-rotatelogs/internal/option/option.go new file mode 100644 index 0000000..42afc93 --- /dev/null +++ b/log/file-rotatelogs/internal/option/option.go @@ -0,0 +1,26 @@ +package option + +type Interface interface { + Name() string + Value() interface{} +} + +type Option struct { + name string + value interface{} +} + +func New(name string, value interface{}) *Option { + return &Option{ + name: name, + value: value, + } +} + +func (o *Option) Name() string { + return o.name +} + +func (o *Option) Value() interface{} { + return o.value +} diff --git a/log/file-rotatelogs/options.go b/log/file-rotatelogs/options.go new file mode 100644 index 0000000..e13cbb5 --- /dev/null +++ b/log/file-rotatelogs/options.go @@ -0,0 +1,88 @@ +package rotatelogs + +import ( + "github.com/openimsdk/tools/log/file-rotatelogs/internal/option" + "time" +) + +const ( + optkeyClock = "clock" + optkeyHandler = "handler" + optkeyLinkName = "link-name" + optkeyMaxAge = "max-age" + optkeyRotationTime = "rotation-time" + optkeyRotationSize = "rotation-size" + optkeyRotationCount = "rotation-count" + optkeyForceNewFile = "force-new-file" +) + +// WithClock creates a new Option that sets a clock +// that the RotateLogs object will use to determine +// the current time. +// +// By default rotatelogs.Local, which returns the +// current time in the local time zone, is used. If you +// would rather use UTC, use rotatelogs.UTC as the argument +// to this option, and pass it to the constructor. +func WithClock(c Clock) Option { + return option.New(optkeyClock, c) +} + +// WithLocation creates a new Option that sets up a +// "Clock" interface that the RotateLogs object will use +// to determine the current time. +// +// This optin works by always returning the in the given +// location. +func WithLocation(loc *time.Location) Option { + return option.New(optkeyClock, clockFn(func() time.Time { + return time.Now().In(loc) + })) +} + +// WithLinkName creates a new Option that sets the +// symbolic link name that gets linked to the current +// file name being used. +func WithLinkName(s string) Option { + return option.New(optkeyLinkName, s) +} + +// WithMaxAge creates a new Option that sets the +// max age of a log file before it gets purged from +// the file system. +func WithMaxAge(d time.Duration) Option { + return option.New(optkeyMaxAge, d) +} + +// WithRotationTime creates a new Option that sets the +// time between rotation. +func WithRotationTime(d time.Duration) Option { + return option.New(optkeyRotationTime, d) +} + +// WithRotationSize creates a new Option that sets the +// log file size between rotation. +func WithRotationSize(s int64) Option { + return option.New(optkeyRotationSize, s) +} + +// WithRotationCount creates a new Option that sets the +// number of files should be kept before it gets +// purged from the file system. +func WithRotationCount(n uint) Option { + return option.New(optkeyRotationCount, n) +} + +// WithHandler creates a new Option that specifies the +// Handler object that gets invoked when an event occurs. +// Currently `FileRotated` event is supported +func WithHandler(h Handler) Option { + return option.New(optkeyHandler, h) +} + +// ForceNewFile ensures a new file is created every time New() +// is called. If the base file name already exists, an implicit +// rotation is performed +func ForceNewFile() Option { + return option.New(optkeyForceNewFile, true) +} diff --git a/log/file-rotatelogs/rotatelogs.go b/log/file-rotatelogs/rotatelogs.go new file mode 100644 index 0000000..6f17a9d --- /dev/null +++ b/log/file-rotatelogs/rotatelogs.go @@ -0,0 +1,386 @@ +// package rotatelogs is a port of File-RotateLogs from Perl +// (https://metacpan.org/release/File-RotateLogs), and it allows +// you to automatically rotate output files when you write to them +// according to the filename pattern that you can specify. +package rotatelogs + +import ( + "fmt" + "github.com/openimsdk/tools/log/file-rotatelogs/internal/fileutil" + "io" + "os" + "path/filepath" + "regexp" + "strings" + "sync" + "time" + + strftime "github.com/lestrrat-go/strftime" + "github.com/pkg/errors" +) + +func (c clockFn) Now() time.Time { + return c() +} + +// New creates a new RotateLogs object. A log filename pattern +// must be passed. Optional `Option` parameters may be passed +func New(p string, options ...Option) (*RotateLogs, error) { + globPattern := p + for _, re := range patternConversionRegexps { + globPattern = re.ReplaceAllString(globPattern, "*") + } + + pattern, err := strftime.New(p) + if err != nil { + return nil, errors.Wrap(err, `invalid strftime pattern`) + } + + var clock Clock = Local + rotationTime := 24 * time.Hour + var rotationSize int64 + var rotationCount uint + var linkName string + var maxAge time.Duration + var handler Handler + var forceNewFile bool + + for _, o := range options { + switch o.Name() { + case optkeyClock: + clock = o.Value().(Clock) + case optkeyLinkName: + linkName = o.Value().(string) + case optkeyMaxAge: + maxAge = o.Value().(time.Duration) + if maxAge < 0 { + maxAge = 0 + } + case optkeyRotationTime: + rotationTime = o.Value().(time.Duration) + if rotationTime < 0 { + rotationTime = 0 + } + case optkeyRotationSize: + rotationSize = o.Value().(int64) + if rotationSize < 0 { + rotationSize = 0 + } + case optkeyRotationCount: + rotationCount = o.Value().(uint) + case optkeyHandler: + handler = o.Value().(Handler) + case optkeyForceNewFile: + forceNewFile = true + } + } + + if maxAge > 0 && rotationCount > 0 { + return nil, errors.New("options MaxAge and RotationCount cannot be both set") + } + + if maxAge == 0 && rotationCount == 0 { + // if both are 0, give maxAge a sane default + maxAge = 7 * 24 * time.Hour + } + + return &RotateLogs{ + clock: clock, + eventHandler: handler, + globPattern: globPattern, + linkName: linkName, + maxAge: maxAge, + pattern: pattern, + rotationTime: rotationTime, + rotationSize: rotationSize, + rotationCount: rotationCount, + forceNewFile: forceNewFile, + }, nil +} + +// Write satisfies the io.Writer interface. It writes to the +// appropriate file handle that is currently being used. +// If we have reached rotation time, the target file gets +// automatically rotated, and also purged if necessary. +func (rl *RotateLogs) Write(p []byte) (n int, err error) { + // Guard against concurrent writes + rl.mutex.Lock() + defer rl.mutex.Unlock() + + out, err := rl.getWriterNolock(false, false) + if err != nil { + return 0, errors.Wrap(err, `failed to acquite target io.Writer`) + } + + return out.Write(p) +} + +// must be locked during this operation +func (rl *RotateLogs) getWriterNolock(bailOnRotateFail, useGenerationalNames bool) (io.Writer, error) { + generation := rl.generation + previousFn := rl.curFn + + // This filename contains the name of the "NEW" filename + // to log to, which may be newer than rl.currentFilename + baseFn := fileutil.GenerateFn(rl.pattern, rl.clock, rl.rotationTime) + filename := baseFn + var forceNewFile bool + + fi, err := os.Stat(rl.curFn) + sizeRotation := false + if err == nil && rl.rotationSize > 0 && rl.rotationSize <= fi.Size() { + forceNewFile = true + sizeRotation = true + } + + if baseFn != rl.curBaseFn { + generation = 0 + // even though this is the first write after calling New(), + // check if a new file needs to be created + if rl.forceNewFile { + forceNewFile = true + } + } else { + if !useGenerationalNames && !sizeRotation { + // nothing to do + return rl.outFh, nil + } + forceNewFile = true + generation++ + } + if forceNewFile { + // A new file has been requested. Instead of just using the + // regular strftime pattern, we create a new file name using + // generational names such as "foo.1", "foo.2", "foo.3", etc + var name string + for { + if generation == 0 { + name = filename + } else { + name = fmt.Sprintf("%s.%d", filename, generation) + } + if _, err := os.Stat(name); err != nil { + filename = name + + break + } + generation++ + } + } + + fh, err := fileutil.CreateFile(filename) + if err != nil { + return nil, errors.Wrapf(err, `failed to create a new file %v`, filename) + } + + if err := rl.rotateNolock(filename); err != nil { + err = errors.Wrap(err, "failed to rotate") + if bailOnRotateFail { + // Failure to rotate is a problem, but it's really not a great + // idea to stop your application just because you couldn't rename + // your log. + // + // We only return this error when explicitly needed (as specified by bailOnRotateFail) + // + // However, we *NEED* to close `fh` here + if fh != nil { // probably can't happen, but being paranoid + fh.Close() + } + + return nil, err + } + fmt.Fprintf(os.Stderr, "%s\n", err.Error()) + } + + rl.outFh.Close() + rl.outFh = fh + rl.curBaseFn = baseFn + rl.curFn = filename + rl.generation = generation + + if h := rl.eventHandler; h != nil { + go h.Handle(&FileRotatedEvent{ + prev: previousFn, + current: filename, + }) + } + + return fh, nil +} + +// CurrentFileName returns the current file name that +// the RotateLogs object is writing to +func (rl *RotateLogs) CurrentFileName() string { + rl.mutex.RLock() + defer rl.mutex.RUnlock() + + return rl.curFn +} + +var patternConversionRegexps = []*regexp.Regexp{ + regexp.MustCompile(`%[%+A-Za-z]`), + regexp.MustCompile(`\*+`), +} + +type cleanupGuard struct { + enable bool + fn func() + mutex sync.Mutex +} + +func (g *cleanupGuard) Enable() { + g.mutex.Lock() + defer g.mutex.Unlock() + g.enable = true +} + +func (g *cleanupGuard) Run() { + g.fn() +} + +// Rotate forcefully rotates the log files. If the generated file name +// clash because file already exists, a numeric suffix of the form +// ".1", ".2", ".3" and so forth are appended to the end of the log file +// +// Thie method can be used in conjunction with a signal handler so to +// emulate servers that generate new log files when they receive a +// SIGHUP +func (rl *RotateLogs) Rotate() error { + rl.mutex.Lock() + defer rl.mutex.Unlock() + _, err := rl.getWriterNolock(true, true) + + return err +} + +func (rl *RotateLogs) rotateNolock(filename string) error { + lockfn := filename + `_lock` + fh, err := os.OpenFile(lockfn, os.O_CREATE|os.O_EXCL, 0644) + if err != nil { + // Can't lock, just return + return err + } + + var guard cleanupGuard + guard.fn = func() { + fh.Close() + os.Remove(lockfn) + } + defer guard.Run() + + if rl.linkName != "" { + tmpLinkName := filename + `_symlink` + + // Change how the link name is generated based on where the + // target location is. if the location is directly underneath + // the main filename's parent directory, then we create a + // symlink with a relative path + linkDest := filename + linkDir := filepath.Dir(rl.linkName) + + baseDir := filepath.Dir(filename) + if strings.Contains(rl.linkName, baseDir) { + tmp, err := filepath.Rel(linkDir, filename) + if err != nil { + return errors.Wrapf(err, `failed to evaluate relative path from %#v to %#v`, baseDir, rl.linkName) + } + + linkDest = tmp + } + + if err := os.Symlink(linkDest, tmpLinkName); err != nil { + return errors.Wrap(err, `failed to create new symlink`) + } + + // the directory where rl.linkName should be created must exist + _, err := os.Stat(linkDir) + if err != nil { // Assume err != nil means the directory doesn't exist + if err := os.MkdirAll(linkDir, 0755); err != nil { + return errors.Wrapf(err, `failed to create directory %s`, linkDir) + } + } + + if err := os.Rename(tmpLinkName, rl.linkName); err != nil { + return errors.Wrap(err, `failed to rename new symlink`) + } + } + + if rl.maxAge <= 0 && rl.rotationCount <= 0 { + return errors.New("panic: maxAge and rotationCount are both set") + } + + matches, err := filepath.Glob(rl.globPattern) + if err != nil { + return err + } + + cutoff := rl.clock.Now().Add(-1 * rl.maxAge) + + // the linter tells me to pre allocate this... + toUnlink := make([]string, 0, len(matches)) + for _, path := range matches { + // Ignore lock files + if strings.HasSuffix(path, "_lock") || strings.HasSuffix(path, "_symlink") { + continue + } + + fi, err := os.Stat(path) + if err != nil { + continue + } + + fl, err := os.Lstat(path) + if err != nil { + continue + } + + if rl.maxAge > 0 && fi.ModTime().After(cutoff) { + continue + } + + if rl.rotationCount > 0 && fl.Mode()&os.ModeSymlink == os.ModeSymlink { + continue + } + toUnlink = append(toUnlink, path) + } + + if rl.rotationCount > 0 { + // Only delete if we have more than rotationCount + if rl.rotationCount >= uint(len(toUnlink)) { + return nil + } + + toUnlink = toUnlink[:len(toUnlink)-int(rl.rotationCount)] + } + + if len(toUnlink) <= 0 { + return nil + } + + guard.Enable() + go func() { + // unlink files on a separate goroutine + for _, path := range toUnlink { + os.Remove(path) + } + }() + + return nil +} + +// Close satisfies the io.Closer interface. You must +// call this method if you performed any writes to +// the object. +func (rl *RotateLogs) Close() error { + rl.mutex.Lock() + defer rl.mutex.Unlock() + + if rl.outFh == nil { + return nil + } + + rl.outFh.Close() + rl.outFh = nil + + return nil +} diff --git a/log/file-rotatelogs/rotatelogs_test.go b/log/file-rotatelogs/rotatelogs_test.go new file mode 100644 index 0000000..055fd3a --- /dev/null +++ b/log/file-rotatelogs/rotatelogs_test.go @@ -0,0 +1,582 @@ +package rotatelogs_test + +import ( + "fmt" + "io" + "io/ioutil" + "log" + "os" + "path/filepath" + "strings" + "testing" + "time" + + "github.com/jonboulle/clockwork" + rotatelogs "github.com/lestrrat-go/file-rotatelogs" + "github.com/pkg/errors" + "github.com/stretchr/testify/assert" +) + +func TestSatisfiesIOWriter(t *testing.T) { + var w io.Writer + w, _ = rotatelogs.New("/foo/bar") + _ = w +} + +func TestSatisfiesIOCloser(t *testing.T) { + var c io.Closer + c, _ = rotatelogs.New("/foo/bar") + _ = c +} + +func TestLogRotate(t *testing.T) { + testCases := []struct { + Name string + FixArgs func([]rotatelogs.Option, string) []rotatelogs.Option + CheckExtras func(*testing.T, *rotatelogs.RotateLogs, string) bool + }{ + { + Name: "Basic Usage", + }, + { + Name: "With Symlink", + FixArgs: func(options []rotatelogs.Option, dir string) []rotatelogs.Option { + linkName := filepath.Join(dir, "log") + + return append(options, rotatelogs.WithLinkName(linkName)) + }, + CheckExtras: func(t *testing.T, rl *rotatelogs.RotateLogs, dir string) bool { + linkName := filepath.Join(dir, "log") + linkDest, err := os.Readlink(linkName) + if !assert.NoError(t, err, `os.Readlink(%#v) should succeed`, linkName) { + return false + } + + expectedLinkDest := filepath.Base(rl.CurrentFileName()) + t.Logf("expecting relative link: %s", expectedLinkDest) + + return assert.Equal(t, linkDest, expectedLinkDest, `Symlink destination should match expected filename (%#v != %#v)`, expectedLinkDest, linkDest) + }, + }, + { + Name: "With Symlink (multiple levels)", + FixArgs: func(options []rotatelogs.Option, dir string) []rotatelogs.Option { + linkName := filepath.Join(dir, "nest1", "nest2", "log") + + return append(options, rotatelogs.WithLinkName(linkName)) + }, + CheckExtras: func(t *testing.T, rl *rotatelogs.RotateLogs, dir string) bool { + linkName := filepath.Join(dir, "nest1", "nest2", "log") + linkDest, err := os.Readlink(linkName) + if !assert.NoError(t, err, `os.Readlink(%#v) should succeed`, linkName) { + return false + } + + expectedLinkDest := filepath.Join("..", "..", filepath.Base(rl.CurrentFileName())) + t.Logf("expecting relative link: %s", expectedLinkDest) + + return assert.Equal(t, linkDest, expectedLinkDest, `Symlink destination should match expected filename (%#v != %#v)`, expectedLinkDest, linkDest) + }, + }, + } + + for i, tc := range testCases { + i := i // avoid lint errors + tc := tc // avoid lint errors + t.Run(tc.Name, func(t *testing.T) { + dir, err := ioutil.TempDir("", fmt.Sprintf("file-rotatelogs-test%d", i)) + if !assert.NoError(t, err, "creating temporary directory should succeed") { + return + } + defer os.RemoveAll(dir) + + // Change current time, so we can safely purge old logs + dummyTime := time.Now().Add(-7 * 24 * time.Hour) + dummyTime = dummyTime.Add(time.Duration(-1 * dummyTime.Nanosecond())) + clock := clockwork.NewFakeClockAt(dummyTime) + + options := []rotatelogs.Option{rotatelogs.WithClock(clock), rotatelogs.WithMaxAge(24 * time.Hour)} + if fn := tc.FixArgs; fn != nil { + options = fn(options, dir) + } + + rl, err := rotatelogs.New(filepath.Join(dir, "log%Y%m%d%H%M%S"), options...) + if !assert.NoError(t, err, `rotatelogs.New should succeed`) { + return + } + defer rl.Close() + + str := "Hello, World" + n, err := rl.Write([]byte(str)) + if !assert.NoError(t, err, "rl.Write should succeed") { + return + } + + if !assert.Len(t, str, n, "rl.Write should succeed") { + return + } + + fn := rl.CurrentFileName() + if fn == "" { + t.Errorf("Could not get filename %s", fn) + } + + content, err := ioutil.ReadFile(fn) + if err != nil { + t.Errorf("Failed to read file %s: %s", fn, err) + } + + if string(content) != str { + t.Errorf(`File content does not match (was "%s")`, content) + } + + err = os.Chtimes(fn, dummyTime, dummyTime) + if err != nil { + t.Errorf("Failed to change access/modification times for %s: %s", fn, err) + } + + fi, err := os.Stat(fn) + if err != nil { + t.Errorf("Failed to stat %s: %s", fn, err) + } + + if !fi.ModTime().Equal(dummyTime) { + t.Errorf("Failed to chtime for %s (expected %s, got %s)", fn, fi.ModTime(), dummyTime) + } + + clock.Advance(7 * 24 * time.Hour) + + // This next Write() should trigger Rotate() + rl.Write([]byte(str)) + newfn := rl.CurrentFileName() + if newfn == fn { + t.Errorf(`New file name and old file name should not match ("%s" != "%s")`, fn, newfn) + } + + content, err = ioutil.ReadFile(newfn) + if err != nil { + t.Errorf("Failed to read file %s: %s", newfn, err) + } + + if string(content) != str { + t.Errorf(`File content does not match (was "%s")`, content) + } + + time.Sleep(time.Second) + + // fn was declared above, before mocking CurrentTime + // Old files should have been unlinked + _, err = os.Stat(fn) + if !assert.Error(t, err, "os.Stat should have failed") { + return + } + + if fn := tc.CheckExtras; fn != nil { + if !fn(t, rl, dir) { + return + } + } + }) + } +} + +func CreateRotationTestFile(dir string, base time.Time, d time.Duration, n int) { + timestamp := base + for i := 0; i < n; i++ { + // %Y%m%d%H%M%S + suffix := timestamp.Format("20060102150405") + path := filepath.Join(dir, "log"+suffix) + ioutil.WriteFile(path, []byte("rotation test file\n"), os.ModePerm) + os.Chtimes(path, timestamp, timestamp) + timestamp = timestamp.Add(d) + } +} + +func TestLogRotationCount(t *testing.T) { + dir, err := ioutil.TempDir("", "file-rotatelogs-rotationcount-test") + if !assert.NoError(t, err, "creating temporary directory should succeed") { + return + } + defer os.RemoveAll(dir) + + dummyTime := time.Now().Add(-7 * 24 * time.Hour) + dummyTime = dummyTime.Add(time.Duration(-1 * dummyTime.Nanosecond())) + clock := clockwork.NewFakeClockAt(dummyTime) + + t.Run("Either maxAge or rotationCount should be set", func(t *testing.T) { + rl, err := rotatelogs.New( + filepath.Join(dir, "log%Y%m%d%H%M%S"), + rotatelogs.WithClock(clock), + rotatelogs.WithMaxAge(time.Duration(0)), + rotatelogs.WithRotationCount(0), + ) + if !assert.NoError(t, err, `Both of maxAge and rotationCount is disabled`) { + return + } + defer rl.Close() + }) + + t.Run("Either maxAge or rotationCount should be set", func(t *testing.T) { + rl, err := rotatelogs.New( + filepath.Join(dir, "log%Y%m%d%H%M%S"), + rotatelogs.WithClock(clock), + rotatelogs.WithMaxAge(1), + rotatelogs.WithRotationCount(1), + ) + if !assert.Error(t, err, `Both of maxAge and rotationCount is enabled`) { + return + } + if rl != nil { + defer rl.Close() + } + }) + + t.Run("Only latest log file is kept", func(t *testing.T) { + rl, err := rotatelogs.New( + filepath.Join(dir, "log%Y%m%d%H%M%S"), + rotatelogs.WithClock(clock), + rotatelogs.WithMaxAge(-1), + rotatelogs.WithRotationCount(1), + ) + if !assert.NoError(t, err, `rotatelogs.New should succeed`) { + return + } + defer rl.Close() + + n, err := rl.Write([]byte("dummy")) + if !assert.NoError(t, err, "rl.Write should succeed") { + return + } + if !assert.Len(t, "dummy", n, "rl.Write should succeed") { + return + } + time.Sleep(time.Second) + files, _ := filepath.Glob(filepath.Join(dir, "log*")) + if !assert.Equal(t, 1, len(files), "Only latest log is kept") { + return + } + }) + + t.Run("Old log files are purged except 2 log files", func(t *testing.T) { + CreateRotationTestFile(dir, dummyTime, time.Hour, 5) + rl, err := rotatelogs.New( + filepath.Join(dir, "log%Y%m%d%H%M%S"), + rotatelogs.WithClock(clock), + rotatelogs.WithMaxAge(-1), + rotatelogs.WithRotationCount(2), + ) + if !assert.NoError(t, err, `rotatelogs.New should succeed`) { + return + } + defer rl.Close() + + n, err := rl.Write([]byte("dummy")) + if !assert.NoError(t, err, "rl.Write should succeed") { + return + } + if !assert.Len(t, "dummy", n, "rl.Write should succeed") { + return + } + time.Sleep(time.Second) + files, _ := filepath.Glob(filepath.Join(dir, "log*")) + if !assert.Equal(t, 2, len(files), "One file is kept") { + return + } + }) +} + +func TestLogSetOutput(t *testing.T) { + dir, err := ioutil.TempDir("", "file-rotatelogs-test") + if err != nil { + t.Errorf("Failed to create temporary directory: %s", err) + } + defer os.RemoveAll(dir) + + rl, err := rotatelogs.New(filepath.Join(dir, "log%Y%m%d%H%M%S")) + if !assert.NoError(t, err, `rotatelogs.New should succeed`) { + return + } + defer rl.Close() + + log.SetOutput(rl) + defer log.SetOutput(os.Stderr) + + str := "Hello, World" + log.Print(str) + + fn := rl.CurrentFileName() + if fn == "" { + t.Errorf("Could not get filename %s", fn) + } + + content, err := ioutil.ReadFile(fn) + if err != nil { + t.Errorf("Failed to read file %s: %s", fn, err) + } + + if !strings.Contains(string(content), str) { + t.Errorf(`File content does not contain "%s" (was "%s")`, str, content) + } +} + +func TestGHIssue16(t *testing.T) { + defer func() { + if v := recover(); v != nil { + assert.NoError(t, errors.Errorf("%s", v), "error should be nil") + } + }() + + dir, err := ioutil.TempDir("", "file-rotatelogs-gh16") + if !assert.NoError(t, err, `creating temporary directory should succeed`) { + return + } + defer os.RemoveAll(dir) + + rl, err := rotatelogs.New( + filepath.Join(dir, "log%Y%m%d%H%M%S"), + rotatelogs.WithLinkName("./test.log"), + rotatelogs.WithRotationTime(10*time.Second), + rotatelogs.WithRotationCount(3), + rotatelogs.WithMaxAge(-1), + ) + if !assert.NoError(t, err, `rotatelogs.New should succeed`) { + return + } + + if !assert.NoError(t, rl.Rotate(), "rl.Rotate should succeed") { + return + } + defer rl.Close() +} + +func TestRotationGenerationalNames(t *testing.T) { + dir, err := ioutil.TempDir("", "file-rotatelogs-generational") + if !assert.NoError(t, err, `creating temporary directory should succeed`) { + return + } + defer os.RemoveAll(dir) + + t.Run("Rotate over unchanged pattern", func(t *testing.T) { + rl, err := rotatelogs.New( + filepath.Join(dir, "unchanged-pattern.log"), + ) + if !assert.NoError(t, err, `rotatelogs.New should succeed`) { + return + } + + seen := map[string]struct{}{} + for i := 0; i < 10; i++ { + rl.Write([]byte("Hello, World!")) + if !assert.NoError(t, rl.Rotate(), "rl.Rotate should succeed") { + return + } + + // Because every call to Rotate should yield a new log file, + // and the previous files already exist, the filenames should share + // the same prefix and have a unique suffix + fn := filepath.Base(rl.CurrentFileName()) + if !assert.True(t, strings.HasPrefix(fn, "unchanged-pattern.log"), "prefix for all filenames should match") { + return + } + rl.Write([]byte("Hello, World!")) + suffix := strings.TrimPrefix(fn, "unchanged-pattern.log") + expectedSuffix := fmt.Sprintf(".%d", i+1) + if !assert.True(t, suffix == expectedSuffix, "expected suffix %s found %s", expectedSuffix, suffix) { + return + } + assert.FileExists(t, rl.CurrentFileName(), "file does not exist %s", rl.CurrentFileName()) + stat, err := os.Stat(rl.CurrentFileName()) + if err == nil { + if !assert.True(t, stat.Size() == 13, "file %s size is %d, expected 13", rl.CurrentFileName(), stat.Size()) { + return + } + } else { + assert.Failf(t, "could not stat file %s", rl.CurrentFileName()) + + return + } + + if _, ok := seen[suffix]; !assert.False(t, ok, `filename suffix %s should be unique`, suffix) { + return + } + seen[suffix] = struct{}{} + } + defer rl.Close() + }) + t.Run("Rotate over pattern change over every second", func(t *testing.T) { + rl, err := rotatelogs.New( + filepath.Join(dir, "every-second-pattern-%Y%m%d%H%M%S.log"), + rotatelogs.WithRotationTime(time.Nanosecond), + ) + if !assert.NoError(t, err, `rotatelogs.New should succeed`) { + return + } + + for i := 0; i < 10; i++ { + time.Sleep(time.Second) + rl.Write([]byte("Hello, World!")) + if !assert.NoError(t, rl.Rotate(), "rl.Rotate should succeed") { + return + } + + // because every new Write should yield a new logfile, + // every rorate should be create a filename ending with a .1 + if !assert.True(t, strings.HasSuffix(rl.CurrentFileName(), ".1"), "log name should end with .1") { + return + } + } + defer rl.Close() + }) +} + +type ClockFunc func() time.Time + +func (f ClockFunc) Now() time.Time { + return f() +} + +func TestGHIssue23(t *testing.T) { + dir, err := ioutil.TempDir("", "file-rotatelogs-generational") + if !assert.NoError(t, err, `creating temporary directory should succeed`) { + return + } + defer os.RemoveAll(dir) + + for _, locName := range []string{"Asia/Tokyo", "Pacific/Honolulu"} { + locName := locName + loc, _ := time.LoadLocation(locName) + tests := []struct { + Expected string + Clock rotatelogs.Clock + }{ + { + Expected: filepath.Join(dir, strings.ToLower(strings.Replace(locName, "/", "_", -1))+".201806010000.log"), + Clock: ClockFunc(func() time.Time { + return time.Date(2018, 6, 1, 3, 18, 0, 0, loc) + }), + }, + { + Expected: filepath.Join(dir, strings.ToLower(strings.Replace(locName, "/", "_", -1))+".201712310000.log"), + Clock: ClockFunc(func() time.Time { + return time.Date(2017, 12, 31, 23, 52, 0, 0, loc) + }), + }, + } + for _, test := range tests { + test := test + t.Run(fmt.Sprintf("location = %s, time = %s", locName, test.Clock.Now().Format(time.RFC3339)), func(t *testing.T) { + template := strings.ToLower(strings.Replace(locName, "/", "_", -1)) + ".%Y%m%d%H%M.log" + rl, err := rotatelogs.New( + filepath.Join(dir, template), + rotatelogs.WithClock(test.Clock), // we're not using WithLocation, but it's the same thing + ) + if !assert.NoError(t, err, "rotatelogs.New should succeed") { + return + } + + t.Logf("expected %s", test.Expected) + rl.Rotate() + if !assert.Equal(t, test.Expected, rl.CurrentFileName(), "file names should match") { + return + } + }) + } + } +} + +func TestForceNewFile(t *testing.T) { + dir, err := ioutil.TempDir("", "file-rotatelogs-force-new-file") + if !assert.NoError(t, err, `creating temporary directory should succeed`) { + return + } + defer os.RemoveAll(dir) + + t.Run("Force a new file", func(t *testing.T) { + rl, err := rotatelogs.New( + filepath.Join(dir, "force-new-file.log"), + rotatelogs.ForceNewFile(), + ) + if !assert.NoError(t, err, "rotatelogs.New should succeed") { + return + } + rl.Write([]byte("Hello, World!")) + rl.Close() + + for i := 0; i < 10; i++ { + baseFn := filepath.Join(dir, "force-new-file.log") + rl, err := rotatelogs.New( + baseFn, + rotatelogs.ForceNewFile(), + ) + if !assert.NoError(t, err, "rotatelogs.New should succeed") { + return + } + rl.Write([]byte("Hello, World")) + rl.Write([]byte(fmt.Sprintf("%d", i))) + rl.Close() + + fn := filepath.Base(rl.CurrentFileName()) + suffix := strings.TrimPrefix(fn, "force-new-file.log") + expectedSuffix := fmt.Sprintf(".%d", i+1) + if !assert.True(t, suffix == expectedSuffix, "expected suffix %s found %s", expectedSuffix, suffix) { + return + } + assert.FileExists(t, rl.CurrentFileName(), "file does not exist %s", rl.CurrentFileName()) + content, err := ioutil.ReadFile(rl.CurrentFileName()) + if !assert.NoError(t, err, "ioutil.ReadFile %s should succeed", rl.CurrentFileName()) { + return + } + str := fmt.Sprintf("Hello, World%d", i) + if !assert.Equal(t, str, string(content), "read %s from file %s, not expected %s", string(content), rl.CurrentFileName(), str) { + return + } + + assert.FileExists(t, baseFn, "file does not exist %s", baseFn) + content, err = ioutil.ReadFile(baseFn) + if !assert.NoError(t, err, "ioutil.ReadFile should succeed") { + return + } + if !assert.Equal(t, "Hello, World!", string(content), "read %s from file %s, not expected Hello, World!", string(content), baseFn) { + return + } + } + }) + + t.Run("Force a new file with Rotate", func(t *testing.T) { + baseFn := filepath.Join(dir, "force-new-file-rotate.log") + rl, err := rotatelogs.New( + baseFn, + rotatelogs.ForceNewFile(), + ) + if !assert.NoError(t, err, "rotatelogs.New should succeed") { + return + } + rl.Write([]byte("Hello, World!")) + + for i := 0; i < 10; i++ { + if !assert.NoError(t, rl.Rotate(), "rl.Rotate should succeed") { + return + } + rl.Write([]byte("Hello, World")) + rl.Write([]byte(fmt.Sprintf("%d", i))) + assert.FileExists(t, rl.CurrentFileName(), "file does not exist %s", rl.CurrentFileName()) + content, err := ioutil.ReadFile(rl.CurrentFileName()) + if !assert.NoError(t, err, "ioutil.ReadFile %s should succeed", rl.CurrentFileName()) { + return + } + str := fmt.Sprintf("Hello, World%d", i) + if !assert.Equal(t, str, string(content), "read %s from file %s, not expected %s", string(content), rl.CurrentFileName(), str) { + return + } + + assert.FileExists(t, baseFn, "file does not exist %s", baseFn) + content, err = ioutil.ReadFile(baseFn) + if !assert.NoError(t, err, "ioutil.ReadFile should succeed") { + return + } + if !assert.Equal(t, "Hello, World!", string(content), "read %s from file %s, not expected Hello, World!", string(content), baseFn) { + return + } + } + }) +} From 916967f5c3c0c32d6e2064e326609a358c6d3f28 Mon Sep 17 00:00:00 2001 From: icey-yu <1186114839@qq.com> Date: Sun, 21 Jul 2024 10:01:32 +0800 Subject: [PATCH 3/3] fix: log --- go.mod | 10 ++++++---- go.sum | 1 - log/file-rotatelogs/rotatelogs.go | 3 +-- log/zap.go | 2 +- 4 files changed, 8 insertions(+), 8 deletions(-) diff --git a/go.mod b/go.mod index a3d4cae..60132dd 100644 --- a/go.mod +++ b/go.mod @@ -30,7 +30,6 @@ require ( github.com/golang-jwt/jwt/v4 v4.5.0 github.com/google/uuid v1.6.0 github.com/jinzhu/copier v0.4.0 - github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible github.com/magefile/mage v1.15.0 github.com/minio/minio-go/v7 v7.0.69 github.com/openimsdk/protocol v0.0.69-alpha.4 @@ -66,7 +65,7 @@ require ( github.com/jcmturner/rpc/v2 v2.0.3 // indirect github.com/jinzhu/inflection v1.0.0 // indirect github.com/jinzhu/now v1.1.5 // indirect - github.com/jonboulle/clockwork v0.4.0 // indirect + github.com/jonboulle/clockwork v0.4.0 github.com/pierrec/lz4/v4 v4.1.21 // indirect github.com/rcrowley/go-metrics v0.0.0-20201227073835-cf1acfcdf475 // indirect github.com/rogpeppe/go-internal v1.11.0 // indirect @@ -74,6 +73,11 @@ require ( gopkg.in/yaml.v3 v3.0.1 ) +require ( + github.com/lestrrat-go/file-rotatelogs v2.4.0+incompatible + github.com/lestrrat-go/strftime v1.0.6 +) + require ( github.com/bytedance/sonic v1.9.1 // indirect github.com/cespare/xxhash/v2 v2.2.0 // indirect @@ -102,7 +106,6 @@ require ( github.com/klauspost/cpuid/v2 v2.2.6 // indirect github.com/kr/pretty v0.3.1 // indirect github.com/leodido/go-urn v1.2.4 // indirect - github.com/lestrrat-go/strftime v1.0.6 // indirect github.com/mattn/go-isatty v0.0.19 // indirect github.com/minio/md5-simd v1.1.2 // indirect github.com/minio/sha256-simd v1.0.1 // indirect @@ -142,7 +145,6 @@ require ( google.golang.org/genproto v0.0.0-20240123012728-ef4313101c80 // indirect google.golang.org/genproto/googleapis/api v0.0.0-20240123012728-ef4313101c80 // indirect gopkg.in/ini.v1 v1.67.0 // indirect - gopkg.in/natefinch/lumberjack.v2 v2.2.1 // indirect gopkg.in/src-d/go-billy.v4 v4.3.2 // indirect gopkg.in/warnings.v0 v0.1.2 // indirect ) diff --git a/go.sum b/go.sum index 17c1691..99e2c62 100644 --- a/go.sum +++ b/go.sum @@ -417,7 +417,6 @@ gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EV gopkg.in/errgo.v2 v2.1.0/go.mod h1:hNsd1EY+bozCKY1Ytp96fpM3vjJbqLJn88ws8XvfDNI= gopkg.in/ini.v1 v1.67.0 h1:Dgnx+6+nfE+IfzjUEISNeydPJh9AXNNsWbGP9KzCsOA= gopkg.in/ini.v1 v1.67.0/go.mod h1:pNLf8WUiyNEtQjuu5G5vTm06TEv9tsIgeAvK8hOrP4k= -gopkg.in/natefinch/lumberjack.v2 v2.2.1/go.mod h1:YD8tP3GAjkrDg1eZH7EGmyESg/lsYskCTPBJVb9jqSc= gopkg.in/src-d/go-billy.v4 v4.3.2 h1:0SQA1pRztfTFx2miS8sA97XvooFeNOmvUenF4o0EcVg= gopkg.in/src-d/go-billy.v4 v4.3.2/go.mod h1:nDjArDMp+XMs1aFAESLRjfGSgfvoYN0hDfzEk0GjC98= gopkg.in/src-d/go-git-fixtures.v3 v3.5.0 h1:ivZFOIltbce2Mo8IjzUHAFoq/IylO9WHhNOAJK+LsJg= diff --git a/log/file-rotatelogs/rotatelogs.go b/log/file-rotatelogs/rotatelogs.go index 6f17a9d..3c4f282 100644 --- a/log/file-rotatelogs/rotatelogs.go +++ b/log/file-rotatelogs/rotatelogs.go @@ -173,7 +173,7 @@ func (rl *RotateLogs) getWriterNolock(bailOnRotateFail, useGenerationalNames boo return nil, errors.Wrapf(err, `failed to create a new file %v`, filename) } - if err := rl.rotateNolock(filename); err != nil { + if err := rl.rotateNolock(filename); err != nil && errors.Is(err, errors.New("The file exists")) { err = errors.Wrap(err, "failed to rotate") if bailOnRotateFail { // Failure to rotate is a problem, but it's really not a great @@ -186,7 +186,6 @@ func (rl *RotateLogs) getWriterNolock(bailOnRotateFail, useGenerationalNames boo if fh != nil { // probably can't happen, but being paranoid fh.Close() } - return nil, err } fmt.Fprintf(os.Stderr, "%s\n", err.Error()) diff --git a/log/zap.go b/log/zap.go index 0745273..3fbd3b3 100644 --- a/log/zap.go +++ b/log/zap.go @@ -17,12 +17,12 @@ package log import ( "context" "fmt" + rotatelogs "github.com/openimsdk/tools/log/file-rotatelogs" "github.com/openimsdk/tools/utils/stringutil" "os" "path/filepath" "time" - rotatelogs "github.com/lestrrat-go/file-rotatelogs" "github.com/openimsdk/protocol/constant" "github.com/openimsdk/tools/mcontext" "go.uber.org/zap"