Example #1
0
def setup_worker(message_handler: MessageHandler, logging_queue: Queue):
    """
    This function will be called after a new worker process has been created. Its purpose is to set the global
    variables in this specific worker process so that they can be reused across multiple requests. Otherwise we would
    have to pickle them each and every time, and because they are static that would be a waste.

    :param message_handler: The message handler for the incoming requests
    :param logging_queue: The queue where we can deposit log messages so the main process can log them
    """
    # Let's shorten the process name a bit by removing everything except the "Worker-x" bit at the end
    this_process = current_process()
    this_process.name = re.sub(r'^.*(Worker-\d+)$', r'\1', this_process.name)

    # Ignore normal signal handling
    signal.signal(signal.SIGINT, lambda signum, frame: None)
    signal.signal(signal.SIGTERM, lambda signum, frame: None)
    signal.signal(signal.SIGHUP, lambda signum, frame: None)

    # Save the logger, don't let it filter, send everything to the queue
    global logger
    logger = logging.getLogger()
    logger.setLevel(logging.NOTSET)

    global logging_handler
    logging_handler = WorkerQueueHandler(logging_queue)
    logger.addHandler(logging_handler)

    # Save the message handler
    global current_message_handler
    current_message_handler = message_handler

    # Run the per-process startup code for the message handler and its children
    message_handler.worker_init()
    def setUp(self):
        # Add a dummy extensions that modifies the marks
        server_extension_registry['dummy'] = DummyExtension()

        # Some mock objects to use
        self.dummy_handler = DeepCopyMagicMock(spec=Handler)
        unicast_me_filter = MarkedWithFilter(filter_condition='unicast-me',
                                             sub_handlers=[ServerUnicastOptionHandler(
                                                 address=IPv6Address('2001:db8::1')
                                             )])
        ignore_me_filter = MarkedWithFilter(filter_condition='ignore-me', sub_handlers=[IgnoreRequestHandler()])
        reject_me_filter = MarkedWithFilter(filter_condition='reject-me', sub_handlers=[BadExceptionHandler()])

        # Prove to PyCharm that this is really a handler
        self.assertIsInstance(self.dummy_handler, Handler)

        # This is the DUID that is used in the message fixtures
        self.duid = LinkLayerTimeDUID(hardware_type=1, time=488458703, link_layer_address=bytes.fromhex('00137265ca42'))

        # Create some message handlers
        self.message_handler = MessageHandler(server_id=self.duid,
                                              sub_filters=[unicast_me_filter, ignore_me_filter, reject_me_filter],
                                              sub_handlers=[self.dummy_handler],
                                              allow_rapid_commit=False,
                                              rapid_commit_rejections=False)
        self.rapid_message_handler = MessageHandler(server_id=self.duid,
                                                    sub_handlers=[self.dummy_handler],
                                                    allow_rapid_commit=True,
                                                    rapid_commit_rejections=False)
        self.very_rapid_message_handler = MessageHandler(server_id=self.duid,
                                                         sub_handlers=[self.dummy_handler],
                                                         allow_rapid_commit=True,
                                                         rapid_commit_rejections=True)
Example #3
0
def setup_worker(message_handler: MessageHandler, logging_queue: Queue,
                 lowest_log_level: int, statistics: ServerStatistics,
                 master_pid: int):
    """
    This function will be called after a new worker process has been created. Its purpose is to set the global
    variables in this specific worker process so that they can be reused across multiple requests. Otherwise we would
    have to pickle them each and every time, and because they are static that would be a waste.

    :param message_handler: The message handler for the incoming requests
    :param logging_queue: The queue where we can deposit log messages so the main process can log them
    :param lowest_log_level: The lowest log level that is going to be handled by the main process
    :param statistics: Container for shared memory with statistics counters
    :param master_pid: The PID of the master process, in case we have critical errors while initialising
    """
    try:
        # Let's shorten the process name a bit by removing everything except the "Worker-x" bit at the end
        this_process = current_process()
        this_process.name = re.sub(r'^.*(Worker-\d+)$', r'\1',
                                   this_process.name)

        # Ignore normal signal handling
        signal.signal(signal.SIGINT, lambda signum, frame: None)
        signal.signal(signal.SIGTERM, lambda signum, frame: None)
        signal.signal(signal.SIGHUP, lambda signum, frame: None)

        # Save the logger, don't let it filter, send everything to the queue
        global logger
        logger = logging.getLogger()
        logger.setLevel(logging.NOTSET)

        global logging_handler
        logging_handler = WorkerQueueHandler(logging_queue)
        logging_handler.setLevel(lowest_log_level)
        logger.addHandler(logging_handler)

        # Save the message handler
        global current_message_handler
        current_message_handler = message_handler

        global shared_statistics
        shared_statistics = statistics

        # Run the per-process startup code for the message handler and its children
        message_handler.worker_init()
    except Exception as e:
        if logger:
            logger.error("Error initialising worker: {}".format(e))

        # Signal our predicament
        os.kill(master_pid, signal.SIGUSR1)

        # Redirect to stderr to prevent stack traces on console
        sys.stderr = open(os.devnull, 'w')
        raise e
