add latency measuring with ping command

Author: luos

Diff for: latency_filter.py

@@ -0,0 +1,27 @@
+from oslo_log import log as logging
+import nova.conf
+
+from nova.scheduler.filters import BaseHostFilter
+
+from latency_meter.server import start_server_on_other_thread
+
+LOG = logging.getLogger(__name__)
+
+CONF = nova.conf.CONF
+
+
+class LatencyAwareFilter(BaseHostFilter):
+    def __init__(self):
+        super(LatencyAwareFilter, self).__init__()
+        LOG.debug("GLLS Starting up")
+        start_server_on_other_thread(LOG)
+
+    def host_passes(self, host_state, spec_obj):
+        """
+        :type host_state: nova.scheduler.host_manager.HostState
+        :type spec_obj: nova.objects.request_spec.RequestSpec
+        """
+        LOG.debug("GLLS")
+        LOG.debug("GLLS " + str(host_state))
+        LOG.debug("GLLS" + str(spec_obj))
+        return True

Diff for: latency_meter/__init__.py

@@ -0,0 +1,12 @@
+from latency_meter.client.api import MeasurementProvider
+
+
+class Client:
+    def __init__(self, measurement_provider):
+        """
+
+        :type measurement_provider: MeasurementProvider
+        """
+        self.measurement_provider = measurement_provider
+
+

Diff for: latency_meter/client.py

@@ -0,0 +1,10 @@
+class MeasurementProvider():
+    pass
+
+
+class MeasuredLatency():
+    def __init__(self, received_packet_count, average_latency, success, error_code=None):
+        self.error_code = error_code
+        self.success = success
+        self.average_latency = average_latency
+        self.packet_count = received_packet_count

Diff for: latency_meter/client/__init__.py

@@ -0,0 +1,102 @@
+from subprocess import call, check_output, CalledProcessError, STDOUT
+
+from latency_meter.client.api import MeasuredLatency
+import re
+
+
+class Pinger():
+    PING_COUNT = 3
+    ERROR_UKNOWN_HOST = "unknown-host"
+    ERROR_PACKET_LOSS = "100pc-packet-loss"
+    ERROR_UNKNOWN = "unknown-error"
+
+    def __init__(self, command_runner):
+        """
+
+        :type command_runner: CommandRunner
+        """
+        self.command_runner = command_runner
+        self._first_line_regexp = re.compile(".* packets transmitted, (?P<received_count>[\d]*) received, .*")
+        self._second_line_regexp = re.compile("rtt min\/avg\/max\/mdev \= (.*)/(?P<avg>.*)/(.*)/(.*) ms")
+        self._uknown_host_regexp = re.compile("(.*)ping: unknown host(.*)")
+
+    def get_latency(self, target_host):
+        # type: (str) -> MeasuredLatency
+
+
+        ping_result = self._ping_host(target_host)
+
+        result = self._check_for_errors(ping_result)
+        if result:
+            return result
+
+        output = ping_result[1]
+
+        first_line_match = self._first_line_regexp.match(output[-2])
+        packet_count = int(first_line_match.groups('received_count')[0])
+
+        second_line_match = self._second_line_regexp.match(output[-1])
+        avg = second_line_match.group('avg')
+
+        return MeasuredLatency(
+            received_packet_count=packet_count,
+            average_latency=float(avg),
+            success=True
+        )
+
+    def _ping_host(self, target_host):
+        return self.command_runner.run(["ping", "-Dn", "-c", self.PING_COUNT, target_host])
+
+    def _check_for_errors(self, run_result):
+        return_code = run_result[0]
+        output = run_result[1]
+
+        first_line_match = self._first_line_regexp.match(output[-1])
+
+        if first_line_match:
+            packet_count = int(first_line_match.groups('received_count')[0])
+
+            if (packet_count == 0):
+                return MeasuredLatency(
+                    received_packet_count=0,
+                    average_latency=None,
+                    success=False,
+                    error_code=self.ERROR_PACKET_LOSS
+                )
+
+        if self._uknown_host_regexp.match(output[-1]):
+            return MeasuredLatency(
+                received_packet_count=0,
+                average_latency=None,
+                success=False,
+                error_code=self.ERROR_UKNOWN_HOST
+            )
+
+        if (return_code != 0):
+            return MeasuredLatency(
+                received_packet_count=None,
+                average_latency=None,
+                success=False,
+                error_code=self.ERROR_UNKNOWN
+            )
+        return None
+
+
+class CommandRunner():
+    def run(self, command):
+        """
+
+        :type command: list
+        :returns (int, str) (rc,output)
+        """
+        try:
+            rc = 0
+            result = check_output([str(c) for c in command], stderr=STDOUT)
+        except CalledProcessError as e:
+            rc = e.returncode
+            result = e.output
+
+        return (rc, self._process_lines(result))
+
+    def _process_lines(self, result):
+        return result.strip().splitlines()

