diff --git a/go/vt/logutil/logutil_test.go b/go/vt/logutil/logutil_test.go index 4b0e6b54ee2..bd7f79f23a6 100644 --- a/go/vt/logutil/logutil_test.go +++ b/go/vt/logutil/logutil_test.go @@ -43,7 +43,7 @@ func TestParsing(t *testing.T) { } } -func TestPurge(t *testing.T) { +func TestPurgeByTimestamp(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,7 +67,7 @@ func TestPurge(t *testing.T) { t.Fatalf("os.Symlink: %v", err) } - purgeLogsOnce(now, logDir, "zkocc", 30*time.Minute) + purgeLogsByTimestamp(now, logDir, "zkocc", 30*time.Minute) left, err := filepath.Glob(path.Join(logDir, "zkocc.*")) if err != nil { @@ -82,3 +82,72 @@ func TestPurge(t *testing.T) { } } + +func TestPurgeByIndex(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) + + files := []string{ + "vtadam.localhost.vitess.log.INFO.20200104-000000.00000", + "vtadam.localhost.vitess.log.INFO.20200103-000000.00000", + "vtadam.localhost.vitess.log.INFO.20200102-000000.00000", + "vtadam.localhost.vitess.log.INFO.20200101-000000.00000", + "vtadam.localhost.vitess.log.ERROR.20200104-000000.00000", + "vtadam.localhost.vitess.log.ERROR.20200103-000000.00000", + "vtadam.localhost.vitess.log.ERROR.20200102-000000.00000", + "vtadam.localhost.vitess.log.ERROR.20200101-000000.00000", + } + + for _, file := range files { + if _, err := os.Create(path.Join(logDir, file)); err != nil { + t.Fatalf("os.Create: %v", err) + } + } + if err := os.Symlink(files[0], path.Join(logDir, "vtadam.INFO")); err != nil { + // vtadam.INFO -> vtadam.localhost.vitess.log.INFO.20200104-000000.00000 + t.Fatalf("os.Symlink: %v", err) + } + if err := os.Symlink(files[4], path.Join(logDir, "vtadam.ERROR")); err != nil { + // vtadam.ERROR -> vtadam.localhost.vitess.log.ERROR.20200104-000000.00000 + t.Fatalf("os.Symlink: %v", err) + } + + purgeLogsByIndex(logDir, "vtadam", 3) + + remaining, err := filepath.Glob(path.Join(logDir, "vtadam.*")) + if err != nil { + t.Fatalf("filepath.Glob: %v", err) + } + + expectedRemainingLogs := map[string]bool{ + path.Join(logDir, files[0]): true, + path.Join(logDir, files[1]): true, + path.Join(logDir, files[2]): true, + path.Join(logDir, files[4]): true, + path.Join(logDir, files[5]): true, + path.Join(logDir, files[6]): true, + path.Join(logDir, "vtadam.INFO"): true, + path.Join(logDir, "vtadam.ERROR"): true, + } + + for _, remainingLog := range remaining { + if !expectedRemainingLogs[remainingLog] { + t.Errorf("unexpected remaining log file: got %v", remainingLog) + } + } + + for expectedRemainingLog, _ := range expectedRemainingLogs { + found := false + for _, remainingLog := range remaining { + if remainingLog == expectedRemainingLog { + found = true + } + } + if !found { + t.Errorf("expected remaining log file: want %v", expectedRemainingLog) + } + } +} diff --git a/go/vt/logutil/purge.go b/go/vt/logutil/purge.go index 47a0f8ecef0..1edeeb32b18 100644 --- a/go/vt/logutil/purge.go +++ b/go/vt/logutil/purge.go @@ -22,12 +22,14 @@ import ( "os" "path" "path/filepath" + "sort" "strings" "time" ) var ( keepLogs = flag.Duration("keep_logs", 0*time.Second, "keep logs for this long (zero to keep forever)") + keepLatestNLogs = flag.Int("keep_latest_n_logs", 0, "keep the latest N log files per error level (zero to keep all)") purgeLogsInterval = flag.Duration("purge_logs_interval", 1*time.Hour, "how often try to remove old logs") ) @@ -44,18 +46,10 @@ func parseTimestamp(filename string) (timestamp time.Time, err error) { var levels = []string{"INFO", "ERROR", "WARNING", "FATAL"} -// purgeLogsOnce removes logfiles for program for dir, if their age +// purgeLogsByTimestamp removes log files 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) { - current := make(map[string]bool) - for _, level := range levels { - c, err := os.Readlink(path.Join(dir, fmt.Sprintf("%s.%s", program, level))) - if err != nil { - continue - } - current[c] = true - } - +func purgeLogsByTimestamp(now time.Time, dir, program string, keep time.Duration) { + current := getCurrentLogMap(dir, program) files, err := filepath.Glob(path.Join(dir, fmt.Sprintf("%s.*", program))) if err != nil { return @@ -74,22 +68,87 @@ func purgeLogsOnce(now time.Time, dir, program string, keep time.Duration) { } } -// PurgeLogs removes any log files that were started more than -// keepLogs ago and that aren't the current log. +// purgeLogsByIndex removes all except the latest keepLogCount log files for +// program in dir +func purgeLogsByIndex(dir, program string, keepLogCount int) { + current := getCurrentLogMap(dir, program) + for _, level := range levels { + files, err := filepath.Glob(path.Join(dir, fmt.Sprintf("%s.*.%s.*", program, level))) + if err != nil { + return + } + sort.Sort(byTimestamp(files)) + for fileIdx, file := range files { + if current[file] { + continue + } + if fileIdx >= keepLogCount { + os.Remove(file) + } + } + } +} + +// getCurrentLogMap returns a map of current log files (current meaning +// currently being written to) +func getCurrentLogMap(dir, program string) map[string]bool { + current := make(map[string]bool) + for _, level := range levels { + c, err := os.Readlink(path.Join(dir, fmt.Sprintf("%s.%s", program, level))) + if err != nil { + continue + } + current[c] = true + } + return current +} + +// byTimestamp is a sort.Interface for sorting a []string of file paths by +// their timestamp +type byTimestamp []string + +func (s byTimestamp) Len() int { + return len(s) +} +func (s byTimestamp) Swap(i, j int) { + s[i], s[j] = s[j], s[i] +} +func (s byTimestamp) Less(i, j int) bool { + createdI, errI := parseTimestamp(s[i]) + createdJ, errJ := parseTimestamp(s[j]) + if errI != nil && errJ != nil { + return false + } else if errI != nil { + return false // send parseTimestamp errors to bottom of list + } else if errJ != nil { + return true // send parseTimestamp errors to bottom of list + } + return createdJ.Before(createdI) +} + +// PurgeLogs removes old log files according to `-keep_logs` and +// `-keep_latest_n_logs` flags. Current log files are never removed. func PurgeLogs() { f := flag.Lookup("log_dir") if f == nil { panic("the logging module doesn't specify a log_dir flag") } - if *keepLogs == 0*time.Second { + if *keepLogs == 0*time.Second && *keepLatestNLogs == 0 { + // We will never purge anything; bail early return } + + // Run purge routines every `-purge_logs_interval` seconds logDir := f.Value.String() program := filepath.Base(os.Args[0]) - timer := time.NewTimer(*purgeLogsInterval) for range timer.C { - purgeLogsOnce(time.Now(), logDir, program, *keepLogs) + if *keepLogs != 0*time.Second { + purgeLogsByTimestamp(time.Now(), logDir, program, *keepLogs) + } + if *keepLatestNLogs != 0 { + purgeLogsByIndex(logDir, program, *keepLatestNLogs) + } } }