Example #4
0
def setup_worker(message_handler: MessageHandler, logging_queue: Queue, lowest_log_level: int,
                 statistics: ServerStatistics, master_pid: int):
    """
    This function will be called after a new worker process has been created. Its purpose is to set the global
    variables in this specific worker process so that they can be reused across multiple requests. Otherwise we would
    have to pickle them each and every time, and because they are static that would be a waste.

    :param message_handler: The message handler for the incoming requests
    :param logging_queue: The queue where we can deposit log messages so the main process can log them
    :param lowest_log_level: The lowest log level that is going to be handled by the main process
    :param statistics: Container for shared memory with statistics counters
    :param master_pid: The PID of the master process, in case we have critical errors while initialising
    """
    try:
        # Let's shorten the process name a bit by removing everything except the "Worker-x" bit at the end
        this_process = current_process()
        this_process.name = re.sub(r'^.*(Worker-\d+)$', r'\1', this_process.name)

        # Ignore normal signal handling
        signal.signal(signal.SIGINT, lambda signum, frame: None)
        signal.signal(signal.SIGTERM, lambda signum, frame: None)
        signal.signal(signal.SIGHUP, lambda signum, frame: None)

        # Save the logger, don't let it filter, send everything to the queue
        global logger
        logger = logging.getLogger()
        logger.setLevel(logging.NOTSET)

        global logging_handler
        logging_handler = WorkerQueueHandler(logging_queue)
        logging_handler.setLevel(lowest_log_level)
        logger.addHandler(logging_handler)

        # Save the message handler
        global current_message_handler
        current_message_handler = message_handler

        global shared_statistics
        shared_statistics = statistics

        # Run the per-process startup code for the message handler and its children
        message_handler.worker_init()
    except Exception as e:
        if logger:
            logger.error("Error initialising worker: {}".format(e))

        # Signal our predicament
        os.kill(master_pid, signal.SIGUSR1)

        # Redirect to stderr to prevent stack traces on console
        sys.stderr = open(os.devnull, 'w')
        raise e
Example #5
0
def setup_worker(message_handler: MessageHandler, logging_queue: Queue,
                 lowest_log_level: int, statistics: ServerStatistics):
    """
    This function will be called after a new worker process has been created. Its purpose is to set the global
    variables in this specific worker process so that they can be reused across multiple requests. Otherwise we would
    have to pickle them each and every time, and because they are static that would be a waste.

    :param message_handler: The message handler for the incoming requests
    :param logging_queue: The queue where we can deposit log messages so the main process can log them
    :param lowest_log_level: The lowest log level that is going to be handled by the main process
    :param statistics: Container for shared memory with statistics counters
    """
    # Let's shorten the process name a bit by removing everything except the "Worker-x" bit at the end
    this_process = current_process()
    this_process.name = re.sub(r'^.*(Worker-\d+)$', r'\1', this_process.name)

    # Ignore normal signal handling
    signal.signal(signal.SIGINT, lambda signum, frame: None)
    signal.signal(signal.SIGTERM, lambda signum, frame: None)
    signal.signal(signal.SIGHUP, lambda signum, frame: None)

    # Save the logger, don't let it filter, send everything to the queue
    global logger
    logger = logging.getLogger()
    logger.setLevel(logging.NOTSET)

    global logging_handler
    logging_handler = WorkerQueueHandler(logging_queue)
    logging_handler.setLevel(lowest_log_level)
    logger.addHandler(logging_handler)

    # Save the message handler
    global current_message_handler
    current_message_handler = message_handler

    global shared_statistics
    shared_statistics = statistics

    # Run the per-process startup code for the message handler and its children
    message_handler.worker_init()
Example #6
0
    def create_message_handler(self) -> MessageHandler:
        """
        Create a message handler based on this configuration.

        :return: The message handler
        """
        sub_filters = []
        for filter_factory in self.section.filter_factories:
            sub_filters.append(filter_factory())

        sub_handlers = []
        for handler_factory in self.section.handler_factories:
            sub_handlers.append(handler_factory())

        return MessageHandler(self.section.server_id, sub_filters,
                              sub_handlers, self.section.allow_rapid_commit)
Example #7
0
    def setUp(self):
        # Add a dummy extensions that modifies the marks
        server_extension_registry['dummy'] = DummyExtension()

        # Some mock objects to use
        self.dummy_handler = DeepCopyMagicMock(spec=Handler)
        unicast_me_filter = MarkedWithFilter(
            filter_condition='unicast-me',
            sub_handlers=[
                ServerUnicastOptionHandler(address=IPv6Address('2001:db8::1'))
            ])
        ignore_me_filter = MarkedWithFilter(
            filter_condition='ignore-me',
            sub_handlers=[IgnoreRequestHandler()])
        reject_me_filter = MarkedWithFilter(
            filter_condition='reject-me', sub_handlers=[BadExceptionHandler()])

        # Prove to PyCharm that this is really a handler
        self.assertIsInstance(self.dummy_handler, Handler)

        # This is the DUID that is used in the message fixtures
        self.duid = LinkLayerTimeDUID(
            hardware_type=1,
            time=488458703,
            link_layer_address=bytes.fromhex('00137265ca42'))

        # Create some message handlers
        self.message_handler = MessageHandler(
            server_id=self.duid,
            sub_filters=[
                unicast_me_filter, ignore_me_filter, reject_me_filter
            ],
            sub_handlers=[self.dummy_handler],
            allow_rapid_commit=False,
            rapid_commit_rejections=False)
        self.rapid_message_handler = MessageHandler(
            server_id=self.duid,
            sub_handlers=[self.dummy_handler],
            allow_rapid_commit=True,
            rapid_commit_rejections=False)
        self.very_rapid_message_handler = MessageHandler(
            server_id=self.duid,
            sub_handlers=[self.dummy_handler],
            allow_rapid_commit=True,
            rapid_commit_rejections=True)