Diff for: latency_meter/client/api.py

@@ -0,0 +1,81 @@
+import BaseHTTPServer
+import SimpleHTTPServer
+import SocketServer
+import threading
+from BaseHTTPServer import BaseHTTPRequestHandler
+from SimpleHTTPServer import SimpleHTTPRequestHandler
+from SocketServer import ThreadingTCPServer, TCPServer
+
+
+class MeasurementHandler():
+    data = {}
+
+    def record_measurement(self, measurement):
+        """
+
+        :type measurement: Measurement
+        """
+        self.data[measurement.from_host] = {
+            measurement.to_host: measurement.average_latency
+        }
+
+    def get_measurements_from_host(self, host):
+        return self.data[host]
+
+
+class Measurement():
+    def __init__(self, from_host, to_host, average_latency):
+        self.average_latency = average_latency
+        self.to_host = to_host
+        self.from_host = from_host
+
+
+class MeasurementRequestHandler(SimpleHTTPRequestHandler):
+    def __init__(self, request, client_address, server):
+        BaseHTTPRequestHandler.__init__(self, request, client_address, server)
+        print("blah")
+
+    def handle_one_request(self):
+        print("handing request")
+        BaseHTTPRequestHandler.handle_one_request(self)
+
+    def do_GET(self):
+        self.send_response(200)
+        self.end_headers()
+        self.wfile.write("hello world")
+        print(self.raw_requestline)
+        print(self.request)
+        self.wfile.close()
+
+
+class Httpserver(TCPServer):
+    allow_reuse_address = 1
+
+    def __init__(self, server_address, RequestHandlerClass, bind_and_activate=True, logger=None):
+        TCPServer.__init__(self, server_address, RequestHandlerClass, bind_and_activate)
+        self.logger = logger
+        logger.debug("GLLS Inicialized server")
+
+
+def start_server(port=9913, logger=None):
+    http_handler = MeasurementRequestHandler
+    server = Httpserver(('0.0.0.0', port), http_handler, logger=logger)
+    logger.debug("Listening on " + str(port))
+    try:
+        server.serve_forever()
+    except KeyboardInterrupt as e:
+        logger.debug("GLLS Shutting down")
+        logger.debug("GLLS " + e.message)
+        server.server_close()
+        server.shutdown()
+
+
+def start_server_on_other_thread(logger):
+    logger.debug("GLLS Server started")
+    thread = threading.Thread(target=lambda: start_server(logger=logger))
+    thread.start()
+
+
+class MockLogger():
+    def debug(self, string):
+        print(string)

Diff for: latency_meter/client/ping_measurement_provider.py

@@ -0,0 +1,22 @@
+from unittest import TestCase
+
+from latency_meter.server import Measurement, MeasurementHandler
+
+
+class TestMeasurementHandler(TestCase):
+    def test_given_no_measurements_returns_none(self):
+        handler = MeasurementHandler()
+        self.assertIsNone(handler.get_measurements_from_host('blah'))
+
+    def test_given_a_server_when_recording_measurements_stores_average_latency(self):
+        measurement = Measurement(
+            from_host="192.11.00.12",
+            to_host="192.00.00.99",
+            average_latency=5.95
+        )
+        handler = MeasurementHandler()
+        handler.record_measurement(measurement)
+        got = handler.get_measurements_from_host('192.11.00.12')
+        self.assertEqual(got, {
+            '192.00.00.99': 5.95
+        })

Diff for: latency_meter/server/__init__.py

