Merge lp:~ralsina/ubuntu-push/server-limits-doc into lp:ubuntu-push

[Roberto Alsina]

Add section describing limitations of the server API

Add section describing limitations of the server API

Unmerged revisions

=== modified file 'PACKAGE_DEPS'
--- PACKAGE_DEPS	2014-09-05 10:48:36 +0000
+++ PACKAGE_DEPS	2014-11-13 14:37:31 +0000
@@ -12,3 +12,4 @@
 libclick-0.4-dev
 liburl-dispatcher1-dev
 libaccounts-glib-dev
+system-image-dbus
 
=== modified file 'client/service/service.go'
--- client/service/service.go	2014-11-03 13:36:00 +0000
+++ client/service/service.go	2014-11-13 14:37:31 +0000
@@ -140,6 +140,8 @@
 		case resp.StatusCode >= http.StatusInternalServerError:
 			// XXX retry on 503
 			return nil, ErrBadServer
+		case resp.StatusCode == http.StatusUnauthorized:
+			return nil, ErrBadAuth
 		default:
 			return nil, ErrBadRequest
 		}
 
=== modified file 'client/service/service_test.go'
--- client/service/service_test.go	2014-08-06 09:01:59 +0000
+++ client/service/service_test.go	2014-11-13 14:37:31 +0000
@@ -240,6 +240,23 @@
 	c.Check(err, ErrorMatches, "unable to request registration: .*")
 }
 
+func (ss *serviceSuite) TestManageRegFailsOn401(c *C) {
+	ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		http.Error(w, "Unauthorized", 401)
+	}))
+	defer ts.Close()
+	setup := &PushServiceSetup{
+		DeviceId:   "fake-device-id",
+		RegURL:     helpers.ParseURL(ts.URL),
+		AuthGetter: func(string) string { return "tok" },
+	}
+	svc := NewPushService(setup, ss.log)
+	svc.Bus = ss.bus
+	reg, err := svc.register(aPackageOnBus, []interface{}{anAppId}, nil)
+	c.Check(err, Equals, ErrBadAuth)
+	c.Check(reg, IsNil)
+}
+
 func (ss *serviceSuite) TestManageRegFailsOn40x(c *C) {
 	ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		http.Error(w, "I'm a teapot", 418)
 
=== modified file 'client/session/session.go'
--- client/session/session.go	2014-11-03 13:36:00 +0000
+++ client/session/session.go	2014-11-13 14:37:31 +0000
@@ -430,7 +430,7 @@
 		return err
 	}
 	sess.clearShouldDelay()
-	sess.Log.Debugf("broadcast chan:%v app:%v topLevel:%d payloads:%s",
+	sess.Log.Infof("broadcast chan:%v app:%v topLevel:%d payloads:%s",
 		bcast.ChanId, bcast.AppId, bcast.TopLevel, bcast.Payloads)
 	if bcast.ChanId == protocol.SystemChannelId {
 		// the system channel id, the only one we care about for now
@@ -438,7 +438,7 @@
 		sess.BroadcastCh <- sess.decodeBroadcast(bcast)
 		sess.Log.Debugf("sent bcast over")
 	} else {
-		sess.Log.Debugf("what is this weird channel, %#v?", bcast.ChanId)
+		sess.Log.Errorf("what is this weird channel, %#v?", bcast.ChanId)
 	}
 	return nil
 }
@@ -468,7 +468,7 @@
 		if to == nil {
 			continue
 		}
