Code review comment for lp:~thumper/juju-core/fix-backlog-limits

Reviewers: mp+215333_code.launchpad.net,

Message:
Please take a look.

Description:
Fix the limit for the debug-log calls.

Unbeknownst to me, the filter method was being called
during the backlog iteration as well. This fix introduces
a callback that the tailer calls when it starts the forward
filtering.

This allows us to count the filter calls only when the
filter is being called to write out the results. We cannot
count the write calls because the tailer uses buffered i/o
there.

https://code.launchpad.net/~thumper/juju-core/fix-backlog-limits/+merge/215333

Requires:
https://code.launchpad.net/~thumper/juju-core/debug-log-api/+merge/215323

(do not edit description out of merge proposal)

Please review this at https://codereview.appspot.com/85570045/

Affected files (+42, -10 lines):
   A [revision details]
   M container/lxc/clonetemplate.go
   M state/apiserver/debuglog.go
   M state/apiserver/debuglog_internal_test.go
   M state/apiserver/debuglog_test.go
   M utils/tailer/tailer.go
   M utils/tailer/tailer_test.go

Index: [revision details]
=== added file '[revision details]'
--- [revision details] 2012-01-01 00:00:00 +0000
+++ [revision details] 2012-01-01 00:00:00 +0000
@@ -0,0 +1,2 @@
+Old revision: <email address hidden>
+New revision: <email address hidden>

Index: container/lxc/clonetemplate.go
=== modified file 'container/lxc/clonetemplate.go'
--- container/lxc/clonetemplate.go 2014-04-04 03:46:13 +0000
+++ container/lxc/clonetemplate.go 2014-04-11 01:57:45 +0000
@@ -179,7 +179,7 @@
   }

   tailWriter := &logTail{tick: time.Now()}
- consoleTailer := tailer.NewTailer(console, tailWriter, nil)
+ consoleTailer := tailer.NewTailer(console, tailWriter, nil, nil)
   defer consoleTailer.Stop()

   // We should wait maybe 1 minute between output?

Index: state/apiserver/debuglog.go
=== modified file 'state/apiserver/debuglog.go'
--- state/apiserver/debuglog.go 2014-04-10 09:43:51 +0000
+++ state/apiserver/debuglog.go 2014-04-11 01:54:49 +0000
@@ -209,18 +209,23 @@
   maxLines uint
   lineCount uint
   fromTheStart bool
+ started bool
  }

  // start the tailer listening to the logFile, and sending the matching
  // lines to the writer.
  func (stream *logStream) start(logFile io.ReadSeeker, writer io.Writer) {
   if stream.fromTheStart {
- stream.logTailer = tailer.NewTailer(logFile, writer, stream.filterLine)
+ stream.logTailer = tailer.NewTailer(logFile, writer, stream.filterLine,
stream.tailStarted)
   } else {
- stream.logTailer = tailer.NewTailerBacktrack(logFile, writer,
stream.backlog, stream.filterLine)
+ stream.logTailer = tailer.NewTailerBacktrack(logFile, writer,
stream.backlog, stream.filterLine, stream.tailStarted)
   }
  }

