Rework of statistics reporting

- Cleanup of the format.yaml file.
- Adding of the packet mis-ordering statistics
- Added a warmup phase to get the correct mis-ordering statistics since
  ARP messages need to be dealt with before we can collect correct
  misordering stats
- Code cleanup avoiding some long lines
- Removing background traffic control from rapid_flowsizetest.py since
  this is already done in the iteration code in rapid_test.py

Change-Id: I4c60a90353f27b8e2d0b62505e8f1cd886a17f0a
Signed-off-by: Luc Provoost <luc.provoost@intel.com>

1 files changed, 105 insertions, 49 deletions

diff --git a/VNFs/DPPD-PROX/helper-scripts/rapid/rapid_flowsizetest.py b/VNFs/DPPD-PROX/helper-scripts/rapid/rapid_flowsizetest.py
index d65afd62..0ca7c71f 100644
--- a/VNFs/DPPD-PROX/helper-scripts/rapid/rapid_flowsizetest.py
+++ b/VNFs/DPPD-PROX/helper-scripts/rapid/rapid_flowsizetest.py
@@ -64,8 +64,10 @@ class FlowSizeTest(RapidTest):
             if success:
                 self.test['TST009_L'] = self.test['TST009_m'] + 1
             else:
-                self.test['TST009_R'] = max(self.test['TST009_m'] - 1, self.test['TST009_L'])
-            self.test['TST009_m'] = int (old_div((self.test['TST009_L'] + self.test['TST009_R']),2))
+                self.test['TST009_R'] = max(self.test['TST009_m'] - 1,
+                        self.test['TST009_L'])
+            self.test['TST009_m'] = int (old_div((self.test['TST009_L'] +
+                self.test['TST009_R']),2))
             return (self.get_percentageof10Gbps(self.test['TST009_S'][self.test['TST009_m']],size))
         else:
             if success:
@@ -82,7 +84,8 @@ class FlowSizeTest(RapidTest):
         elif 'TST009' in self.test.keys():
             self.test['TST009_L'] = 0
             self.test['TST009_R'] = self.test['TST009_n'] - 1
-            self.test['TST009_m'] = int(old_div((self.test['TST009_L'] + self.test['TST009_R']), 2))
+            self.test['TST009_m'] = int(old_div((self.test['TST009_L'] +
+                self.test['TST009_R']), 2))
             return (self.get_percentageof10Gbps(self.test['TST009_S'][self.test['TST009_m']],size))
         else:
             self.test['minspeed'] = 0
@@ -97,24 +100,64 @@ class FlowSizeTest(RapidTest):
         else:
             return ((self.test['maxspeed'] - self.test['minspeed']) <= self.test['accuracy'])
 
+    def warm_up(self):
+        # Running at low speed to make sure the ARP messages can get through.
+        # If not doing this, the ARP message could be dropped by a switch in overload and then the test will not give proper results
+        # Note however that if we would run the test steps during a very long time, the ARP would expire in the switch.
+        # PROX will send a new ARP request every seconds so chances are very low that they will all fail to get through
+        imix = self.test['warmupimix']
+        FLOWSIZE = self.test['warmupflowsize']
+        WARMUPSPEED = self.test['warmupspeed']
+        WARMUPTIME = self.test['warmuptime']
+        RapidLog.info(("Warming up during {} seconds..., packet size = {},"
+            " flows = {}, speed = {}").format(WARMUPTIME, imix, FLOWSIZE,
+                WARMUPSPEED))
+        self.gen_machine.set_generator_speed(WARMUPSPEED)
+        self.set_background_speed(self.background_machines, WARMUPSPEED)
+        self.gen_machine.set_udp_packet_size(imix)
+        self.set_background_size(self.background_machines, imix)
+        _ = self.gen_machine.set_flows(FLOWSIZE)
+        self.set_background_flows(self.background_machines, FLOWSIZE)
+        self.gen_machine.start()
+        self.start_background_traffic(self.background_machines)
+        time.sleep(WARMUPTIME)
+        self.stop_background_traffic(self.background_machines)
+        self.gen_machine.stop()
+
     def run(self):
         result_details = {'Details': 'Nothing'}
         TestResult = 0
         end_data = {}
         iteration_prefix = {}