-		sess.Log.Debugf("unicast app:%v msg:%s payload:%s",
+		sess.Log.Infof("unicast app:%v msg:%s payload:%s",
 			notif.AppId, notif.MsgId, notif.Payload)
 		sess.Log.Debugf("sending ucast over")
 		sess.NotificationsCh <- AddressedNotification{to, notif}
 
=== modified file 'debian/config.json'
--- debian/config.json	2014-08-21 10:47:12 +0000
+++ debian/config.json	2014-11-13 14:37:31 +0000
@@ -12,7 +12,7 @@
     "recheck_timeout": "10m",
     "connectivity_check_url": "http://start.ubuntu.com/connectivity-check.html",
     "connectivity_check_md5": "4589f42e1546aa47ca181e5d949d310b",
-    "log_level": "debug",
+    "log_level": "info",
     "fallback_vibration": {"pattern": [100, 100], "repeat": 2},
     "fallback_sound": "sounds/ubuntu/notifications/Slick.ogg",
     "poll_interval": "5m",
 
=== modified file 'docs/_common.txt'
--- docs/_common.txt	2014-10-09 16:06:52 +0000
+++ docs/_common.txt	2014-11-13 14:37:31 +0000
@@ -185,3 +185,46 @@
 :clear_pending: Discards all previous pending notifications. Usually in response to getting a "too-many-pending" error.
 :replace_tag: If there's a pending notification with the same tag, delete it before queuing this new one.
 :data: A JSON object.
+
+Limitations of the Server API
+-----------------------------
+
+The push notification infrastructure is meant to help ensuring timely
+delivery of application notifications if the device is online or
+timely informing the device user about application notifications that
+were pending when the device comes back online. This in the face of
+applications not being allowed to be running all the time, and
+avoiding the resource cost of many applications all polling different services
+frequently.
+
+The push notification infrastructure is architected to guarantee at
+least best-effort with respect to these goals and beyond it, on the
+other end applications should not expect to be able to use and only
+rely on the push notification infrastructure to store application
+messages if they want ensure all their notification or messages are
+delivered, the infrastructure is not intended to be the only long term
+"inbox" storage for an application.
+
+To preserve overall throughput the infrastructure imposes some limits
+on applications:
+
+ * message data payload is limited to 2K
+
+ * when inserted all messages need to specify an expiration date after
+   which they can be dropped and not delivered
+
+ * an application is limited in the number of messages per token
+   (application/user/device combination) that can be undelivered/pending at the
+   same time (100 currently)
+
+replace_tag can be used to implement notifications for which the newest
+one replace the previous one if pending.
+
+clear_pending can be used to be deal with a pending message limit
+reached, possibly substituting the current undelivered messages with a
+more generic one.
+
+Applications using the push notification HTTP API should be robust
+against receiving 503 errors, retrying after waiting with increasing
+back-off. Later rate limits (signaled with the 429 status) may also come
+into play.
 
=== modified file 'docs/example-client/main.qml'
--- docs/example-client/main.qml	2014-09-10 14:38:40 +0000
+++ docs/example-client/main.qml	2014-11-13 14:37:31 +0000
@@ -26,9 +26,42 @@
         property alias nickEnabled: nickEdit.enabled
     }
 
+    states: [
+        State {
+            name: "no-push-token"
+            when: (pushClient.token == "")
+            PropertyChanges { target: nickEdit; readOnly: true}
+            PropertyChanges { target: nickEdit; focus: true}
+            PropertyChanges { target: messageEdit; enabled: false}
+            PropertyChanges { target: loginButton; enabled: false}
+            PropertyChanges { target: loginButton; text: "Login"}
+        },
+        State {
+            name: "push-token-not-registered"
+            when: ((pushClient.token != "") && (chatClient.registered == false))
+            PropertyChanges { target: nickEdit; readOnly: false}
+            PropertyChanges { target: nickEdit; text: ""}
+            PropertyChanges { target: nickEdit; focus: true}
+            PropertyChanges { target: messageEdit; enabled: false}
+            PropertyChanges { target: loginButton; enabled: true}
+            PropertyChanges { target: loginButton; text: "Login"}
+        },
+        State {
+            name: "registered"
+            when: ((pushClient.token != "") && (chatClient.registered == true))
+            PropertyChanges { target: nickEdit; readOnly: true}
+            PropertyChanges { target: nickEdit; text: "Your nick is " + chatClient.nick}
+            PropertyChanges { target: messageEdit; focus: true}
+            PropertyChanges { target: messageEdit; enabled: true}
+            PropertyChanges { target: loginButton; enabled: true}
+            PropertyChanges { target: loginButton; text: "Logout"}
+        }
+    ]
+
+    state: "no-push-token"
+
     ChatClient {
         id: chatClient
-        onRegisteredChanged: {nickEdit.registered()}
         onError: {messageList.handle_error(msg)}
         token: pushClient.token
     }