Example #8
0
class MessageHandlerTestCase(unittest.TestCase):
    def setUp(self):
        # Add a dummy extensions that modifies the marks
        server_extension_registry['dummy'] = DummyExtension()

        # Some mock objects to use
        self.dummy_handler = DeepCopyMagicMock(spec=Handler)
        unicast_me_filter = MarkedWithFilter(
            filter_condition='unicast-me',
            sub_handlers=[
                ServerUnicastOptionHandler(address=IPv6Address('2001:db8::1'))
            ])
        ignore_me_filter = MarkedWithFilter(
            filter_condition='ignore-me',
            sub_handlers=[IgnoreRequestHandler()])
        reject_me_filter = MarkedWithFilter(
            filter_condition='reject-me', sub_handlers=[BadExceptionHandler()])

        # Prove to PyCharm that this is really a handler
        self.assertIsInstance(self.dummy_handler, Handler)

        # This is the DUID that is used in the message fixtures
        self.duid = LinkLayerTimeDUID(
            hardware_type=1,
            time=488458703,
            link_layer_address=bytes.fromhex('00137265ca42'))

        # Create some message handlers
        self.message_handler = MessageHandler(
            server_id=self.duid,
            sub_filters=[
                unicast_me_filter, ignore_me_filter, reject_me_filter
            ],
            sub_handlers=[self.dummy_handler],
            allow_rapid_commit=False,
            rapid_commit_rejections=False)
        self.rapid_message_handler = MessageHandler(
            server_id=self.duid,
            sub_handlers=[self.dummy_handler],
            allow_rapid_commit=True,
            rapid_commit_rejections=False)
        self.very_rapid_message_handler = MessageHandler(
            server_id=self.duid,
            sub_handlers=[self.dummy_handler],
            allow_rapid_commit=True,
            rapid_commit_rejections=True)

    def test_worker_init(self):
        self.message_handler.worker_init()
        self.dummy_handler.assert_has_calls([call.worker_init()])

    def test_empty_message(self):
        with self.assertLogs(level=logging.WARNING) as cm:
            bundle = TransactionBundle(incoming_message=RelayForwardMessage(),
                                       received_over_multicast=True)
            result = self.message_handler.handle(bundle, StatisticsSet())
            self.assertIsNone(result)

        self.assertEqual(len(cm.output), 1)
        self.assertRegex(cm.output[0],
                         '^WARNING:.*:A server should not receive')

    def test_ignorable_multicast_message(self):
        with self.assertLogs(level=logging.DEBUG) as cm:
            bundle = TransactionBundle(incoming_message=solicit_message,
                                       received_over_multicast=True,
                                       marks=['ignore-me'])
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message
            self.assertIsNone(result)

        self.assertEqual(len(cm.output), 3)
        self.assertRegex(cm.output[0], '^DEBUG:.*:Handling SolicitMessage')
        self.assertRegex(cm.output[1],
                         '^INFO:.*:Configured to ignore SolicitMessage')
        self.assertRegex(cm.output[2], '^WARNING:.*:.*ignoring')

    def test_reject_unicast_message(self):
        with self.assertLogs(level=logging.DEBUG) as cm:
            bundle = TransactionBundle(incoming_message=solicit_message,
                                       received_over_multicast=False)
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message
            self.assertIsInstance(result, ReplyMessage)
            self.assertEqual(
                result.get_option_of_type(StatusCodeOption).status_code,
                STATUS_USE_MULTICAST)

        self.assertEqual(len(cm.output), 3)
        self.assertRegex(cm.output[0], '^DEBUG:.*:Handling SolicitMessage')
        self.assertRegex(cm.output[1],
                         '^INFO:.*:Rejecting unicast SolicitMessage')
        self.assertRegex(cm.output[2], '^DEBUG:.*:.*multicast is required')

    def test_accept_unicast_message(self):
        bundle = TransactionBundle(incoming_message=solicit_message,
                                   received_over_multicast=False,
                                   marks=['unicast-me'])
        self.message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message
        self.assertIsInstance(result, AdvertiseMessage)
        self.assertIsNone(result.get_option_of_type(StatusCodeOption))

    def test_badly_rejected_multicast_message(self):
        with self.assertLogs(level=logging.DEBUG) as cm:
            bundle = TransactionBundle(incoming_message=solicit_message,
                                       received_over_multicast=True,
                                       marks=['reject-me'])
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message
            self.assertIsNone(result)

        self.assertEqual(len(cm.output), 3)
        self.assertRegex(cm.output[0], '^DEBUG:.*:Handling SolicitMessage')
        self.assertRegex(cm.output[1], '^DEBUG:.*:.*multicast is required')
        self.assertRegex(cm.output[2],
                         '^ERROR:.*:Not telling client to use multicast')

    def test_solicit_message(self):
        bundle = TransactionBundle(incoming_message=solicit_message,
                                   received_over_multicast=True,
                                   marks=['one', 'two', 'one'])
        self.message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message

        self.assertIsInstance(result, AdvertiseMessage)
        self.assertEqual(result.transaction_id, solicit_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption),
                         solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(
            result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(
            result.get_option_of_type(IANAOption).get_option_of_type(
                StatusCodeOption).status_code, STATUS_NO_ADDRS_AVAIL)
        self.assertEqual(
            result.get_option_of_type(IAPDOption).get_option_of_type(
                StatusCodeOption).status_code, STATUS_NO_PREFIX_AVAIL)

        # Check if the handlers are called correctly
        for method_name in ['pre', 'handle', 'post']:
            method = getattr(self.dummy_handler, method_name)

            self.assertEqual(method.call_count, 1)
            args, kwargs = method.call_args
            self.assertEqual(len(args), 1)
            self.assertEqual(len(kwargs), 0)
            self.assertIsInstance(args[0], TransactionBundle)

        # Check the types and values at various stages
        # In the pre phase there is no response yet
        bundle = self.dummy_handler.pre.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one', 'two', 'pre-setup'})
        self.assertIsNone(bundle.response)
        self.assertIsNone(bundle.outgoing_relay_messages)

        # In the handle phase there is an AdvertiseMessage
        bundle = self.dummy_handler.handle.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(
            bundle.marks,
            {'one', 'two', 'pre-setup', 'pre-cleanup', 'handle-setup'})
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

        # In the post phase there is still an AdvertiseMessage (no rapid commit)
        bundle = self.dummy_handler.post.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(
            bundle.marks, {
                'one', 'two', 'pre-setup', 'pre-cleanup', 'handle-setup',
                'handle-cleanup', 'post-setup'
            })
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

    def test_rapid_solicit_message(self):
        bundle = TransactionBundle(incoming_message=solicit_message,
                                   received_over_multicast=True,
                                   marks=['one', 'two'])
        self.rapid_message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message

        self.assertIsInstance(result, AdvertiseMessage)
        self.assertEqual(result.transaction_id, solicit_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption),
                         solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(
            result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(
            result.get_option_of_type(IANAOption).get_option_of_type(
                StatusCodeOption).status_code, STATUS_NO_ADDRS_AVAIL)
        self.assertEqual(
            result.get_option_of_type(IAPDOption).get_option_of_type(
                StatusCodeOption).status_code, STATUS_NO_PREFIX_AVAIL)

        # Check if the handlers are called correctly
        for method_name in ['pre', 'handle', 'post']:
            method = getattr(self.dummy_handler, method_name)

            self.assertEqual(method.call_count, 1)
            args, kwargs = method.call_args
            self.assertEqual(len(args), 1)
            self.assertEqual(len(kwargs), 0)
            self.assertIsInstance(args[0], TransactionBundle)

        # Check the types and values at various stages
        # In the pre phase there is no response yet
        bundle = self.dummy_handler.pre.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one', 'two', 'pre-setup'})
        self.assertIsNone(bundle.response)
        self.assertIsNone(bundle.outgoing_relay_messages)

        # In the handle phase there is an AdvertiseMessage
        bundle = self.dummy_handler.handle.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(
            bundle.marks,
            {'one', 'two', 'pre-setup', 'pre-cleanup', 'handle-setup'})
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

        # In the post phase there is still an AdvertiseMessage (rapid commit, but no rapid commit rejections)
        bundle = self.dummy_handler.post.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(
            bundle.marks, {
                'one', 'two', 'pre-setup', 'pre-cleanup', 'handle-setup',
                'handle-cleanup', 'post-setup'
            })
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

    def test_very_rapid_solicit_message(self):
        bundle = TransactionBundle(incoming_message=solicit_message,
                                   received_over_multicast=True,
                                   marks=['one'])
        self.very_rapid_message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message

        self.assertIsInstance(result, ReplyMessage)
        self.assertEqual(result.transaction_id, solicit_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption),
                         solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(
            result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(
            result.get_option_of_type(IANAOption).get_option_of_type(
                StatusCodeOption).status_code, STATUS_NO_ADDRS_AVAIL)
        self.assertEqual(
            result.get_option_of_type(IAPDOption).get_option_of_type(
                StatusCodeOption).status_code, STATUS_NO_PREFIX_AVAIL)

        # Check if the handlers are called correctly
        for method_name in ['pre', 'handle', 'post']:
            method = getattr(self.dummy_handler, method_name)

            self.assertEqual(method.call_count, 1)
            args, kwargs = method.call_args
            self.assertEqual(len(args), 1)
            self.assertEqual(len(kwargs), 0)
            self.assertIsInstance(args[0], TransactionBundle)

        # Check the types and values at various stages
        # In the pre phase there is no response yet
        bundle = self.dummy_handler.pre.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one', 'pre-setup'})
        self.assertIsNone(bundle.response)
        self.assertIsNone(bundle.outgoing_relay_messages)

        # In the handle phase there is an AdvertiseMessage
        bundle = self.dummy_handler.handle.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks,
                         {'one', 'pre-setup', 'pre-cleanup', 'handle-setup'})
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

        # In the post phase there is a ReplyMessage(rapid commit rejections)
        bundle = self.dummy_handler.post.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(
            bundle.marks, {
                'one', 'pre-setup', 'pre-cleanup', 'handle-setup',
                'handle-cleanup', 'post-setup'
            })
        self.assertIsInstance(bundle.response, ReplyMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

    def test_request_message(self):
        bundle = TransactionBundle(incoming_message=request_message,
                                   received_over_multicast=True,
                                   marks=['one'])
        self.message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message

        self.assertIsInstance(result, ReplyMessage)
        self.assertEqual(result.transaction_id, solicit_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption),
                         solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(
            result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(
            result.get_option_of_type(IANAOption).get_option_of_type(
                StatusCodeOption).status_code, STATUS_NO_ADDRS_AVAIL)
        self.assertEqual(
            result.get_option_of_type(IAPDOption).get_option_of_type(
                StatusCodeOption).status_code, STATUS_NO_PREFIX_AVAIL)

    def test_confirm_message(self):
        with self.assertLogs() as cm:
            bundle = TransactionBundle(incoming_message=confirm_message,
                                       received_over_multicast=True,
                                       marks=['one'])
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message

        self.assertEqual(len(cm.output), 1)
        self.assertRegex(cm.output[0], '^WARNING:.*:No handler confirmed')

        self.assertIsInstance(result, ReplyMessage)
        self.assertEqual(result.transaction_id, request_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption),
                         solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(
            result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(
            result.get_option_of_type(StatusCodeOption).status_code,
            STATUS_NOT_ON_LINK)

    def test_empty_confirm_message(self):
        with self.assertLogs() as cm:
            bundle = TransactionBundle(
                incoming_message=ConfirmMessage(transaction_id=b'abcd'),
                received_over_multicast=True,
                marks=['one'])
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message

        self.assertEqual(len(cm.output), 1)
        self.assertRegex(cm.output[0],
                         '^WARNING:.*:No IAs present in confirm reply')

        # ConfirmMessage without IANAOption/IATAOption/IAPDOption must be ignored
        self.assertIsNone(result)

    def test_not_implemented_message(self):
        class NotImplementedMessage(ClientServerMessage):
            """
            A non-existent message type to check how we handle unknown messages
            """
            message_type = 255
            from_client_to_server = True

        with self.assertLogs() as cm:
            bundle = TransactionBundle(
                incoming_message=NotImplementedMessage(transaction_id=b'abcd'),
                received_over_multicast=True,
                marks=['one'])
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message

        self.assertEqual(len(cm.output), 1)
        self.assertRegex(cm.output[0], '^WARNING:.*:Do not know how to reply')

        self.assertIsNone(result)
    def setUp(self):
        # This is the DUID that is used in the message fixtures
        self.duid = LinkLayerTimeDUID(hardware_type=1, time=488458703, link_layer_address=bytes.fromhex('00137265ca42'))

        # Create a message handler
        self.message_handler = MessageHandler(server_id=self.duid)
class RelayHandlerTestCase(unittest.TestCase):
    def setUp(self):
        # This is the DUID that is used in the message fixtures
        self.duid = LinkLayerTimeDUID(hardware_type=1, time=488458703, link_layer_address=bytes.fromhex('00137265ca42'))

        # Create a message handler
        self.message_handler = MessageHandler(server_id=self.duid)

    def test_empty_echo_request(self):
        relayed_solicit_message = RelayForwardMessage(
            hop_count=1,
            link_address=IPv6Address('2001:db8:ffff:1::1'),
            peer_address=IPv6Address('fe80::3631:c4ff:fe3c:b2f1'),
            options=[
                RelayMessageOption(relayed_message=SolicitMessage(
                    transaction_id=bytes.fromhex('f350d6'),
                    options=[
                        ElapsedTimeOption(elapsed_time=0),
                        ClientIdOption(duid=LinkLayerDUID(hardware_type=1,
                                                          link_layer_address=bytes.fromhex('3431c43cb2f1'))),
                        IANAOption(iaid=bytes.fromhex('c43cb2f1')),
                    ],
                )),
                EchoRequestOption(requested_options=[]),
                UnknownOption(option_type=65535),
                InterfaceIdOption(interface_id=b'Fa2/3'),
                RemoteIdOption(enterprise_number=9,
                               remote_id=bytes.fromhex('020023000001000a0003000100211c7d486e')),
            ]
        )

        bundle = TransactionBundle(incoming_message=relayed_solicit_message, received_over_multicast=True)
        self.message_handler.handle(bundle, StatisticsSet())

        self.assertIsInstance(bundle.outgoing_message, RelayReplyMessage)
        self.assertEqual(len(bundle.outgoing_message.options), 2)
        self.assertIsInstance(bundle.outgoing_message.options[0], InterfaceIdOption)
        self.assertIsInstance(bundle.outgoing_message.options[1], RelayMessageOption)

    def test_unnecessary_echo_request(self):
        relayed_solicit_message = RelayForwardMessage(
            hop_count=1,
            link_address=IPv6Address('2001:db8:ffff:1::1'),
            peer_address=IPv6Address('fe80::3631:c4ff:fe3c:b2f1'),
            options=[
                RelayMessageOption(relayed_message=SolicitMessage(
                    transaction_id=bytes.fromhex('f350d6'),
                    options=[
                        ElapsedTimeOption(elapsed_time=0),
                        ClientIdOption(duid=LinkLayerDUID(hardware_type=1,
                                                          link_layer_address=bytes.fromhex('3431c43cb2f1'))),
                        IANAOption(iaid=bytes.fromhex('c43cb2f1')),
                    ],
                )),
                EchoRequestOption(requested_options=[OPTION_INTERFACE_ID]),
                UnknownOption(option_type=65535),
                InterfaceIdOption(interface_id=b'Fa2/3'),
                RemoteIdOption(enterprise_number=9,
                               remote_id=bytes.fromhex('020023000001000a0003000100211c7d486e')),
            ]
        )

        bundle = TransactionBundle(incoming_message=relayed_solicit_message, received_over_multicast=True)
        self.message_handler.handle(bundle, StatisticsSet())

        self.assertIsInstance(bundle.outgoing_message, RelayReplyMessage)
        self.assertEqual(len(bundle.outgoing_message.options), 2)
        self.assertIsInstance(bundle.outgoing_message.options[0], InterfaceIdOption)
        self.assertIsInstance(bundle.outgoing_message.options[1], RelayMessageOption)

    def test_absent_option_echo_request(self):
        relayed_solicit_message = RelayForwardMessage(
            hop_count=1,
            link_address=IPv6Address('2001:db8:ffff:1::1'),
            peer_address=IPv6Address('fe80::3631:c4ff:fe3c:b2f1'),
            options=[
                RelayMessageOption(relayed_message=SolicitMessage(
                    transaction_id=bytes.fromhex('f350d6'),
                    options=[
                        ElapsedTimeOption(elapsed_time=0),
                        ClientIdOption(duid=LinkLayerDUID(hardware_type=1,
                                                          link_layer_address=bytes.fromhex('3431c43cb2f1'))),
                        IANAOption(iaid=bytes.fromhex('c43cb2f1')),
                    ],
                )),
                EchoRequestOption(requested_options=[OPTION_SUBSCRIBER_ID]),
                UnknownOption(option_type=65535),
                InterfaceIdOption(interface_id=b'Fa2/3'),
                RemoteIdOption(enterprise_number=9,
                               remote_id=bytes.fromhex('020023000001000a0003000100211c7d486e')),
            ]
        )

        bundle = TransactionBundle(incoming_message=relayed_solicit_message, received_over_multicast=True)
        self.message_handler.handle(bundle, StatisticsSet())

        self.assertIsInstance(bundle.outgoing_message, RelayReplyMessage)
        self.assertEqual(len(bundle.outgoing_message.options), 2)
        self.assertIsInstance(bundle.outgoing_message.options[0], InterfaceIdOption)
        self.assertIsInstance(bundle.outgoing_message.options[1], RelayMessageOption)

    def test_remote_id_echo_request(self):
        relayed_solicit_message = RelayForwardMessage(
            hop_count=1,
            link_address=IPv6Address('2001:db8:ffff:1::1'),
            peer_address=IPv6Address('fe80::3631:c4ff:fe3c:b2f1'),
            options=[
                RelayMessageOption(relayed_message=SolicitMessage(
                    transaction_id=bytes.fromhex('f350d6'),
                    options=[
                        ElapsedTimeOption(elapsed_time=0),
                        ClientIdOption(duid=LinkLayerDUID(hardware_type=1,
                                                          link_layer_address=bytes.fromhex('3431c43cb2f1'))),
                        IANAOption(iaid=bytes.fromhex('c43cb2f1')),
                    ],
                )),
                EchoRequestOption(requested_options=[OPTION_REMOTE_ID]),
                UnknownOption(option_type=65535),
                InterfaceIdOption(interface_id=b'Fa2/3'),
                RemoteIdOption(enterprise_number=9,
                               remote_id=bytes.fromhex('020023000001000a0003000100211c7d486e')),
            ]
        )

        bundle = TransactionBundle(incoming_message=relayed_solicit_message, received_over_multicast=True)
        self.message_handler.handle(bundle, StatisticsSet())

        self.assertIsInstance(bundle.outgoing_message, RelayReplyMessage)
        self.assertEqual(len(bundle.outgoing_message.options), 3)
        self.assertIsInstance(bundle.outgoing_message.options[0], InterfaceIdOption)
        self.assertIsInstance(bundle.outgoing_message.options[1], RelayMessageOption)
        self.assertIsInstance(bundle.outgoing_message.options[2], RemoteIdOption)
class MessageHandlerTestCase(unittest.TestCase):
    def setUp(self):
        # Add a dummy extensions that modifies the marks
        server_extension_registry['dummy'] = DummyExtension()

        # Some mock objects to use
        self.dummy_handler = DeepCopyMagicMock(spec=Handler)
        unicast_me_filter = MarkedWithFilter(filter_condition='unicast-me',
                                             sub_handlers=[ServerUnicastOptionHandler(
                                                 address=IPv6Address('2001:db8::1')
                                             )])
        ignore_me_filter = MarkedWithFilter(filter_condition='ignore-me', sub_handlers=[IgnoreRequestHandler()])
        reject_me_filter = MarkedWithFilter(filter_condition='reject-me', sub_handlers=[BadExceptionHandler()])

        # Prove to PyCharm that this is really a handler
        self.assertIsInstance(self.dummy_handler, Handler)

        # This is the DUID that is used in the message fixtures
        self.duid = LinkLayerTimeDUID(hardware_type=1, time=488458703, link_layer_address=bytes.fromhex('00137265ca42'))

        # Create some message handlers
        self.message_handler = MessageHandler(server_id=self.duid,
                                              sub_filters=[unicast_me_filter, ignore_me_filter, reject_me_filter],
                                              sub_handlers=[self.dummy_handler],
                                              allow_rapid_commit=False,
                                              rapid_commit_rejections=False)
        self.rapid_message_handler = MessageHandler(server_id=self.duid,
                                                    sub_handlers=[self.dummy_handler],
                                                    allow_rapid_commit=True,
                                                    rapid_commit_rejections=False)
        self.very_rapid_message_handler = MessageHandler(server_id=self.duid,
                                                         sub_handlers=[self.dummy_handler],
                                                         allow_rapid_commit=True,
                                                         rapid_commit_rejections=True)

    def test_worker_init(self):
        self.message_handler.worker_init()
        self.dummy_handler.assert_has_calls([
            call.worker_init()
        ])

    def test_empty_message(self):
        with self.assertLogs(level=logging.WARNING) as cm:
            bundle = TransactionBundle(incoming_message=RelayForwardMessage(),
                                       received_over_multicast=True)
            result = self.message_handler.handle(bundle, StatisticsSet())
            self.assertIsNone(result)

        self.assertEqual(len(cm.output), 1)
        self.assertRegex(cm.output[0], '^WARNING:.*:A server should not receive')

    def test_ignorable_multicast_message(self):
        with self.assertLogs(level=logging.DEBUG) as cm:
            bundle = TransactionBundle(incoming_message=solicit_message,
                                       received_over_multicast=True,
                                       marks=['ignore-me'])
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message
            self.assertIsNone(result)

        self.assertEqual(len(cm.output), 3)
        self.assertRegex(cm.output[0], '^DEBUG:.*:Handling SolicitMessage')
        self.assertRegex(cm.output[1], '^INFO:.*:Configured to ignore SolicitMessage')
        self.assertRegex(cm.output[2], '^WARNING:.*:.*ignoring')

    def test_reject_unicast_message(self):
        with self.assertLogs(level=logging.DEBUG) as cm:
            bundle = TransactionBundle(incoming_message=solicit_message,
                                       received_over_multicast=False)
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message
            self.assertIsInstance(result, ReplyMessage)
            self.assertEqual(result.get_option_of_type(StatusCodeOption).status_code, STATUS_USE_MULTICAST)

        self.assertEqual(len(cm.output), 3)
        self.assertRegex(cm.output[0], '^DEBUG:.*:Handling SolicitMessage')
        self.assertRegex(cm.output[1], '^INFO:.*:Rejecting unicast SolicitMessage')
        self.assertRegex(cm.output[2], '^DEBUG:.*:.*multicast is required')

    def test_accept_unicast_message(self):
        bundle = TransactionBundle(incoming_message=solicit_message,
                                   received_over_multicast=False,
                                   marks=['unicast-me'])
        self.message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message
        self.assertIsInstance(result, AdvertiseMessage)
        self.assertIsNone(result.get_option_of_type(StatusCodeOption))

    def test_badly_rejected_multicast_message(self):
        with self.assertLogs(level=logging.DEBUG) as cm:
            bundle = TransactionBundle(incoming_message=solicit_message,
                                       received_over_multicast=True,
                                       marks=['reject-me'])
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message
            self.assertIsNone(result)

        self.assertEqual(len(cm.output), 3)
        self.assertRegex(cm.output[0], '^DEBUG:.*:Handling SolicitMessage')
        self.assertRegex(cm.output[1], '^DEBUG:.*:.*multicast is required')
        self.assertRegex(cm.output[2], '^ERROR:.*:Not telling client to use multicast')

    def test_solicit_message(self):
        bundle = TransactionBundle(incoming_message=solicit_message,
                                   received_over_multicast=True,
                                   marks=['one', 'two', 'one'])
        self.message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message

        self.assertIsInstance(result, AdvertiseMessage)
        self.assertEqual(result.transaction_id, solicit_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption), solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(result.get_option_of_type(IANAOption).get_option_of_type(StatusCodeOption).status_code,
                         STATUS_NO_ADDRS_AVAIL)
        self.assertEqual(result.get_option_of_type(IAPDOption).get_option_of_type(StatusCodeOption).status_code,
                         STATUS_NO_PREFIX_AVAIL)

        # Check if the handlers are called correctly
        for method_name in ['pre', 'handle', 'post']:
            method = getattr(self.dummy_handler, method_name)

            self.assertEqual(method.call_count, 1)
            args, kwargs = method.call_args
            self.assertEqual(len(args), 1)
            self.assertEqual(len(kwargs), 0)
            self.assertIsInstance(args[0], TransactionBundle)

        # Check the types and values at various stages
        # In the pre phase there is no response yet
        bundle = self.dummy_handler.pre.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one', 'two',
                                        'pre-setup'})
        self.assertIsNone(bundle.response)
        self.assertIsNone(bundle.outgoing_relay_messages)

        # In the handle phase there is an AdvertiseMessage
        bundle = self.dummy_handler.handle.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one', 'two',
                                        'pre-setup', 'pre-cleanup',
                                        'handle-setup'})
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

        # In the post phase there is still an AdvertiseMessage (no rapid commit)
        bundle = self.dummy_handler.post.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one', 'two',
                                        'pre-setup', 'pre-cleanup',
                                        'handle-setup', 'handle-cleanup',
                                        'post-setup'})
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

    def test_rapid_solicit_message(self):
        bundle = TransactionBundle(incoming_message=solicit_message,
                                   received_over_multicast=True,
                                   marks=['one', 'two'])
        self.rapid_message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message

        self.assertIsInstance(result, AdvertiseMessage)
        self.assertEqual(result.transaction_id, solicit_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption), solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(result.get_option_of_type(IANAOption).get_option_of_type(StatusCodeOption).status_code,
                         STATUS_NO_ADDRS_AVAIL)
        self.assertEqual(result.get_option_of_type(IAPDOption).get_option_of_type(StatusCodeOption).status_code,
                         STATUS_NO_PREFIX_AVAIL)

        # Check if the handlers are called correctly
        for method_name in ['pre', 'handle', 'post']:
            method = getattr(self.dummy_handler, method_name)

            self.assertEqual(method.call_count, 1)
            args, kwargs = method.call_args
            self.assertEqual(len(args), 1)
            self.assertEqual(len(kwargs), 0)
            self.assertIsInstance(args[0], TransactionBundle)

        # Check the types and values at various stages
        # In the pre phase there is no response yet
        bundle = self.dummy_handler.pre.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one', 'two',
                                        'pre-setup'})
        self.assertIsNone(bundle.response)
        self.assertIsNone(bundle.outgoing_relay_messages)

        # In the handle phase there is an AdvertiseMessage
        bundle = self.dummy_handler.handle.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one', 'two',
                                        'pre-setup', 'pre-cleanup',
                                        'handle-setup'})
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

        # In the post phase there is still an AdvertiseMessage (rapid commit, but no rapid commit rejections)
        bundle = self.dummy_handler.post.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one', 'two',
                                        'pre-setup', 'pre-cleanup',
                                        'handle-setup', 'handle-cleanup',
                                        'post-setup'})
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

    def test_very_rapid_solicit_message(self):
        bundle = TransactionBundle(incoming_message=solicit_message,
                                   received_over_multicast=True,
                                   marks=['one'])
        self.very_rapid_message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message

        self.assertIsInstance(result, ReplyMessage)
        self.assertEqual(result.transaction_id, solicit_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption), solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(result.get_option_of_type(IANAOption).get_option_of_type(StatusCodeOption).status_code,
                         STATUS_NO_ADDRS_AVAIL)
        self.assertEqual(result.get_option_of_type(IAPDOption).get_option_of_type(StatusCodeOption).status_code,
                         STATUS_NO_PREFIX_AVAIL)

        # Check if the handlers are called correctly
        for method_name in ['pre', 'handle', 'post']:
            method = getattr(self.dummy_handler, method_name)

            self.assertEqual(method.call_count, 1)
            args, kwargs = method.call_args
            self.assertEqual(len(args), 1)
            self.assertEqual(len(kwargs), 0)
            self.assertIsInstance(args[0], TransactionBundle)

        # Check the types and values at various stages
        # In the pre phase there is no response yet
        bundle = self.dummy_handler.pre.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one',
                                        'pre-setup'})
        self.assertIsNone(bundle.response)
        self.assertIsNone(bundle.outgoing_relay_messages)

        # In the handle phase there is an AdvertiseMessage
        bundle = self.dummy_handler.handle.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one',
                                        'pre-setup', 'pre-cleanup',
                                        'handle-setup'})
        self.assertIsInstance(bundle.response, AdvertiseMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

        # In the post phase there is a ReplyMessage(rapid commit rejections)
        bundle = self.dummy_handler.post.call_args[0][0]
        self.assertEqual(bundle.request, solicit_message)
        self.assertEqual(bundle.incoming_relay_messages, [])
        self.assertEqual(bundle.marks, {'one',
                                        'pre-setup', 'pre-cleanup',
                                        'handle-setup', 'handle-cleanup',
                                        'post-setup'})
        self.assertIsInstance(bundle.response, ReplyMessage)
        self.assertEqual(bundle.outgoing_relay_messages, [])

    def test_request_message(self):
        bundle = TransactionBundle(incoming_message=request_message,
                                   received_over_multicast=True,
                                   marks=['one'])
        self.message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message

        self.assertIsInstance(result, ReplyMessage)
        self.assertEqual(result.transaction_id, solicit_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption), solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(result.get_option_of_type(IANAOption).get_option_of_type(StatusCodeOption).status_code,
                         STATUS_NO_ADDRS_AVAIL)
        self.assertEqual(result.get_option_of_type(IAPDOption).get_option_of_type(StatusCodeOption).status_code,
                         STATUS_NO_PREFIX_AVAIL)

    def test_confirm_message(self):
        with self.assertLogs() as cm:
            bundle = TransactionBundle(incoming_message=confirm_message,
                                       received_over_multicast=True,
                                       marks=['one'])
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message

        self.assertEqual(len(cm.output), 1)
        self.assertRegex(cm.output[0], '^WARNING:.*:No handler confirmed')

        self.assertIsInstance(result, ReplyMessage)
        self.assertEqual(result.transaction_id, request_message.transaction_id)
        self.assertEqual(result.get_option_of_type(ClientIdOption), solicit_message.get_option_of_type(ClientIdOption))
        self.assertEqual(result.get_option_of_type(ServerIdOption).duid, self.duid)
        self.assertEqual(result.get_option_of_type(StatusCodeOption).status_code, STATUS_NOT_ON_LINK)

    def test_empty_confirm_message(self):
        bundle = TransactionBundle(incoming_message=ConfirmMessage(transaction_id=b'abcd'),
                                   received_over_multicast=True,
                                   marks=['one'])
        self.message_handler.handle(bundle, StatisticsSet())
        result = bundle.outgoing_message

        # ConfirmMessage without IANAOption/IATAOption/IAPDOption must be ignored
        self.assertIsNone(result)

    def test_not_implemented_message(self):
        class NotImplementedMessage(ClientServerMessage):
            """
            A non-existent message type to check how we handle unknown messages
            """
            message_type = 255
            from_client_to_server = True

        with self.assertLogs() as cm:
            bundle = TransactionBundle(incoming_message=NotImplementedMessage(transaction_id=b'abcd'),
                                       received_over_multicast=True,
                                       marks=['one'])
            self.message_handler.handle(bundle, StatisticsSet())
            result = bundle.outgoing_message

        self.assertEqual(len(cm.output), 1)
        self.assertRegex(cm.output[0], '^WARNING:.*:Do not know how to reply')

        self.assertIsNone(result)