+        self.warm_up()
         for imix in self.test['imixs']:
             size = mean(imix)
             self.gen_machine.set_udp_packet_size(imix)
             if self.background_machines:
-                backgroundinfo = '{}Running {} x background traffic not represented in the table{}'.format(bcolors.FLASH,len(self.background_machines),bcolors.ENDC)
+                backgroundinfo = ('{}Running {} x background traffic not '
+                    'represented in the table{}').format(bcolors.FLASH,
+                            len(self.background_machines),bcolors.ENDC)
             else:
                 backgroundinfo = '{}{}'.format(bcolors.FLASH,bcolors.ENDC)
             self.set_background_size(self.background_machines, imix)
-            RapidLog.info("+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+")
-            RapidLog.info('| UDP, {:>5} bytes, different number of flows by randomizing SRC & DST UDP port. {:116.116}|'.format(round(size), backgroundinfo))
-            RapidLog.info("+--------+------------------+-------------+-------------+-------------+------------------------+----------+----------+----------+-----------+-----------+-----------+-----------+-------+----+")
-            RapidLog.info('| Flows  | Speed requested  | Gen by core | Sent by NIC | Fwrd by SUT | Rec. by core           | Avg. Lat.|{:.0f} Pcentil| Max. Lat.|   Sent    |  Received |    Lost   | Total Lost|L.Ratio|Time|'.format(self.test['lat_percentile']*100))
-            RapidLog.info("+--------+------------------+-------------+-------------+-------------+------------------------+----------+----------+----------+-----------+-----------+-----------+-----------+-------+----+")
+            RapidLog.info('+' + '-' * 188 + '+')
+            RapidLog.info(("| UDP, {:>5} bytes, different number of flows by "
+                "randomizing SRC & DST UDP port. {:116.116}|").
+                format(round(size), backgroundinfo))
+            RapidLog.info('+' + '-' * 8 + '+' + '-' * 18 + '+' + '-' * 13 +
+                    '+' + '-' * 13 + '+' + '-' * 13 + '+' + '-' * 24 + '+' +
+                    '-' * 10 + '+' + '-' * 10 + '+' + '-' * 10 + '+' + '-' * 11
+                    + '+' + '-' * 11 + '+' + '-' * 11 + '+'  + '-' * 11 +  '+'
+                    + '-' * 7 + '+' + '-' * 4 + '+')
+            RapidLog.info(('| Flows  | Speed requested  | Gen by core | Sent by'
+                ' NIC | Fwrd by SUT | Rec. by core           | Avg. Lat.|{:.0f}'
+                ' Pcentil| Max. Lat.|   Sent    |  Received |    Lost   | Total'
+                ' Lost|L.Ratio|Time|').format(self.test['lat_percentile']*100))
+            RapidLog.info('+' + '-' * 8 + '+' + '-' * 18 + '+' + '-' * 13 +
+                    '+' + '-' * 13 + '+' + '-' * 13 + '+' + '-' * 24 + '+' +
+                    '-' * 10 + '+' + '-' * 10 + '+' + '-' * 10 + '+' + '-' * 11
+                    + '+' + '-' * 11 + '+' + '-' * 11 + '+'  + '-' * 11 +  '+'
+                    + '-' * 7 + '+' + '-' * 4 + '+')
             for flow_number in self.test['flows']:
                 attempts = 0
                 self.gen_machine.reset_stats()
@@ -122,31 +165,33 @@ class FlowSizeTest(RapidTest):
                     self.sut_machine.reset_stats()
                 flow_number = self.gen_machine.set_flows(flow_number)
                 self.set_background_flows(self.background_machines, flow_number)
-#                endspeed = None
                 end_data['speed'] = None
                 speed = self.get_start_speed_and_init(size)
                 while True:
                     attempts += 1
                     endwarning = False
-                    print(str(flow_number)+' flows: Measurement ongoing at speed: ' + str(round(speed,2)) + '%      ',end='\r')
+                    print('{} flows: Measurement ongoing at speed: {}%'.format(
+                        str(flow_number), str(round(speed, 2))), end='     \r')
                     sys.stdout.flush()
