Merge pull request #4890 from adsr/patch-purge-mtime

Add `-keep_logs_by_mtime` flag for purging old log files by mtime instead of ctime + bugfix

go/vt/logutil/logutil_test.go

@@ -32,7 +32,7 @@ func TestParsing(t *testing.T) {
  "/tmp/something.foo/zkocc.goedel.szopa.test.log.ERROR.20130806-151006.10530"}
 
  for _, filepath := range path {
- ts, err := parseTimestamp(filepath)
+ ts, err := parseCreatedTimestamp(filepath)
  if err != nil {
  t.Fatalf("parse: %v", err)
  }
@@ -43,7 +43,7 @@ func TestParsing(t *testing.T) {
  }
 }
 
-func TestPurge(t *testing.T) {
+func TestPurgeByCtime(t *testing.T) {
  logDir := path.Join(os.TempDir(), fmt.Sprintf("%v-%v", os.Args[0], os.Getpid()))
  if err := os.MkdirAll(logDir, 0777); err != nil {
  t.Fatalf("os.MkdirAll: %v", err)
@@ -67,18 +67,69 @@ func TestPurge(t *testing.T) {
  t.Fatalf("os.Symlink: %v", err)
  }
 
- purgeLogsOnce(now, logDir, "zkocc", 30*time.Minute)
+ purgeLogsOnce(now, logDir, "zkocc", 30*time.Minute, 0)
 
  left, err := filepath.Glob(path.Join(logDir, "zkocc.*"))
  if err != nil {
  t.Fatalf("filepath.Glob: %v", err)
  }
 
- if len(left) != 2 {
- // 151006 is still good, 131006 is the "current" log
- // (symlinked to zkocc.INFO), the rest should be
- // removed.
- t.Errorf("wrong number of files remain: want %v, got %v", 2, len(left))
+ if len(left) != 3 {
+ // 131006 is current
+ // 151006 is within 30 min
+ // symlink remains
+ // the rest should be removed.
+ t.Errorf("wrong number of files remain: want %v, got %v", 3, len(left))
  }
+}
+
+func TestPurgeByMtime(t *testing.T) {
+ logDir := path.Join(os.TempDir(), fmt.Sprintf("%v-%v", os.Args[0], os.Getpid()))
+ if err := os.MkdirAll(logDir, 0777); err != nil {
+ t.Fatalf("os.MkdirAll: %v", err)
+ }
+ defer os.RemoveAll(logDir)
+ createFileWithMtime := func(filename, mtimeStr string) {
+ var err error
+ var mtime time.Time
+ filepath := path.Join(logDir, filename)
+ if mtime, err = time.Parse(time.RFC3339, mtimeStr); err != nil {
+ t.Fatalf("time.Parse: %v", err)
+ }
+ if _, err = os.Create(filepath); err != nil {
+ t.Fatalf("os.Create: %v", err)
+ }
+ if err = os.Chtimes(filepath, mtime, mtime); err != nil {
+ t.Fatalf("os.Chtimes: %v", err)
+ }
+ }
+ now := time.Date(2020, 1, 1, 12, 15, 0, 0, time.UTC)
+ filenameMtimeMap := map[string]string{
+ "vtadam.localhost.vitess.log.INFO.20200101-120000.00000": "2020-01-01T12:00:00.000Z",
+ "vtadam.localhost.vitess.log.INFO.20200101-113000.00000": "2020-01-01T11:30:00.000Z",
+ "vtadam.localhost.vitess.log.INFO.20200101-100000.00000": "2020-01-01T10:00:00.000Z",
+ "vtadam.localhost.vitess.log.INFO.20200101-090000.00000": "2020-01-01T09:00:00.000Z",
+ "vtadam.localhost.vitess.log.INFO.20200101-080000.00000": "2020-01-01T08:00:00.000Z",
+ }
+ for filename, mtimeStr := range filenameMtimeMap {
+ createFileWithMtime(filename, mtimeStr)
+ }
+ if err := os.Symlink("vtadam.localhost.vitess.log.INFO.20200101-120000.00000", path.Join(logDir, "vtadam.INFO")); err != nil {
+ t.Fatalf("os.Symlink: %v", err)
+ }
+
+ purgeLogsOnce(now, logDir, "vtadam", 0, 1*time.Hour)
 
+ left, err := filepath.Glob(path.Join(logDir, "vtadam.*"))
+ if err != nil {
+ t.Fatalf("filepath.Glob: %v", err)
+ }
+
+ if len(left) != 3 {
+ // 20200101-120000 is current
+ // 20200101-113000 is within 1 hour
+ // symlink remains
+ // rest are removed
+ t.Errorf("wrong number of files remain: want %v, got %v", 3, len(left))
+ }
 }

go/vt/logutil/purge.go

@@ -27,13 +27,14 @@ import (
 )
 
 var (
- keepLogs = flag.Duration("keep_logs", 0*time.Second, "keep logs for this long (zero to keep forever)")
+ keepLogsByCtime = flag.Duration("keep_logs", 0, "keep logs for this long (using ctime) (zero to keep forever)")
+ keepLogsByMtime = flag.Duration("keep_logs_by_mtime", 0, "keep logs for this long (using mtime) (zero to keep forever)")
  purgeLogsInterval = flag.Duration("purge_logs_interval", 1*time.Hour, "how often try to remove old logs")
 )
 
 // parse parses a file name (as used by glog) and returns its process
 // name and timestamp.
-func parseTimestamp(filename string) (timestamp time.Time, err error) {
+func parseCreatedTimestamp(filename string) (timestamp time.Time, err error) {
  parts := strings.Split(filepath.Base(filename), ".")
  if len(parts) < 6 {
  return time.Time{}, fmt.Errorf("malformed logfile name: %v", filename)
@@ -42,14 +43,22 @@ func parseTimestamp(filename string) (timestamp time.Time, err error) {
 
 }
 
+func getModifiedTimestamp(filename string) (timestamp time.Time, err error) {
+ fileInfo, err := os.Stat(filename)
+ if err != nil {
+ return time.Time{}, err
+ }
+ return fileInfo.ModTime(), nil
+}
+
 var levels = []string{"INFO", "ERROR", "WARNING", "FATAL"}
 
 // purgeLogsOnce removes logfiles for program for dir, if their age
-// relative to now is greater than keep.
-func purgeLogsOnce(now time.Time, dir, program string, keep time.Duration) {
+// relative to now is greater than [cm]timeDelta
+func purgeLogsOnce(now time.Time, dir, program string, ctimeDelta time.Duration, mtimeDelta time.Duration) {
  current := make(map[string]bool)
  for _, level := range levels {
- c, err := os.Readlink(path.Join(dir, fmt.Sprintf("%s.%s", program, level)))
+ c, err := filepath.EvalSymlinks(path.Join(dir, fmt.Sprintf("%s.%s", program, level)))
  if err != nil {
  continue
  }
@@ -64,11 +73,22 @@ func purgeLogsOnce(now time.Time, dir, program string, keep time.Duration) {
  if current[file] {
  continue
  }
- created, err := parseTimestamp(file)
- if err != nil {
- continue
+ purgeFile := false
+ if ctimeDelta != 0 {
+ createdTs, err := parseCreatedTimestamp(file)
+ if err != nil {
+ continue
+ }
+ purgeFile = purgeFile || now.Sub(createdTs) > ctimeDelta
+ }
+ if mtimeDelta != 0 {
+ modifiedTs, err := getModifiedTimestamp(file)
+ if err != nil {
+ continue
+ }
+ purgeFile = purgeFile || now.Sub(modifiedTs) > mtimeDelta
  }
- if now.Sub(created) > keep {
+ if purgeFile {
  os.Remove(file)
  }
  }
@@ -81,15 +101,13 @@ func PurgeLogs() {
  if f == nil {
  panic("the logging module doesn't specify a log_dir flag")
  }
-
- if *keepLogs == 0*time.Second {
+ if *keepLogsByCtime == 0 && *keepLogsByMtime == 0 {
  return
  }
  logDir := f.Value.String()
  program := filepath.Base(os.Args[0])
-
  timer := time.NewTimer(*purgeLogsInterval)
  for range timer.C {
- purgeLogsOnce(time.Now(), logDir, program, *keepLogs)
+ purgeLogsOnce(time.Now(), logDir, program, *keepLogsByCtime, *keepLogsByMtime)
  }
 }