From 4912331ddc2fe46d70540d0674e2c3c6c6384099 Mon Sep 17 00:00:00 2001 From: John Date: Thu, 26 Mar 2020 09:29:36 +0800 Subject: [PATCH] improve mtime feature for gfile; improve rotation feature for glog --- os/gfile/gfile_time.go | 28 ++++++++----- os/gfile/gfile_z_time_test.go | 8 ++-- os/glog/glog_logger_rotate.go | 64 +++++++++++++++--------------- os/glog/glog_z_unit_rotate_test.go | 47 +++++++++++++++++++++- 4 files changed, 101 insertions(+), 46 deletions(-) diff --git a/os/gfile/gfile_time.go b/os/gfile/gfile_time.go index 8cacb7677..80b4b3754 100644 --- a/os/gfile/gfile_time.go +++ b/os/gfile/gfile_time.go @@ -8,22 +8,32 @@ package gfile import ( "os" + "time" ) // MTime returns the modification time of file given by in second. -func MTime(path string) int64 { +func MTime(path string) time.Time { s, e := os.Stat(path) if e != nil { - return 0 + return time.Time{} } - return s.ModTime().Unix() + return s.ModTime() } -// MTimeMillisecond returns the modification time of file given by in millisecond. -func MTimeMillisecond(path string) int64 { - s, e := os.Stat(path) - if e != nil { - return 0 +// MTimestamp returns the modification time of file given by in second. +func MTimestamp(path string) int64 { + mtime := MTime(path) + if mtime.IsZero() { + return -1 } - return s.ModTime().UnixNano() / 1000000 + return mtime.Unix() +} + +// MTimestampMilli returns the modification time of file given by in millisecond. +func MTimestampMilli(path string) int64 { + mtime := MTime(path) + if mtime.IsZero() { + return -1 + } + return mtime.UnixNano() / 1000000 } diff --git a/os/gfile/gfile_z_time_test.go b/os/gfile/gfile_z_time_test.go index 06508a610..37dfaf87e 100644 --- a/os/gfile/gfile_z_time_test.go +++ b/os/gfile/gfile_z_time_test.go @@ -29,8 +29,8 @@ func Test_MTime(t *testing.T) { fileobj, err = os.Stat(testpath() + file1) t.Assert(err, nil) - t.Assert(gfile.MTime(testpath()+file1), fileobj.ModTime().Unix()) - t.Assert(gfile.MTime(""), 0) + t.Assert(gfile.MTime(testpath()+file1), fileobj.ModTime()) + t.Assert(gfile.MTime(""), "") }) } @@ -49,9 +49,9 @@ func Test_MTimeMillisecond(t *testing.T) { time.Sleep(time.Millisecond * 100) t.AssertGE( - gfile.MTimeMillisecond(testpath()+file1), + gfile.MTimestampMilli(testpath()+file1), fileobj.ModTime().UnixNano()/1000000, ) - t.Assert(gfile.MTimeMillisecond(""), 0) + t.Assert(gfile.MTimestampMilli(""), -1) }) } diff --git a/os/glog/glog_logger_rotate.go b/os/glog/glog_logger_rotate.go index ba0c1042b..9e2f3caa4 100644 --- a/os/glog/glog_logger_rotate.go +++ b/os/glog/glog_logger_rotate.go @@ -31,7 +31,7 @@ func (l *Logger) rotateFileBySize(now time.Time) { } } -// doRotateFile rotates the current logging file. +// doRotateFile rotates the given logging file. func (l *Logger) doRotateFile(filePath string) error { // No backups, it then just removes the current logging file. if l.config.RotateBackLimit == 0 { @@ -77,29 +77,30 @@ func (l *Logger) rotateChecksTimely() { // ============================================================= // Rotation expire file checks. // ============================================================= - rotateExpireFileArray := garray.NewStrArray() if l.config.RotateExpire > 0 { + var ( + mtime time.Time + subDuration time.Duration + expireRotated bool + ) for _, file := range files { if gfile.ExtName(file) == "gz" { continue } - stat, err := gfile.Stat(file) - if err != nil { - intlog.Error(err) - continue - } - if now.Sub(stat.ModTime()) > l.config.RotateExpire { - intlog.Printf(`rotation expire logging file: %s`, file) - rotateExpireFileArray.Append(file) - } - } - if rotateExpireFileArray.Len() > 0 { - rotateExpireFileArray.Iterator(func(_ int, path string) bool { - if err := l.doRotateFile(path); err != nil { + mtime = gfile.MTime(file) + subDuration = now.Sub(mtime) + if subDuration > l.config.RotateExpire { + expireRotated = true + intlog.Printf( + `%v - %v = %v > %v, rotation expire logging file: %s`, + now, mtime, subDuration, l.config.RotateExpire, file, + ) + if err := l.doRotateFile(file); err != nil { intlog.Error(err) } - return true - }) + } + } + if expireRotated { // Update the files array. files, _ = gfile.ScanDirFile(l.config.Path, pattern, true) } @@ -152,17 +153,18 @@ func (l *Logger) rotateChecksTimely() { originalLoggingFilePath, _ = gregex.ReplaceString(`\.\d{14,}`, "", file) if backupFilesMap[originalLoggingFilePath] == nil { backupFilesMap[originalLoggingFilePath] = garray.NewSortedArray(func(a, b interface{}) int { - // Sorted by backup file mtime. - // The old backup file is put in the head of array. + // Sorted by rotated/backup file mtime. + // The old rotated/backup file is put in the head of array. file1 := a.(string) file2 := b.(string) - result := gfile.MTimeMillisecond(file1) - gfile.MTimeMillisecond(file2) + result := gfile.MTimestampMilli(file1) - gfile.MTimestampMilli(file2) if result <= 0 { return -1 } return 1 }) } + // Check if this file a rotated/backup file. if gregex.IsMatchString(`.+\.\d{14,}`, gfile.Name(file)) { backupFilesMap[originalLoggingFilePath].Add(file) } @@ -178,23 +180,21 @@ func (l *Logger) rotateChecksTimely() { } } } - // Expiration checks. + // Backup expiration checks. if l.config.RotateBackExpire > 0 { - nowTimestampMilli := gtime.TimestampMilli() - // As for Golang version < 1.13, there's no method Milliseconds for time.Duration. - // So we need calculate the milliseconds using its nanoseconds value. - expireMillisecond := l.config.RotateBackExpire.Nanoseconds() / 1000000 + var ( + mtime time.Time + subDuration time.Duration + ) for _, array := range backupFilesMap { array.Iterator(func(_ int, v interface{}) bool { path := v.(string) - mtime := gfile.MTimeMillisecond(path) - differ := nowTimestampMilli - mtime - if differ > expireMillisecond { + mtime = gfile.MTime(path) + subDuration = now.Sub(mtime) + if subDuration > l.config.RotateBackExpire { intlog.Printf( - `%d - %d = %d > %d, remove expired backup file: %s`, - nowTimestampMilli, mtime, differ, - expireMillisecond, - path, + `%v - %v = %v > %v, remove expired backup file: %s`, + now, mtime, subDuration, l.config.RotateBackExpire, path, ) if err := gfile.Remove(path); err != nil { intlog.Print(err) diff --git a/os/glog/glog_z_unit_rotate_test.go b/os/glog/glog_z_unit_rotate_test.go index d706d58d6..b14859fba 100644 --- a/os/glog/glog_z_unit_rotate_test.go +++ b/os/glog/glog_z_unit_rotate_test.go @@ -17,7 +17,8 @@ import ( "time" ) -func Test_Rotate(t *testing.T) { +func Test_Rotate_Size(t *testing.T) { + t.Parallel() gtest.C(t, func(t *gtest.T) { l := glog.New() p := gfile.Join(gfile.TempDir(), gtime.TimestampNanoStr()) @@ -54,3 +55,47 @@ func Test_Rotate(t *testing.T) { t.Assert(len(files), 0) }) } + +func Test_Rotate_Expire(t *testing.T) { + t.Parallel() + gtest.C(t, func(t *gtest.T) { + l := glog.New() + p := gfile.Join(gfile.TempDir(), gtime.TimestampNanoStr()) + err := l.SetConfigWithMap(g.Map{ + "Path": p, + "File": "access.log", + "StdoutPrint": false, + "RotateExpire": time.Second, + "RotateBackLimit": 2, + "RotateBackExpire": 5 * time.Second, + "RotateBackCompress": 9, + "RotateInterval": time.Second, // For unit testing only. + }) + t.Assert(err, nil) + defer gfile.Remove(p) + + s := "1234567890abcdefg" + for i := 0; i < 10; i++ { + l.Print(s) + } + + files, err := gfile.ScanDirFile(p, "*.gz") + t.Assert(err, nil) + t.Assert(len(files), 0) + + t.Assert(gstr.Count(gfile.GetContents(gfile.Join(p, "access.log")), s), 10) + + time.Sleep(time.Second * 3) + + files, err = gfile.ScanDirFile(p, "*.gz") + t.Assert(err, nil) + t.Assert(len(files), 1) + + t.Assert(gstr.Count(gfile.GetContents(gfile.Join(p, "access.log")), s), 0) + + time.Sleep(time.Second * 5) + files, err = gfile.ScanDirFile(p, "*.gz") + t.Assert(err, nil) + t.Assert(len(files), 0) + }) +}