-                    # Start generating packets at requested speed (in % of a 10Gb/s link)
-                    self.gen_machine.set_generator_speed(speed)
-                    self.set_background_speed(self.background_machines, speed)
-                    self.start_background_traffic(self.background_machines)
-                    # Get statistics now that the generation is stable and initial ARP messages are dealt with
                     iteration_data = self.run_iteration(
                             float(self.test['runtime']),flow_number,size,speed)
-                    iteration_data['speed'] = speed
-                    self.stop_background_traffic(self.background_machines)
                     if iteration_data['r'] > 1:
-                        retry_warning = bcolors.WARNING + ' {:1} retries needed'.format(iteration_data['r']) +  bcolors.ENDC
+                        retry_warning = '{} {:1} retries needed{}'.format(
+                                bcolors.WARNING, iteration_data['r'],
+                                bcolors.ENDC)
                     else:
                         retry_warning = ''
-                    # Drop rate is expressed in percentage. lat_used is a ratio (0 to 1). The sum of these 2 should be 100%.
-                    # If the sum is lower than 95, it means that more than 5% of the latency measurements where dropped for accuracy reasons.
-                    if (iteration_data['drop_rate'] + iteration_data['lat_used'] * 100) < 95:
-                        lat_warning = bcolors.WARNING + ' Latency accuracy issue?: {:>3.0f}%'.format(iteration_data['lat_used']*100) +  bcolors.ENDC
+                    # Drop rate is expressed in percentage. lat_used is a ratio
+                    # (0 to 1). The sum of these 2 should be 100%.
+                    # If the sum is lower than 95, it means that more than 5%
+                    # of the latency measurements where dropped for accuracy
+                    # reasons.
+                    if (iteration_data['drop_rate'] +
+                            iteration_data['lat_used'] * 100) < 95:
+                        lat_warning = ('{} Latency accuracy issue?: {:>3.0f}%'
+                            '{}').format(bcolors.WARNING,
+                                    iteration_data['lat_used'] * 100,
+                                    bcolors.ENDC)
                     else:
                         lat_warning = ''
                     iteration_prefix = {'speed' : bcolors.ENDC,
@@ -159,11 +204,18 @@ class FlowSizeTest(RapidTest):
                         end_data = copy.deepcopy(iteration_data)
                         end_prefix = copy.deepcopy(iteration_prefix)
                         if lat_warning or retry_warning:
-                            endwarning = '|        | {:177.177} |'.format(retry_warning + lat_warning)
+                            endwarning = '|        | {:177.177} |'.format(
+                                    retry_warning + lat_warning)
                         success = True
-                        #TestResult = TestResult + iteration_data['pps_rx'] # fixed rate testing result is strange: we just report the pps received
-                    # The following if statement is testing if we pass the success criteria of a certain drop rate, average latency and maximum latency below the threshold
-                    # The drop rate success can be achieved in 2 ways: either the drop rate is below a treshold, either we want that no packet has been lost during the test
+                        # TestResult = TestResult + iteration_data['pps_rx']
+                        # fixed rate testing result is strange: we just report
+                        # the pps received
+                    # The following if statement is testing if we pass the
+                    # success criteria of a certain drop rate, average latency
+                    # and maximum latency below the threshold.
+                    # The drop rate success can be achieved in 2 ways: either
+                    # the drop rate is below a treshold, either we want that no
+                    # packet has been lost during the test.
                     # This can be specified by putting 0 in the .test file
                     elif ((iteration_data['drop_rate'] < self.test['drop_rate_threshold']) or (iteration_data['abs_dropped']==self.test['drop_rate_threshold']==0)) and (iteration_data['lat_avg']< self.test['lat_avg_threshold']) and (iteration_data['lat_perc']< self.test['lat_perc_threshold']) and (iteration_data['lat_max'] < self.test['lat_max_threshold']):
                         if (old_div((self.get_pps(speed,size) - iteration_data['pps_tx']),self.get_pps(speed,size)))>0.01:
@@ -177,7 +229,6 @@ class FlowSizeTest(RapidTest):
                             gen_warning = ''
                         end_data = copy.deepcopy(iteration_data)
                         end_prefix = copy.deepcopy(iteration_prefix)
-                        end_data['abs_dropped'] = None
                         if lat_warning or gen_warning or retry_warning:
                             endwarning = '|        | {:186.186} |'.format(retry_warning + lat_warning + gen_warning)
                         success = True
@@ -219,25 +270,30 @@ class FlowSizeTest(RapidTest):
                             break
                     elif self.resolution_achieved():
                         break
-                if end_data['speed'] is not None:
-                    RapidLog.info(self.report_result(flow_number, size,
-                        end_data, end_prefix))
-                    if end_data['avg_bg_rate']:
-                        tot_avg_rx_rate = end_data['pps_rx'] + (end_data['avg_bg_rate'] * len(self.background_machines))
-                        endtotaltrafficrate = '|        | Total amount of traffic received by all generators during this test: {:>4.3f} Gb/s {:7.3f} Mpps {} |'.format(RapidTest.get_speed(tot_avg_rx_rate,size) , tot_avg_rx_rate, ' '*84)
-                        RapidLog.info (endtotaltrafficrate)
-                    if endwarning:
-                        RapidLog.info (endwarning)
-                    RapidLog.info("+--------+------------------+-------------+-------------+-------------+------------------------+----------+----------+----------+-----------+-----------+-----------+-----------+-------+----+")
-                    if self.test['test'] != 'fixed_rate':
-                        TestResult = TestResult + end_data['pps_rx']
-                        end_data['test'] = self.test['testname']
-                        end_data['environment_file'] = self.test['environment_file']
-                        end_data['Flows'] = flow_number
-                        end_data['Size'] = size
-                        end_data['RequestedSpeed'] = RapidTest.get_pps(end_data['speed'] ,size)
-                        result_details = self.post_data('rapid_flowsizetest', end_data)
-                else:
-                    RapidLog.info('|{:>7}'.format(str(flow_number))+" | Speed 0 or close to 0")
-        self.gen_machine.stop_latency_cores()
+                if end_data['speed'] is None:
+                    end_data = iteration_data
+                    end_prefix = iteration_prefix
+                    RapidLog.info('|{:>7} | {:<177} |'.format("FAILED","Speed 0 or close to 0, data for last failed step below:"))
+                RapidLog.info(self.report_result(flow_number, size,
+                    end_data, end_prefix))
+                if end_data['avg_bg_rate']:
+                    tot_avg_rx_rate = end_data['pps_rx'] + (end_data['avg_bg_rate'] * len(self.background_machines))
+                    endtotaltrafficrate = '|        | Total amount of traffic received by all generators during this test: {:>4.3f} Gb/s {:7.3f} Mpps {} |'.format(RapidTest.get_speed(tot_avg_rx_rate,size) , tot_avg_rx_rate, ' '*84)
+                    RapidLog.info (endtotaltrafficrate)
+                if endwarning:
+                    RapidLog.info (endwarning)
+                if self.test['test'] != 'fixed_rate':
+                    TestResult = TestResult + end_data['pps_rx']
+                    end_data['test'] = self.test['testname']
+                    end_data['environment_file'] = self.test['environment_file']
+                    end_data['Flows'] = flow_number
+                    end_data['Size'] = size
+                    end_data['RequestedSpeed'] = RapidTest.get_pps(end_data['speed'] ,size)
+                    result_details = self.post_data(end_data)
+                    RapidLog.debug(result_details)
+                RapidLog.info('+' + '-' * 8 + '+' + '-' * 18 + '+' + '-' * 13 +
+                    '+' + '-' * 13 + '+' + '-' * 13 + '+' + '-' * 24 + '+' +
+                    '-' * 10 + '+' + '-' * 10 + '+' + '-' * 10 + '+' + '-' * 11
+                    + '+' + '-' * 11 + '+' + '-' * 11 + '+'  + '-' * 11 +  '+'
+                    + '-' * 7 + '+' + '-' * 4 + '+')
         return (TestResult, result_details)