context: use the line object instead of rendered strings (makes elide…

…, subseconds-only mode, etc. work correctly)

pkg/parse/context.go

@@ -1,45 +1,54 @@
 package parse
 
-import (
-	"bytes"
-)
-
 type context struct {
 	Before, After int
 
-	lines      []string
+	lines      []line
 	printAfter int
 	line       int
 	lastPrint  int
 }
 
-func (c *context) Print(buf *bytes.Buffer, msg string, selected bool) {
+// Print returns the lines that should be displayed right now, based on the line that is being
+// added, its filtering status, and the context configuration.
+func (c *context) Print(msg *line, selected bool) []*line {
 	c.line++
 	if selected {
+		var result []*line
 		c.printAfter = c.After
-		if c.lastPrint != 0 && (c.After != 0 || c.Before != 0) && c.line-len(c.lines)-c.lastPrint > 1 {
-			buf.WriteString("---\n")
+
+		if true &&
+			// suppress separator if it's the first line of output
+			c.lastPrint != 0 &&
+			// suppress separator if we are no-op context
+			(c.After != 0 || c.Before != 0) &&
+			// suppress separator if end of after is contigious with the start of before
+			c.line-len(c.lines)-c.lastPrint > 1 {
+
+			result = append(result, &line{isSeparator: true})
 		}
 		for _, l := range c.lines {
-			buf.WriteString(l)
+			line := l
+			result = append(result, &line)
 		}
-		buf.WriteString(msg)
+		result = append(result, msg)
 		c.lastPrint = c.line
-		c.lines = nil
-		return
+		c.lines = nil // TODO: allocate full capacity here
+		return result
 	}
 
 	if c.printAfter > 0 {
-		buf.WriteString(msg)
 		c.lastPrint = c.line
 		c.printAfter--
-		return
+		return []*line{msg}
 	}
 
 	if c.Before > 0 {
-		c.lines = append(c.lines, msg)
+		// TODO: allocate full capacity here
+		c.lines = append(c.lines, *msg) // shallow copy
 		if len(c.lines) > c.Before {
 			c.lines = c.lines[1:]
 		}
 	}
+	return nil
 }

pkg/parse/context_test.go

@@ -139,9 +139,20 @@ func TestContext(t *testing.T) {
 				After:  test.after,
 			}
 			out := new(bytes.Buffer)
-			for _, l := range test.input {
-				selected := test.match.MatchString(l)
-				ctx.Print(out, l+"\n", selected)
+			var l line // ensure that our stored pointers do enough copying
+			for _, msg := range test.input {
+				l.reset()
+				l.msg = msg
+				selected := test.match.MatchString(msg)
+				print := ctx.Print(&l, selected)
+				for _, x := range print {
+					if x.isSeparator {
+						out.WriteString("---")
+					} else {
+						out.WriteString(x.msg)
+					}
+					out.WriteByte('\n')
+				}
 			}
 
 			gotOutput := out.String()
@@ -153,7 +164,8 @@ func TestContext(t *testing.T) {
 				got = got[:len(got)-1]
 			}
 			if diff := cmp.Diff(got, test.want, cmpopts.EquateEmpty()); diff != "" {
-				t.Errorf("diff:\n%s", diff)
+				t.Errorf("output:\n  got: %v\n want: %v", got, test.want)
+				t.Logf("diff:\n%s", diff)
 			}
 		})
 	}

pkg/parse/parse.go

