Merge lp:~pedronis/ubuntu-push/testlog-more into lp:ubuntu-push

[Samuele Pedroni]

use TestLogger in more places

use TestLogger in more places

[lp:~pedronis/ubuntu-push/testlog-more]

62. By Samuele Pedroni on 2014-02-04

use TestLogger

[John Lenton (chipaca)]

review: Approve

=== modified file 'server/api/middleware_test.go'
--- server/api/middleware_test.go	2014-01-16 16:15:23 +0000
+++ server/api/middleware_test.go	2014-02-04 22:50:59 +0000
@@ -17,10 +17,8 @@
 package api
 
 import (
-	"bytes"
 	. "launchpad.net/gocheck"
-	"launchpad.net/ubuntu-push/logger"
-	// "launchpad.net/ubuntu-push/testing"
+	helpers "launchpad.net/ubuntu-push/testing"
 	"net/http"
 	"net/http/httptest"
 )
@@ -30,8 +28,7 @@
 var _ = Suite(&middlewareSuite{})
 
 func (s *middlewareSuite) TestPanicTo500Handler(c *C) {
-	buf := &bytes.Buffer{}
-	logger := logger.NewSimpleLogger(buf, "debug")
+	logger := helpers.NewTestLogger(c, "debug")
 	panicking := http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
 		panic("panic in handler")
 	})
@@ -40,7 +37,7 @@
 	w := httptest.NewRecorder()
 	h.ServeHTTP(w, nil)
 	c.Check(w.Code, Equals, 500)
-	c.Check(buf.String(), Matches, "(?s).* ERROR\\(PANIC\\) serving http: panic in handler:.*")
+	c.Check(logger.Captured(), Matches, "(?s)ERROR\\(PANIC\\) serving http: panic in handler:.*")
 	c.Check(w.Header().Get("Content-Type"), Equals, "application/json")
 	c.Check(w.Body.String(), Equals, `{"error":"internal","message":"INTERNAL SERVER ERROR"}`)
 }
 
=== modified file 'server/bootlog_test.go'
--- server/bootlog_test.go	2014-01-23 15:33:30 +0000
+++ server/bootlog_test.go	2014-02-04 22:50:59 +0000
@@ -17,9 +17,8 @@
 package server
 
 import (
-	"bytes"
 	. "launchpad.net/gocheck"
-	"launchpad.net/ubuntu-push/logger"
+	helpers "launchpad.net/ubuntu-push/testing"
 	"net"
 	"testing"
 )
@@ -31,9 +30,9 @@
 var _ = Suite(&bootlogSuite{})
 
 func (s *bootlogSuite) TestBootLogListener(c *C) {
-	buf := &bytes.Buffer{}
 	prevBootLogger := BootLogger
-	BootLogger = logger.NewSimpleLogger(buf, "info")
+	testlog := helpers.NewTestLogger(c, "info")
+	BootLogger = testlog
 	defer func() {
 		BootLogger = prevBootLogger
 	}()
@@ -41,5 +40,5 @@
 	c.Assert(err, IsNil)
 	defer lst.Close()
 	BootLogListener("client", lst)
-	c.Check(buf.String(), Matches, ".* INFO listening for client on "+lst.Addr().String()+"\n")
+	c.Check(testlog.Captured(), Matches, "INFO listening for client on "+lst.Addr().String()+"\n")
 }
 
=== modified file 'server/broker/testsuite/suite.go'
--- server/broker/testsuite/suite.go	2014-02-04 21:35:11 +0000
+++ server/broker/testsuite/suite.go	2014-02-04 22:50:59 +0000
@@ -192,7 +192,10 @@
 }
 
 func (s *CommonBrokerSuite) TestBroadcastFail(c *C) {
-	s.testlog.Written = make(chan bool, 1)
+	logged := make(chan bool, 1)
+	s.testlog.SetLogEventCb(func(string) {
+		logged <- true
+	})
 	sto := &testFailingStore{countdownToFail: 1}
 	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
@@ -203,7 +206,7 @@
 	select {
 	case <-time.After(5 * time.Second):
 		c.Fatal("taking too long to log error")
-	case <-s.testlog.Written:
+	case <-logged:
 	}
 	c.Check(s.testlog.Captured(), Matches, "ERROR unsuccessful broadcast, get channel snapshot for 0: get channel snapshot fail\n")
 }
 
