From 68aaa8ce8b20ba39040aa2469b384f59709620a7 Mon Sep 17 00:00:00 2001 From: Xavier Simonart Date: Fri, 1 Jun 2018 12:16:38 +0200 Subject: Fix NSB NFVi metrics accuracy JIRA: YARDSTICK-1212 Change-Id: Ic4d4a3c00e4e278f4de06cc176ff663892895569 Signed-off-by: Xavier Simonart --- .../vnf_generic/vnf/test_prox_helpers.py | 41 ++++++++++--------- .../traffic_profile/prox_binsearch.py | 24 +++++------ .../vnf_generic/vnf/prox_helpers.py | 46 ++++++++++++++-------- .../network_services/vnf_generic/vnf/prox_vnf.py | 24 ++++++----- .../network_services/vnf_generic/vnf/sample_vnf.py | 2 +- .../traffic_profile/test_prox_binsearch.py | 7 ++-- 6 files changed, 82 insertions(+), 62 deletions(-) diff --git a/tests/unit/network_services/vnf_generic/vnf/test_prox_helpers.py b/tests/unit/network_services/vnf_generic/vnf/test_prox_helpers.py index bc48f994c..301a90cfe 100644 --- a/tests/unit/network_services/vnf_generic/vnf/test_prox_helpers.py +++ b/tests/unit/network_services/vnf_generic/vnf/test_prox_helpers.py @@ -1,3 +1,4 @@ + # Copyright (c) 2016-2017 Intel Corporation # # Licensed under the Apache License, Version 2.0 (the "License"); @@ -151,12 +152,12 @@ class TestProxTestDataTuple(unittest.TestCase): self.assertEqual(prox_test_data.latency, 6) self.assertEqual(prox_test_data.rx_total, 7) self.assertEqual(prox_test_data.tx_total, 8) - self.assertEqual(prox_test_data.pps, 9) + self.assertEqual(prox_test_data.requested_pps, 9) def test_properties(self): prox_test_data = ProxTestDataTuple(1, 2, 3, 4, 5, 6, 7, 8, 9) self.assertEqual(prox_test_data.pkt_loss, 12.5) - self.assertEqual(prox_test_data.mpps, 1.6 / 1e6) + self.assertEqual(prox_test_data.tx_mpps, 1.6 / 1e6) self.assertEqual(prox_test_data.can_be_lost, 0) self.assertEqual(prox_test_data.drop_total, 1) self.assertFalse(prox_test_data.success) @@ -172,11 +173,12 @@ class TestProxTestDataTuple(unittest.TestCase): prox_test_data = ProxTestDataTuple(1, 2, 3, 4, 5, [6.1, 6.9, 6.4], 7, 8, 9) expected = { - "Throughput": 1.6 / 1e6, + "Throughput": 1.2 / 1e6, "DropPackets": 12.5, "CurrentDropPackets": 12.5, - "TxThroughput": 9 / 1e6, - "RxThroughput": 1.6 / 1e6, + "RequestedTxThroughput": 9 / 1e6, + "TxThroughput": 1.6 / 1e6, + "RxThroughput": 1.2 / 1e6, "PktSize": 64, "PortSample": 1, "LatencyMin": 6.1, @@ -187,11 +189,12 @@ class TestProxTestDataTuple(unittest.TestCase): self.assertDictEqual(result, expected) expected = { - "Throughput": 1.6 / 1e6, + "Throughput": 1.2 / 1e6, "DropPackets": 0.123, "CurrentDropPackets": 0.123, - "TxThroughput": 9 / 1e6, - "RxThroughput": 1.6 / 1e6, + "RequestedTxThroughput": 9 / 1e6, + "TxThroughput": 1.6 / 1e6, + "RxThroughput": 1.2 / 1e6, "PktSize": 64, "LatencyMin": 6.1, "LatencyMax": 6.9, @@ -200,17 +203,17 @@ class TestProxTestDataTuple(unittest.TestCase): result = prox_test_data.get_samples(64, 0.123) self.assertDictEqual(result, expected) - @mock.patch('yardstick.network_services.vnf_generic.vnf.prox_helpers.LOG') + @mock.patch('yardstick.LOG_RESULT', create=True) def test_log_data(self, mock_logger): my_mock_logger = mock.MagicMock() prox_test_data = ProxTestDataTuple(1, 2, 3, 4, 5, [6.1, 6.9, 6.4], 7, 8, 9) prox_test_data.log_data() self.assertEqual(my_mock_logger.debug.call_count, 0) - self.assertEqual(mock_logger.debug.call_count, 2) + self.assertEqual(mock_logger.debug.call_count, 0) mock_logger.debug.reset_mock() prox_test_data.log_data(my_mock_logger) - self.assertEqual(my_mock_logger.debug.call_count, 2) + self.assertEqual(my_mock_logger.debug.call_count, 0) self.assertEqual(mock_logger.debug.call_count, 0) @@ -334,17 +337,17 @@ class TestProxSocketHelper(unittest.TestCase): mock_select.select.side_effect = chain([[object()], [None]], repeat([1], 3)) mock_recv.decode.return_value = PACKET_DUMP_2 ret = prox.get_data() - self.assertEqual(mock_select.select.call_count, 2) + self.assertEqual(mock_select.select.call_count, 1) self.assertEqual(ret, 'jumped over') self.assertEqual(len(prox._pkt_dumps), 3) def test__parse_socket_data_mixed_data(self): prox = ProxSocketHelper(mock.MagicMock()) - ret = prox._parse_socket_data(PACKET_DUMP_NON_1, False) + ret, _ = prox._parse_socket_data(PACKET_DUMP_NON_1, False) self.assertEqual(ret, 'not_a_dump,1,2') self.assertEqual(len(prox._pkt_dumps), 0) - ret = prox._parse_socket_data(PACKET_DUMP_MIXED_1, False) + ret, _ = prox._parse_socket_data(PACKET_DUMP_MIXED_1, False) self.assertEqual(ret, 'not_a_dump,1,2') self.assertEqual(len(prox._pkt_dumps), 1) @@ -356,18 +359,18 @@ class TestProxSocketHelper(unittest.TestCase): with self.assertRaises(ValueError): prox._parse_socket_data(PACKET_DUMP_BAD_2, False) - ret = prox._parse_socket_data(PACKET_DUMP_BAD_3, False) + ret, _ = prox._parse_socket_data(PACKET_DUMP_BAD_3, False) self.assertEqual(ret, 'pktdump,3') def test__parse_socket_data_pkt_dump_only(self): prox = ProxSocketHelper(mock.MagicMock()) - ret = prox._parse_socket_data('', True) + ret, _ = prox._parse_socket_data('', True) self.assertFalse(ret) - ret = prox._parse_socket_data(PACKET_DUMP_1, True) + ret, _ = prox._parse_socket_data(PACKET_DUMP_1, True) self.assertTrue(ret) - ret = prox._parse_socket_data(PACKET_DUMP_2, True) + ret, _ = prox._parse_socket_data(PACKET_DUMP_2, True) self.assertTrue(ret) def test_put_command(self): @@ -1542,7 +1545,7 @@ class TestProxDataHelper(unittest.TestCase): self.assertEqual(data_helper.rx_total, 6) self.assertEqual(data_helper.tx_total, 7) - self.assertEqual(data_helper.pps, 6.25e6) + self.assertEqual(data_helper.requested_pps, 6.25e6) def test_samples(self): vnfd_helper = mock.MagicMock() diff --git a/yardstick/network_services/traffic_profile/prox_binsearch.py b/yardstick/network_services/traffic_profile/prox_binsearch.py index 1e926aca2..225ee4356 100644 --- a/yardstick/network_services/traffic_profile/prox_binsearch.py +++ b/yardstick/network_services/traffic_profile/prox_binsearch.py @@ -108,7 +108,6 @@ class ProxBinSearchProfile(ProxProfile): self.tolerated_loss, line_speed) self.curr_time = time.time() - diff_time = self.curr_time - self.prev_time self.prev_time = self.curr_time if result.success: @@ -120,10 +119,11 @@ class ProxBinSearchProfile(ProxProfile): # store results with success tag in influxdb success_samples = {'Success_' + key: value for key, value in samples.items()} - success_samples["Success_rx_total"] = int(result.rx_total / diff_time) - success_samples["Success_tx_total"] = int(result.tx_total / diff_time) - success_samples["Success_can_be_lost"] = int(result.can_be_lost / diff_time) - success_samples["Success_drop_total"] = int(result.drop_total / diff_time) + # Store number of packets based statistics (we already have throughput) + success_samples["Success_rx_total"] = int(result.rx_total) + success_samples["Success_tx_total"] = int(result.tx_total) + success_samples["Success_can_be_lost"] = int(result.can_be_lost) + success_samples["Success_drop_total"] = int(result.drop_total) self.queue.put(success_samples) # Store Actual throughput for result samples @@ -133,20 +133,16 @@ class ProxBinSearchProfile(ProxProfile): LOG.debug("Failure... Decreasing upper bound") self.current_upper = test_value samples = result.get_samples(pkt_size, successful_pkt_loss, port_samples) + # samples contains data such as Latency, Throughput, number of packets + # Hence they should not be divided by the time difference - for k in samples: - tmp = samples[k] - if isinstance(tmp, dict): - for k2 in tmp: - samples[k][k2] = int(samples[k][k2] / diff_time) - - if theor_max_thruput < samples["TxThroughput"]: - theor_max_thruput = samples['TxThroughput'] + if theor_max_thruput < samples["RequestedTxThroughput"]: + theor_max_thruput = samples['RequestedTxThroughput'] self.queue.put({'theor_max_throughput': theor_max_thruput}) LOG.debug("Collect TG KPIs %s %s", datetime.datetime.now(), samples) self.queue.put(samples) result_samples["Result_pktSize"] = pkt_size - result_samples["Result_theor_max_throughput"] = theor_max_thruput/(1000 * 1000) + result_samples["Result_theor_max_throughput"] = theor_max_thruput self.queue.put(result_samples) diff --git a/yardstick/network_services/vnf_generic/vnf/prox_helpers.py b/yardstick/network_services/vnf_generic/vnf/prox_helpers.py index 31ed30140..7816c6d91 100644 --- a/yardstick/network_services/vnf_generic/vnf/prox_helpers.py +++ b/yardstick/network_services/vnf_generic/vnf/prox_helpers.py @@ -44,6 +44,8 @@ SECTION_CONTENTS = 1 LOG = logging.getLogger(__name__) LOG.setLevel(logging.DEBUG) +LOG_RESULT = logging.getLogger('yardstick') +LOG_RESULT.setLevel(logging.DEBUG) BITS_PER_BYTE = 8 RETRY_SECONDS = 60 @@ -123,7 +125,8 @@ class TotStatsTuple(namedtuple('TotStats', 'rx,tx,tsc,hz')): class ProxTestDataTuple(namedtuple('ProxTestDataTuple', 'tolerated,tsc_hz,delta_rx,' 'delta_tx,delta_tsc,' - 'latency,rx_total,tx_total,pps')): + 'latency,rx_total,tx_total,' + 'requested_pps')): @property def pkt_loss(self): try: @@ -132,10 +135,15 @@ class ProxTestDataTuple(namedtuple('ProxTestDataTuple', 'tolerated,tsc_hz,delta_ return 100.0 @property - def mpps(self): + def tx_mpps(self): # calculate the effective throughput in Mpps return float(self.delta_tx) * self.tsc_hz / self.delta_tsc / 1e6 + @property + def rx_mpps(self): + # calculate the effective throughput in Mpps + return float(self.delta_rx) * self.tsc_hz / self.delta_tsc / 1e6 + @property def can_be_lost(self): return int(self.tx_total * self.tolerated / 1e2) @@ -162,11 +170,12 @@ class ProxTestDataTuple(namedtuple('ProxTestDataTuple', 'tolerated,tsc_hz,delta_ ] samples = { - "Throughput": self.mpps, + "Throughput": self.rx_mpps, + "RxThroughput": self.rx_mpps, "DropPackets": pkt_loss, "CurrentDropPackets": pkt_loss, - "TxThroughput": self.pps / 1e6, - "RxThroughput": self.mpps, + "RequestedTxThroughput": self.requested_pps / 1e6, + "TxThroughput": self.tx_mpps, "PktSize": pkt_size, } if port_samples: @@ -177,11 +186,12 @@ class ProxTestDataTuple(namedtuple('ProxTestDataTuple', 'tolerated,tsc_hz,delta_ def log_data(self, logger=None): if logger is None: - logger = LOG + logger = LOG_RESULT template = "RX: %d; TX: %d; dropped: %d (tolerated: %d)" - logger.debug(template, self.rx_total, self.tx_total, self.drop_total, self.can_be_lost) - logger.debug("Mpps configured: %f; Mpps effective %f", self.pps / 1e6, self.mpps) + logger.info(template, self.rx_total, self.tx_total, self.drop_total, self.can_be_lost) + logger.info("Mpps configured: %f; Mpps generated %f; Mpps received %f", + self.requested_pps / 1e6, self.tx_mpps, self.rx_mpps) class PacketDump(object): @@ -288,7 +298,7 @@ class ProxSocketHelper(object): if mode != 'pktdump': # Regular 1-line message. Stop reading from the socket. LOG.debug("Regular response read") - return ret_str + return ret_str, True LOG.debug("Packet dump header read: [%s]", ret_str) @@ -309,11 +319,11 @@ class ProxSocketHelper(object): # Return boolean instead of string to signal # successful reception of the packet dump. LOG.debug("Packet dump stored, returning") - return True + return True, False index = data_end + 1 - return ret_str + return ret_str, False def get_data(self, pkt_dump_only=False, timeout=1): """ read data from the socket """ @@ -352,7 +362,9 @@ class ProxSocketHelper(object): ret_str = "" for status in iter(is_ready, False): decoded_data = self._sock.recv(256).decode('utf-8') - ret_str = self._parse_socket_data(decoded_data, pkt_dump_only) + ret_str, done = self._parse_socket_data(decoded_data, pkt_dump_only) + if (done): + break LOG.debug("Received data from socket: [%s]", ret_str) return ret_str if status else '' @@ -1001,8 +1013,8 @@ class ProxDataHelper(object): def totals_and_pps(self): if self._totals_and_pps is None: rx_total, tx_total = self.sut.port_stats(range(self.port_count))[6:8] - pps = self.value / 100.0 * self.line_rate_to_pps() - self._totals_and_pps = rx_total, tx_total, pps + requested_pps = self.value / 100.0 * self.line_rate_to_pps() + self._totals_and_pps = rx_total, tx_total, requested_pps return self._totals_and_pps @property @@ -1014,7 +1026,7 @@ class ProxDataHelper(object): return self.totals_and_pps[1] @property - def pps(self): + def requested_pps(self): return self.totals_and_pps[2] @property @@ -1055,7 +1067,7 @@ class ProxDataHelper(object): self.latency, self.rx_total, self.tx_total, - self.pps, + self.requested_pps, ) self.result_tuple.log_data() @@ -1134,6 +1146,7 @@ class ProxProfileHelper(object): self.sut.set_pkt_size(self.test_cores, pkt_size) self.sut.set_speed(self.test_cores, value) self.sut.start_all() + time.sleep(1) yield finally: self.sut.stop_all() @@ -1246,6 +1259,7 @@ class ProxMplsProfileHelper(ProxProfileHelper): ratio = 1.0 * (pkt_size - 4 + 20) / (pkt_size + 20) self.sut.set_speed(self.plain_cores, value * ratio) self.sut.start_all() + time.sleep(1) yield finally: self.sut.stop_all() diff --git a/yardstick/network_services/vnf_generic/vnf/prox_vnf.py b/yardstick/network_services/vnf_generic/vnf/prox_vnf.py index 285e08659..36f1a19d0 100644 --- a/yardstick/network_services/vnf_generic/vnf/prox_vnf.py +++ b/yardstick/network_services/vnf_generic/vnf/prox_vnf.py @@ -15,8 +15,6 @@ import errno import logging import datetime -import time - from yardstick.common.process import check_if_process_failed from yardstick.network_services.vnf_generic.vnf.prox_helpers import ProxDpdkVnfSetupEnvHelper @@ -44,7 +42,8 @@ class ProxApproxVnf(SampleVNF): self.prev_packets_in = 0 self.prev_packets_sent = 0 - self.prev_time = time.time() + self.prev_tsc = 0 + self.tsc_hz = 0 super(ProxApproxVnf, self).__init__(name, vnfd, setup_env_helper_type, resource_helper_type) @@ -68,8 +67,7 @@ class ProxApproxVnf(SampleVNF): def collect_kpi(self): # we can't get KPIs if the VNF is down - check_if_process_failed(self._vnf_process) - + check_if_process_failed(self._vnf_process, 0.01) if self.resource_helper is None: result = { "packets_in": 0, @@ -79,6 +77,12 @@ class ProxApproxVnf(SampleVNF): } return result + if (self.tsc_hz == 0): + self.tsc_hz = float(self.resource_helper.sut.hz()) + LOG.debug("TSC = %f", self.tsc_hz) + if (self.tsc_hz == 0): + raise RuntimeError("Unable to retrieve TSC") + # use all_ports so we only use ports matched in topology port_count = len(self.vnfd_helper.port_pairs.all_ports) if port_count not in {1, 2, 4}: @@ -86,10 +90,10 @@ class ProxApproxVnf(SampleVNF): "1, 2 or 4 ports only supported at this time") self.port_stats = self.vnf_execute('port_stats', range(port_count)) - curr_time = time.time() try: rx_total = self.port_stats[6] tx_total = self.port_stats[7] + tsc = self.port_stats[10] except IndexError: LOG.debug("port_stats parse fail ") # return empty dict so we don't mess up existing KPIs @@ -103,15 +107,17 @@ class ProxApproxVnf(SampleVNF): # collectd KPIs here and not TG KPIs, so use a different method name "collect_stats": self.resource_helper.collect_collectd_kpi(), } - curr_packets_in = int((rx_total - self.prev_packets_in) / (curr_time - self.prev_time)) - curr_packets_fwd = int((tx_total - self.prev_packets_sent) / (curr_time - self.prev_time)) + curr_packets_in = int(((rx_total - self.prev_packets_in) * self.tsc_hz) + / (tsc - self.prev_tsc) * port_count) + curr_packets_fwd = int(((tx_total - self.prev_packets_sent) * self.tsc_hz) + / (tsc - self.prev_tsc) * port_count) result["curr_packets_in"] = curr_packets_in result["curr_packets_fwd"] = curr_packets_fwd self.prev_packets_in = rx_total self.prev_packets_sent = tx_total - self.prev_time = curr_time + self.prev_tsc = tsc LOG.debug("%s collect KPIs %s %s", self.APP_NAME, datetime.datetime.now(), result) return result diff --git a/yardstick/network_services/vnf_generic/vnf/sample_vnf.py b/yardstick/network_services/vnf_generic/vnf/sample_vnf.py index 16873611e..ef8b3f126 100644 --- a/yardstick/network_services/vnf_generic/vnf/sample_vnf.py +++ b/yardstick/network_services/vnf_generic/vnf/sample_vnf.py @@ -825,7 +825,7 @@ class SampleVNF(GenericVNF): def collect_kpi(self): # we can't get KPIs if the VNF is down - check_if_process_failed(self._vnf_process) + check_if_process_failed(self._vnf_process, 0.01) stats = self.get_stats() m = re.search(self.COLLECT_KPI, stats, re.MULTILINE) if m: diff --git a/yardstick/tests/unit/network_services/traffic_profile/test_prox_binsearch.py b/yardstick/tests/unit/network_services/traffic_profile/test_prox_binsearch.py index 58343ffb2..7bfd67fe0 100644 --- a/yardstick/tests/unit/network_services/traffic_profile/test_prox_binsearch.py +++ b/yardstick/tests/unit/network_services/traffic_profile/test_prox_binsearch.py @@ -65,9 +65,10 @@ class TestProxBinSearchProfile(unittest.TestCase): self.assertEqual(len(runs), 7) # Result Samples inc theor_max - result_tuple = {"Result_Actual_throughput": 7.5e-07, - "Result_theor_max_throughput": 1.234e-10, - "Result_pktSize": 200} + result_tuple = {'Result_Actual_throughput': 5e-07, + 'Result_theor_max_throughput': 0.00012340000000000002, + 'Result_pktSize': 200} + profile.queue.put.assert_called_with(result_tuple) success_result_tuple = {"Success_CurrentDropPackets": 0.5, -- cgit 1.2.3-korg