implement reverse reader for log reads

in cases where the log file exceeds the available memory of a system, we had a bug that triggered an oom because the entire logfile was being read when the tail parameter was given.  this reads in chunks and is more or less memory safe.

fixes: #5131

Signed-off-by: Brent Baude <bbaude@redhat.com>

hack/get_ci_vm.sh

@@ -97,7 +97,7 @@ keys=[k for k in env if "ENCRYPTED" not in str(env[k])]
 for k,v in env.items():
     v=str(v)
     if "ENCRYPTED" not in v:
-        print "{0}=\"{1}\"".format(k, v),
+        print("{0}=\"{1}\"".format(k, v)),
     '
 }
 

libpod/logs/log.go

@@ -2,13 +2,16 @@ package logs
 
 import (
 	"fmt"
-	"io/ioutil"
+	"io"
+	"os"
 	"strings"
 	"sync"
 	"time"
 
+	"github.com/containers/libpod/libpod/logs/reversereader"
 	"github.com/hpcloud/tail"
 	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 )
 
 const (
@@ -74,43 +77,84 @@ func GetLogFile(path string, options *LogOptions) (*tail.Tail, []*LogLine, error
 
 func getTailLog(path string, tail int) ([]*LogLine, error) {
 	var (
-		tailLog     []*LogLine
-		nlls        []*LogLine
-		tailCounter int
-		partial     string
+		nlls       []*LogLine
+		nllCounter int
+		leftover   string
+		partial    string
+		tailLog    []*LogLine
 	)
-	content, err := ioutil.ReadFile(path)
+	f, err := os.Open(path)
 	if err != nil {
 		return nil, err
 	}
-	splitContent := strings.Split(string(content), "\n")
-	// We read the content in reverse and add each nll until we have the same
-	// number of F type messages as the desired tail
-	for i := len(splitContent) - 1; i >= 0; i-- {
-		if len(splitContent[i]) == 0 {
-			continue
+	rr, err := reversereader.NewReverseReader(f)
+	if err != nil {
+		return nil, err
+	}
+
+	inputs := make(chan []string)
+	go func() {
+		for {
+			s, err := rr.Read()
+			if err != nil {
+				if errors.Cause(err) == io.EOF {
+					inputs <- []string{leftover}
+					close(inputs)
+					break
+				}
+				logrus.Error(err)
+				close(inputs)
+			}
+			line := strings.Split(s+leftover, "\n")
+			if len(line) > 1 {
+				inputs <- line[1:]
+			}
+			leftover = line[0]
 		}
-		nll, err := NewLogLine(splitContent[i])
-		if err != nil {
-			return nil, err
+	}()
+
+	for i := range inputs {
+		// the incoming array is FIFO; we want FIFO so
+		// reverse the slice read order
+		for j := len(i) - 1; j >= 0; j-- {
+			// lines that are "" are junk
+			if len(i[j]) < 1 {
+				continue
+			}
+			// read the content in reverse and add each nll until we have the same
+			// number of F type messages as the desired tail
+			nll, err := NewLogLine(i[j])
+			if err != nil {
+				return nil, err
+			}
+			nlls = append(nlls, nll)
+			if !nll.Partial() {
+				nllCounter++
+			}
 		}
-		nlls = append(nlls, nll)
-		if !nll.Partial() {
-			tailCounter++
-		}
-		if tailCounter == tail {
+		// if we have enough loglines, we can hangup
+		if nllCounter >= tail {
+			if err := f.Close(); err != nil {
+				logrus.Error(err)
+			}
 			break
 		}
 	}
-	// Now we iterate the results and assemble partial messages to become full messages
+
+	// re-assemble the log lines and trim (if needed) to the
+	// tail length
 	for _, nll := range nlls {
 		if nll.Partial() {
 			partial += nll.Msg
 		} else {
 			nll.Msg += partial
-			tailLog = append(tailLog, nll)
+			// prepend because we need to reverse the order again to FIFO
+			tailLog = append([]*LogLine{nll}, tailLog...)
 			partial = ""
 		}
+		if len(tailLog) == tail {
+			break
+		}
 	}
 	return tailLog, nil
 }

libpod/logs/reversereader/reversereader.go

@@ -0,0 +1,66 @@
+package reversereader
+
+import (
+	"io"
+	"os"
+
+	"github.com/pkg/errors"
+)
+
+// ReverseReader structure for reading a file backwards
+type ReverseReader struct {
+	reader   *os.File
+	offset   int64
+	readSize int64
+}
+
+// NewReverseReader returns a reader that reads from the end of a file
+// rather than the beginning.  It sets the readsize to pagesize and determines
+// the first offset using using modulus.
+func NewReverseReader(reader *os.File) (*ReverseReader, error) {
+	// pagesize should be safe for memory use and file reads should be on page
+	// boundaries as well
+	pageSize := int64(os.Getpagesize())
+	stat, err := reader.Stat()
+	if err != nil {
+		return nil, err
+	}
+	// figure out the last page boundary
+	remainder := stat.Size() % pageSize
+	end, err := reader.Seek(0, 2)
+	if err != nil {
+		return nil, err
+	}
+	// set offset (starting position) to the last page boundary or
+	// zero if fits in one page
+	startOffset := end - remainder
+	if startOffset < 0 {
+		startOffset = 0
+	}
+	rr := ReverseReader{
+		reader:   reader,
+		offset:   startOffset,
+		readSize: pageSize,
+	}
+	return &rr, nil
+}
+
+// ReverseReader reads from a given offset to the previous offset and
+// then sets the newoff set one pagesize less than the previous read.
+func (r *ReverseReader) Read() (string, error) {
+	if r.offset < 0 {
+		return "", errors.Wrap(io.EOF, "at beginning of file")
+	}
+	// Read from given offset
+	b := make([]byte, r.readSize)
+	n, err := r.reader.ReadAt(b, r.offset)
+	if err != nil && errors.Cause(err) != io.EOF {
+		return "", err
+	}
+	if int64(n) < r.readSize {
+		b = b[0:n]
+	}
+	// Set to the next page boundary
+	r.offset = -r.readSize
+	return string(b), nil
+}

pkg/adapter/containers.go

@@ -338,7 +338,11 @@ func (r *LocalRuntime) Log(c *cliconfig.LogsValues, options *logs.LogOptions) er
 	if tailLen < 0 {
 		tailLen = 0
 	}
-	logChannel := make(chan *logs.LogLine, tailLen*len(c.InputArgs)+1)
+	numContainers := len(c.InputArgs)
+	if numContainers == 0 {
+		numContainers = 1
+	}
+	logChannel := make(chan *logs.LogLine, tailLen*numContainers+1)
 	containers, err := shortcuts.GetContainersByContext(false, c.Latest, c.InputArgs, r.Runtime)
 	if err != nil {
 		return err