Fix for #188: remove_pairing uses wrong content-type (#191)

Fix the issue and add test capabilities to verify no wrong
content type header was used.

homekit/accessoryserver.py

@@ -545,6 +545,8 @@ def _put_characteristics(self):
         if AccessoryRequestHandler.DEBUG_PUT_CHARACTERISTICS:
             self.log_message('PUT /characteristics')
             self.log_message('body: %s', self.body)
+        # see Spec R2 page 68 Chapter 6.7.2.2
+        self._log_wrong_content_type('application/hap+json')
 
         data = json.loads(self.body.decode())
         characteristics_to_set = data['characteristics']
@@ -642,6 +644,7 @@ def _get_accessories(self):
         self.wfile.write(result_bytes)
 
     def _post_pair_verify(self):
+        self._log_wrong_content_type('application/pairing+tlv8')
         d_req = tlv8.decode(self.body, {
             TlvTypes.State: tlv8.DataType.INTEGER,
             TlvTypes.PublicKey: tlv8.DataType.BYTES,
@@ -787,6 +790,11 @@ def _post_resource(self):
         self.send_error(HttpStatusCodes.NOT_FOUND)
 
     def _post_pairings(self):
+        """
+
+        :return:
+        """
+        self._log_wrong_content_type('application/pairing+tlv8')
         d_req = tlv8.decode(self.body, {
             TlvTypes.State: tlv8.DataType.INTEGER,
             TlvTypes.Method: tlv8.DataType.INTEGER,
@@ -940,7 +948,19 @@ def send_error_reply(self, state, error):
 
         self.wfile.write(result_bytes)
 
+    def _log_wrong_content_type(self, expected_content_type):
+        """
+        Issue a log entry if the content type from the headers does not match the expected content type.
+
+        :param expected_content_type: the expected content type as `str` e.g. 'application/pairing+tlv8'
+        :return: None
+        """
+        content_type = self.headers.get('Content-Type', None)
+        if content_type is not None and content_type != expected_content_type:
+            self.log_error('Wrong content type: was %s but %s was expected', content_type, expected_content_type)
+
     def _post_pair_setup(self):
+        self._log_wrong_content_type('application/pairing+tlv8')
         d_req = tlv8.decode(self.body, {
             TlvTypes.State: tlv8.DataType.INTEGER,
             TlvTypes.PublicKey: tlv8.DataType.BYTES,
@@ -1214,6 +1234,8 @@ def log_message(self, format, *args):
             pass
         elif self.server.logger == sys.stderr:
             BaseHTTPRequestHandler.log_message(self, format, *args)
+        elif isinstance(self.server.logger, list):
+            self.server.logger.append("%s" % (format % args))
         else:
             self.server.logger.info("%s" % (format % args))
 
@@ -1222,6 +1244,8 @@ def log_debug(self, format, *args):
             pass
         elif self.server.logger == sys.stderr:
             BaseHTTPRequestHandler.log_message(self, format, *args)
+        elif isinstance(self.server.logger, list):
+            self.server.logger.append("%s" % (format % args))
         else:
             self.server.logger.debug("%s" % (format % args))
 
@@ -1230,6 +1254,8 @@ def log_error(self, format, *args):
             pass
         elif self.server.logger == sys.stderr:
             BaseHTTPRequestHandler.log_error(self, format, *args)
+        elif isinstance(self.server.logger, list):
+            self.server.logger.append("%s" % (format % args))
         else:
             self.server.logger.error("%s" % (format % args))
 
@@ -1252,7 +1278,7 @@ def __init__(self, config_file, logger=sys.stderr, request_handler_class=Accesso
         :raises ConfigurationError: if either the logger cannot be used or the request_handler_class is not a subclass
         of AccessoryRequestHandler
         """
-        if logger is None or logger == sys.stderr or isinstance(logger, logging.Logger):
+        if logger is None or logger == sys.stderr or isinstance(logger, logging.Logger) or isinstance(logger, list):
             self.logger = logger
         else:
             raise ConfigurationError('Invalid logger given.')

homekit/controller/controller.py

@@ -540,7 +540,7 @@ def remove_pairing(self, alias, pairingId=None):
             if not IP_TRANSPORT_SUPPORTED:
                 raise TransportNotSupportedError('IP')
             session = IpSession(pairing_data)
-            response = session.post('/pairings', request_tlv)
+            response = session.post('/pairings', request_tlv, content_type='application/pairing+tlv8')
             session.close()
             data = response.read()
             data = tlv8.decode(data, {

tests/ble_controller_test.py

@@ -358,6 +358,8 @@ def __init__(self, char):
         self.data = char.service.device
         self.session_id = self.data.session_id
         self.sessions = self.data.sessions
+        # headers are not a BLE thing, but since we reuse the default accessory request handler here...
+        self.headers = {}
 
     def log_request(self, *args):
         pass

tests/controller_test.py

@@ -192,7 +192,8 @@ def setUpClass(cls):
         # Make sure get_id() numbers are stable between tests
         model_mixin.id_counter = 0
 
-        cls.httpd = AccessoryServer(cls.config_file.name, None)
+        cls.logger = list()
+        cls.httpd = AccessoryServer(cls.config_file.name, logger=cls.logger)
         cls.httpd.set_identify_callback(identify_callback)
         accessory = Accessory('Testlicht', 'lusiardi.de', 'Demoserver', '0001', '0.1')
         accessory.set_identify_callback(identify_callback)
@@ -231,6 +232,7 @@ def tearDownClass(cls):
 
     def setUp(self):
         self.controller = Controller()
+        self.__class__.logger.clear()
 
     def tearDown(self):
         self.controller.shutdown()
@@ -242,16 +244,19 @@ def test_01_1_discover(self):
             if '12:34:56:00:01:0A' == device['id']:
                 found = device
         self.assertIsNotNone(found)
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_02_pair_alias_exists(self):
         """Try to pair the test accessory"""
         self.controller.load_data(self.controller_file.name)
         self.assertRaises(AlreadyPairedError, self.controller.perform_pairing, 'alias', '12:34:56:00:01:0B',
                           '010-22-020')
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_02_paired_identify_wrong_method(self):
         """Try to identify an already paired accessory via the controller's method for unpaired accessories."""
         self.assertRaises(AlreadyPairedError, self.controller.identify, '12:34:56:00:01:0A')
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_03_get_accessories(self):
         self.controller.load_data(self.controller_file.name)
@@ -265,6 +270,7 @@ def test_03_get_accessories(self):
         result = result[0]
         self.assertIn('aid', result)
         self.assertIn('services', result)
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_04_1_get_characteristic(self):
         self.controller.load_data(self.controller_file.name)
@@ -274,6 +280,7 @@ def test_04_1_get_characteristic(self):
         self.assertIn('value', result[(1, 4)])
         self.assertEqual('lusiardi.de', result[(1, 4)]['value'])
         self.assertEqual(['value'], list(result[(1, 4)].keys()))
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_04_2_get_characteristics(self):
         self.controller.load_data(self.controller_file.name)
@@ -285,6 +292,7 @@ def test_04_2_get_characteristics(self):
         self.assertIn((1, 10), result)
         self.assertIn('value', result[(1, 10)])
         self.assertEqual(False, result[(1, 10)]['value'])
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_04_3_get_characteristic_with_events(self):
         """This tests the include_events flag on get_characteristics"""
@@ -295,6 +303,7 @@ def test_04_3_get_characteristic_with_events(self):
         self.assertIn('value', result[(1, 4)])
         self.assertEqual('lusiardi.de', result[(1, 4)]['value'])
         self.assertIn('ev', result[(1, 4)])
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_04_4_get_characteristic_with_type(self):
         """This tests the include_type flag on get_characteristics"""
@@ -306,6 +315,7 @@ def test_04_4_get_characteristic_with_type(self):
         self.assertEqual('lusiardi.de', result[(1, 4)]['value'])
         self.assertIn('type', result[(1, 4)])
         self.assertEqual('20', result[(1, 4)]['type'])
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_04_5_get_characteristic_with_perms(self):
         """This tests the include_perms flag on get_characteristics"""
@@ -319,6 +329,7 @@ def test_04_5_get_characteristic_with_perms(self):
         self.assertEqual(['pr'], result[(1, 4)]['perms'])
         result = pairing.get_characteristics([(1, 3)], include_perms=True)
         self.assertEqual(['pw'], result[(1, 3)]['perms'])
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_04_4_get_characteristic_with_meta(self):
         """This tests the include_meta flag on get_characteristics"""
@@ -332,6 +343,7 @@ def test_04_4_get_characteristic_with_meta(self):
         self.assertEqual('string', result[(1, 4)]['format'])
         self.assertIn('maxLen', result[(1, 4)])
         self.assertEqual(64, result[(1, 4)]['maxLen'])
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_05_1_put_characteristic(self):
         """"""
@@ -344,6 +356,7 @@ def test_05_1_put_characteristic(self):
         result = pairing.put_characteristics([(1, 10, 'Off')])
         self.assertEqual(result, {})
         self.assertEqual(0, value)
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_05_2_put_characteristic_do_conversion(self):
         """"""
@@ -356,12 +369,14 @@ def test_05_2_put_characteristic_do_conversion(self):
         result = pairing.put_characteristics([(1, 10, 'Off')], do_conversion=True)
         self.assertEqual(result, {})
         self.assertEqual(0, value)
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_05_2_put_characteristic_do_conversion_wrong_value(self):
         """Tests that values that are not convertible to boolean cause a HomeKitTypeException"""
         self.controller.load_data(self.controller_file.name)
         pairing = self.controller.get_pairings()['alias']
         self.assertRaises(FormatError, pairing.put_characteristics, [(1, 10, 'Hallo Welt')], do_conversion=True)
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_06_list_pairings(self):
         """Gets the listing of registered controllers of the device. Count must be 1."""
@@ -382,6 +397,7 @@ def test_06_list_pairings(self):
         self.assertEqual('decc6fa3-de3e-41c9-adba-ef7409821bfc', result['pairingId'])
         self.assertEqual(result['controllerType'], 'admin')
         self.assertEqual(result['permissions'], 1)
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_07_paired_identify(self):
         """Tests the paired variant of the identify method."""
@@ -392,13 +408,15 @@ def test_07_paired_identify(self):
         self.assertTrue(result)
         self.assertEqual(1, identify)
         identify = 0
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
     def test_99_remove_pairing(self):
         """Tests that a removed pairing is not present in the list of pairings anymore."""
         self.controller.load_data(self.controller_file.name)
         self.controller.remove_pairing('alias')
         pairings = self.controller.get_pairings()
         self.assertNotIn('alias', pairings)
+        self.assertNotIn('Wrong content type', '\n'.join(self.__class__.logger))
 
 
 class TestController(unittest.TestCase):