@@ -0,0 +1,25 @@
+import unittest
+
+from latency_meter.client.ping_measurement_provider import Pinger, CommandRunner
+
+
+class TestPingerIntegration(unittest.TestCase):
+    def test_given_a_real_command_runner_can_ping_localhost(self):
+        pinger = Pinger(CommandRunner())
+        result = pinger.get_latency("localhost")
+        self.assertTrue(result.success)
+        self.assertEqual(Pinger.PING_COUNT, result.packet_count)
+
+    def test_given_a_made_up_ip_100_pc_packet_loss(self):
+        pinger = Pinger(CommandRunner())
+        result = pinger.get_latency("240.0.0.1") #unallocated block
+        self.assertFalse(result.success)
+        self.assertEqual(Pinger.ERROR_PACKET_LOSS, result.error_code)
+        self.assertEqual(0, result.packet_count)
+
+    def test_given_an_unknown_host_returns_unknown_host_error(self):
+        pinger = Pinger(CommandRunner())
+        result = pinger.get_latency("thisisanunknown.host")
+        self.assertFalse(result.success)
+        self.assertEqual(Pinger.ERROR_UKNOWN_HOST, result.error_code)
+        self.assertEqual(0, result.packet_count)

Diff for: latency_meter/server/test_recording_measurements.py

@@ -0,0 +1,95 @@
+from unittest import TestCase
+
+from latency_meter.client.api import MeasuredLatency
+from latency_meter.client.ping_measurement_provider import Pinger, CommandRunner
+
+
+class TestPinger(TestCase):
+    def test_given_a_ping_calls_command_runner_with_host(self):
+        command_runner = MockCommandRunner(
+            command_output="3 packets transmitted, 3 received, 0% packet loss, time 1998ms\n"
+                           "rtt min/avg/max/mdev = 0.402/0.580/0.701/0.128 ms"
+        )
+        pinger = Pinger(command_runner=command_runner)
+        pinger.get_latency("test-host")
+        self.assertEqual(
+            command_runner.was_called_with_command,
+            ["ping", "-Dn", "-c", Pinger.PING_COUNT, "test-host"]
+        )
+
+    def test_given_a_ping_parses_output_and_returns_measured_latency(self):
+        got = self.run_pinger_with_output(
+            "3 packets transmitted, 3 received, 0% packet loss, time 1998ms\n"
+            "rtt min/avg/max/mdev = 0.402/0.580/0.701/0.128 ms"
+        )
+        expected = MeasuredLatency(3, 0.58, success=True)
+        self.assertEqual(expected.packet_count, got.packet_count)
+        self.assertEqual(expected.average_latency, got.average_latency)
+        self.assertTrue(got.success)
+
+    def test_given_more_ping_output_parses_correctly(self):
+        ping_output = """PING index.hu (217.20.130.99) 56(84) bytes of data.
+[1491753086.899682] 64 bytes from 217.20.130.99: icmp_seq=1 ttl=57 time=9.43 ms
+[1491753087.900707] 64 bytes from 217.20.130.99: icmp_seq=2 ttl=57 time=8.77 ms
+[1491753088.902781] 64 bytes from 217.20.130.99: icmp_seq=3 ttl=57 time=8.90 ms
+
+--- index.hu ping statistics ---
+3 packets transmitted, 3 received, 0% packet loss, time 2003ms
+rtt min/avg/max/mdev = 8.773/9.039/9.437/0.286 ms
+        """
+        got = self.run_pinger_with_output(ping_output)
+        expected = MeasuredLatency(3, 9.039, True)
+        self.assertEqual(expected.packet_count, got.packet_count)
+        self.assertEqual(expected.average_latency, got.average_latency)
+        self.assertTrue(got.success)
+
+    def test_given_100_percent_packet_loss_return_error(self):
+        got = self.run_pinger_with_output("""
+PING 240.0.0.1 (240.0.0.1) 56(84) bytes of data.
+
+--- 240.0.0.1 ping statistics ---
+3 packets transmitted, 0 received, 100% packet loss, time 1999ms
+
+""")
+        self.assertFalse(got.success)
+        self.assertEqual(Pinger.ERROR_PACKET_LOSS, got.error_code)
+        self.assertIsNone(got.average_latency)
+        self.assertEqual(0, got.packet_count)
+
+    def test_given_a_command_returns_with_nonzero_return_code_but_the_error_doesnt_match_return_unknown_error(self):
+        failing_runner = MockCommandRunner("This error was very unexpected.", return_code=1)
+        got = self._run_with_command_runner(failing_runner)
+        self.assertFalse(got.success)
+        self.assertEqual(Pinger.ERROR_UNKNOWN, got.error_code)
+
+    def test_given_a_command_returns_unknown_host_expect_error_unknown_host(self):
+        failing_runner = MockCommandRunner(
+            """ping: unknown host a-host.unknown
+            """
+            , return_code=2)
+        got = self._run_with_command_runner(failing_runner)
+        self.assertFalse(got.success)
+        self.assertEqual(Pinger.ERROR_UKNOWN_HOST, got.error_code)
+
+    def run_pinger_with_output(self, ping_output):
+        command_runner = MockCommandRunner(
+            command_output=ping_output
+        )
+        got = self._run_with_command_runner(command_runner)
+        return got
+
+    def _run_with_command_runner(self, command_runner):
+        pinger = Pinger(command_runner=command_runner)
+        got = pinger.get_latency("test-host")
+        return got
+
+
+class MockCommandRunner(CommandRunner):
+    def __init__(self, command_output, return_code=0):
+        self.rc = return_code
+        self.was_called_with_command = None
+        self.command_output = command_output
+
+    def run(self, command):
+        self.was_called_with_command = command
+        return (self.rc, self._process_lines(self.command_output))