@@ -44,7 +77,6 @@
 
     TextField {
         id: nickEdit
-        focus: true
         placeholderText: "Your nickname"
         inputMethodHints: Qt.ImhNoAutoUppercase | Qt.ImhNoPredictiveText | Qt.ImhPreferLowercase
         anchors.left: parent.left
@@ -53,31 +85,17 @@
         anchors.leftMargin: units.gu(.5)
         anchors.rightMargin: units.gu(1)
         anchors.topMargin: units.gu(.5)
-        function registered() {
-            readOnly = true
-            text = "Your nick is " + chatClient.nick
-            messageEdit.focus = true
-            messageEdit.enabled = true
-            loginButton.text = "Logout"
-        }
         onAccepted: { loginButton.clicked() }
     }
 
     Button {
         id: loginButton
-        text: chatClient.rgistered? "Logout": "Login"
         anchors.top: nickEdit.top
         anchors.right: parent.right
         anchors.rightMargin: units.gu(.5)
         onClicked: {
             if (chatClient.nick) { // logout
                 chatClient.nick = ""
-                text = "Login"
-                nickEdit.enabled = true
-                nickEdit.readOnly = false
-                nickEdit.text = ""
-                nickEdit.focus = true
-                messageEdit.enabled = false
             } else { // login
                 chatClient.nick = nickEdit.text
             }
@@ -94,7 +112,6 @@
         anchors.rightMargin: units.gu(.5)
         anchors.leftMargin: units.gu(.5)
         placeholderText: "Your message"
-        enabled: false
         onAccepted: {
             console.log("sending " + text)
             var idx = text.indexOf(":")
 
=== modified file 'docs/example-client/manifest.json'
--- docs/example-client/manifest.json	2014-09-10 14:38:31 +0000
+++ docs/example-client/manifest.json	2014-11-13 14:37:31 +0000
@@ -15,5 +15,5 @@
     "maintainer": "Roberto Alsina <[e-mail]>",
     "name": "com.ubuntu.developer.ralsina.hello",
     "title": "Hello",
-    "version": "0.4.2"
+    "version": "0.4.3"
 }
 
=== modified file 'docs/lowlevel.txt'
--- docs/lowlevel.txt	2014-10-15 16:34:25 +0000
+++ docs/lowlevel.txt	2014-11-13 14:37:31 +0000
@@ -57,6 +57,8 @@
 The Register method takes as argument the APP_ID (in the example, com.ubuntu.music_music) and returns a token identifying the user
 and device. For this to succeed the user **must** have an Ubuntu One account configured in the device.
 
+In the case the Register method returns a "bad auth" error, the application should inform the user to generate new Ubuntu One tokens.
+
 The APP_ID is as described in the `ApplicationId documentation <https://wiki.ubuntu.com/AppStore/Interfaces/ApplicationId>`__
 except that the version is treated as optional. Therefore both ``com.ubuntu.music_music`` and ``com.ubuntu.music_music_1.3.496``
 are valid. Keep in mind that while both versioned and unversioned APP_IDs are valid, they are still different and will affect
 
=== modified file 'launch_helper/kindpool.go'
--- launch_helper/kindpool.go	2014-08-20 12:42:51 +0000
+++ launch_helper/kindpool.go	2014-11-13 14:37:31 +0000
@@ -294,12 +294,13 @@
 	}
 	payload, err := ioutil.ReadFile(args.FileOut)
 	if err != nil {
-		pool.log.Errorf("unable to read output from helper: %v", err)
+		pool.log.Errorf("unable to read output from %v helper: %v", args.AppId, err)
 	} else {
+		pool.log.Infof("%v helper output: %#v", args.AppId, payload)
 		res := &HelperResult{Input: args.Input}
 		err = json.Unmarshal(payload, &res.HelperOutput)
 		if err != nil {
-			pool.log.Debugf("failed to parse HelperOutput from helper output: %v", err)
+			pool.log.Errorf("failed to parse HelperOutput from %v helper output: %v", args.AppId, err)
 		} else {
 			pool.chOut <- res
 		}
 
=== modified file 'launch_helper/legacy/legacy.go'
--- launch_helper/legacy/legacy.go	2014-08-21 18:03:49 +0000
+++ launch_helper/legacy/legacy.go	2014-11-13 14:37:31 +0000
@@ -55,7 +55,7 @@
 	err error
 }
 
-func (lhl *legacyHelperLauncher) Launch(_, progname, f1, f2 string) (string, error) {
+func (lhl *legacyHelperLauncher) Launch(appId, progname, f1, f2 string) (string, error) {
 	comm := make(chan msg)
 
 	go func() {
@@ -78,9 +78,8 @@
 		p_err := cmd.Wait()
 		if p_err != nil {
 			// Helper failed or got killed, log output/errors
-			lhl.log.Errorf("Legacy helper failed: %v", p_err)
-			lhl.log.Errorf("Legacy helper failed. Stdout: %s", stdout)
-			lhl.log.Errorf("Legacy helper failed. Stderr: %s", stderr)
+			lhl.log.Errorf("Legacy helper failed: appId: %v, helper: %v, pid: %v, error: %v, stdout: %#v, stderr: %#v.",
+				appId, progname, id, p_err, stdout.String(), stderr.String())
 		}
 		lhl.done(id)
 	}()
 
=== modified file 'server/acceptance/suites/helpers.go'
--- server/acceptance/suites/helpers.go	2014-07-08 15:08:52 +0000
+++ server/acceptance/suites/helpers.go	2014-11-13 14:37:31 +0000
@@ -127,6 +127,11 @@
 				c.Log(info)
 				continue
 			}
+			if strings.HasPrefix(info, "DEBUG ") && !strings.HasPrefix(info, "DEBUG session(") {
+				// skip non session DEBUG logs
+				c.Log(info)
+				continue
+			}
 			logs <- info
 		}
 	}()