=== modified file 'server/runner_test.go'
--- server/runner_test.go	2014-01-23 15:33:30 +0000
+++ server/runner_test.go	2014-02-04 22:50:59 +0000
@@ -17,12 +17,10 @@
 package server
 
 import (
-	"bytes"
 	"fmt"
 	"io/ioutil"
 	. "launchpad.net/gocheck"
 	"launchpad.net/ubuntu-push/config"
-	"launchpad.net/ubuntu-push/logger"
 	helpers "launchpad.net/ubuntu-push/testing"
 	"net"
 	"net/http"
@@ -102,9 +100,9 @@
 }
 
 func (s *runnerSuite) TestDevicesRunner(c *C) {
-	buf := &bytes.Buffer{}
 	prevBootLogger := BootLogger
-	BootLogger = logger.NewSimpleLogger(buf, "debug")
+	testlog := helpers.NewTestLogger(c, "debug")
+	BootLogger = testlog
 	defer func() {
 		BootLogger = prevBootLogger
 	}()
 
=== modified file 'server/session/session_test.go'
--- server/session/session_test.go	2014-01-31 17:25:02 +0000
+++ server/session/session_test.go	2014-02-04 22:50:59 +0000
@@ -18,17 +18,15 @@
 
 import (
 	"bufio"
-	"bytes"
 	"encoding/json"
 	"errors"
 	"fmt"
 	"io"
-	"io/ioutil"
 	. "launchpad.net/gocheck"
-	"launchpad.net/ubuntu-push/logger"
 	"launchpad.net/ubuntu-push/protocol"
 	"launchpad.net/ubuntu-push/server/broker"
 	"launchpad.net/ubuntu-push/server/broker/testing"
+	helpers "launchpad.net/ubuntu-push/testing"
 	"net"
 	"reflect"
 	gotesting "testing"
@@ -37,7 +35,13 @@
 
 func TestSession(t *gotesting.T) { TestingT(t) }
 
-type sessionSuite struct{}
+type sessionSuite struct {
+	testlog *helpers.TestLogger
+}
+
+func (s *sessionSuite) SetUpTest(c *C) {
+	s.testlog = helpers.NewTestLogger(c, "debug")
+}
 
 var _ = Suite(&sessionSuite{})
 
@@ -216,7 +220,7 @@
 }
 
 func (s *sessionSuite) TestSessionLoop(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	up := make(chan interface{}, 5)
 	down := make(chan interface{}, 5)
@@ -238,7 +242,7 @@
 }
 
 func (s *sessionSuite) TestSessionLoopWriteError(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	up := make(chan interface{}, 5)
 	down := make(chan interface{}, 5)
@@ -255,7 +259,7 @@
 }
 
 func (s *sessionSuite) TestSessionLoopMismatch(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	up := make(chan interface{}, 5)
 	down := make(chan interface{}, 5)
@@ -317,7 +321,7 @@
 }
 
 func (s *sessionSuite) TestSessionLoopExchange(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	up := make(chan interface{}, 5)
 	down := make(chan interface{}, 5)
@@ -341,7 +345,7 @@
 }
 
 func (s *sessionSuite) TestSessionLoopExchangeSplit(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	up := make(chan interface{}, 5)
 	down := make(chan interface{}, 5)
@@ -372,7 +376,7 @@
 }
 
 func (s *sessionSuite) TestSessionLoopExchangePrepareError(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	up := make(chan interface{}, 5)
 	down := make(chan interface{}, 5)
@@ -389,7 +393,7 @@
 }
 
 func (s *sessionSuite) TestSessionLoopExchangeAckedError(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	up := make(chan interface{}, 5)
 	down := make(chan interface{}, 5)
@@ -410,7 +414,7 @@
 }
 
 func (s *sessionSuite) TestSessionLoopExchangeWriteError(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	up := make(chan interface{}, 5)
 	down := make(chan interface{}, 5)
@@ -438,7 +442,7 @@
 }
 
 func (s *sessionSuite) TestSessionLoopExchangeNextPing(c *C) {
-	track := &testTracker{NewTracker(nopLogger), make(chan interface{}, 1)}
+	track := &testTracker{NewTracker(s.testlog), make(chan interface{}, 1)}
 	errCh := make(chan error, 1)
 	up := make(chan interface{}, 5)
 	down := make(chan interface{}, 5)
@@ -458,8 +462,9 @@
 	c.Check(takeNext(down), Equals, "deadline 5ms")
 	c.Check(takeNext(down), DeepEquals, protocol.PingPongMsg{Type: "ping"})
 	effectiveOfPing := float64(interval) / float64(10*time.Millisecond)
-	c.Check(effectiveOfPing > 0.95, Equals, true)
-	c.Check(effectiveOfPing < 1.15, Equals, true)
+	comment := Commentf("effectiveOfPing=%f", effectiveOfPing)
+	c.Check(effectiveOfPing > 0.95, Equals, true, comment)
+	c.Check(effectiveOfPing < 1.15, Equals, true, comment)
 	up <- nil // no write error
 	up <- io.EOF
 	err := <-errCh
@@ -507,11 +512,8 @@
 	exchangeTimeout: 10 * time.Millisecond,
 }
 
-var nopLogger = logger.NewSimpleLogger(ioutil.Discard, "error")
-
 func (s *sessionSuite) TestSessionWire(c *C) {
-	buf := &bytes.Buffer{}
-	track := NewTracker(logger.NewSimpleLogger(buf, "debug"))
+	track := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	srv, cli, lst := serverClientWire()
 	defer lst.Close()
@@ -543,11 +545,11 @@
 	c.Check(err, Equals, io.EOF)
 	c.Check(takeNext(brkr.registration), Equals, "unregister DEV")
 	// tracking
-	c.Check(buf.String(), Matches, `.*connected.*\n.*registered DEV.*\n.*ended with: EOF\n`)
+	c.Check(s.testlog.Captured(), Matches, `.*connected.*\n.*registered DEV.*\n.*ended with: EOF\n`)
 }
 
 func (s *sessionSuite) TestSessionWireTimeout(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	srv, cli, lst := serverClientWire()
 	defer lst.Close()
@@ -563,8 +565,7 @@
 }
 
 func (s *sessionSuite) TestSessionWireWrongVersion(c *C) {
-	buf := &bytes.Buffer{}
-	track := NewTracker(logger.NewSimpleLogger(buf, "debug"))
+	track := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	srv, cli, lst := serverClientWire()
 	defer lst.Close()
@@ -577,13 +578,12 @@
 	c.Check(err, DeepEquals, &broker.ErrAbort{"unexpected wire format version"})
 	cli.Close()
 	// tracking
-	c.Check(buf.String(), Matches, `.*connected.*\n.*ended with: session aborted \(unexpected.*version\)\n`)
+	c.Check(s.testlog.Captured(), Matches, `.*connected.*\n.*ended with: session aborted \(unexpected.*version\)\n`)
 
 }
 
 func (s *sessionSuite) TestSessionWireEarlyClose(c *C) {
-	buf := &bytes.Buffer{}
-	track := NewTracker(logger.NewSimpleLogger(buf, "debug"))
+	track := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	srv, cli, lst := serverClientWire()
 	defer lst.Close()
@@ -595,13 +595,12 @@
 	err := <-errCh
 	c.Check(err, Equals, io.EOF)
 	// tracking
-	c.Check(buf.String(), Matches, `.*connected.*\n.*ended with: EOF\n`)
+	c.Check(s.testlog.Captured(), Matches, `.*connected.*\n.*ended with: EOF\n`)
 
 }
 
 func (s *sessionSuite) TestSessionWireEarlyClose2(c *C) {
-	buf := &bytes.Buffer{}
-	track := NewTracker(logger.NewSimpleLogger(buf, "debug"))
+	track := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	srv, cli, lst := serverClientWire()
 	defer lst.Close()
@@ -615,11 +614,11 @@
 	err := <-errCh
 	c.Check(err, Equals, io.EOF)
 	// tracking
-	c.Check(buf.String(), Matches, `.*connected.*\n.*ended with: EOF\n`)
+	c.Check(s.testlog.Captured(), Matches, `.*connected.*\n.*ended with: EOF\n`)
 }
 
 func (s *sessionSuite) TestSessionWireTimeout2(c *C) {
-	nopTrack := NewTracker(nopLogger)
+	nopTrack := NewTracker(s.testlog)
 	errCh := make(chan error, 1)
 	srv, cli, lst := serverClientWire()
 	defer lst.Close()
 
=== modified file 'server/session/tracker_test.go'
--- server/session/tracker_test.go	2014-01-30 12:56:08 +0000
+++ server/session/tracker_test.go	2014-02-04 22:50:59 +0000
@@ -17,16 +17,21 @@
 package session
 
 import (
-	"bytes"
 	"fmt"
 	. "launchpad.net/gocheck"
-	"launchpad.net/ubuntu-push/logger"
 	"launchpad.net/ubuntu-push/server/broker"
 	"launchpad.net/ubuntu-push/server/broker/testing"
+	helpers "launchpad.net/ubuntu-push/testing"
 	"net"
 )
 
-type trackerSuite struct{}
+type trackerSuite struct {
+	testlog *helpers.TestLogger
+}
+
+func (s *trackerSuite) SetUpTest(c *C) {
+	s.testlog = helpers.NewTestLogger(c, "debug")
+}
 
 var _ = Suite(&trackerSuite{})
 
@@ -37,31 +42,25 @@
 }
 
 func (s *trackerSuite) TestSessionTrackStart(c *C) {
-	buf := &bytes.Buffer{}
-	logger := logger.NewSimpleLogger(buf, "debug")
-	track := NewTracker(logger)
+	track := NewTracker(s.testlog)
 	track.Start(&testRemoteAddrable{})
 	c.Check(track.(*tracker).sessionId, Not(Equals), 0)
-	regExpected := fmt.Sprintf(`.* DEBUG session\(%x\) connected 127\.0\.0\.1:9999\n`, track.(*tracker).sessionId)
-	c.Check(buf.String(), Matches, regExpected)
+	regExpected := fmt.Sprintf(`DEBUG session\(%x\) connected 127\.0\.0\.1:9999\n`, track.(*tracker).sessionId)
+	c.Check(s.testlog.Captured(), Matches, regExpected)
 }
 
 func (s *trackerSuite) TestSessionTrackRegistered(c *C) {
-	buf := &bytes.Buffer{}
-	logger := logger.NewSimpleLogger(buf, "debug")
-	track := NewTracker(logger)
+	track := NewTracker(s.testlog)
 	track.Start(&testRemoteAddrable{})
 	track.Registered(&testing.TestBrokerSession{DeviceId: "DEV-ID"})
-	regExpected := fmt.Sprintf(`.*connected.*\n.* INFO session\(%x\) registered DEV-ID\n`, track.(*tracker).sessionId)
-	c.Check(buf.String(), Matches, regExpected)
+	regExpected := fmt.Sprintf(`.*connected.*\nINFO session\(%x\) registered DEV-ID\n`, track.(*tracker).sessionId)
+	c.Check(s.testlog.Captured(), Matches, regExpected)
 }
 
 func (s *trackerSuite) TestSessionTrackEnd(c *C) {
-	buf := &bytes.Buffer{}
-	logger := logger.NewSimpleLogger(buf, "debug")
-	track := NewTracker(logger)
+	track := NewTracker(s.testlog)
 	track.Start(&testRemoteAddrable{})
 	track.End(&broker.ErrAbort{})
-	regExpected := fmt.Sprintf(`.*connected.*\n.* DEBUG session\(%x\) ended with: session aborted \(\)\n`, track.(*tracker).sessionId)
-	c.Check(buf.String(), Matches, regExpected)
+	regExpected := fmt.Sprintf(`.*connected.*\nDEBUG session\(%x\) ended with: session aborted \(\)\n`, track.(*tracker).sessionId)
+	c.Check(s.testlog.Captured(), Matches, regExpected)
 }
 
=== modified file 'testing/helpers.go'
--- testing/helpers.go	2014-02-04 21:35:11 +0000
+++ testing/helpers.go	2014-02-04 22:50:59 +0000
@@ -29,7 +29,7 @@
 	outputFunc func(int, string) error
 	lock       sync.Mutex
 	logEvents  []string
-	written    *chan bool
+	logEventCb func(string)
 }
 
 func (h *captureHelper) Output(calldepth int, s string) error {
@@ -37,8 +37,8 @@
 	if err == nil {
 		h.lock.Lock()
 		defer h.lock.Unlock()
-		if *h.written != nil {
-			*h.written <- true
+		if h.logEventCb != nil {
+			h.logEventCb(s)
 		}
 		h.logEvents = append(h.logEvents, s+"\n")
 	}
@@ -57,12 +57,17 @@
 	h.logEvents = nil
 }
 
+func (h *captureHelper) setLogEventCb(cb func(string)) {
+	h.lock.Lock()
+	defer h.lock.Unlock()
+	h.logEventCb = cb
+}
+
 // TestLogger implements logger.Logger using gocheck.C and supporting
 // capturing log strings.
 type TestLogger struct {
 	logger.Logger
-	helper  *captureHelper
-	Written chan bool
+	helper *captureHelper
 }
 
 // NewTestLogger can be used in tests instead of NewSimpleLogger(FromMinimalLogger).
@@ -74,7 +79,6 @@
 		Logger: logger.NewSimpleLoggerFromMinimalLogger(h, level),
 		helper: h,
 	}
-	h.written = &log.Written
 	return log
 }
 
@@ -88,6 +92,11 @@
 	tlog.helper.reset()
 }
 
+// SetLogEventCb sets a callback invoked for log events.
+func (tlog *TestLogger) SetLogEventCb(cb func(string)) {
+	tlog.helper.setLogEventCb(cb)
+}
+
 // SourceRelative produces a path relative to the source code, makes
 // sense only for tests when the code is available on disk.
 func SourceRelative(relativePath string) string {