+func (stream *logStream) tailStarted() {
+ stream.started = true
+}
+
  // loop starts the tailer with the log file and the web socket.
  func (stream *logStream) loop() error {
   select {
@@ -239,7 +244,7 @@
    stream.checkIncludeModule(log) &&
    !stream.exclude(log) &&
    stream.checkLevel(log)
- if result && stream.maxLines > 0 {
+ if stream.started && result && stream.maxLines > 0 {
    stream.lineCount++
    result = stream.lineCount <= stream.maxLines
    if stream.lineCount == stream.maxLines {

Index: state/apiserver/debuglog_internal_test.go
=== modified file 'state/apiserver/debuglog_internal_test.go'
--- state/apiserver/debuglog_internal_test.go 2014-04-07 05:11:48 +0000
+++ state/apiserver/debuglog_internal_test.go 2014-04-11 02:05:44 +0000
@@ -183,6 +183,7 @@
   stream := &logStream{
    filterLevel: loggo.INFO,
    maxLines: 5,
+ started: true,
   }
   line := []byte("machine-0: date time WARNING juju")
   c.Check(stream.filterLine(line), jc.IsTrue)

Index: state/apiserver/debuglog_test.go
=== modified file 'state/apiserver/debuglog_test.go'
--- state/apiserver/debuglog_test.go 2014-04-10 09:43:51 +0000
+++ state/apiserver/debuglog_test.go 2014-04-11 01:45:10 +0000
@@ -122,6 +122,18 @@
   s.assertWebsocketClosed(c, reader)
  }

+func (s *debugLogSuite) TestBacklogWithMaxLines(c *gc.C) {
+ s.writeLogLines(c, 10)
+
+ reader := s.openWebsocket(c, url.Values{"backlog": {"5"}, "maxLines":
{"10"}})
+ s.assertLogFollowing(c, reader)
+ s.writeLogLines(c, logLineCount)
+
+ linesRead := s.readLogLines(c, reader, 10)
+ c.Assert(linesRead, jc.DeepEquals, logLines[5:15])
+ s.assertWebsocketClosed(c, reader)
+}
+
  func (s *debugLogSuite) TestFilter(c *gc.C) {
   s.ensureLogFile(c)

Index: utils/tailer/tailer.go
=== modified file 'utils/tailer/tailer.go'
--- utils/tailer/tailer.go 2014-04-04 04:35:44 +0000
+++ utils/tailer/tailer.go 2014-04-11 01:54:49 +0000
@@ -27,6 +27,10 @@
  // returns true) of shall be omitted (func returns false).
  type TailerFilterFunc func(line []byte) bool

+// TailerFilterStartedFunc is a callback that is called when the filtering
is
+// starting.
+type TailerFilterStartedFunc func()
+
  // Tailer reads an input line by line an tails them into the passed Writer.
  // The lines have to be terminated with a newline.
  type Tailer struct {
@@ -40,6 +44,7 @@
   bufferSize int
   polltime time.Duration
   lookBack bool
+ callback TailerFilterStartedFunc
  }

  // NewTailerBacktrack starts a Tailer which reads strings from the passed
@@ -47,21 +52,24 @@
  // lines are filtered. The matching lines are written to the passed
  // Writer. The reading begins the specified number of matching lines
  // from the end.
-func NewTailerBacktrack(readSeeker io.ReadSeeker, writer io.Writer, lines
uint, filter TailerFilterFunc) *Tailer {
- return newTailer(readSeeker, writer, lines, filter, bufferSize, polltime,
true)
+func NewTailerBacktrack(readSeeker io.ReadSeeker, writer io.Writer, lines
uint,
+ filter TailerFilterFunc, callback TailerFilterStartedFunc) *Tailer {
+ return newTailer(readSeeker, writer, lines, filter, callback, bufferSize,
polltime, true)
  }

  // NewTailer starts a Tailer which reads strings from the passed
  // ReadSeeker line by line. If a filter function is specified the read
  // lines are filtered. The matching lines are written to the passed
  // Writer.
-func NewTailer(readSeeker io.ReadSeeker, writer io.Writer, filter
TailerFilterFunc) *Tailer {
- return newTailer(readSeeker, writer, 0, filter, bufferSize, polltime,
false)
+func NewTailer(readSeeker io.ReadSeeker, writer io.Writer,
+ filter TailerFilterFunc, callback TailerFilterStartedFunc) *Tailer {
+ return newTailer(readSeeker, writer, 0, filter, callback, bufferSize,
polltime, false)
  }

  // newTailer starts a Tailer like NewTailer but allows the setting of
  // the read buffer size and the time between pollings for testing.
-func newTailer(readSeeker io.ReadSeeker, writer io.Writer, lines uint,
filter TailerFilterFunc,
+func newTailer(readSeeker io.ReadSeeker, writer io.Writer, lines uint,
+ filter TailerFilterFunc, callback TailerFilterStartedFunc,
   bufferSize int, polltime time.Duration, lookBack bool) *Tailer {
   t := &Tailer{
    readSeeker: readSeeker,
@@ -72,6 +80,7 @@
    bufferSize: bufferSize,
    polltime: polltime,
    lookBack: lookBack,
+ callback: callback,
   }
   go func() {
    defer t.tomb.Done()
@@ -113,6 +122,9 @@
     return err
    }
   }
+ if t.callback != nil {
+ t.callback()
+ }
   // Start polling.
   // TODO(mue) 2013-12-06
   // Handling of read-seeker/files being truncated during

Index: utils/tailer/tailer_test.go
=== modified file 'utils/tailer/tailer_test.go'
--- utils/tailer/tailer_test.go 2014-04-04 03:46:13 +0000
+++ utils/tailer/tailer_test.go 2014-04-11 01:57:45 +0000
@@ -337,7 +337,7 @@
    reader, writer := io.Pipe()
    sigc := make(chan struct{}, 1)
    rs := startReadSeeker(c, test.data, test.initialLinesWritten, sigc)
- tailer := tailer.NewTestTailer(rs, writer, test.initialLinesRequested,
test.filter, bufferSize, 2*time.Millisecond, !test.fromStart)
+ tailer := tailer.NewTestTailer(rs, writer, test.initialLinesRequested,
test.filter, nil, bufferSize, 2*time.Millisecond, !test.fromStart)
    linec := startReading(c, tailer, reader, writer)

    // Collect initial data.