@@ -136,16 +141,12 @@
 const (
 	DevListeningOnPat  = "INFO listening for devices on "
 	HTTPListeningOnPat = "INFO listening for http on "
-	debugPrefix        = "DEBUG "
 )
 
-// ExtractListeningAddr goes over logs ignoring DEBUG lines
-// until a line starting with pat and returns the rest of that line.
+// ExtractListeningAddr goes over logs until a line starting with pat
+// and returns the rest of that line.
 func ExtractListeningAddr(c *C, logs <-chan string, pat string) string {
 	for line := range logs {
-		if strings.HasPrefix(line, debugPrefix) {
-			continue
-		}
 		if !strings.HasPrefix(line, pat) {
 			c.Fatalf("matching %v: %v", pat, line)
 		}
 
=== modified file 'server/api/handlers.go'
--- server/api/handlers.go	2014-07-14 15:23:17 +0000
+++ server/api/handlers.go	2014-11-13 14:37:31 +0000
@@ -98,6 +98,12 @@
 		"Wrong request method, should be POST",
 		nil,
 	}
+	ErrWrongRequestMethodGET = &APIError{
+		http.StatusMethodNotAllowed,
+		invalidRequest,
+		"Wrong request method, should be GET",
+		nil,
+	}
 	ErrMalformedJSONObject = &APIError{
 		http.StatusBadRequest,
 		invalidRequest,
@@ -452,14 +458,17 @@
 	if err != nil {
 		switch err {
 		case store.ErrUnknownToken:
+			ctx.logger.Debugf("notify: %v %v unknown", ucast.AppId, ucast.Token)
 			return nil, ErrUnknownToken
 		case store.ErrUnauthorized:
+			ctx.logger.Debugf("notify: %v %v unauthorized", ucast.AppId, ucast.Token)
 			return nil, ErrUnauthorized
 		default:
 			ctx.logger.Errorf("could not resolve token: %v", err)
 			return nil, ErrCouldNotResolveToken
 		}
 	}
+	ctx.logger.Debugf("notify: %v %v -> %v", ucast.AppId, ucast.Token, chanId)
 
 	_, notifs, meta, err := sto.GetChannelUnfiltered(chanId)
 	if err != nil {
@@ -491,6 +500,7 @@
 	if ucast.ClearPending {
 		scrubCriteria = []string{ucast.AppId}
 	} else if forApp >= ctx.storage.GetMaxNotificationsPerApplication() {
+		ctx.logger.Debugf("notify: %v %v too many pending", ucast.AppId, chanId)
 		return nil, apiErrorWithExtra(ErrTooManyPendingNotifications,
 			&last.Payload)
 	} else if replaceable > 0 {
@@ -518,6 +528,8 @@
 	}
 
 	ctx.broker.Unicast(chanId)
+
+	ctx.logger.Debugf("notify: ok %v %v id:%v clear:%v replace:%v expired:%v", ucast.AppId, chanId, msgId, ucast.ClearPending, replaceable, expired)
 	return nil, nil
 }
 
 
=== modified file 'server/api/handlers_test.go'
--- server/api/handlers_test.go	2014-07-15 15:03:49 +0000
+++ server/api/handlers_test.go	2014-11-13 14:37:31 +0000
@@ -362,7 +362,7 @@
 	}
 	sto := store.NewInMemoryPendingStore()
 	bsend := &checkBrokerSending{store: sto}
-	ctx := &context{testStoreAccess(nil), bsend, nil}
+	ctx := &context{testStoreAccess(nil), bsend, s.testlog}
 	payload := json.RawMessage(`{"a": 1}`)
 	res, apiErr := doUnicast(ctx, sto, &Unicast{
 		UserId:   "user1",
@@ -487,7 +487,7 @@
 	sto.AppendToUnicastChannel(chanId, "app1", n, "m4", expire)
 
 	bsend := &checkBrokerSending{store: sto}
-	ctx := &context{testStoreAccess(nil), bsend, nil}
+	ctx := &context{testStoreAccess(nil), bsend, s.testlog}
 	payload := json.RawMessage(`{"a": 1}`)
 	res, apiErr := doUnicast(ctx, sto, &Unicast{
 		UserId:   "user1",
@@ -528,7 +528,7 @@
 	sto.AppendToUnicastChannel(chanId, "app1", n, "m1", expire)
 
 	bsend := &checkBrokerSending{store: sto}
-	ctx := &context{testStoreAccess(nil), bsend, nil}
+	ctx := &context{testStoreAccess(nil), bsend, s.testlog}
 	payload := json.RawMessage(`{"a": 1}`)
 	res, apiErr := doUnicast(ctx, sto, &Unicast{
 		UserId:     "user1",
@@ -634,7 +634,7 @@
 	sto.AppendToUnicastChannel(chanId, "app1", n, "m4", expire)
 
 	bsend := &checkBrokerSending{store: sto}
-	ctx := &context{testStoreAccess(nil), bsend, nil}
+	ctx := &context{testStoreAccess(nil), bsend, s.testlog}
 	payload := json.RawMessage(`{"a": 1}`)
 	res, apiErr := doUnicast(ctx, sto, &Unicast{
 		UserId:       "user1",
@@ -965,7 +965,7 @@
 		return sto, nil
 	})
 	bsend := testBrokerSending{make(chan store.InternalChannelId, 1)}
-	testServer := httptest.NewServer(MakeHandlersMux(storage, bsend, nil))
+	testServer := httptest.NewServer(MakeHandlersMux(storage, bsend, s.testlog))
 	defer testServer.Close()
 
 	payload := json.RawMessage(`{"foo":"bar"}`)
@@ -1049,7 +1049,7 @@
 		return sto, nil
 	})
 	bsend := testBrokerSending{make(chan store.InternalChannelId, 1)}
-	testServer := httptest.NewServer(MakeHandlersMux(storage, bsend, nil))
+	testServer := httptest.NewServer(MakeHandlersMux(storage, bsend, s.testlog))
 	defer testServer.Close()
 
 	request := newPostRequest("/register", &Registration{
 
=== modified file 'server/broker/testsuite/suite.go'
--- server/broker/testsuite/suite.go	2014-09-25 11:16:38 +0000
+++ server/broker/testsuite/suite.go	2014-11-13 14:37:31 +0000
@@ -66,12 +66,12 @@
 
 func (s *CommonBrokerSuite) TestSanity(c *C) {
 	sto := store.NewInMemoryPendingStore()
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	c.Check(s.RevealSession(b, "FOO"), IsNil)
 }
 
 func (s *CommonBrokerSuite) TestStartStop(c *C) {
-	b := s.MakeBroker(nil, testBrokerConfig, nil)
+	b := s.MakeBroker(nil, testBrokerConfig, s.testlog)
 	b.Start()
 	c.Check(b.Running(), Equals, true)
 	b.Start()
@@ -82,7 +82,7 @@
 
 func (s *CommonBrokerSuite) TestRegistration(c *C) {
 	sto := store.NewInMemoryPendingStore()
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
 	defer b.Stop()
 	sess, err := b.Register(&protocol.ConnectMsg{
@@ -112,7 +112,7 @@
 
 func (s *CommonBrokerSuite) TestRegistrationBrokenLevels(c *C) {
 	sto := store.NewInMemoryPendingStore()
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
 	defer b.Stop()
 	_, err := b.Register(&protocol.ConnectMsg{Type: "connect", DeviceId: "dev-1", Levels: map[string]int64{"z": 5}}, s.MakeTracker("s1"))
@@ -121,7 +121,7 @@
 
 func (s *CommonBrokerSuite) TestRegistrationInfoErrors(c *C) {
 	sto := store.NewInMemoryPendingStore()
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
 	defer b.Stop()
 	info := map[string]interface{}{
@@ -140,7 +140,7 @@
 	notification1 := json.RawMessage(`{"m": "M"}`)
 	muchLater := time.Now().Add(10 * time.Minute)
 	sto.AppendToChannel(store.SystemInternalChannelId, notification1, muchLater)
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
 	defer b.Stop()
 	sess, err := b.Register(&protocol.ConnectMsg{Type: "connect", DeviceId: "dev-1"}, s.MakeTracker("s1"))
@@ -166,7 +166,7 @@
 
 func (s *CommonBrokerSuite) TestRegistrationLastWins(c *C) {
 	sto := store.NewInMemoryPendingStore()
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
 	defer b.Stop()
 	sess1, err := b.Register(&protocol.ConnectMsg{Type: "connect", DeviceId: "dev-1"}, s.MakeTracker("s1"))
@@ -197,7 +197,7 @@
 	sto := store.NewInMemoryPendingStore()
 	notification1 := json.RawMessage(`{"m": "M"}`)
 	decoded1 := map[string]interface{}{"m": "M"}
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
 	defer b.Stop()
 	sess1, err := b.Register(&protocol.ConnectMsg{Type: "connect", DeviceId: "dev-1"}, s.MakeTracker("s1"))
@@ -278,7 +278,7 @@
 	notification2 := json.RawMessage(`{"m": "M2"}`)
 	chanId1 := store.UnicastInternalChannelId("dev1", "dev1")
 	chanId2 := store.UnicastInternalChannelId("dev2", "dev2")
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
 	defer b.Stop()
 	sess1, err := b.Register(&protocol.ConnectMsg{Type: "connect", DeviceId: "dev1"}, s.MakeTracker("s1"))
@@ -312,7 +312,7 @@
 	sto := store.NewInMemoryPendingStore()
 	notification1 := json.RawMessage(`{"m": "M1"}`)
 	chanId1 := store.UnicastInternalChannelId("dev3", "dev3")
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
 	defer b.Stop()
 	sess1, err := b.Register(&protocol.ConnectMsg{Type: "connect", DeviceId: "dev3"}, s.MakeTracker("s1"))
@@ -354,7 +354,7 @@
 
 func (s *CommonBrokerSuite) TestSessionFeed(c *C) {
 	sto := store.NewInMemoryPendingStore()
-	b := s.MakeBroker(sto, testBrokerConfig, nil)
+	b := s.MakeBroker(sto, testBrokerConfig, s.testlog)
 	b.Start()
 	defer b.Stop()
 	sess1, err := b.Register(&protocol.ConnectMsg{Type: "connect", DeviceId: "dev3"}, s.MakeTracker("s1"))