Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 1 commit into from
Jun 1, 2019
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
67 changes: 59 additions & 8 deletions go/vt/logutil/logutil_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
}
Expand All @@ -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)
Expand All @@ -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))
}
}
44 changes: 31 additions & 13 deletions go/vt/logutil/purge.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand All @@ -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
}
Expand All @@ -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)
}
}
Expand All @@ -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)
}
}