Diff for: latency_meter/tests/__init__.py

@@ -0,0 +1,2 @@
+nova-scheduler.log:2017-04-08 18:42:00.917 8932 DEBUG nova.scheduler.filter_scheduler [req-e3a713de-66ec-4b7a-a83f-c67ace2f669a 5f14c47f62e2481ba6b79534a82bcda4 329b3f3bab484a62bc176caf142389b2 - - -] <Context {'domain': None, 'project_name': u'admin', 'project_domain': None, 'timestamp': '2017-04-08T18:41:59.543412', 'auth_token': u'gAAAAABY6SKmFcU6odoBvbO0NxGrDVd4lvz0OMHtGGAa1qRby8jT_2WhWUiC75uY_NXu133yq0wVntnBJTp2ZB9X9t_UlbbtyunNHvKoYaLA3bZjHt6dqZLU4tTOOdmvvmAVR9-NCfHahIkCQspzu_xNYb589s5TBf__L6aJgm5frnrkESg_1kfqq-nuDcXLXmSnTACl1at7', 'remote_address': u'10.199.0.11', 'quota_class': None, 'resource_uuid': None, 'is_admin': True, 'user': u'5f14c47f62e2481ba6b79534a82bcda4', 'service_catalog': [{u'endpoints': [{u'adminURL': u'http://controller:8778', u'region': u'RegionOne', u'internalURL': u'http://', u'publicURL': u'http://controller:8778'}], u'type': u'placement', u'name': u'placement'}], 'tenant': u'329b3f3bab484a62bc176caf142389b2', 'read_only': False, 'project_id': u'329b3f3bab484a62bc176caf142389b2', 'user_id': u'5f14c47f62e2481ba6b79534a82bcda4', 'show_deleted': False, 'roles': [u'admin'], 'user_identity': u'5f14c47f62e2481ba6b79534a82bcda4 329b3f3bab484a62bc176caf142389b2 - - -', 'is_admin_project': True, 'read_deleted': u'no', 'request_id': u'req-e3a713de-66ec-4b7a-a83f-c67ace2f669a', 'instance_lock_checked': False, 'user_domain': None, 'user_name': u'admin'}> select_destinations /usr/lib/python2.7/dist-packages/nova/scheduler/filter_scheduler.py:56
+nova-scheduler.log:2017-04-08 18:42:00.917 8932 DEBUG nova.scheduler.filter_scheduler [req-e3a713de-66ec-4b7a-a83f-c67ace2f669a 5f14c47f62e2481ba6b79534a82bcda4 329b3f3bab484a62bc176caf142389b2 - - -] RequestSpec(availability_zone='nova',flavor=Flavor(2),force_hosts=None,force_nodes=None,id=<?>,ignore_hosts=None,image=ImageMeta(93c6eb95-8456-4a56-8785-86539eddb50e),instance_group=None,instance_uuid=d63eaf51-defc-4772-94f9-a5a4529ab8c3,limits=SchedulerLimits,num_instances=1,numa_topology=None,pci_requests=InstancePCIRequests,project_id='329b3f3bab484a62bc176caf142389b2',requested_destination=None,retry=None,scheduler_hints={},security_groups=<?>) select_destinations /usr/lib/python2.7/dist-packages/nova/scheduler/filter_scheduler.py:57