blob: 65bc7a980786c241606ad6d69395bd6cd9e0197f [file] [log] [blame]
andrewonlab2a6c9342014-10-16 13:40:15 -04001#TopoPerfNext
2#
3#Topology Performance test for ONOS-next
4#
5#andrew@onlab.us
andrewonlab4f50ec92014-11-11 14:24:45 -05006#
7#If your machine does not come with numpy
8#run the following command:
9#sudo apt-get install python-numpy python-scipy
andrewonlab2a6c9342014-10-16 13:40:15 -040010
11import time
12import sys
13import os
14import re
15
16class TopoPerfNext:
17 def __init__(self):
18 self.default = ''
19
20 def CASE1(self, main):
21 '''
22 ONOS startup sequence
23 '''
andrewonlabe9fb6722014-10-24 12:20:35 -040024 import time
25
andrewonlab2a6c9342014-10-16 13:40:15 -040026 cell_name = main.params['ENV']['cellName']
27
28 git_pull = main.params['GIT']['autoPull']
29 checkout_branch = main.params['GIT']['checkout']
30
31 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlabba44bcf2014-10-16 16:54:41 -040032 ONOS2_ip = main.params['CTRL']['ip2']
33 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab6c8bbeb2014-11-14 12:43:48 -050034
35 #### Hardcoded ONOS nodes particular to my env ####
36 ONOS4_ip = "10.128.174.4"
37 ONOS5_ip = "10.128.174.5"
38 ONOS6_ip = "10.128.174.6"
39 ONOS7_ip = "10.128.174.7"
40 #### ####
41
andrewonlab2a6c9342014-10-16 13:40:15 -040042 MN1_ip = main.params['MN']['ip1']
43 BENCH_ip = main.params['BENCH']['ip']
44
andrewonlab0e1825c2014-11-20 20:07:00 -050045 topo_cfg_file = main.params['TEST']['topo_config_file']
46 topo_cfg_name = main.params['TEST']['topo_config_name']
47
andrewonlab2a6c9342014-10-16 13:40:15 -040048 main.case("Setting up test environment")
andrewonlabc1850522014-11-21 12:07:33 -050049 main.log.info("Copying topology event accumulator config"+\
andrewonlab28b84eb2014-12-02 15:53:35 -050050 " to ONOS /package/etc")
andrewonlabc1850522014-11-21 12:07:33 -050051 main.ONOSbench.handle.sendline("cp ~/"+\
52 topo_cfg_file+\
andrewonlab28b84eb2014-12-02 15:53:35 -050053 " ~/ONOS/tools/package/etc/"+\
andrewonlab0e1825c2014-11-20 20:07:00 -050054 topo_cfg_name)
55 main.ONOSbench.handle.expect("\$")
56
andrewonlabf9828f02014-11-10 14:50:27 -050057 main.log.report("Setting up test environment")
andrewonlab2a6c9342014-10-16 13:40:15 -040058
andrewonlab6c8bbeb2014-11-14 12:43:48 -050059 main.step("Cleaning previously installed ONOS if any")
60 main.ONOSbench.onos_uninstall(node_ip=ONOS4_ip)
61 main.ONOSbench.onos_uninstall(node_ip=ONOS5_ip)
62 main.ONOSbench.onos_uninstall(node_ip=ONOS6_ip)
63 main.ONOSbench.onos_uninstall(node_ip=ONOS7_ip)
64
andrewonlab2a6c9342014-10-16 13:40:15 -040065 main.step("Creating cell file")
66 cell_file_result = main.ONOSbench.create_cell_file(
andrewonlab28b84eb2014-12-02 15:53:35 -050067 BENCH_ip, cell_name, MN1_ip, "onos-core,onos-app-metrics",
andrewonlabba44bcf2014-10-16 16:54:41 -040068 ONOS1_ip, ONOS2_ip, ONOS3_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -040069
70 main.step("Applying cell file to environment")
71 cell_apply_result = main.ONOSbench.set_cell(cell_name)
72 verify_cell_result = main.ONOSbench.verify_cell()
73
andrewonlab6e78adf2014-11-14 12:57:29 -050074 #NOTE: This step may be removed after proper
75 # copy cat log functionality
76 main.step("Removing raft/copy-cat logs from ONOS nodes")
77 main.ONOSbench.onos_remove_raft_logs()
andrewonlab28b84eb2014-12-02 15:53:35 -050078 time.sleep(30)
79
andrewonlab2a6c9342014-10-16 13:40:15 -040080 main.step("Git checkout and pull "+checkout_branch)
81 if git_pull == 'on':
82 checkout_result = \
83 main.ONOSbench.git_checkout(checkout_branch)
84 pull_result = main.ONOSbench.git_pull()
85 else:
86 checkout_result = main.TRUE
87 pull_result = main.TRUE
88 main.log.info("Skipped git checkout and pull")
89
andrewonlab92844342014-11-18 16:39:11 -050090 #TODO: Uncomment when wiki posting works
91 #main.log.report("Commit information - ")
92 #main.ONOSbench.get_version(report=True)
93
andrewonlab2a6c9342014-10-16 13:40:15 -040094 main.step("Using mvn clean & install")
andrewonlab8d29f122014-10-22 17:15:04 -040095 #mvn_result = main.ONOSbench.clean_install()
96 mvn_result = main.TRUE
andrewonlab2a6c9342014-10-16 13:40:15 -040097
andrewonlabb1998c52014-11-10 13:31:43 -050098 main.step("Set cell for ONOS cli env")
99 main.ONOS1cli.set_cell(cell_name)
100 main.ONOS2cli.set_cell(cell_name)
101 main.ONOS3cli.set_cell(cell_name)
102
andrewonlab2a6c9342014-10-16 13:40:15 -0400103 main.step("Creating ONOS package")
104 package_result = main.ONOSbench.onos_package()
105
106 main.step("Installing ONOS package")
andrewonlabe9fb6722014-10-24 12:20:35 -0400107 install1_result = main.ONOSbench.onos_install(node=ONOS1_ip)
108 install2_result = main.ONOSbench.onos_install(node=ONOS2_ip)
109 install3_result = main.ONOSbench.onos_install(node=ONOS3_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -0400110
andrewonlabe9fb6722014-10-24 12:20:35 -0400111 time.sleep(10)
112
andrewonlab867212a2014-10-22 20:13:38 -0400113 main.step("Start onos cli")
andrewonlabe9fb6722014-10-24 12:20:35 -0400114 cli1 = main.ONOS1cli.start_onos_cli(ONOS1_ip)
115 cli2 = main.ONOS2cli.start_onos_cli(ONOS2_ip)
116 cli3 = main.ONOS3cli.start_onos_cli(ONOS3_ip)
117
andrewonlab2a6c9342014-10-16 13:40:15 -0400118 utilities.assert_equals(expect=main.TRUE,
119 actual= cell_file_result and cell_apply_result and\
120 verify_cell_result and checkout_result and\
121 pull_result and mvn_result and\
andrewonlabe9fb6722014-10-24 12:20:35 -0400122 install1_result and install2_result and\
123 install3_result,
andrewonlabf9828f02014-11-10 14:50:27 -0500124 onpass="Test Environment setup successful",
125 onfail="Failed to setup test environment")
andrewonlab2a6c9342014-10-16 13:40:15 -0400126
andrewonlabba44bcf2014-10-16 16:54:41 -0400127 def CASE2(self, main):
128 '''
129 Assign s1 to ONOS1 and measure latency
andrewonlab3a7c3c72014-10-24 17:21:03 -0400130
131 There are 4 levels of latency measurements to this test:
132 1) End-to-end measurement: Complete end-to-end measurement
133 from TCP (SYN/ACK) handshake to Graph change
134 2) OFP-to-graph measurement: 'ONOS processing' snippet of
135 measurement from OFP Vendor message to Graph change
136 3) OFP-to-device measurement: 'ONOS processing without
137 graph change' snippet of measurement from OFP vendor
138 message to Device change timestamp
139 4) T0-to-device measurement: Measurement that includes
140 the switch handshake to devices timestamp without
141 the graph view change. (TCP handshake -> Device
142 change)
andrewonlabba44bcf2014-10-16 16:54:41 -0400143 '''
144 import time
andrewonlabe6745342014-10-17 14:29:13 -0400145 import subprocess
146 import json
147 import requests
148 import os
andrewonlab4f50ec92014-11-11 14:24:45 -0500149 import numpy
andrewonlabba44bcf2014-10-16 16:54:41 -0400150
151 ONOS1_ip = main.params['CTRL']['ip1']
152 ONOS2_ip = main.params['CTRL']['ip2']
153 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlabe6745342014-10-17 14:29:13 -0400154 ONOS_user = main.params['CTRL']['user']
155
andrewonlabba44bcf2014-10-16 16:54:41 -0400156 default_sw_port = main.params['CTRL']['port1']
157
158 #Number of iterations of case
159 num_iter = main.params['TEST']['numIter']
andrewonlab4b5c8b92014-11-10 16:04:33 -0500160 #Number of first 'x' iterations to ignore:
161 iter_ignore = int(main.params['TEST']['iterIgnore'])
162
andrewonlab226024e2014-10-24 16:01:32 -0400163 #Timestamp 'keys' for json metrics output.
164 #These are subject to change, hence moved into params
165 deviceTimestamp = main.params['JSON']['deviceTimestamp']
166 graphTimestamp = main.params['JSON']['graphTimestamp']
167
andrewonlab58f7d702014-11-07 13:21:19 -0500168 debug_mode = main.params['TEST']['debugMode']
andrewonlabb1998c52014-11-10 13:31:43 -0500169 onos_log = main.params['TEST']['onosLogFile']
andrewonlab58f7d702014-11-07 13:21:19 -0500170
andrewonlabe5bcef92014-11-06 17:53:20 -0500171 #Threshold for the test
172 threshold_str = main.params['TEST']['singleSwThreshold']
173 threshold_obj = threshold_str.split(",")
174 threshold_min = int(threshold_obj[0])
175 threshold_max = int(threshold_obj[1])
176
andrewonlab226024e2014-10-24 16:01:32 -0400177 #List of switch add latency collected from
178 #all iterations
179 latency_end_to_end_list = []
180 latency_ofp_to_graph_list = []
181 latency_ofp_to_device_list = []
182 latency_t0_to_device_list = []
andrewonlab65d73892014-11-10 17:36:00 -0500183 latency_tcp_to_ofp_list = []
andrewonlab226024e2014-10-24 16:01:32 -0400184
andrewonlabba44bcf2014-10-16 16:54:41 -0400185 #Directory/file to store tshark results
186 tshark_of_output = "/tmp/tshark_of_topo.txt"
187 tshark_tcp_output = "/tmp/tshark_tcp_topo.txt"
188
189 #String to grep in tshark output
190 tshark_tcp_string = "TCP 74 "+default_sw_port
191 tshark_of_string = "OFP 86 Vendor"
andrewonlabe6745342014-10-17 14:29:13 -0400192
193 #Initialize assertion to TRUE
194 assertion = main.TRUE
andrewonlab58f7d702014-11-07 13:21:19 -0500195
196 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500197 local_time = local_time.replace("/","")
198 local_time = local_time.replace(" ","_")
199 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500200 if debug_mode == 'on':
201 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500202 "/tmp/single_sw_lat_pcap_"+local_time)
203
204 main.log.info("TEST")
andrewonlab58f7d702014-11-07 13:21:19 -0500205
andrewonlab4b5c8b92014-11-10 16:04:33 -0500206 main.log.report("Latency of adding one switch to controller")
207 main.log.report("First "+str(iter_ignore)+" iterations ignored"+
208 " for jvm warmup time")
209 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlabba44bcf2014-10-16 16:54:41 -0400210
211 for i in range(0, int(num_iter)):
212 main.log.info("Starting tshark capture")
213
214 #* TCP [ACK, SYN] is used as t0_a, the
215 # very first "exchange" between ONOS and
216 # the switch for end-to-end measurement
217 #* OFP [Stats Reply] is used for t0_b
218 # the very last OFP message between ONOS
219 # and the switch for ONOS measurement
220 main.ONOS1.tshark_grep(tshark_tcp_string,
221 tshark_tcp_output)
222 main.ONOS1.tshark_grep(tshark_of_string,
223 tshark_of_output)
224
225 #Wait and ensure tshark is started and
226 #capturing
227 time.sleep(10)
228
229 main.log.info("Assigning s1 to controller")
230
231 main.Mininet1.assign_sw_controller(sw="1",
232 ip1=ONOS1_ip, port1=default_sw_port)
233
234 #Wait and ensure switch is assigned
235 #before stopping tshark
andrewonlab867212a2014-10-22 20:13:38 -0400236 time.sleep(30)
andrewonlab226024e2014-10-24 16:01:32 -0400237
238 main.log.info("Stopping all Tshark processes")
andrewonlabba44bcf2014-10-16 16:54:41 -0400239 main.ONOS1.stop_tshark()
240
andrewonlabe6745342014-10-17 14:29:13 -0400241 #tshark output is saved in ONOS. Use subprocess
242 #to copy over files to TestON for parsing
243 main.log.info("Copying over tshark files")
244
245 #TCP CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400246 #Copy the tshark output from ONOS machine to
247 #TestON machine in tshark_tcp_output directory>file
248 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
249 tshark_tcp_output+" /tmp/")
250 tcp_file = open(tshark_tcp_output, 'r')
251 temp_text = tcp_file.readline()
andrewonlabe6745342014-10-17 14:29:13 -0400252 temp_text = temp_text.split(" ")
andrewonlabba44bcf2014-10-16 16:54:41 -0400253
andrewonlabe6745342014-10-17 14:29:13 -0400254 main.log.info("Object read in from TCP capture: "+
255 str(temp_text))
andrewonlab867212a2014-10-22 20:13:38 -0400256 if len(temp_text) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400257 t0_tcp = float(temp_text[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400258 else:
259 main.log.error("Tshark output file for TCP"+
260 " returned unexpected results")
261 t0_tcp = 0
262 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400263
264 tcp_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400265 #****************
andrewonlabba44bcf2014-10-16 16:54:41 -0400266
andrewonlabe6745342014-10-17 14:29:13 -0400267 #OF CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400268 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
269 tshark_of_output+" /tmp/")
270 of_file = open(tshark_of_output, 'r')
271
272 line_ofp = ""
andrewonlab226024e2014-10-24 16:01:32 -0400273 #Read until last line of file
andrewonlabe6745342014-10-17 14:29:13 -0400274 while True:
andrewonlab8d29f122014-10-22 17:15:04 -0400275 temp_text = of_file.readline()
276 if temp_text !='':
andrewonlabe6745342014-10-17 14:29:13 -0400277 line_ofp = temp_text
278 else:
279 break
280 obj = line_ofp.split(" ")
281
282 main.log.info("Object read in from OFP capture: "+
283 str(line_ofp))
284
andrewonlab867212a2014-10-22 20:13:38 -0400285 if len(line_ofp) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400286 t0_ofp = float(obj[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400287 else:
288 main.log.error("Tshark output file for OFP"+
289 " returned unexpected results")
290 t0_ofp = 0
291 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400292
293 of_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400294 #****************
295
andrewonlab867212a2014-10-22 20:13:38 -0400296 json_str_1 = main.ONOS1cli.topology_events_metrics()
297 json_str_2 = main.ONOS2cli.topology_events_metrics()
298 json_str_3 = main.ONOS3cli.topology_events_metrics()
andrewonlab867212a2014-10-22 20:13:38 -0400299
300 json_obj_1 = json.loads(json_str_1)
301 json_obj_2 = json.loads(json_str_2)
302 json_obj_3 = json.loads(json_str_3)
303
andrewonlab226024e2014-10-24 16:01:32 -0400304 #Obtain graph timestamp. This timestsamp captures
305 #the epoch time at which the topology graph was updated.
306 graph_timestamp_1 = \
307 json_obj_1[graphTimestamp]['value']
308 graph_timestamp_2 = \
309 json_obj_2[graphTimestamp]['value']
310 graph_timestamp_3 = \
311 json_obj_3[graphTimestamp]['value']
andrewonlab867212a2014-10-22 20:13:38 -0400312
andrewonlab226024e2014-10-24 16:01:32 -0400313 #Obtain device timestamp. This timestamp captures
314 #the epoch time at which the device event happened
315 device_timestamp_1 = \
316 json_obj_1[deviceTimestamp]['value']
317 device_timestamp_2 = \
318 json_obj_2[deviceTimestamp]['value']
319 device_timestamp_3 = \
320 json_obj_3[deviceTimestamp]['value']
andrewonlabe9fb6722014-10-24 12:20:35 -0400321
andrewonlab226024e2014-10-24 16:01:32 -0400322 #t0 to device processing latency
323 delta_device_1 = int(device_timestamp_1) - int(t0_tcp)
324 delta_device_2 = int(device_timestamp_2) - int(t0_tcp)
325 delta_device_3 = int(device_timestamp_3) - int(t0_tcp)
326
327 #Get average of delta from all instances
328 avg_delta_device = \
329 (int(delta_device_1)+\
330 int(delta_device_2)+\
331 int(delta_device_3)) / 3
andrewonlabba44bcf2014-10-16 16:54:41 -0400332
andrewonlab226024e2014-10-24 16:01:32 -0400333 #Ensure avg delta meets the threshold before appending
andrewonlab4b5c8b92014-11-10 16:04:33 -0500334 if avg_delta_device > 0.0 and avg_delta_device < 10000\
andrewonlab65d73892014-11-10 17:36:00 -0500335 and int(i) > iter_ignore:
andrewonlab226024e2014-10-24 16:01:32 -0400336 latency_t0_to_device_list.append(avg_delta_device)
andrewonlabee4efeb2014-10-24 16:44:51 -0400337 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400338 main.log.info("Results for t0-to-device ignored"+\
andrewonlab4b5c8b92014-11-10 16:04:33 -0500339 "due to excess in threshold / warmup iteration.")
andrewonlabee4efeb2014-10-24 16:44:51 -0400340
andrewonlab226024e2014-10-24 16:01:32 -0400341 #t0 to graph processing latency (end-to-end)
342 delta_graph_1 = int(graph_timestamp_1) - int(t0_tcp)
343 delta_graph_2 = int(graph_timestamp_2) - int(t0_tcp)
344 delta_graph_3 = int(graph_timestamp_3) - int(t0_tcp)
345
346 #Get average of delta from all instances
347 avg_delta_graph = \
348 (int(delta_graph_1)+\
349 int(delta_graph_2)+\
350 int(delta_graph_3)) / 3
351
andrewonlab226024e2014-10-24 16:01:32 -0400352 #Ensure avg delta meets the threshold before appending
andrewonlab4b5c8b92014-11-10 16:04:33 -0500353 if avg_delta_graph > 0.0 and avg_delta_graph < 10000\
andrewonlab65d73892014-11-10 17:36:00 -0500354 and int(i) > iter_ignore:
andrewonlab09d973e2014-10-24 18:56:58 -0400355 latency_end_to_end_list.append(avg_delta_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400356 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400357 main.log.info("Results for end-to-end ignored"+\
358 "due to excess in threshold")
andrewonlab226024e2014-10-24 16:01:32 -0400359
360 #ofp to graph processing latency (ONOS processing)
361 delta_ofp_graph_1 = int(graph_timestamp_1) - int(t0_ofp)
362 delta_ofp_graph_2 = int(graph_timestamp_2) - int(t0_ofp)
363 delta_ofp_graph_3 = int(graph_timestamp_3) - int(t0_ofp)
364
365 avg_delta_ofp_graph = \
366 (int(delta_ofp_graph_1)+\
367 int(delta_ofp_graph_2)+\
368 int(delta_ofp_graph_3)) / 3
369
andrewonlabe5bcef92014-11-06 17:53:20 -0500370 if avg_delta_ofp_graph > threshold_min \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500371 and avg_delta_ofp_graph < threshold_max\
andrewonlab65d73892014-11-10 17:36:00 -0500372 and int(i) > iter_ignore:
andrewonlab226024e2014-10-24 16:01:32 -0400373 latency_ofp_to_graph_list.append(avg_delta_ofp_graph)
andrewonlab92844342014-11-18 16:39:11 -0500374 elif avg_delta_ofp_graph > (-10) and \
375 avg_delta_ofp_graph < 0.0 and\
376 int(i) > iter_ignore:
377 main.log.info("Sub-millisecond result likely; "+
378 "negative result was rounded to 0")
379 #NOTE: Current metrics framework does not
380 #support sub-millisecond accuracy. Therefore,
381 #if the result is negative, we can reasonably
382 #conclude sub-millisecond results and just
383 #append the best rounded effort - 0 ms.
384 latency_ofp_to_graph_list.append(0)
andrewonlabee4efeb2014-10-24 16:44:51 -0400385 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400386 main.log.info("Results for ofp-to-graph "+\
387 "ignored due to excess in threshold")
andrewonlabee4efeb2014-10-24 16:44:51 -0400388
andrewonlab226024e2014-10-24 16:01:32 -0400389 #ofp to device processing latency (ONOS processing)
andrewonlabee4efeb2014-10-24 16:44:51 -0400390 delta_ofp_device_1 = float(device_timestamp_1) - float(t0_ofp)
391 delta_ofp_device_2 = float(device_timestamp_2) - float(t0_ofp)
392 delta_ofp_device_3 = float(device_timestamp_3) - float(t0_ofp)
andrewonlab226024e2014-10-24 16:01:32 -0400393
394 avg_delta_ofp_device = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400395 (float(delta_ofp_device_1)+\
396 float(delta_ofp_device_2)+\
andrewonlab4b5c8b92014-11-10 16:04:33 -0500397 float(delta_ofp_device_3)) / 3
andrewonlab226024e2014-10-24 16:01:32 -0400398
andrewonlabf47993a2014-10-24 17:56:01 -0400399 #NOTE: ofp - delta measurements are occasionally negative
400 # due to system time misalignment.
andrewonlabf47993a2014-10-24 17:56:01 -0400401 latency_ofp_to_device_list.append(avg_delta_ofp_device)
andrewonlabba44bcf2014-10-16 16:54:41 -0400402
andrewonlab65d73892014-11-10 17:36:00 -0500403 delta_ofp_tcp = int(t0_ofp) - int(t0_tcp)
404 if delta_ofp_tcp > threshold_min \
405 and delta_ofp_tcp < threshold_max and\
406 int(i) > iter_ignore:
407 latency_tcp_to_ofp_list.append(delta_ofp_tcp)
408 else:
409 main.log.info("Results fo tcp-to-ofp "+\
410 "ignored due to excess in threshold")
411
andrewonlabe6745342014-10-17 14:29:13 -0400412 #TODO:
413 #Fetch logs upon threshold excess
andrewonlabba44bcf2014-10-16 16:54:41 -0400414
andrewonlab226024e2014-10-24 16:01:32 -0400415 main.log.info("ONOS1 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400416 str(delta_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400417 main.log.info("ONOS2 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400418 str(delta_graph_2) + " ms")
419 main.log.info("ONOS3 delta end-to-end: "+
420 str(delta_graph_3) + " ms")
andrewonlabba44bcf2014-10-16 16:54:41 -0400421
andrewonlab226024e2014-10-24 16:01:32 -0400422 main.log.info("ONOS1 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400423 str(delta_ofp_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400424 main.log.info("ONOS2 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400425 str(delta_ofp_graph_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400426 main.log.info("ONOS3 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400427 str(delta_ofp_graph_3) + " ms")
andrewonlabe6745342014-10-17 14:29:13 -0400428
andrewonlab226024e2014-10-24 16:01:32 -0400429 main.log.info("ONOS1 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400430 str(delta_device_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400431 main.log.info("ONOS2 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400432 str(delta_device_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400433 main.log.info("ONOS3 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400434 str(delta_device_3) + " ms")
andrewonlab65d73892014-11-10 17:36:00 -0500435
436 main.log.info("TCP to OFP delta: "+
437 str(delta_ofp_tcp) + " ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500438 #main.log.info("ONOS1 delta OFP - device: "+
439 # str(delta_ofp_device_1) + " ms")
440 #main.log.info("ONOS2 delta OFP - device: "+
441 # str(delta_ofp_device_2) + " ms")
442 #main.log.info("ONOS3 delta OFP - device: "+
443 # str(delta_ofp_device_3) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400444
andrewonlab8d29f122014-10-22 17:15:04 -0400445 main.step("Remove switch from controller")
446 main.Mininet1.delete_sw_controller("s1")
andrewonlabba44bcf2014-10-16 16:54:41 -0400447
andrewonlab8d29f122014-10-22 17:15:04 -0400448 time.sleep(5)
andrewonlabba44bcf2014-10-16 16:54:41 -0400449
andrewonlab09d973e2014-10-24 18:56:58 -0400450 #END of for loop iteration
andrewonlabf47993a2014-10-24 17:56:01 -0400451
andrewonlabee4efeb2014-10-24 16:44:51 -0400452 #If there is at least 1 element in each list,
andrewonlabc15c9582014-10-24 16:35:52 -0400453 #pass the test case
454 if len(latency_end_to_end_list) > 0 and\
455 len(latency_ofp_to_graph_list) > 0 and\
456 len(latency_ofp_to_device_list) > 0 and\
andrewonlab65d73892014-11-10 17:36:00 -0500457 len(latency_t0_to_device_list) > 0 and\
458 len(latency_tcp_to_ofp_list) > 0:
andrewonlabc15c9582014-10-24 16:35:52 -0400459 assertion = main.TRUE
andrewonlabf47993a2014-10-24 17:56:01 -0400460 elif len(latency_end_to_end_list) == 0:
461 #The appending of 0 here is to prevent
462 #the min,max,sum functions from failing
463 #below
464 latency_end_to_end_list.append(0)
465 assertion = main.FALSE
466 elif len(latency_ofp_to_graph_list) == 0:
467 latency_ofp_to_graph_list.append(0)
468 assertion = main.FALSE
469 elif len(latency_ofp_to_device_list) == 0:
470 latency_ofp_to_device_list.append(0)
471 assertion = main.FALSE
472 elif len(latency_t0_to_device_list) == 0:
473 latency_t0_to_device_list.append(0)
474 assertion = main.FALSE
andrewonlab65d73892014-11-10 17:36:00 -0500475 elif len(latency_tcp_to_ofp_list) == 0:
476 latency_tcp_to_ofp_list.append(0)
477 assertion = main.FALSE
andrewonlabc15c9582014-10-24 16:35:52 -0400478
479 #Calculate min, max, avg of latency lists
480 latency_end_to_end_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400481 int(max(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400482 latency_end_to_end_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400483 int(min(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400484 latency_end_to_end_avg = \
andrewonlabc90667c2014-10-24 16:48:28 -0400485 (int(sum(latency_end_to_end_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400486 len(latency_end_to_end_list))
andrewonlab69864162014-11-11 16:28:48 -0500487 latency_end_to_end_std_dev = \
488 str(round(numpy.std(latency_end_to_end_list),1))
489
andrewonlabc15c9582014-10-24 16:35:52 -0400490 latency_ofp_to_graph_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400491 int(max(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400492 latency_ofp_to_graph_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400493 int(min(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400494 latency_ofp_to_graph_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400495 (int(sum(latency_ofp_to_graph_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400496 len(latency_ofp_to_graph_list))
andrewonlab69864162014-11-11 16:28:48 -0500497 latency_ofp_to_graph_std_dev = \
498 str(round(numpy.std(latency_ofp_to_graph_list),1))
andrewonlabc15c9582014-10-24 16:35:52 -0400499
500 latency_ofp_to_device_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400501 int(max(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400502 latency_ofp_to_device_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400503 int(min(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400504 latency_ofp_to_device_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400505 (int(sum(latency_ofp_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400506 len(latency_ofp_to_device_list))
andrewonlab69864162014-11-11 16:28:48 -0500507 latency_ofp_to_device_std_dev = \
508 str(round(numpy.std(latency_ofp_to_device_list),1))
andrewonlabc15c9582014-10-24 16:35:52 -0400509
510 latency_t0_to_device_max = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500511 int(max(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400512 latency_t0_to_device_min = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500513 int(min(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400514 latency_t0_to_device_avg = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500515 (int(sum(latency_t0_to_device_list)) / \
andrewonlab69864162014-11-11 16:28:48 -0500516 len(latency_t0_to_device_list))
517 latency_ofp_to_device_std_dev = \
518 str(round(numpy.std(latency_t0_to_device_list),1))
andrewonlabc15c9582014-10-24 16:35:52 -0400519
andrewonlab65d73892014-11-10 17:36:00 -0500520 latency_tcp_to_ofp_max = \
521 int(max(latency_tcp_to_ofp_list))
522 latency_tcp_to_ofp_min = \
523 int(min(latency_tcp_to_ofp_list))
524 latency_tcp_to_ofp_avg = \
525 (int(sum(latency_tcp_to_ofp_list)) / \
526 len(latency_tcp_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500527 latency_tcp_to_ofp_std_dev = \
528 str(round(numpy.std(latency_tcp_to_ofp_list),1))
andrewonlab65d73892014-11-10 17:36:00 -0500529
andrewonlabf9828f02014-11-10 14:50:27 -0500530 main.log.report("Switch add - End-to-end latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500531 "Avg: "+str(latency_end_to_end_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500532 "Std Deviation: "+latency_end_to_end_std_dev+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -0500533 main.log.report("Switch add - OFP-to-Graph latency: "+\
andrewonlab92844342014-11-18 16:39:11 -0500534 "Note: results are not accurate to sub-millisecond. "+
535 "Any sub-millisecond results are rounded to 0 ms. ")
536 main.log.report("Avg: "+str(latency_ofp_to_graph_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500537 "Std Deviation: "+latency_ofp_to_graph_std_dev+" ms")
andrewonlab65d73892014-11-10 17:36:00 -0500538 main.log.report("Switch add - TCP-to-OFP latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500539 "Avg: "+str(latency_tcp_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500540 "Std Deviation: "+latency_tcp_to_ofp_std_dev+" ms")
andrewonlab226024e2014-10-24 16:01:32 -0400541
andrewonlabb1998c52014-11-10 13:31:43 -0500542 if debug_mode == 'on':
543 main.ONOS1.cp_logs_to_dir("/opt/onos/log/karaf.log",
544 "/tmp/", copy_file_name="sw_lat_karaf")
545
andrewonlab8d29f122014-10-22 17:15:04 -0400546 utilities.assert_equals(expect=main.TRUE, actual=assertion,
547 onpass="Switch latency test successful",
548 onfail="Switch latency test failed")
andrewonlabba44bcf2014-10-16 16:54:41 -0400549
andrewonlab8d29f122014-10-22 17:15:04 -0400550 def CASE3(self, main):
551 '''
552 Bring port up / down and measure latency.
553 Port enable / disable is simulated by ifconfig up / down
andrewonlab393531a2014-10-27 18:36:26 -0400554
555 In ONOS-next, we must ensure that the port we are
556 manipulating is connected to another switch with a valid
557 connection. Otherwise, graph view will not be updated.
andrewonlab8d29f122014-10-22 17:15:04 -0400558 '''
559 import time
560 import subprocess
561 import os
562 import requests
563 import json
andrewonlab4f50ec92014-11-11 14:24:45 -0500564 import numpy
andrewonlab2a6c9342014-10-16 13:40:15 -0400565
andrewonlab8d29f122014-10-22 17:15:04 -0400566 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlab393531a2014-10-27 18:36:26 -0400567 ONOS2_ip = main.params['CTRL']['ip2']
568 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab8d29f122014-10-22 17:15:04 -0400569 ONOS_user = main.params['CTRL']['user']
andrewonlab8d29f122014-10-22 17:15:04 -0400570
andrewonlab393531a2014-10-27 18:36:26 -0400571 default_sw_port = main.params['CTRL']['port1']
andrewonlab8790abb2014-11-06 13:51:54 -0500572
573 assertion = main.TRUE
andrewonlab393531a2014-10-27 18:36:26 -0400574 #Number of iterations of case
575 num_iter = main.params['TEST']['numIter']
576
577 #Timestamp 'keys' for json metrics output.
578 #These are subject to change, hence moved into params
579 deviceTimestamp = main.params['JSON']['deviceTimestamp']
580 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500581
582 debug_mode = main.params['TEST']['debugMode']
583
584 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500585 local_time = local_time.replace("/","")
586 local_time = local_time.replace(" ","_")
587 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500588 if debug_mode == 'on':
589 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500590 "/tmp/port_lat_pcap_"+local_time)
andrewonlab393531a2014-10-27 18:36:26 -0400591
andrewonlabe5bcef92014-11-06 17:53:20 -0500592 #Threshold for this test case
593 up_threshold_str = main.params['TEST']['portUpThreshold']
594 down_threshold_str = main.params['TEST']['portDownThreshold']
andrewonlabb1998c52014-11-10 13:31:43 -0500595
andrewonlabe5bcef92014-11-06 17:53:20 -0500596 up_threshold_obj = up_threshold_str.split(",")
597 down_threshold_obj = down_threshold_str.split(",")
598
599 up_threshold_min = int(up_threshold_obj[0])
600 up_threshold_max = int(up_threshold_obj[1])
601
602 down_threshold_min = int(down_threshold_obj[0])
603 down_threshold_max = int(down_threshold_obj[1])
604
andrewonlab393531a2014-10-27 18:36:26 -0400605 #NOTE: Some hardcoded variables you may need to configure
606 # besides the params
607
andrewonlab8d29f122014-10-22 17:15:04 -0400608 tshark_port_status = "OFP 130 Port Status"
609
610 tshark_port_up = "/tmp/tshark_port_up.txt"
611 tshark_port_down = "/tmp/tshark_port_down.txt"
andrewonlab393531a2014-10-27 18:36:26 -0400612 interface_config = "s1-eth1"
andrewonlab8d29f122014-10-22 17:15:04 -0400613
614 main.log.report("Port enable / disable latency")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500615 main.log.report("Simulated by ifconfig up / down")
616 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab8d29f122014-10-22 17:15:04 -0400617
andrewonlab393531a2014-10-27 18:36:26 -0400618 main.step("Assign switches s1 and s2 to controller 1")
andrewonlab8d29f122014-10-22 17:15:04 -0400619 main.Mininet1.assign_sw_controller(sw="1",ip1=ONOS1_ip,
620 port1=default_sw_port)
andrewonlab393531a2014-10-27 18:36:26 -0400621 main.Mininet1.assign_sw_controller(sw="2",ip1=ONOS1_ip,
622 port1=default_sw_port)
andrewonlab8d29f122014-10-22 17:15:04 -0400623
andrewonlab8790abb2014-11-06 13:51:54 -0500624 #Give enough time for metrics to propagate the
625 #assign controller event. Otherwise, these events may
626 #carry over to our measurements
andrewonlabb1998c52014-11-10 13:31:43 -0500627 time.sleep(15)
andrewonlab8d29f122014-10-22 17:15:04 -0400628
andrewonlab393531a2014-10-27 18:36:26 -0400629 port_up_device_to_ofp_list = []
630 port_up_graph_to_ofp_list = []
631 port_down_device_to_ofp_list = []
632 port_down_graph_to_ofp_list = []
633
andrewonlab8d29f122014-10-22 17:15:04 -0400634 for i in range(0, int(num_iter)):
635 main.step("Starting wireshark capture for port status down")
636 main.ONOS1.tshark_grep(tshark_port_status,
637 tshark_port_down)
638
andrewonlabb1998c52014-11-10 13:31:43 -0500639 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400640
andrewonlab393531a2014-10-27 18:36:26 -0400641 #Disable interface that is connected to switch 2
642 main.step("Disable port: "+interface_config)
andrewonlabb1998c52014-11-10 13:31:43 -0500643 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400644 interface_config+" down")
andrewonlabb1998c52014-11-10 13:31:43 -0500645 main.Mininet1.handle.expect("mininet>")
andrewonlab8d29f122014-10-22 17:15:04 -0400646
andrewonlabb1998c52014-11-10 13:31:43 -0500647 time.sleep(3)
andrewonlab8d29f122014-10-22 17:15:04 -0400648 main.ONOS1.tshark_stop()
andrewonlabb1998c52014-11-10 13:31:43 -0500649
650 main.step("Obtain t1 by metrics call")
651 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
652 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
653 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
654
655 json_obj_1 = json.loads(json_str_up_1)
656 json_obj_2 = json.loads(json_str_up_2)
657 json_obj_3 = json.loads(json_str_up_3)
andrewonlab8d29f122014-10-22 17:15:04 -0400658
659 #Copy tshark output file from ONOS to TestON instance
660 #/tmp directory
661 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
662 tshark_port_down+" /tmp/")
663
664 f_port_down = open(tshark_port_down, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400665 #Get first line of port down event from tshark
andrewonlab8d29f122014-10-22 17:15:04 -0400666 f_line = f_port_down.readline()
667 obj_down = f_line.split(" ")
668 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500669 timestamp_begin_pt_down = int(float(obj_down[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400670 main.log.info("Port down begin timestamp: "+
671 str(timestamp_begin_pt_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400672 else:
673 main.log.info("Tshark output file returned unexpected"+
andrewonlab393531a2014-10-27 18:36:26 -0400674 " results: "+str(obj_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400675 timestamp_begin_pt_down = 0
andrewonlab393531a2014-10-27 18:36:26 -0400676
677 f_port_down.close()
andrewonlab8d29f122014-10-22 17:15:04 -0400678
andrewonlab4e124482014-11-04 13:37:25 -0500679 main.log.info("TEST tshark obj: "+str(obj_down))
680
andrewonlabb1998c52014-11-10 13:31:43 -0500681 time.sleep(3)
andrewonlab393531a2014-10-27 18:36:26 -0400682
683 #Obtain graph timestamp. This timestsamp captures
684 #the epoch time at which the topology graph was updated.
685 graph_timestamp_1 = \
686 json_obj_1[graphTimestamp]['value']
687 graph_timestamp_2 = \
688 json_obj_2[graphTimestamp]['value']
689 graph_timestamp_3 = \
690 json_obj_3[graphTimestamp]['value']
691
andrewonlabb1998c52014-11-10 13:31:43 -0500692 main.log.info("TEST graph timestamp ONOS1: "+
693 str(graph_timestamp_1))
694
andrewonlab393531a2014-10-27 18:36:26 -0400695 #Obtain device timestamp. This timestamp captures
696 #the epoch time at which the device event happened
697 device_timestamp_1 = \
698 json_obj_1[deviceTimestamp]['value']
699 device_timestamp_2 = \
700 json_obj_2[deviceTimestamp]['value']
701 device_timestamp_3 = \
702 json_obj_3[deviceTimestamp]['value']
andrewonlab393531a2014-10-27 18:36:26 -0400703
704 #Get delta between graph event and OFP
705 pt_down_graph_to_ofp_1 = int(graph_timestamp_1) -\
706 int(timestamp_begin_pt_down)
707 pt_down_graph_to_ofp_2 = int(graph_timestamp_2) -\
708 int(timestamp_begin_pt_down)
709 pt_down_graph_to_ofp_3 = int(graph_timestamp_3) -\
710 int(timestamp_begin_pt_down)
711
712 #Get delta between device event and OFP
713 pt_down_device_to_ofp_1 = int(device_timestamp_1) -\
714 int(timestamp_begin_pt_down)
715 pt_down_device_to_ofp_2 = int(device_timestamp_2) -\
716 int(timestamp_begin_pt_down)
717 pt_down_device_to_ofp_3 = int(device_timestamp_3) -\
718 int(timestamp_begin_pt_down)
719
720 #Caluclate average across clusters
721 pt_down_graph_to_ofp_avg =\
722 (int(pt_down_graph_to_ofp_1) +
723 int(pt_down_graph_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500724 int(pt_down_graph_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400725 pt_down_device_to_ofp_avg = \
726 (int(pt_down_device_to_ofp_1) +
727 int(pt_down_device_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500728 int(pt_down_device_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400729
andrewonlabb1998c52014-11-10 13:31:43 -0500730 if pt_down_graph_to_ofp_avg > down_threshold_min and \
731 pt_down_graph_to_ofp_avg < down_threshold_max:
andrewonlab393531a2014-10-27 18:36:26 -0400732 port_down_graph_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500733 pt_down_graph_to_ofp_avg)
734 main.log.info("Port down: graph to ofp avg: "+
735 str(pt_down_graph_to_ofp_avg) + " ms")
andrewonlab393531a2014-10-27 18:36:26 -0400736 else:
737 main.log.info("Average port down graph-to-ofp result" +
738 " exceeded the threshold: "+
739 str(pt_down_graph_to_ofp_avg))
740
andrewonlab3622beb2014-10-28 16:07:56 -0400741 if pt_down_device_to_ofp_avg > 0 and \
742 pt_down_device_to_ofp_avg < 1000:
743 port_down_device_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500744 pt_down_device_to_ofp_avg)
745 main.log.info("Port down: device to ofp avg: "+
746 str(pt_down_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400747 else:
748 main.log.info("Average port down device-to-ofp result" +
749 " exceeded the threshold: "+
750 str(pt_down_device_to_ofp_avg))
751
andrewonlab8d29f122014-10-22 17:15:04 -0400752 #Port up events
753 main.step("Enable port and obtain timestamp")
754 main.step("Starting wireshark capture for port status up")
andrewonlabb1998c52014-11-10 13:31:43 -0500755 main.ONOS1.tshark_grep(tshark_port_status, tshark_port_up)
andrewonlab8790abb2014-11-06 13:51:54 -0500756 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400757
andrewonlabb1998c52014-11-10 13:31:43 -0500758 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400759 interface_config+" up")
andrewonlabb1998c52014-11-10 13:31:43 -0500760 main.Mininet1.handle.expect("mininet>")
andrewonlab8790abb2014-11-06 13:51:54 -0500761
andrewonlabb1998c52014-11-10 13:31:43 -0500762 #Allow time for tshark to capture event
763 time.sleep(3)
andrewonlab8790abb2014-11-06 13:51:54 -0500764 main.ONOS1.tshark_stop()
andrewonlab8d29f122014-10-22 17:15:04 -0400765
andrewonlabb1998c52014-11-10 13:31:43 -0500766 #Obtain metrics shortly afterwards
767 #This timestsamp captures
768 #the epoch time at which the topology graph was updated.
769 main.step("Obtain t1 by REST call")
770 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
771 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
772 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
773
774 json_obj_1 = json.loads(json_str_up_1)
775 json_obj_2 = json.loads(json_str_up_2)
776 json_obj_3 = json.loads(json_str_up_3)
777
andrewonlab8d29f122014-10-22 17:15:04 -0400778 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
779 tshark_port_up+" /tmp/")
780
781 f_port_up = open(tshark_port_up, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400782 f_line = f_port_up.readline()
andrewonlab8d29f122014-10-22 17:15:04 -0400783 obj_up = f_line.split(" ")
784 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500785 timestamp_begin_pt_up = int(float(obj_up[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400786 main.log.info("Port up begin timestamp: "+
787 str(timestamp_begin_pt_up))
andrewonlab8d29f122014-10-22 17:15:04 -0400788 else:
789 main.log.info("Tshark output file returned unexpected"+
790 " results.")
791 timestamp_begin_pt_up = 0
792
andrewonlab393531a2014-10-27 18:36:26 -0400793 f_port_up.close()
794
andrewonlab393531a2014-10-27 18:36:26 -0400795 graph_timestamp_1 = \
796 json_obj_1[graphTimestamp]['value']
797 graph_timestamp_2 = \
798 json_obj_2[graphTimestamp]['value']
799 graph_timestamp_3 = \
800 json_obj_3[graphTimestamp]['value']
801
802 #Obtain device timestamp. This timestamp captures
803 #the epoch time at which the device event happened
804 device_timestamp_1 = \
805 json_obj_1[deviceTimestamp]['value']
806 device_timestamp_2 = \
807 json_obj_2[deviceTimestamp]['value']
808 device_timestamp_3 = \
809 json_obj_3[deviceTimestamp]['value']
810
811 #Get delta between graph event and OFP
812 pt_up_graph_to_ofp_1 = int(graph_timestamp_1) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400813 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400814 pt_up_graph_to_ofp_2 = int(graph_timestamp_2) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400815 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400816 pt_up_graph_to_ofp_3 = int(graph_timestamp_3) -\
817 int(timestamp_begin_pt_up)
818
819 #Get delta between device event and OFP
820 pt_up_device_to_ofp_1 = int(device_timestamp_1) -\
821 int(timestamp_begin_pt_up)
822 pt_up_device_to_ofp_2 = int(device_timestamp_2) -\
823 int(timestamp_begin_pt_up)
824 pt_up_device_to_ofp_3 = int(device_timestamp_3) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400825 int(timestamp_begin_pt_up)
andrewonlab3622beb2014-10-28 16:07:56 -0400826
andrewonlabb1998c52014-11-10 13:31:43 -0500827 main.log.info("ONOS1 delta G2O: "+str(pt_up_graph_to_ofp_1))
828 main.log.info("ONOS2 delta G2O: "+str(pt_up_graph_to_ofp_2))
829 main.log.info("ONOS3 delta G2O: "+str(pt_up_graph_to_ofp_3))
830
831 main.log.info("ONOS1 delta D2O: "+str(pt_up_device_to_ofp_1))
832 main.log.info("ONOS2 delta D2O: "+str(pt_up_device_to_ofp_2))
833 main.log.info("ONOS3 delta D2O: "+str(pt_up_device_to_ofp_3))
834
andrewonlab3622beb2014-10-28 16:07:56 -0400835 pt_up_graph_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500836 (int(pt_up_graph_to_ofp_1) +
837 int(pt_up_graph_to_ofp_2) +
838 int(pt_up_graph_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400839
840 pt_up_device_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500841 (int(pt_up_device_to_ofp_1) +
842 int(pt_up_device_to_ofp_2) +
843 int(pt_up_device_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400844
andrewonlabe5bcef92014-11-06 17:53:20 -0500845 if pt_up_graph_to_ofp_avg > up_threshold_min and \
846 pt_up_graph_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400847 port_up_graph_to_ofp_list.append(
848 pt_up_graph_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500849 main.log.info("Port down: graph to ofp avg: "+
850 str(pt_up_graph_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400851 else:
852 main.log.info("Average port up graph-to-ofp result"+
853 " exceeded the threshold: "+
854 str(pt_up_graph_to_ofp_avg))
855
andrewonlabe5bcef92014-11-06 17:53:20 -0500856 if pt_up_device_to_ofp_avg > up_threshold_min and \
857 pt_up_device_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400858 port_up_device_to_ofp_list.append(
859 pt_up_device_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500860 main.log.info("Port up: device to ofp avg: "+
861 str(pt_up_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400862 else:
andrewonlababb11c32014-11-04 15:03:24 -0500863 main.log.info("Average port up device-to-ofp result"+
andrewonlab3622beb2014-10-28 16:07:56 -0400864 " exceeded the threshold: "+
865 str(pt_up_device_to_ofp_avg))
andrewonlab8d29f122014-10-22 17:15:04 -0400866
andrewonlab3622beb2014-10-28 16:07:56 -0400867 #END ITERATION FOR LOOP
andrewonlab8790abb2014-11-06 13:51:54 -0500868
869 #Check all list for latency existence and set assertion
870 if (port_down_graph_to_ofp_list and port_down_device_to_ofp_list\
871 and port_up_graph_to_ofp_list and port_up_device_to_ofp_list):
872 assertion = main.TRUE
873
andrewonlababb11c32014-11-04 15:03:24 -0500874 #Calculate and report latency measurements
andrewonlab3622beb2014-10-28 16:07:56 -0400875 port_down_graph_to_ofp_min = min(port_down_graph_to_ofp_list)
876 port_down_graph_to_ofp_max = max(port_down_graph_to_ofp_list)
877 port_down_graph_to_ofp_avg = \
878 (sum(port_down_graph_to_ofp_list) /
879 len(port_down_graph_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500880 port_down_graph_to_ofp_std_dev = \
881 str(round(numpy.std(port_down_graph_to_ofp_list),1))
andrewonlab3622beb2014-10-28 16:07:56 -0400882
andrewonlab4f50ec92014-11-11 14:24:45 -0500883 main.log.report("Port down graph-to-ofp "+
884 "Avg: "+str(port_down_graph_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500885 "Std Deviation: "+port_down_graph_to_ofp_std_dev+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500886
887 port_down_device_to_ofp_min = min(port_down_device_to_ofp_list)
888 port_down_device_to_ofp_max = max(port_down_device_to_ofp_list)
889 port_down_device_to_ofp_avg = \
890 (sum(port_down_device_to_ofp_list) /\
891 len(port_down_device_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500892 port_down_device_to_ofp_std_dev = \
893 str(round(numpy.std(port_down_device_to_ofp_list),1))
andrewonlababb11c32014-11-04 15:03:24 -0500894
andrewonlab4f50ec92014-11-11 14:24:45 -0500895 main.log.report("Port down device-to-ofp "+
896 "Avg: "+str(port_down_device_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500897 "Std Deviation: "+port_down_device_to_ofp_std_dev+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500898
899 port_up_graph_to_ofp_min = min(port_up_graph_to_ofp_list)
900 port_up_graph_to_ofp_max = max(port_up_graph_to_ofp_list)
901 port_up_graph_to_ofp_avg = \
902 (sum(port_up_graph_to_ofp_list) /\
903 len(port_up_graph_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500904 port_up_graph_to_ofp_std_dev = \
905 str(round(numpy.std(port_up_graph_to_ofp_list),1))
andrewonlab8790abb2014-11-06 13:51:54 -0500906
andrewonlab4f50ec92014-11-11 14:24:45 -0500907 main.log.report("Port up graph-to-ofp "+
908 "Avg: "+str(port_up_graph_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500909 "Std Deviation: "+port_up_graph_to_ofp_std_dev+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500910
911 port_up_device_to_ofp_min = min(port_up_device_to_ofp_list)
912 port_up_device_to_ofp_max = max(port_up_device_to_ofp_list)
913 port_up_device_to_ofp_avg = \
914 (sum(port_up_device_to_ofp_list) /\
915 len(port_up_device_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500916 port_up_device_to_ofp_std_dev = \
917 str(round(numpy.std(port_up_device_to_ofp_list),1))
andrewonlab8790abb2014-11-06 13:51:54 -0500918
andrewonlab4f50ec92014-11-11 14:24:45 -0500919 main.log.report("Port up device-to-ofp "+
920 "Avg: "+str(port_up_device_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500921 "Std Deviation: "+port_up_device_to_ofp_std_dev+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500922
923 utilities.assert_equals(expect=main.TRUE, actual=assertion,
924 onpass="Port discovery latency calculation successful",
925 onfail="Port discovery test failed")
andrewonlababb11c32014-11-04 15:03:24 -0500926
andrewonlab3622beb2014-10-28 16:07:56 -0400927 def CASE4(self, main):
928 '''
929 Link down event using loss rate 100%
andrewonlab53b641c2014-10-31 19:44:44 -0400930
931 Important:
932 Use a simple 2 switch topology with 1 link between
933 the two switches. Ensure that mac addresses of the
934 switches are 1 / 2 respectively
andrewonlab3622beb2014-10-28 16:07:56 -0400935 '''
936 import time
937 import subprocess
938 import os
939 import requests
940 import json
andrewonlab4f50ec92014-11-11 14:24:45 -0500941 import numpy
942
andrewonlab3622beb2014-10-28 16:07:56 -0400943 ONOS1_ip = main.params['CTRL']['ip1']
944 ONOS2_ip = main.params['CTRL']['ip2']
945 ONOS3_ip = main.params['CTRL']['ip3']
946 ONOS_user = main.params['CTRL']['user']
947
948 default_sw_port = main.params['CTRL']['port1']
949
950 #Number of iterations of case
951 num_iter = main.params['TEST']['numIter']
952
953 #Timestamp 'keys' for json metrics output.
954 #These are subject to change, hence moved into params
955 deviceTimestamp = main.params['JSON']['deviceTimestamp']
956 linkTimestamp = main.params['JSON']['linkTimestamp']
andrewonlab53b641c2014-10-31 19:44:44 -0400957 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500958
959 debug_mode = main.params['TEST']['debugMode']
960
961 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500962 local_time = local_time.replace("/","")
963 local_time = local_time.replace(" ","_")
964 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500965 if debug_mode == 'on':
966 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500967 "/tmp/link_lat_pcap_"+local_time)
andrewonlab53b641c2014-10-31 19:44:44 -0400968
andrewonlabe5bcef92014-11-06 17:53:20 -0500969 #Threshold for this test case
970 up_threshold_str = main.params['TEST']['linkUpThreshold']
971 down_threshold_str = main.params['TEST']['linkDownThreshold']
972
973 up_threshold_obj = up_threshold_str.split(",")
974 down_threshold_obj = down_threshold_str.split(",")
975
976 up_threshold_min = int(up_threshold_obj[0])
977 up_threshold_max = int(up_threshold_obj[1])
978
979 down_threshold_min = int(down_threshold_obj[0])
980 down_threshold_max = int(down_threshold_obj[1])
981
andrewonlab3622beb2014-10-28 16:07:56 -0400982 assertion = main.TRUE
983 #Link event timestamp to system time list
984 link_down_link_to_system_list = []
985 link_up_link_to_system_list = []
986 #Graph event timestamp to system time list
987 link_down_graph_to_system_list = []
988 link_up_graph_to_system_list = []
989
andrewonlab4b5c8b92014-11-10 16:04:33 -0500990 main.log.report("Link up / down discovery latency between "+
andrewonlab3622beb2014-10-28 16:07:56 -0400991 "two switches")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500992 main.log.report("Simulated by setting loss-rate 100%")
993 main.log.report("'tc qdisc add dev <intfs> root netem loss 100%'")
994 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab3622beb2014-10-28 16:07:56 -0400995
996 main.step("Assign all switches")
997 main.Mininet1.assign_sw_controller(sw="1",
998 ip1=ONOS1_ip, port1=default_sw_port)
999 main.Mininet1.assign_sw_controller(sw="2",
1000 ip1=ONOS1_ip, port1=default_sw_port)
1001
1002 main.step("Verifying switch assignment")
1003 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
1004 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
andrewonlab3622beb2014-10-28 16:07:56 -04001005
1006 #Allow time for events to finish before taking measurements
1007 time.sleep(10)
1008
andrewonlababb11c32014-11-04 15:03:24 -05001009 link_down1 = False
1010 link_down2 = False
1011 link_down3 = False
andrewonlab3622beb2014-10-28 16:07:56 -04001012 #Start iteration of link event test
1013 for i in range(0, int(num_iter)):
1014 main.step("Getting initial system time as t0")
andrewonlab8d29f122014-10-22 17:15:04 -04001015
andrewonlab3622beb2014-10-28 16:07:56 -04001016 timestamp_link_down_t0 = time.time() * 1000
1017 #Link down is simulated by 100% loss rate using traffic
1018 #control command
1019 main.Mininet1.handle.sendline(
1020 "sh tc qdisc add dev s1-eth1 root netem loss 100%")
1021
andrewonlab53b641c2014-10-31 19:44:44 -04001022 #TODO: Iterate through 'links' command to verify that
andrewonlababb11c32014-11-04 15:03:24 -05001023 # link s1 -> s2 went down (loop timeout 30 seconds)
1024 # on all 3 ONOS instances
andrewonlab53b641c2014-10-31 19:44:44 -04001025 main.log.info("Checking ONOS for link update")
1026 loop_count = 0
andrewonlababb11c32014-11-04 15:03:24 -05001027 while( not (link_down1 and link_down2 and link_down3)\
1028 and loop_count < 30 ):
1029 json_str1 = main.ONOS1cli.links()
1030 json_str2 = main.ONOS2cli.links()
1031 json_str3 = main.ONOS3cli.links()
1032
1033 if not (json_str1 and json_str2 and json_str3):
1034 main.log.error("CLI command returned error ")
andrewonlab53b641c2014-10-31 19:44:44 -04001035 break
1036 else:
andrewonlababb11c32014-11-04 15:03:24 -05001037 json_obj1 = json.loads(json_str1)
1038 json_obj2 = json.loads(json_str2)
1039 json_obj3 = json.loads(json_str3)
1040 for obj1 in json_obj1:
1041 if '01' not in obj1['src']['device']:
1042 link_down1 = True
andrewonlabf9828f02014-11-10 14:50:27 -05001043 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001044 "s1 -> s2 on ONOS1 detected")
1045 for obj2 in json_obj2:
1046 if '01' not in obj2['src']['device']:
1047 link_down2 = True
andrewonlabf9828f02014-11-10 14:50:27 -05001048 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001049 "s1 -> s2 on ONOS2 detected")
1050 for obj3 in json_obj3:
1051 if '01' not in obj3['src']['device']:
1052 link_down3 = True
andrewonlabf9828f02014-11-10 14:50:27 -05001053 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001054 "s1 -> s2 on ONOS3 detected")
1055
andrewonlab53b641c2014-10-31 19:44:44 -04001056 loop_count += 1
andrewonlababb11c32014-11-04 15:03:24 -05001057 #If CLI doesn't like the continuous requests
1058 #and exits in this loop, increase the sleep here.
1059 #Consequently, while loop timeout will increase
andrewonlab53b641c2014-10-31 19:44:44 -04001060 time.sleep(1)
1061
1062 #Give time for metrics measurement to catch up
andrewonlababb11c32014-11-04 15:03:24 -05001063 #NOTE: May need to be configured more accurately
andrewonlab53b641c2014-10-31 19:44:44 -04001064 time.sleep(10)
andrewonlababb11c32014-11-04 15:03:24 -05001065 #If we exited the while loop and link down 1,2,3 are still
andrewonlab53b641c2014-10-31 19:44:44 -04001066 #false, then ONOS has failed to discover link down event
andrewonlababb11c32014-11-04 15:03:24 -05001067 if not (link_down1 and link_down2 and link_down3):
andrewonlab53b641c2014-10-31 19:44:44 -04001068 main.log.info("Link down discovery failed")
1069
1070 link_down_lat_graph1 = 0
1071 link_down_lat_graph2 = 0
1072 link_down_lat_graph3 = 0
1073 link_down_lat_device1 = 0
1074 link_down_lat_device2 = 0
1075 link_down_lat_device3 = 0
1076
1077 assertion = main.FALSE
1078 else:
1079 json_topo_metrics_1 =\
1080 main.ONOS1cli.topology_events_metrics()
1081 json_topo_metrics_2 =\
1082 main.ONOS2cli.topology_events_metrics()
1083 json_topo_metrics_3 =\
1084 main.ONOS3cli.topology_events_metrics()
1085 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1086 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1087 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1088
1089 main.log.info("Obtaining graph and device timestamp")
1090 graph_timestamp_1 = \
1091 json_topo_metrics_1[graphTimestamp]['value']
1092 graph_timestamp_2 = \
1093 json_topo_metrics_2[graphTimestamp]['value']
1094 graph_timestamp_3 = \
1095 json_topo_metrics_3[graphTimestamp]['value']
1096
1097 link_timestamp_1 = \
1098 json_topo_metrics_1[linkTimestamp]['value']
1099 link_timestamp_2 = \
1100 json_topo_metrics_2[linkTimestamp]['value']
1101 link_timestamp_3 = \
1102 json_topo_metrics_3[linkTimestamp]['value']
1103
1104 if graph_timestamp_1 and graph_timestamp_2 and\
1105 graph_timestamp_3 and link_timestamp_1 and\
1106 link_timestamp_2 and link_timestamp_3:
1107 link_down_lat_graph1 = int(graph_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001108 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001109 link_down_lat_graph2 = int(graph_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001110 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001111 link_down_lat_graph3 = int(graph_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001112 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001113
1114 link_down_lat_link1 = int(link_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001115 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001116 link_down_lat_link2 = int(link_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001117 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001118 link_down_lat_link3 = int(link_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001119 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001120 else:
1121 main.log.error("There was an error calculating"+
1122 " the delta for link down event")
1123 link_down_lat_graph1 = 0
1124 link_down_lat_graph2 = 0
1125 link_down_lat_graph3 = 0
1126
1127 link_down_lat_device1 = 0
1128 link_down_lat_device2 = 0
1129 link_down_lat_device3 = 0
1130
andrewonlabf9828f02014-11-10 14:50:27 -05001131 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001132 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001133 str(link_down_lat_graph1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001134 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001135 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001136 str(link_down_lat_graph2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001137 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001138 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001139 str(link_down_lat_graph3)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001140
andrewonlabf9828f02014-11-10 14:50:27 -05001141 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001142 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001143 str(link_down_lat_link1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001144 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001145 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001146 str(link_down_lat_link2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001147 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001148 str(i)+" (link-event-to-system-timestamp): "+
1149 str(link_down_lat_link3))
1150
1151 #Calculate avg of node calculations
1152 link_down_lat_graph_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001153 (link_down_lat_graph1 +
1154 link_down_lat_graph2 +
andrewonlab65d73892014-11-10 17:36:00 -05001155 link_down_lat_graph3) / 3
andrewonlab4e124482014-11-04 13:37:25 -05001156 link_down_lat_link_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001157 (link_down_lat_link1 +
1158 link_down_lat_link2 +
andrewonlab65d73892014-11-10 17:36:00 -05001159 link_down_lat_link3) / 3
andrewonlab53b641c2014-10-31 19:44:44 -04001160
andrewonlab4e124482014-11-04 13:37:25 -05001161 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001162 if link_down_lat_graph_avg > down_threshold_min and\
1163 link_down_lat_graph_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001164 link_down_graph_to_system_list.append(
1165 link_down_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001166 else:
1167 main.log.info("Link down latency exceeded threshold")
1168 main.log.info("Results for iteration "+str(i)+
1169 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001170 if link_down_lat_link_avg > down_threshold_min and\
1171 link_down_lat_link_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001172 link_down_link_to_system_list.append(
1173 link_down_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001174 else:
1175 main.log.info("Link down latency exceeded threshold")
1176 main.log.info("Results for iteration "+str(i)+
1177 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001178
1179 #NOTE: To remove loss rate and measure latency:
1180 # 'sh tc qdisc del dev s1-eth1 root'
andrewonlababb11c32014-11-04 15:03:24 -05001181 timestamp_link_up_t0 = time.time() * 1000
andrewonlab53b641c2014-10-31 19:44:44 -04001182 main.Mininet1.handle.sendline("sh tc qdisc del dev "+
1183 "s1-eth1 root")
1184 main.Mininet1.handle.expect("mininet>")
andrewonlababb11c32014-11-04 15:03:24 -05001185
1186 main.log.info("Checking ONOS for link update")
1187
1188 link_down1 = True
1189 link_down2 = True
1190 link_down3 = True
1191 loop_count = 0
1192 while( (link_down1 and link_down2 and link_down3)\
1193 and loop_count < 30 ):
1194 json_str1 = main.ONOS1cli.links()
1195 json_str2 = main.ONOS2cli.links()
1196 json_str3 = main.ONOS3cli.links()
1197 if not (json_str1 and json_str2 and json_str3):
1198 main.log.error("CLI command returned error ")
1199 break
1200 else:
1201 json_obj1 = json.loads(json_str1)
1202 json_obj2 = json.loads(json_str2)
1203 json_obj3 = json.loads(json_str3)
1204
1205 for obj1 in json_obj1:
1206 if '01' in obj1['src']['device']:
1207 link_down1 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001208 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001209 "s1 -> s2 on ONOS1 detected")
1210 for obj2 in json_obj2:
1211 if '01' in obj2['src']['device']:
1212 link_down2 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001213 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001214 "s1 -> s2 on ONOS2 detected")
1215 for obj3 in json_obj3:
1216 if '01' in obj3['src']['device']:
1217 link_down3 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001218 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001219 "s1 -> s2 on ONOS3 detected")
1220
1221 loop_count += 1
1222 time.sleep(1)
1223
1224 if (link_down1 and link_down2 and link_down3):
1225 main.log.info("Link up discovery failed")
1226
1227 link_up_lat_graph1 = 0
1228 link_up_lat_graph2 = 0
1229 link_up_lat_graph3 = 0
1230 link_up_lat_device1 = 0
1231 link_up_lat_device2 = 0
1232 link_up_lat_device3 = 0
1233
1234 assertion = main.FALSE
1235 else:
1236 json_topo_metrics_1 =\
1237 main.ONOS1cli.topology_events_metrics()
1238 json_topo_metrics_2 =\
1239 main.ONOS2cli.topology_events_metrics()
1240 json_topo_metrics_3 =\
1241 main.ONOS3cli.topology_events_metrics()
1242 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1243 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1244 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1245
1246 main.log.info("Obtaining graph and device timestamp")
1247 graph_timestamp_1 = \
1248 json_topo_metrics_1[graphTimestamp]['value']
1249 graph_timestamp_2 = \
1250 json_topo_metrics_2[graphTimestamp]['value']
1251 graph_timestamp_3 = \
1252 json_topo_metrics_3[graphTimestamp]['value']
1253
1254 link_timestamp_1 = \
1255 json_topo_metrics_1[linkTimestamp]['value']
1256 link_timestamp_2 = \
1257 json_topo_metrics_2[linkTimestamp]['value']
1258 link_timestamp_3 = \
1259 json_topo_metrics_3[linkTimestamp]['value']
1260
1261 if graph_timestamp_1 and graph_timestamp_2 and\
1262 graph_timestamp_3 and link_timestamp_1 and\
1263 link_timestamp_2 and link_timestamp_3:
1264 link_up_lat_graph1 = int(graph_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001265 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001266 link_up_lat_graph2 = int(graph_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001267 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001268 link_up_lat_graph3 = int(graph_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001269 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001270
1271 link_up_lat_link1 = int(link_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001272 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001273 link_up_lat_link2 = int(link_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001274 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001275 link_up_lat_link3 = int(link_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001276 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001277 else:
1278 main.log.error("There was an error calculating"+
1279 " the delta for link down event")
1280 link_up_lat_graph1 = 0
1281 link_up_lat_graph2 = 0
1282 link_up_lat_graph3 = 0
1283
1284 link_up_lat_device1 = 0
1285 link_up_lat_device2 = 0
1286 link_up_lat_device3 = 0
andrewonlab58f7d702014-11-07 13:21:19 -05001287
1288 if debug_mode == 'on':
1289 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001290 str(i)+" (end-to-end): "+
1291 str(link_up_lat_graph1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001292 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001293 str(i)+" (end-to-end): "+
1294 str(link_up_lat_graph2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001295 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001296 str(i)+" (end-to-end): "+
1297 str(link_up_lat_graph3)+" ms")
1298
andrewonlab58f7d702014-11-07 13:21:19 -05001299 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001300 str(i)+" (link-event-to-system-timestamp): "+
1301 str(link_up_lat_link1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001302 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001303 str(i)+" (link-event-to-system-timestamp): "+
1304 str(link_up_lat_link2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001305 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001306 str(i)+" (link-event-to-system-timestamp): "+
1307 str(link_up_lat_link3))
1308
1309 #Calculate avg of node calculations
1310 link_up_lat_graph_avg =\
1311 (link_up_lat_graph1 +
1312 link_up_lat_graph2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001313 link_up_lat_graph3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001314 link_up_lat_link_avg =\
1315 (link_up_lat_link1 +
1316 link_up_lat_link2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001317 link_up_lat_link3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001318
1319 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001320 if link_up_lat_graph_avg > up_threshold_min and\
1321 link_up_lat_graph_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001322 link_up_graph_to_system_list.append(
1323 link_up_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001324 else:
1325 main.log.info("Link up latency exceeded threshold")
1326 main.log.info("Results for iteration "+str(i)+
1327 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001328 if link_up_lat_link_avg > up_threshold_min and\
1329 link_up_lat_link_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001330 link_up_link_to_system_list.append(
1331 link_up_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001332 else:
1333 main.log.info("Link up latency exceeded threshold")
1334 main.log.info("Results for iteration "+str(i)+
1335 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001336
andrewonlab4e124482014-11-04 13:37:25 -05001337 #Calculate min, max, avg of list and report
1338 link_down_min = min(link_down_graph_to_system_list)
1339 link_down_max = max(link_down_graph_to_system_list)
1340 link_down_avg = sum(link_down_graph_to_system_list) / \
1341 len(link_down_graph_to_system_list)
andrewonlababb11c32014-11-04 15:03:24 -05001342 link_up_min = min(link_up_graph_to_system_list)
1343 link_up_max = max(link_up_graph_to_system_list)
1344 link_up_avg = sum(link_up_graph_to_system_list) / \
1345 len(link_up_graph_to_system_list)
andrewonlab69864162014-11-11 16:28:48 -05001346 link_down_std_dev = \
1347 str(round(numpy.std(link_down_graph_to_system_list),1))
1348 link_up_std_dev = \
1349 str(round(numpy.std(link_up_graph_to_system_list),1))
andrewonlababb11c32014-11-04 15:03:24 -05001350
andrewonlab4f50ec92014-11-11 14:24:45 -05001351 main.log.report("Link down latency " +
1352 "Avg: "+str(link_down_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -05001353 "Std Deviation: "+link_down_std_dev+" ms")
andrewonlab4f50ec92014-11-11 14:24:45 -05001354 main.log.report("Link up latency "+
1355 "Avg: "+str(link_up_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -05001356 "Std Deviation: "+link_up_std_dev+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001357
andrewonlab8790abb2014-11-06 13:51:54 -05001358 utilities.assert_equals(expect=main.TRUE, actual=assertion,
1359 onpass="Link discovery latency calculation successful",
1360 onfail="Link discovery latency case failed")
1361
andrewonlabb54b85b2014-10-28 18:43:57 -04001362 def CASE5(self, main):
1363 '''
1364 100 Switch discovery latency
1365
1366 Important:
andrewonlab16ce4852014-10-30 13:41:09 -04001367 This test case can be potentially dangerous if
1368 your machine has previously set iptables rules.
1369 One of the steps of the test case will flush
1370 all existing iptables rules.
andrewonlab8790abb2014-11-06 13:51:54 -05001371 Note:
1372 You can specify the number of switches in the
1373 params file to adjust the switch discovery size
1374 (and specify the corresponding topology in Mininet1
1375 .topo file)
andrewonlabb54b85b2014-10-28 18:43:57 -04001376 '''
1377 import time
1378 import subprocess
1379 import os
1380 import requests
1381 import json
1382
1383 ONOS1_ip = main.params['CTRL']['ip1']
1384 ONOS2_ip = main.params['CTRL']['ip2']
1385 ONOS3_ip = main.params['CTRL']['ip3']
1386 MN1_ip = main.params['MN']['ip1']
1387 ONOS_user = main.params['CTRL']['user']
1388
1389 default_sw_port = main.params['CTRL']['port1']
1390
1391 #Number of iterations of case
1392 num_iter = main.params['TEST']['numIter']
andrewonlab16ce4852014-10-30 13:41:09 -04001393 num_sw = main.params['TEST']['numSwitch']
1394
andrewonlabb54b85b2014-10-28 18:43:57 -04001395 #Timestamp 'keys' for json metrics output.
1396 #These are subject to change, hence moved into params
1397 deviceTimestamp = main.params['JSON']['deviceTimestamp']
andrewonlab16ce4852014-10-30 13:41:09 -04001398 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -05001399
1400 debug_mode = main.params['TEST']['debugMode']
1401
andrewonlabb1998c52014-11-10 13:31:43 -05001402 local_time = time.strftime('%X')
1403 local_time = local_time.replace("/","")
1404 local_time = local_time.replace(" ","_")
1405 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -05001406 if debug_mode == 'on':
1407 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -05001408 "/tmp/100_sw_lat_pcap_"+local_time)
andrewonlabe5bcef92014-11-06 17:53:20 -05001409
1410 #Threshold for this test case
1411 sw_disc_threshold_str = main.params['TEST']['swDisc100Threshold']
1412 sw_disc_threshold_obj = sw_disc_threshold_str.split(",")
1413 sw_disc_threshold_min = int(sw_disc_threshold_obj[0])
1414 sw_disc_threshold_max = int(sw_disc_threshold_obj[1])
1415
andrewonlab53b641c2014-10-31 19:44:44 -04001416 tshark_ofp_output = "/tmp/tshark_ofp_"+num_sw+"sw.txt"
1417 tshark_tcp_output = "/tmp/tshark_tcp_"+num_sw+"sw.txt"
1418
1419 tshark_ofp_result_list = []
1420 tshark_tcp_result_list = []
andrewonlabb54b85b2014-10-28 18:43:57 -04001421
andrewonlabe5bcef92014-11-06 17:53:20 -05001422 sw_discovery_lat_list = []
1423
andrewonlab16ce4852014-10-30 13:41:09 -04001424 main.case(num_sw+" Switch discovery latency")
andrewonlabb54b85b2014-10-28 18:43:57 -04001425 main.step("Assigning all switches to ONOS1")
andrewonlab16ce4852014-10-30 13:41:09 -04001426 for i in range(1, int(num_sw)+1):
andrewonlabb54b85b2014-10-28 18:43:57 -04001427 main.Mininet1.assign_sw_controller(
1428 sw=str(i),
1429 ip1=ONOS1_ip,
1430 port1=default_sw_port)
andrewonlab16ce4852014-10-30 13:41:09 -04001431
andrewonlabb54b85b2014-10-28 18:43:57 -04001432 #Ensure that nodes are configured with ptpd
andrewonlab16ce4852014-10-30 13:41:09 -04001433 #Just a warning message
1434 main.log.info("Please check ptpd configuration to ensure"+\
1435 " All nodes' system times are in sync")
1436 time.sleep(5)
andrewonlabb54b85b2014-10-28 18:43:57 -04001437
1438 for i in range(0, int(num_iter)):
andrewonlab8d29f122014-10-22 17:15:04 -04001439
andrewonlabb54b85b2014-10-28 18:43:57 -04001440 main.step("Set iptables rule to block incoming sw connections")
1441 #Set iptables rule to block incoming switch connections
andrewonlab53b641c2014-10-31 19:44:44 -04001442 #The rule description is as follows:
1443 # Append to INPUT rule,
1444 # behavior DROP that matches following:
1445 # * packet type: tcp
1446 # * source IP: MN1_ip
1447 # * destination PORT: 6633
andrewonlabb54b85b2014-10-28 18:43:57 -04001448 main.ONOS1.handle.sendline(
andrewonlab16ce4852014-10-30 13:41:09 -04001449 "sudo iptables -A INPUT -p tcp -s "+MN1_ip+
andrewonlabb54b85b2014-10-28 18:43:57 -04001450 " --dport "+default_sw_port+" -j DROP")
1451 main.ONOS1.handle.expect("\$")
andrewonlab53b641c2014-10-31 19:44:44 -04001452 # Append to OUTPUT rule,
1453 # behavior DROP that matches following:
1454 # * packet type: tcp
1455 # * source IP: MN1_ip
1456 # * destination PORT: 6633
1457 main.ONOS1.handle.sendline(
1458 "sudo iptables -A OUTPUT -p tcp -s "+MN1_ip+
1459 " --dport "+default_sw_port+" -j DROP")
1460 main.ONOS1.handle.expect("\$")
andrewonlabb54b85b2014-10-28 18:43:57 -04001461 #Give time to allow rule to take effect
andrewonlab8790abb2014-11-06 13:51:54 -05001462 #NOTE: Sleep period may need to be configured
1463 # based on the number of switches in the topology
andrewonlab16ce4852014-10-30 13:41:09 -04001464 main.log.info("Please wait for switch connection to "+
1465 "time out")
1466 time.sleep(60)
1467
1468 #Gather vendor OFP with tshark
1469 main.ONOS1.tshark_grep("OFP 86 Vendor",
1470 tshark_ofp_output)
andrewonlab53b641c2014-10-31 19:44:44 -04001471 main.ONOS1.tshark_grep("TCP 74 ",
1472 tshark_tcp_output)
andrewonlabb54b85b2014-10-28 18:43:57 -04001473
andrewonlab16ce4852014-10-30 13:41:09 -04001474 #NOTE: Remove all iptables rule quickly (flush)
andrewonlabb54b85b2014-10-28 18:43:57 -04001475 # Before removal, obtain TestON timestamp at which
andrewonlab16ce4852014-10-30 13:41:09 -04001476 # removal took place
1477 # (ensuring nodes are configured via ptp)
andrewonlabb54b85b2014-10-28 18:43:57 -04001478 # sudo iptables -F
andrewonlab16ce4852014-10-30 13:41:09 -04001479
1480 t0_system = time.time() * 1000
1481 main.ONOS1.handle.sendline(
1482 "sudo iptables -F")
andrewonlabb54b85b2014-10-28 18:43:57 -04001483
andrewonlab16ce4852014-10-30 13:41:09 -04001484 #Counter to track loop count
1485 counter_loop = 0
1486 counter_avail1 = 0
1487 counter_avail2 = 0
1488 counter_avail3 = 0
1489 onos1_dev = False
1490 onos2_dev = False
1491 onos3_dev = False
1492 while counter_loop < 60:
1493 #Continue to check devices for all device
1494 #availability. When all devices in all 3
1495 #ONOS instances indicate that devices are available
1496 #obtain graph event timestamp for t1.
1497 device_str_obj1 = main.ONOS1cli.devices()
1498 device_str_obj2 = main.ONOS2cli.devices()
1499 device_str_obj3 = main.ONOS3cli.devices()
1500
1501 device_json1 = json.loads(device_str_obj1)
1502 device_json2 = json.loads(device_str_obj2)
1503 device_json3 = json.loads(device_str_obj3)
1504
1505 for device1 in device_json1:
1506 if device1['available'] == True:
1507 counter_avail1 += 1
1508 if counter_avail1 == int(num_sw):
1509 onos1_dev = True
1510 main.log.info("All devices have been "+
1511 "discovered on ONOS1")
1512 else:
1513 counter_avail1 = 0
1514 for device2 in device_json2:
1515 if device2['available'] == True:
1516 counter_avail2 += 1
1517 if counter_avail2 == int(num_sw):
1518 onos2_dev = True
1519 main.log.info("All devices have been "+
1520 "discovered on ONOS2")
1521 else:
1522 counter_avail2 = 0
1523 for device3 in device_json3:
1524 if device3['available'] == True:
1525 counter_avail3 += 1
1526 if counter_avail3 == int(num_sw):
1527 onos3_dev = True
1528 main.log.info("All devices have been "+
1529 "discovered on ONOS3")
1530 else:
1531 counter_avail3 = 0
1532
1533 if onos1_dev and onos2_dev and onos3_dev:
1534 main.log.info("All devices have been discovered "+
1535 "on all ONOS instances")
1536 json_str_topology_metrics_1 =\
1537 main.ONOS1cli.topology_events_metrics()
1538 json_str_topology_metrics_2 =\
1539 main.ONOS2cli.topology_events_metrics()
1540 json_str_topology_metrics_3 =\
1541 main.ONOS3cli.topology_events_metrics()
andrewonlab53b641c2014-10-31 19:44:44 -04001542
1543 #Exit while loop if all devices discovered
andrewonlab16ce4852014-10-30 13:41:09 -04001544 break
1545
1546 counter_loop += 1
1547 #Give some time in between CLI calls
1548 #(will not affect measurement)
1549 time.sleep(3)
1550
1551 main.ONOS1.tshark_stop()
1552
1553 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1554 tshark_ofp_output+" /tmp/")
andrewonlab53b641c2014-10-31 19:44:44 -04001555 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1556 tshark_tcp_output+" /tmp/")
andrewonlab16ce4852014-10-30 13:41:09 -04001557
andrewonlab16ce4852014-10-30 13:41:09 -04001558 #TODO: Automate OFP output analysis
andrewonlab58f7d702014-11-07 13:21:19 -05001559 #Debug mode - print out packets captured at runtime
1560 if debug_mode == 'on':
1561 ofp_file = open(tshark_ofp_output, 'r')
1562 main.log.info("Tshark OFP Vendor output: ")
1563 for line in ofp_file:
1564 tshark_ofp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001565 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001566 ofp_file.close()
andrewonlab16ce4852014-10-30 13:41:09 -04001567
andrewonlab58f7d702014-11-07 13:21:19 -05001568 tcp_file = open(tshark_tcp_output, 'r')
1569 main.log.info("Tshark TCP 74 output: ")
1570 for line in tcp_file:
1571 tshark_tcp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001572 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001573 tcp_file.close()
andrewonlab53b641c2014-10-31 19:44:44 -04001574
andrewonlab16ce4852014-10-30 13:41:09 -04001575 json_obj_1 = json.loads(json_str_topology_metrics_1)
1576 json_obj_2 = json.loads(json_str_topology_metrics_2)
1577 json_obj_3 = json.loads(json_str_topology_metrics_3)
1578
1579 graph_timestamp_1 = \
1580 json_obj_1[graphTimestamp]['value']
1581 graph_timestamp_2 = \
1582 json_obj_2[graphTimestamp]['value']
1583 graph_timestamp_3 = \
1584 json_obj_3[graphTimestamp]['value']
1585
andrewonlabe5bcef92014-11-06 17:53:20 -05001586 graph_lat_1 = int(graph_timestamp_1) - int(t0_system)
1587 graph_lat_2 = int(graph_timestamp_2) - int(t0_system)
1588 graph_lat_3 = int(graph_timestamp_3) - int(t0_system)
andrewonlab16ce4852014-10-30 13:41:09 -04001589
andrewonlabe5bcef92014-11-06 17:53:20 -05001590 avg_graph_lat = \
1591 (int(graph_lat_1) +\
1592 int(graph_lat_2) +\
1593 int(graph_lat_3)) / 3
1594
1595 if avg_graph_lat > sw_disc_threshold_min \
1596 and avg_graph_lat < sw_disc_threshold_max:
1597 sw_discovery_lat_list.append(
1598 avg_graph_lat)
1599 else:
1600 main.log.info("100 Switch discovery latency "+
1601 "exceeded the threshold.")
1602
1603 #END ITERATION FOR LOOP
andrewonlab16ce4852014-10-30 13:41:09 -04001604
andrewonlabe5bcef92014-11-06 17:53:20 -05001605 sw_lat_min = min(sw_discovery_lat_list)
1606 sw_lat_max = max(sw_discovery_lat_list)
1607 sw_lat_avg = sum(sw_discovery_lat_list) /\
1608 len(sw_discovery_lat_list)
andrewonlab16ce4852014-10-30 13:41:09 -04001609
andrewonlabf9828f02014-11-10 14:50:27 -05001610 main.log.report("100 Switch discovery lat "+\
1611 "Min: "+str(sw_lat_min)+" ms"+\
1612 "Max: "+str(sw_lat_max)+" ms"+\
1613 "Avg: "+str(sw_lat_avg)+" ms")
andrewonlab16ce4852014-10-30 13:41:09 -04001614
andrewonlabb54b85b2014-10-28 18:43:57 -04001615