From fa9658cbfaa94fd5d0425041404e498c01db1aa3 Mon Sep 17 00:00:00 2001 From: baude Date: Tue, 6 Feb 2018 09:07:51 -0600 Subject: podman logs: fix tailing Fix issues with tailing of container logs as described in issue #16. Also add in the ability to use a duration or known time stamp formats for the --since flag. Signed-off-by: baude Closes: #317 Approved by: mheon --- cmd/podman/logs.go | 181 ++++++++++++++++++++++++++++++++++++++++------------- 1 file changed, 138 insertions(+), 43 deletions(-) (limited to 'cmd') diff --git a/cmd/podman/logs.go b/cmd/podman/logs.go index b31dce2d3..5551d6157 100644 --- a/cmd/podman/logs.go +++ b/cmd/podman/logs.go @@ -2,20 +2,23 @@ package main import ( "fmt" + "io" + "os" "strings" "time" - "github.com/hpcloud/tail" + "bufio" "github.com/pkg/errors" "github.com/projectatomic/libpod/libpod" "github.com/urfave/cli" ) type logOptions struct { - details bool - follow bool - sinceTime time.Time - tail uint64 + details bool + follow bool + sinceTime time.Time + tail uint64 + showTimestamps bool } var ( @@ -37,17 +40,22 @@ var ( Name: "tail", Usage: "Output the specified number of LINES at the end of the logs. Defaults to 0, which prints all lines", }, + cli.BoolFlag{ + Name: "timestamps, t", + Usage: "Output the timestamps in the log", + }, LatestFlag, } logsDescription = "The podman logs command batch-retrieves whatever logs are present for a container at the time of execution. This does not guarantee execution" + "order when combined with podman run (i.e. your run may not have generated any logs at the time you execute podman logs" logsCommand = cli.Command{ - Name: "logs", - Usage: "Fetch the logs of a container", - Description: logsDescription, - Flags: logsFlags, - Action: logsCmd, - ArgsUsage: "CONTAINER", + Name: "logs", + Usage: "Fetch the logs of a container", + Description: logsDescription, + Flags: logsFlags, + Action: logsCmd, + ArgsUsage: "CONTAINER", + SkipArgReorder: true, } ) @@ -72,7 +80,7 @@ func logsCmd(c *cli.Context) error { sinceTime := time.Time{} if c.IsSet("since") { // parse time, error out if something is wrong - since, err := time.Parse("2006-01-02T15:04:05.999999999-07:00", c.String("since")) + since, err := parseInputTime(c.String("since")) if err != nil { return errors.Wrapf(err, "could not parse time: %q", c.String("since")) } @@ -80,10 +88,11 @@ func logsCmd(c *cli.Context) error { } opts := logOptions{ - details: c.Bool("details"), - follow: c.Bool("follow"), - sinceTime: sinceTime, - tail: c.Uint64("tail"), + details: c.Bool("details"), + follow: c.Bool("follow"), + sinceTime: sinceTime, + tail: c.Uint64("tail"), + showTimestamps: c.Bool("timestamps"), } if c.Bool("latest") { @@ -95,52 +104,116 @@ func logsCmd(c *cli.Context) error { return err } - logs := make(chan string) - go func() { - err = getLogs(ctr, logs, opts) - }() - printLogs(logs) + file, err := os.Open(ctr.LogPath()) + if err != nil { + return errors.Wrapf(err, "unable to read container log file") + } + defer file.Close() + reader := bufio.NewReader(file) + if opts.follow { + followLog(reader, opts) + } else { + dumpLog(reader, opts) + } return err } -// getLogs returns the logs of a container from the log file -// log file is created when the container is started/ran -func getLogs(container *libpod.Container, logChan chan string, opts logOptions) error { - defer close(logChan) - - seekInfo := &tail.SeekInfo{Offset: 0, Whence: 0} +func followLog(reader *bufio.Reader, opts logOptions) error { + var cacheOutput []string + firstPass := false if opts.tail > 0 { - // seek to correct position in log files - seekInfo.Offset = int64(opts.tail) - seekInfo.Whence = 2 + firstPass = true } - - t, err := tail.TailFile(container.LogPath(), tail.Config{Follow: opts.follow, ReOpen: false, Location: seekInfo}) - for line := range t.Lines { - if since, err := logSinceTime(opts.sinceTime, line.Text); err != nil || !since { + // We need to read the entire file in here until we reach EOF + // and then dump it out in the case that the user also wants + // tail output + for { + line, err := reader.ReadString('\n') + if err == io.EOF && opts.follow { + if firstPass { + firstPass = false + cacheLen := int64(len(cacheOutput)) + start := int64(0) + if cacheLen > int64(opts.tail) { + start = cacheLen - int64(opts.tail) + } + for i := start; i < cacheLen; i++ { + printLine(cacheOutput[i], opts) + } + continue + } + time.Sleep(1 * time.Second) continue } - logMessage := line.Text[secondSpaceIndex(line.Text):] - logChan <- logMessage + // exits + if err != nil { + break + } + if firstPass { + cacheOutput = append(cacheOutput, line) + continue + } + printLine(line, opts) } - return err + return nil } -func printLogs(logs chan string) { - for line := range logs { - fmt.Println(line) +func dumpLog(reader *bufio.Reader, opts logOptions) error { + output := readLog(reader, opts) + for _, line := range output { + printLine(line, opts) } + + return nil +} + +func readLog(reader *bufio.Reader, opts logOptions) []string { + var output []string + for { + line, err := reader.ReadString('\n') + if err != nil { + break + } + output = append(output, line) + } + start := 0 + if opts.tail > 0 { + if len(output) > int(opts.tail) { + start = len(output) - int(opts.tail) + } + } + return output[start:] +} + +func printLine(line string, opts logOptions) { + start := 3 + fields := strings.Fields(line) + if opts.showTimestamps || !isStringTimestamp(fields[0]) { + start = 0 + } + if opts.sinceTime.IsZero() || logSinceTime(opts.sinceTime, fields[0]) { + output := strings.Join(fields[start:], " ") + fmt.Printf("%s\n", output) + } +} + +func isStringTimestamp(t string) bool { + _, err := time.Parse("2006-01-02T15:04:05.999999999-07:00", t) + if err != nil { + return false + } + return true } // returns true if the time stamps of the logs are equal to or after the // timestamp comparing to -func logSinceTime(sinceTime time.Time, logStr string) (bool, error) { +func logSinceTime(sinceTime time.Time, logStr string) bool { timestamp := strings.Split(logStr, " ")[0] logTime, err := time.Parse("2006-01-02T15:04:05.999999999-07:00", timestamp) if err != nil { - return false, err + return false } - return logTime.After(sinceTime) || logTime.Equal(sinceTime), nil + return logTime.After(sinceTime) || logTime.Equal(sinceTime) } // secondSpaceIndex returns the index of the second space in a string @@ -158,3 +231,25 @@ func secondSpaceIndex(line string) int { } return index } + +// parseInputTime takes the users input and to determine if it is valid and +// returns a time format and error. The input is compared to known time formats +// or a duration which implies no-duration +func parseInputTime(inputTime string) (time.Time, error) { + timeFormats := []string{time.RFC3339Nano, time.RFC3339, "2006-01-02T15:04:05", "2006-01-02T15:04:05.999999999", + "2006-01-02Z07:00", "2006-01-02"} + // iterate the supported time formats + for _, tf := range timeFormats { + t, err := time.Parse(tf, inputTime) + if err == nil { + return t, nil + } + } + + // input might be a duration + duration, err := time.ParseDuration(inputTime) + if err != nil { + return time.Time{}, errors.Errorf("unable to interpret time value") + } + return time.Now().Add(-duration), nil +} -- cgit v1.2.3-54-g00ecf