feat: add session log summary on connection close

Logs a summary of session statistics when a client drops its client
connection. Also cleans up several places where the PushState had
its uaid set but not its uaid_obj or uaid_hash.

Closes #448

autopush/tests/test_integration.py

@@ -82,6 +82,11 @@ def logged_ci(self, predicate):
         return self.logged(
             lambda e: 'client_info' in e and predicate(e['client_info']))
 
+    def logged_session(self):
+        """Extract the last logged session"""
+        return filter(lambda e: e["log_format"] == "Session",
+                      self._events)[-1]
+
 
 def setUp():
     logging.getLogger('boto').setLevel(logging.CRITICAL)
@@ -516,6 +521,9 @@ def test_delivery_while_disconnected(self):
         eq_(len(result["updates"]), 1)
         eq_(result["updates"][0]["channelID"], chan)
         yield self.shut_down(client)
+        log_event = self.logs.logged_session()
+        eq_(log_event["connection_type"], "simplepush")
+        eq_(log_event["direct_acked"], 0)
 
     @inlineCallbacks
     def test_delivery_repeat_without_ack(self):
@@ -546,6 +554,10 @@ def test_direct_delivery_without_ack(self):
         result = yield client.send_notification()
         ok_(result != {})
         yield client.disconnect()
+        log_event = self.logs.logged_session()
+        eq_(log_event["direct_acked"], 0)
+        eq_(log_event["direct_storage"], 1)
+
         yield client.connect()
         yield client.hello()
         result2 = yield client.get_notification(timeout=5)
@@ -571,12 +583,19 @@ def test_dont_deliver_acked(self):
         eq_(update["channelID"], chan)
         yield client.ack(chan, update["version"])
         yield client.disconnect()
+        log_event = self.logs.logged_session()
+        eq_(log_event["connection_type"], "simplepush")
+        eq_(log_event["stored_acked"], 1)
+
         time.sleep(0.2)
         yield client.connect()
         yield client.hello()
         result = yield client.get_notification()
         eq_(result, None)
         yield self.shut_down(client)
+        log_event = self.logs.logged_session()
+        eq_(log_event["connection_type"], "simplepush")
+        eq_(log_event["stored_acked"], 0)
 
     @inlineCallbacks
     def test_no_delivery_to_unregistered(self):
@@ -820,6 +839,9 @@ def test_basic_delivery(self):
         eq_(result["data"], base64url_encode(data))
         eq_(result["messageType"], "notification")
         yield self.shut_down(client)
+        log_event = self.logs.logged_session()
+        eq_(log_event["connection_type"], "webpush")
+        eq_(log_event["direct_storage"], 1)
 
     @inlineCallbacks
     def test_topic_basic_delivery(self):

autopush/tests/test_websocket.py

@@ -59,6 +59,7 @@
 dummy_chid = uuid.uuid4()
 dummy_chid_str = str(dummy_chid)
 dummy_uaid = uuid.uuid4()
+dummy_uaid_str = dummy_uaid.hex
 
 
 def dummy_notif(**kwargs):
@@ -340,7 +341,7 @@ def test_bad_json(self):
 
     def test_no_messagetype_after_hello(self):
         self._connect()
-        self.proto.ps.uaid = "asdf"
+        self.proto.ps.uaid = dummy_uaid_str
         self._send_message(dict(data="wassup"))
 
         def check_result(close_args):
@@ -353,7 +354,7 @@ def check_result(close_args):
 
     def test_unknown_messagetype(self):
         self._connect()
-        self.proto.ps.uaid = "asdf"
+        self.proto.ps.uaid = dummy_uaid_str
         self._send_message(dict(messageType="wassup"))
 
         def check_result(close_args):
@@ -366,8 +367,8 @@ def check_result(close_args):
 
     def test_close_with_cleanup(self):
         self._connect()
-        self.proto.ps.uaid = "asdf"
-        self.proto.ap_settings.clients["asdf"] = self.proto
+        self.proto.ps.uaid = dummy_uaid_str
+        self.proto.ap_settings.clients[dummy_uaid_str] = self.proto
 
         # Stick a mock on
         notif_mock = Mock()
@@ -380,8 +381,8 @@ def test_close_with_cleanup(self):
 
     def test_close_with_delivery_cleanup(self):
         self._connect()
-        self.proto.ps.uaid = uuid.uuid4().hex
-        self.proto.ap_settings.clients["asdf"] = self.proto
+        self.proto.ps.uaid = dummy_uaid_str
+        self.proto.ap_settings.clients[dummy_uaid_str] = self.proto
         chid = str(uuid.uuid4())
 
         # Stick an un-acked direct notification in