@@ -115,12 +115,22 @@ func (s *OutputSchema) EmitError(msg string) {
 
 // line represents one log line.
 type line struct {
-	time      time.Time
-	msg       string
-	lvl       Level
-	raw       []byte
-	highlight bool
-	fields    map[string]interface{}
+	time        time.Time
+	msg         string
+	lvl         Level
+	raw         []byte
+	highlight   bool
+	fields      map[string]interface{}
+	isSeparator bool // If true, this is not a line but a separator from context.
+}
+
+func (l *line) reset() {
+	l.raw = nil
+	l.msg = ""
+	l.fields = make(map[string]interface{})
+	l.lvl = LevelUnknown
+	l.time = time.Time{}
+	l.highlight = false
 }
 
 type Summary struct {
@@ -147,7 +157,6 @@ func ReadLog(r io.Reader, w io.Writer, ins *InputSchema, outs *OutputSchema, fil
 	}
 	var sum Summary
 
-	lineBuf := new(bytes.Buffer)
 	buf := new(bytes.Buffer)
 	ctx := &context{
 		After:  outs.AfterContext,
@@ -159,7 +168,6 @@ func ReadLog(r io.Reader, w io.Writer, ins *InputSchema, outs *OutputSchema, fil
 
 		err := func() (retErr error) {
 			var addError, writeRawLine, recoverable bool
-			var filtered bool
 
 			// Adjust counters, print debugging information, flush buffers on the way
 			// out, no matter what.
@@ -168,8 +176,7 @@ func ReadLog(r io.Reader, w io.Writer, ins *InputSchema, outs *OutputSchema, fil
 					sum.Errors++
 				}
 				var writeError bool
-				if lineBuf.Len() > 0 {
-					ctx.Print(buf, lineBuf.String(), !filtered)
+				if buf.Len() > 0 {
 					if _, err := buf.WriteTo(w); err != nil {
 						recoverable = false
 						writeError = true
@@ -214,13 +221,8 @@ func ReadLog(r io.Reader, w io.Writer, ins *InputSchema, outs *OutputSchema, fil
 
 			// Reset state from the last line.
 			buf.Reset()
-			lineBuf.Reset()
+			l.reset()
 			l.raw = s.Bytes()
-			l.msg = ""
-			l.fields = make(map[string]interface{})
-			l.lvl = LevelUnknown
-			l.time = time.Time{}
-			l.highlight = false
 
 			// Parse input.
 			parseErr := ins.ReadLine(&l)
@@ -234,8 +236,7 @@ func ReadLog(r io.Reader, w io.Writer, ins *InputSchema, outs *OutputSchema, fil
 			}
 
 			// Filter.
-			var err error
-			filtered, err = filter.Run(&l)
+			filtered, err := filter.Run(&l)
 			if err != nil {
 				addError = true
 				writeRawLine = true
@@ -258,14 +259,16 @@ func ReadLog(r io.Reader, w io.Writer, ins *InputSchema, outs *OutputSchema, fil
 				}
 			}
 
-			// Emit a line.
-			if !outs.suppressionConfigured {
-				outs.noTime = ins.NoTimeKey
-				outs.noLevel = ins.NoLevelKey
-				outs.noMessage = ins.NoMessageKey
-				outs.suppressionConfigured = true
+			// Emit any lines that are able to be printed based on the context settings.
+			for _, toEmit := range ctx.Print(&l, !filtered) {
+				if !outs.suppressionConfigured {
+					outs.noTime = ins.NoTimeKey
+					outs.noLevel = ins.NoLevelKey
+					outs.noMessage = ins.NoMessageKey
+					outs.suppressionConfigured = true
+				}
+				outs.Emit(*toEmit, buf)
 			}
-			outs.Emit(&l, lineBuf)
 
 			// Copying the buffer to the output writer is handled in defer.
 			if parseErr != nil {
@@ -464,7 +467,13 @@ func (s *InputSchema) ReadLine(l *line) error {
 
 // Emit emits a formatted line to the provided buffer.  The provided line object may not be used
 // again until reinitialized.
-func (s *OutputSchema) Emit(l *line, w *bytes.Buffer) {
+func (s *OutputSchema) Emit(l line, w *bytes.Buffer) {
+	// Is this a line separating unrelated contexts?  If so, print a separator and do nothing else.
+	if l.isSeparator {
+		w.WriteString("---\n")
+		return
+	}
+
 	var needSpace bool
 
 	// Level.

pkg/parse/parse_fuzz_test.go

@@ -136,7 +136,7 @@ func FuzzEmit(f *testing.F) {
 			fields:    fieldMap,
 		}
 		outbuf := new(bytes.Buffer)
-		outs.Emit(l, outbuf)
+		outs.Emit(*l, outbuf)
 		byts := outbuf.Bytes()
 		if len(byts) == 0 {
 			t.Fatal("no output produced")

pkg/parse/parse_test.go

@@ -523,19 +523,19 @@ func TestEmit(t *testing.T) {
 	tests := []struct {
 		name      string
 		state     State
-		line      *line
+		line      line
 		want      string
 		wantState State
 	}{
 
 		{
 			name: "empty",
-			line: &line{},
+			line: line{},
 			want: "{LVL:X} {TS:∅} {MSG:}\n",
 		},
 		{
 			name: "basic",
-			line: &line{
+			line: line{
 				time: time.Unix(1, 0),
 				lvl:  LevelInfo,
 				msg:  "hello, world!!",
@@ -544,7 +544,7 @@ func TestEmit(t *testing.T) {
 		},
 		{
 			name: "basic with fields",
-			line: &line{
+			line: line{
 				time: time.Unix(2, 0),
 				lvl:  LevelDebug,
 				msg:  "hi",
@@ -564,7 +564,7 @@ func TestEmit(t *testing.T) {
 		},
 		{
 			name: "basic with remembered fields",
-			line: &line{
+			line: line{
 				time: time.Unix(3, 0),
 				lvl:  LevelDebug,
 				msg:  "hi",