blob: 49089bf7cfeef8ac65e1cfc2657f86b6ba2ff53b [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"+\
50 " to ONOS /ppackage/etc")
51 main.ONOSbench.handle.sendline("cp ~/"+\
52 topo_cfg_file+\
53 "~/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(
andrewonlabe6745342014-10-17 14:29:13 -040067 BENCH_ip, cell_name, MN1_ip, "onos-core",
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()
78
andrewonlab2a6c9342014-10-16 13:40:15 -040079 main.step("Git checkout and pull "+checkout_branch)
80 if git_pull == 'on':
81 checkout_result = \
82 main.ONOSbench.git_checkout(checkout_branch)
83 pull_result = main.ONOSbench.git_pull()
84 else:
85 checkout_result = main.TRUE
86 pull_result = main.TRUE
87 main.log.info("Skipped git checkout and pull")
88
andrewonlab92844342014-11-18 16:39:11 -050089 #TODO: Uncomment when wiki posting works
90 #main.log.report("Commit information - ")
91 #main.ONOSbench.get_version(report=True)
92
andrewonlab2a6c9342014-10-16 13:40:15 -040093 main.step("Using mvn clean & install")
andrewonlab8d29f122014-10-22 17:15:04 -040094 #mvn_result = main.ONOSbench.clean_install()
95 mvn_result = main.TRUE
andrewonlab2a6c9342014-10-16 13:40:15 -040096
andrewonlabb1998c52014-11-10 13:31:43 -050097 main.step("Set cell for ONOS cli env")
98 main.ONOS1cli.set_cell(cell_name)
99 main.ONOS2cli.set_cell(cell_name)
100 main.ONOS3cli.set_cell(cell_name)
101
andrewonlab2a6c9342014-10-16 13:40:15 -0400102 main.step("Creating ONOS package")
103 package_result = main.ONOSbench.onos_package()
104
105 main.step("Installing ONOS package")
andrewonlabe9fb6722014-10-24 12:20:35 -0400106 install1_result = main.ONOSbench.onos_install(node=ONOS1_ip)
107 install2_result = main.ONOSbench.onos_install(node=ONOS2_ip)
108 install3_result = main.ONOSbench.onos_install(node=ONOS3_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -0400109
andrewonlabe9fb6722014-10-24 12:20:35 -0400110 time.sleep(10)
111
andrewonlab867212a2014-10-22 20:13:38 -0400112 main.step("Start onos cli")
andrewonlabe9fb6722014-10-24 12:20:35 -0400113 cli1 = main.ONOS1cli.start_onos_cli(ONOS1_ip)
114 cli2 = main.ONOS2cli.start_onos_cli(ONOS2_ip)
115 cli3 = main.ONOS3cli.start_onos_cli(ONOS3_ip)
116
andrewonlab867212a2014-10-22 20:13:38 -0400117 main.step("Enable metrics feature")
andrewonlabb1998c52014-11-10 13:31:43 -0500118 main.ONOS1cli.feature_install("onos-app-metrics")
119 main.ONOS2cli.feature_install("onos-app-metrics")
120 main.ONOS3cli.feature_install("onos-app-metrics")
andrewonlab867212a2014-10-22 20:13:38 -0400121
andrewonlab2a6c9342014-10-16 13:40:15 -0400122 utilities.assert_equals(expect=main.TRUE,
123 actual= cell_file_result and cell_apply_result and\
124 verify_cell_result and checkout_result and\
125 pull_result and mvn_result and\
andrewonlabe9fb6722014-10-24 12:20:35 -0400126 install1_result and install2_result and\
127 install3_result,
andrewonlabf9828f02014-11-10 14:50:27 -0500128 onpass="Test Environment setup successful",
129 onfail="Failed to setup test environment")
andrewonlab2a6c9342014-10-16 13:40:15 -0400130
andrewonlabba44bcf2014-10-16 16:54:41 -0400131 def CASE2(self, main):
132 '''
133 Assign s1 to ONOS1 and measure latency
andrewonlab3a7c3c72014-10-24 17:21:03 -0400134
135 There are 4 levels of latency measurements to this test:
136 1) End-to-end measurement: Complete end-to-end measurement
137 from TCP (SYN/ACK) handshake to Graph change
138 2) OFP-to-graph measurement: 'ONOS processing' snippet of
139 measurement from OFP Vendor message to Graph change
140 3) OFP-to-device measurement: 'ONOS processing without
141 graph change' snippet of measurement from OFP vendor
142 message to Device change timestamp
143 4) T0-to-device measurement: Measurement that includes
144 the switch handshake to devices timestamp without
145 the graph view change. (TCP handshake -> Device
146 change)
andrewonlabba44bcf2014-10-16 16:54:41 -0400147 '''
148 import time
andrewonlabe6745342014-10-17 14:29:13 -0400149 import subprocess
150 import json
151 import requests
152 import os
andrewonlab4f50ec92014-11-11 14:24:45 -0500153 import numpy
andrewonlabba44bcf2014-10-16 16:54:41 -0400154
155 ONOS1_ip = main.params['CTRL']['ip1']
156 ONOS2_ip = main.params['CTRL']['ip2']
157 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlabe6745342014-10-17 14:29:13 -0400158 ONOS_user = main.params['CTRL']['user']
159
andrewonlabba44bcf2014-10-16 16:54:41 -0400160 default_sw_port = main.params['CTRL']['port1']
161
162 #Number of iterations of case
163 num_iter = main.params['TEST']['numIter']
andrewonlab4b5c8b92014-11-10 16:04:33 -0500164 #Number of first 'x' iterations to ignore:
165 iter_ignore = int(main.params['TEST']['iterIgnore'])
166
andrewonlab226024e2014-10-24 16:01:32 -0400167 #Timestamp 'keys' for json metrics output.
168 #These are subject to change, hence moved into params
169 deviceTimestamp = main.params['JSON']['deviceTimestamp']
170 graphTimestamp = main.params['JSON']['graphTimestamp']
171
andrewonlab58f7d702014-11-07 13:21:19 -0500172 debug_mode = main.params['TEST']['debugMode']
andrewonlabb1998c52014-11-10 13:31:43 -0500173 onos_log = main.params['TEST']['onosLogFile']
andrewonlab58f7d702014-11-07 13:21:19 -0500174
andrewonlabe5bcef92014-11-06 17:53:20 -0500175 #Threshold for the test
176 threshold_str = main.params['TEST']['singleSwThreshold']
177 threshold_obj = threshold_str.split(",")
178 threshold_min = int(threshold_obj[0])
179 threshold_max = int(threshold_obj[1])
180
andrewonlab226024e2014-10-24 16:01:32 -0400181 #List of switch add latency collected from
182 #all iterations
183 latency_end_to_end_list = []
184 latency_ofp_to_graph_list = []
185 latency_ofp_to_device_list = []
186 latency_t0_to_device_list = []
andrewonlab65d73892014-11-10 17:36:00 -0500187 latency_tcp_to_ofp_list = []
andrewonlab226024e2014-10-24 16:01:32 -0400188
andrewonlabba44bcf2014-10-16 16:54:41 -0400189 #Directory/file to store tshark results
190 tshark_of_output = "/tmp/tshark_of_topo.txt"
191 tshark_tcp_output = "/tmp/tshark_tcp_topo.txt"
192
193 #String to grep in tshark output
194 tshark_tcp_string = "TCP 74 "+default_sw_port
195 tshark_of_string = "OFP 86 Vendor"
andrewonlabe6745342014-10-17 14:29:13 -0400196
197 #Initialize assertion to TRUE
198 assertion = main.TRUE
andrewonlab58f7d702014-11-07 13:21:19 -0500199
200 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500201 local_time = local_time.replace("/","")
202 local_time = local_time.replace(" ","_")
203 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500204 if debug_mode == 'on':
205 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500206 "/tmp/single_sw_lat_pcap_"+local_time)
207
208 main.log.info("TEST")
andrewonlab58f7d702014-11-07 13:21:19 -0500209
andrewonlab4b5c8b92014-11-10 16:04:33 -0500210 main.log.report("Latency of adding one switch to controller")
211 main.log.report("First "+str(iter_ignore)+" iterations ignored"+
212 " for jvm warmup time")
213 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlabba44bcf2014-10-16 16:54:41 -0400214
215 for i in range(0, int(num_iter)):
216 main.log.info("Starting tshark capture")
217
218 #* TCP [ACK, SYN] is used as t0_a, the
219 # very first "exchange" between ONOS and
220 # the switch for end-to-end measurement
221 #* OFP [Stats Reply] is used for t0_b
222 # the very last OFP message between ONOS
223 # and the switch for ONOS measurement
224 main.ONOS1.tshark_grep(tshark_tcp_string,
225 tshark_tcp_output)
226 main.ONOS1.tshark_grep(tshark_of_string,
227 tshark_of_output)
228
229 #Wait and ensure tshark is started and
230 #capturing
231 time.sleep(10)
232
233 main.log.info("Assigning s1 to controller")
234
235 main.Mininet1.assign_sw_controller(sw="1",
236 ip1=ONOS1_ip, port1=default_sw_port)
237
238 #Wait and ensure switch is assigned
239 #before stopping tshark
andrewonlab867212a2014-10-22 20:13:38 -0400240 time.sleep(30)
andrewonlab226024e2014-10-24 16:01:32 -0400241
242 main.log.info("Stopping all Tshark processes")
andrewonlabba44bcf2014-10-16 16:54:41 -0400243 main.ONOS1.stop_tshark()
244
andrewonlabe6745342014-10-17 14:29:13 -0400245 #tshark output is saved in ONOS. Use subprocess
246 #to copy over files to TestON for parsing
247 main.log.info("Copying over tshark files")
248
249 #TCP CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400250 #Copy the tshark output from ONOS machine to
251 #TestON machine in tshark_tcp_output directory>file
252 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
253 tshark_tcp_output+" /tmp/")
254 tcp_file = open(tshark_tcp_output, 'r')
255 temp_text = tcp_file.readline()
andrewonlabe6745342014-10-17 14:29:13 -0400256 temp_text = temp_text.split(" ")
andrewonlabba44bcf2014-10-16 16:54:41 -0400257
andrewonlabe6745342014-10-17 14:29:13 -0400258 main.log.info("Object read in from TCP capture: "+
259 str(temp_text))
andrewonlab867212a2014-10-22 20:13:38 -0400260 if len(temp_text) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400261 t0_tcp = float(temp_text[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400262 else:
263 main.log.error("Tshark output file for TCP"+
264 " returned unexpected results")
265 t0_tcp = 0
266 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400267
268 tcp_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400269 #****************
andrewonlabba44bcf2014-10-16 16:54:41 -0400270
andrewonlabe6745342014-10-17 14:29:13 -0400271 #OF CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400272 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
273 tshark_of_output+" /tmp/")
274 of_file = open(tshark_of_output, 'r')
275
276 line_ofp = ""
andrewonlab226024e2014-10-24 16:01:32 -0400277 #Read until last line of file
andrewonlabe6745342014-10-17 14:29:13 -0400278 while True:
andrewonlab8d29f122014-10-22 17:15:04 -0400279 temp_text = of_file.readline()
280 if temp_text !='':
andrewonlabe6745342014-10-17 14:29:13 -0400281 line_ofp = temp_text
282 else:
283 break
284 obj = line_ofp.split(" ")
285
286 main.log.info("Object read in from OFP capture: "+
287 str(line_ofp))
288
andrewonlab867212a2014-10-22 20:13:38 -0400289 if len(line_ofp) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400290 t0_ofp = float(obj[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400291 else:
292 main.log.error("Tshark output file for OFP"+
293 " returned unexpected results")
294 t0_ofp = 0
295 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400296
297 of_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400298 #****************
299
andrewonlab867212a2014-10-22 20:13:38 -0400300 json_str_1 = main.ONOS1cli.topology_events_metrics()
301 json_str_2 = main.ONOS2cli.topology_events_metrics()
302 json_str_3 = main.ONOS3cli.topology_events_metrics()
andrewonlab867212a2014-10-22 20:13:38 -0400303
304 json_obj_1 = json.loads(json_str_1)
305 json_obj_2 = json.loads(json_str_2)
306 json_obj_3 = json.loads(json_str_3)
307
andrewonlab226024e2014-10-24 16:01:32 -0400308 #Obtain graph timestamp. This timestsamp captures
309 #the epoch time at which the topology graph was updated.
310 graph_timestamp_1 = \
311 json_obj_1[graphTimestamp]['value']
312 graph_timestamp_2 = \
313 json_obj_2[graphTimestamp]['value']
314 graph_timestamp_3 = \
315 json_obj_3[graphTimestamp]['value']
andrewonlab867212a2014-10-22 20:13:38 -0400316
andrewonlab226024e2014-10-24 16:01:32 -0400317 #Obtain device timestamp. This timestamp captures
318 #the epoch time at which the device event happened
319 device_timestamp_1 = \
320 json_obj_1[deviceTimestamp]['value']
321 device_timestamp_2 = \
322 json_obj_2[deviceTimestamp]['value']
323 device_timestamp_3 = \
324 json_obj_3[deviceTimestamp]['value']
andrewonlabe9fb6722014-10-24 12:20:35 -0400325
andrewonlab226024e2014-10-24 16:01:32 -0400326 #t0 to device processing latency
327 delta_device_1 = int(device_timestamp_1) - int(t0_tcp)
328 delta_device_2 = int(device_timestamp_2) - int(t0_tcp)
329 delta_device_3 = int(device_timestamp_3) - int(t0_tcp)
330
331 #Get average of delta from all instances
332 avg_delta_device = \
333 (int(delta_device_1)+\
334 int(delta_device_2)+\
335 int(delta_device_3)) / 3
andrewonlabba44bcf2014-10-16 16:54:41 -0400336
andrewonlab226024e2014-10-24 16:01:32 -0400337 #Ensure avg delta meets the threshold before appending
andrewonlab4b5c8b92014-11-10 16:04:33 -0500338 if avg_delta_device > 0.0 and avg_delta_device < 10000\
andrewonlab65d73892014-11-10 17:36:00 -0500339 and int(i) > iter_ignore:
andrewonlab226024e2014-10-24 16:01:32 -0400340 latency_t0_to_device_list.append(avg_delta_device)
andrewonlabee4efeb2014-10-24 16:44:51 -0400341 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400342 main.log.info("Results for t0-to-device ignored"+\
andrewonlab4b5c8b92014-11-10 16:04:33 -0500343 "due to excess in threshold / warmup iteration.")
andrewonlabee4efeb2014-10-24 16:44:51 -0400344
andrewonlab226024e2014-10-24 16:01:32 -0400345 #t0 to graph processing latency (end-to-end)
346 delta_graph_1 = int(graph_timestamp_1) - int(t0_tcp)
347 delta_graph_2 = int(graph_timestamp_2) - int(t0_tcp)
348 delta_graph_3 = int(graph_timestamp_3) - int(t0_tcp)
349
350 #Get average of delta from all instances
351 avg_delta_graph = \
352 (int(delta_graph_1)+\
353 int(delta_graph_2)+\
354 int(delta_graph_3)) / 3
355
andrewonlab226024e2014-10-24 16:01:32 -0400356 #Ensure avg delta meets the threshold before appending
andrewonlab4b5c8b92014-11-10 16:04:33 -0500357 if avg_delta_graph > 0.0 and avg_delta_graph < 10000\
andrewonlab65d73892014-11-10 17:36:00 -0500358 and int(i) > iter_ignore:
andrewonlab09d973e2014-10-24 18:56:58 -0400359 latency_end_to_end_list.append(avg_delta_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400360 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400361 main.log.info("Results for end-to-end ignored"+\
362 "due to excess in threshold")
andrewonlab226024e2014-10-24 16:01:32 -0400363
364 #ofp to graph processing latency (ONOS processing)
365 delta_ofp_graph_1 = int(graph_timestamp_1) - int(t0_ofp)
366 delta_ofp_graph_2 = int(graph_timestamp_2) - int(t0_ofp)
367 delta_ofp_graph_3 = int(graph_timestamp_3) - int(t0_ofp)
368
369 avg_delta_ofp_graph = \
370 (int(delta_ofp_graph_1)+\
371 int(delta_ofp_graph_2)+\
372 int(delta_ofp_graph_3)) / 3
373
andrewonlabe5bcef92014-11-06 17:53:20 -0500374 if avg_delta_ofp_graph > threshold_min \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500375 and avg_delta_ofp_graph < threshold_max\
andrewonlab65d73892014-11-10 17:36:00 -0500376 and int(i) > iter_ignore:
andrewonlab226024e2014-10-24 16:01:32 -0400377 latency_ofp_to_graph_list.append(avg_delta_ofp_graph)
andrewonlab92844342014-11-18 16:39:11 -0500378 elif avg_delta_ofp_graph > (-10) and \
379 avg_delta_ofp_graph < 0.0 and\
380 int(i) > iter_ignore:
381 main.log.info("Sub-millisecond result likely; "+
382 "negative result was rounded to 0")
383 #NOTE: Current metrics framework does not
384 #support sub-millisecond accuracy. Therefore,
385 #if the result is negative, we can reasonably
386 #conclude sub-millisecond results and just
387 #append the best rounded effort - 0 ms.
388 latency_ofp_to_graph_list.append(0)
andrewonlabee4efeb2014-10-24 16:44:51 -0400389 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400390 main.log.info("Results for ofp-to-graph "+\
391 "ignored due to excess in threshold")
andrewonlabee4efeb2014-10-24 16:44:51 -0400392
andrewonlab226024e2014-10-24 16:01:32 -0400393 #ofp to device processing latency (ONOS processing)
andrewonlabee4efeb2014-10-24 16:44:51 -0400394 delta_ofp_device_1 = float(device_timestamp_1) - float(t0_ofp)
395 delta_ofp_device_2 = float(device_timestamp_2) - float(t0_ofp)
396 delta_ofp_device_3 = float(device_timestamp_3) - float(t0_ofp)
andrewonlab226024e2014-10-24 16:01:32 -0400397
398 avg_delta_ofp_device = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400399 (float(delta_ofp_device_1)+\
400 float(delta_ofp_device_2)+\
andrewonlab4b5c8b92014-11-10 16:04:33 -0500401 float(delta_ofp_device_3)) / 3
andrewonlab226024e2014-10-24 16:01:32 -0400402
andrewonlabf47993a2014-10-24 17:56:01 -0400403 #NOTE: ofp - delta measurements are occasionally negative
404 # due to system time misalignment.
andrewonlabf47993a2014-10-24 17:56:01 -0400405 latency_ofp_to_device_list.append(avg_delta_ofp_device)
andrewonlabba44bcf2014-10-16 16:54:41 -0400406
andrewonlab65d73892014-11-10 17:36:00 -0500407 delta_ofp_tcp = int(t0_ofp) - int(t0_tcp)
408 if delta_ofp_tcp > threshold_min \
409 and delta_ofp_tcp < threshold_max and\
410 int(i) > iter_ignore:
411 latency_tcp_to_ofp_list.append(delta_ofp_tcp)
412 else:
413 main.log.info("Results fo tcp-to-ofp "+\
414 "ignored due to excess in threshold")
415
andrewonlabe6745342014-10-17 14:29:13 -0400416 #TODO:
417 #Fetch logs upon threshold excess
andrewonlabba44bcf2014-10-16 16:54:41 -0400418
andrewonlab226024e2014-10-24 16:01:32 -0400419 main.log.info("ONOS1 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400420 str(delta_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400421 main.log.info("ONOS2 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400422 str(delta_graph_2) + " ms")
423 main.log.info("ONOS3 delta end-to-end: "+
424 str(delta_graph_3) + " ms")
andrewonlabba44bcf2014-10-16 16:54:41 -0400425
andrewonlab226024e2014-10-24 16:01:32 -0400426 main.log.info("ONOS1 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400427 str(delta_ofp_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400428 main.log.info("ONOS2 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400429 str(delta_ofp_graph_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400430 main.log.info("ONOS3 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400431 str(delta_ofp_graph_3) + " ms")
andrewonlabe6745342014-10-17 14:29:13 -0400432
andrewonlab226024e2014-10-24 16:01:32 -0400433 main.log.info("ONOS1 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400434 str(delta_device_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400435 main.log.info("ONOS2 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400436 str(delta_device_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400437 main.log.info("ONOS3 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400438 str(delta_device_3) + " ms")
andrewonlab65d73892014-11-10 17:36:00 -0500439
440 main.log.info("TCP to OFP delta: "+
441 str(delta_ofp_tcp) + " ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500442 #main.log.info("ONOS1 delta OFP - device: "+
443 # str(delta_ofp_device_1) + " ms")
444 #main.log.info("ONOS2 delta OFP - device: "+
445 # str(delta_ofp_device_2) + " ms")
446 #main.log.info("ONOS3 delta OFP - device: "+
447 # str(delta_ofp_device_3) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400448
andrewonlab8d29f122014-10-22 17:15:04 -0400449 main.step("Remove switch from controller")
450 main.Mininet1.delete_sw_controller("s1")
andrewonlabba44bcf2014-10-16 16:54:41 -0400451
andrewonlab8d29f122014-10-22 17:15:04 -0400452 time.sleep(5)
andrewonlabba44bcf2014-10-16 16:54:41 -0400453
andrewonlab09d973e2014-10-24 18:56:58 -0400454 #END of for loop iteration
andrewonlabf47993a2014-10-24 17:56:01 -0400455
andrewonlabee4efeb2014-10-24 16:44:51 -0400456 #If there is at least 1 element in each list,
andrewonlabc15c9582014-10-24 16:35:52 -0400457 #pass the test case
458 if len(latency_end_to_end_list) > 0 and\
459 len(latency_ofp_to_graph_list) > 0 and\
460 len(latency_ofp_to_device_list) > 0 and\
andrewonlab65d73892014-11-10 17:36:00 -0500461 len(latency_t0_to_device_list) > 0 and\
462 len(latency_tcp_to_ofp_list) > 0:
andrewonlabc15c9582014-10-24 16:35:52 -0400463 assertion = main.TRUE
andrewonlabf47993a2014-10-24 17:56:01 -0400464 elif len(latency_end_to_end_list) == 0:
465 #The appending of 0 here is to prevent
466 #the min,max,sum functions from failing
467 #below
468 latency_end_to_end_list.append(0)
469 assertion = main.FALSE
470 elif len(latency_ofp_to_graph_list) == 0:
471 latency_ofp_to_graph_list.append(0)
472 assertion = main.FALSE
473 elif len(latency_ofp_to_device_list) == 0:
474 latency_ofp_to_device_list.append(0)
475 assertion = main.FALSE
476 elif len(latency_t0_to_device_list) == 0:
477 latency_t0_to_device_list.append(0)
478 assertion = main.FALSE
andrewonlab65d73892014-11-10 17:36:00 -0500479 elif len(latency_tcp_to_ofp_list) == 0:
480 latency_tcp_to_ofp_list.append(0)
481 assertion = main.FALSE
andrewonlabc15c9582014-10-24 16:35:52 -0400482
483 #Calculate min, max, avg of latency lists
484 latency_end_to_end_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400485 int(max(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400486 latency_end_to_end_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400487 int(min(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400488 latency_end_to_end_avg = \
andrewonlabc90667c2014-10-24 16:48:28 -0400489 (int(sum(latency_end_to_end_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400490 len(latency_end_to_end_list))
andrewonlab69864162014-11-11 16:28:48 -0500491 latency_end_to_end_std_dev = \
492 str(round(numpy.std(latency_end_to_end_list),1))
493
andrewonlabc15c9582014-10-24 16:35:52 -0400494 latency_ofp_to_graph_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400495 int(max(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400496 latency_ofp_to_graph_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400497 int(min(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400498 latency_ofp_to_graph_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400499 (int(sum(latency_ofp_to_graph_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400500 len(latency_ofp_to_graph_list))
andrewonlab69864162014-11-11 16:28:48 -0500501 latency_ofp_to_graph_std_dev = \
502 str(round(numpy.std(latency_ofp_to_graph_list),1))
andrewonlabc15c9582014-10-24 16:35:52 -0400503
504 latency_ofp_to_device_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400505 int(max(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400506 latency_ofp_to_device_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400507 int(min(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400508 latency_ofp_to_device_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400509 (int(sum(latency_ofp_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400510 len(latency_ofp_to_device_list))
andrewonlab69864162014-11-11 16:28:48 -0500511 latency_ofp_to_device_std_dev = \
512 str(round(numpy.std(latency_ofp_to_device_list),1))
andrewonlabc15c9582014-10-24 16:35:52 -0400513
514 latency_t0_to_device_max = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500515 int(max(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400516 latency_t0_to_device_min = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500517 int(min(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400518 latency_t0_to_device_avg = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500519 (int(sum(latency_t0_to_device_list)) / \
andrewonlab69864162014-11-11 16:28:48 -0500520 len(latency_t0_to_device_list))
521 latency_ofp_to_device_std_dev = \
522 str(round(numpy.std(latency_t0_to_device_list),1))
andrewonlabc15c9582014-10-24 16:35:52 -0400523
andrewonlab65d73892014-11-10 17:36:00 -0500524 latency_tcp_to_ofp_max = \
525 int(max(latency_tcp_to_ofp_list))
526 latency_tcp_to_ofp_min = \
527 int(min(latency_tcp_to_ofp_list))
528 latency_tcp_to_ofp_avg = \
529 (int(sum(latency_tcp_to_ofp_list)) / \
530 len(latency_tcp_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500531 latency_tcp_to_ofp_std_dev = \
532 str(round(numpy.std(latency_tcp_to_ofp_list),1))
andrewonlab65d73892014-11-10 17:36:00 -0500533
andrewonlabf9828f02014-11-10 14:50:27 -0500534 main.log.report("Switch add - End-to-end latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500535 "Avg: "+str(latency_end_to_end_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500536 "Std Deviation: "+latency_end_to_end_std_dev+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -0500537 main.log.report("Switch add - OFP-to-Graph latency: "+\
andrewonlab92844342014-11-18 16:39:11 -0500538 "Note: results are not accurate to sub-millisecond. "+
539 "Any sub-millisecond results are rounded to 0 ms. ")
540 main.log.report("Avg: "+str(latency_ofp_to_graph_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500541 "Std Deviation: "+latency_ofp_to_graph_std_dev+" ms")
andrewonlab65d73892014-11-10 17:36:00 -0500542 main.log.report("Switch add - TCP-to-OFP latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500543 "Avg: "+str(latency_tcp_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500544 "Std Deviation: "+latency_tcp_to_ofp_std_dev+" ms")
andrewonlab226024e2014-10-24 16:01:32 -0400545
andrewonlabb1998c52014-11-10 13:31:43 -0500546 if debug_mode == 'on':
547 main.ONOS1.cp_logs_to_dir("/opt/onos/log/karaf.log",
548 "/tmp/", copy_file_name="sw_lat_karaf")
549
andrewonlab8d29f122014-10-22 17:15:04 -0400550 utilities.assert_equals(expect=main.TRUE, actual=assertion,
551 onpass="Switch latency test successful",
552 onfail="Switch latency test failed")
andrewonlabba44bcf2014-10-16 16:54:41 -0400553
andrewonlab8d29f122014-10-22 17:15:04 -0400554 def CASE3(self, main):
555 '''
556 Bring port up / down and measure latency.
557 Port enable / disable is simulated by ifconfig up / down
andrewonlab393531a2014-10-27 18:36:26 -0400558
559 In ONOS-next, we must ensure that the port we are
560 manipulating is connected to another switch with a valid
561 connection. Otherwise, graph view will not be updated.
andrewonlab8d29f122014-10-22 17:15:04 -0400562 '''
563 import time
564 import subprocess
565 import os
566 import requests
567 import json
andrewonlab4f50ec92014-11-11 14:24:45 -0500568 import numpy
andrewonlab2a6c9342014-10-16 13:40:15 -0400569
andrewonlab8d29f122014-10-22 17:15:04 -0400570 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlab393531a2014-10-27 18:36:26 -0400571 ONOS2_ip = main.params['CTRL']['ip2']
572 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab8d29f122014-10-22 17:15:04 -0400573 ONOS_user = main.params['CTRL']['user']
andrewonlab8d29f122014-10-22 17:15:04 -0400574
andrewonlab393531a2014-10-27 18:36:26 -0400575 default_sw_port = main.params['CTRL']['port1']
andrewonlab8790abb2014-11-06 13:51:54 -0500576
577 assertion = main.TRUE
andrewonlab393531a2014-10-27 18:36:26 -0400578 #Number of iterations of case
579 num_iter = main.params['TEST']['numIter']
580
581 #Timestamp 'keys' for json metrics output.
582 #These are subject to change, hence moved into params
583 deviceTimestamp = main.params['JSON']['deviceTimestamp']
584 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500585
586 debug_mode = main.params['TEST']['debugMode']
587
588 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500589 local_time = local_time.replace("/","")
590 local_time = local_time.replace(" ","_")
591 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500592 if debug_mode == 'on':
593 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500594 "/tmp/port_lat_pcap_"+local_time)
andrewonlab393531a2014-10-27 18:36:26 -0400595
andrewonlabe5bcef92014-11-06 17:53:20 -0500596 #Threshold for this test case
597 up_threshold_str = main.params['TEST']['portUpThreshold']
598 down_threshold_str = main.params['TEST']['portDownThreshold']
andrewonlabb1998c52014-11-10 13:31:43 -0500599
andrewonlabe5bcef92014-11-06 17:53:20 -0500600 up_threshold_obj = up_threshold_str.split(",")
601 down_threshold_obj = down_threshold_str.split(",")
602
603 up_threshold_min = int(up_threshold_obj[0])
604 up_threshold_max = int(up_threshold_obj[1])
605
606 down_threshold_min = int(down_threshold_obj[0])
607 down_threshold_max = int(down_threshold_obj[1])
608
andrewonlab393531a2014-10-27 18:36:26 -0400609 #NOTE: Some hardcoded variables you may need to configure
610 # besides the params
611
andrewonlab8d29f122014-10-22 17:15:04 -0400612 tshark_port_status = "OFP 130 Port Status"
613
614 tshark_port_up = "/tmp/tshark_port_up.txt"
615 tshark_port_down = "/tmp/tshark_port_down.txt"
andrewonlab393531a2014-10-27 18:36:26 -0400616 interface_config = "s1-eth1"
andrewonlab8d29f122014-10-22 17:15:04 -0400617
618 main.log.report("Port enable / disable latency")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500619 main.log.report("Simulated by ifconfig up / down")
620 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab8d29f122014-10-22 17:15:04 -0400621
andrewonlab393531a2014-10-27 18:36:26 -0400622 main.step("Assign switches s1 and s2 to controller 1")
andrewonlab8d29f122014-10-22 17:15:04 -0400623 main.Mininet1.assign_sw_controller(sw="1",ip1=ONOS1_ip,
624 port1=default_sw_port)
andrewonlab393531a2014-10-27 18:36:26 -0400625 main.Mininet1.assign_sw_controller(sw="2",ip1=ONOS1_ip,
626 port1=default_sw_port)
andrewonlab8d29f122014-10-22 17:15:04 -0400627
andrewonlab8790abb2014-11-06 13:51:54 -0500628 #Give enough time for metrics to propagate the
629 #assign controller event. Otherwise, these events may
630 #carry over to our measurements
andrewonlabb1998c52014-11-10 13:31:43 -0500631 time.sleep(15)
andrewonlab8d29f122014-10-22 17:15:04 -0400632
andrewonlab393531a2014-10-27 18:36:26 -0400633 port_up_device_to_ofp_list = []
634 port_up_graph_to_ofp_list = []
635 port_down_device_to_ofp_list = []
636 port_down_graph_to_ofp_list = []
637
andrewonlab8d29f122014-10-22 17:15:04 -0400638 for i in range(0, int(num_iter)):
639 main.step("Starting wireshark capture for port status down")
640 main.ONOS1.tshark_grep(tshark_port_status,
641 tshark_port_down)
642
andrewonlabb1998c52014-11-10 13:31:43 -0500643 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400644
andrewonlab393531a2014-10-27 18:36:26 -0400645 #Disable interface that is connected to switch 2
646 main.step("Disable port: "+interface_config)
andrewonlabb1998c52014-11-10 13:31:43 -0500647 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400648 interface_config+" down")
andrewonlabb1998c52014-11-10 13:31:43 -0500649 main.Mininet1.handle.expect("mininet>")
andrewonlab8d29f122014-10-22 17:15:04 -0400650
andrewonlabb1998c52014-11-10 13:31:43 -0500651 time.sleep(3)
andrewonlab8d29f122014-10-22 17:15:04 -0400652 main.ONOS1.tshark_stop()
andrewonlabb1998c52014-11-10 13:31:43 -0500653
654 main.step("Obtain t1 by metrics call")
655 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
656 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
657 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
658
659 json_obj_1 = json.loads(json_str_up_1)
660 json_obj_2 = json.loads(json_str_up_2)
661 json_obj_3 = json.loads(json_str_up_3)
andrewonlab8d29f122014-10-22 17:15:04 -0400662
663 #Copy tshark output file from ONOS to TestON instance
664 #/tmp directory
665 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
666 tshark_port_down+" /tmp/")
667
668 f_port_down = open(tshark_port_down, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400669 #Get first line of port down event from tshark
andrewonlab8d29f122014-10-22 17:15:04 -0400670 f_line = f_port_down.readline()
671 obj_down = f_line.split(" ")
672 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500673 timestamp_begin_pt_down = int(float(obj_down[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400674 main.log.info("Port down begin timestamp: "+
675 str(timestamp_begin_pt_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400676 else:
677 main.log.info("Tshark output file returned unexpected"+
andrewonlab393531a2014-10-27 18:36:26 -0400678 " results: "+str(obj_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400679 timestamp_begin_pt_down = 0
andrewonlab393531a2014-10-27 18:36:26 -0400680
681 f_port_down.close()
andrewonlab8d29f122014-10-22 17:15:04 -0400682
andrewonlab4e124482014-11-04 13:37:25 -0500683 main.log.info("TEST tshark obj: "+str(obj_down))
684
andrewonlabb1998c52014-11-10 13:31:43 -0500685 time.sleep(3)
andrewonlab393531a2014-10-27 18:36:26 -0400686
687 #Obtain graph timestamp. This timestsamp captures
688 #the epoch time at which the topology graph was updated.
689 graph_timestamp_1 = \
690 json_obj_1[graphTimestamp]['value']
691 graph_timestamp_2 = \
692 json_obj_2[graphTimestamp]['value']
693 graph_timestamp_3 = \
694 json_obj_3[graphTimestamp]['value']
695
andrewonlabb1998c52014-11-10 13:31:43 -0500696 main.log.info("TEST graph timestamp ONOS1: "+
697 str(graph_timestamp_1))
698
andrewonlab393531a2014-10-27 18:36:26 -0400699 #Obtain device timestamp. This timestamp captures
700 #the epoch time at which the device event happened
701 device_timestamp_1 = \
702 json_obj_1[deviceTimestamp]['value']
703 device_timestamp_2 = \
704 json_obj_2[deviceTimestamp]['value']
705 device_timestamp_3 = \
706 json_obj_3[deviceTimestamp]['value']
andrewonlab393531a2014-10-27 18:36:26 -0400707
708 #Get delta between graph event and OFP
709 pt_down_graph_to_ofp_1 = int(graph_timestamp_1) -\
710 int(timestamp_begin_pt_down)
711 pt_down_graph_to_ofp_2 = int(graph_timestamp_2) -\
712 int(timestamp_begin_pt_down)
713 pt_down_graph_to_ofp_3 = int(graph_timestamp_3) -\
714 int(timestamp_begin_pt_down)
715
716 #Get delta between device event and OFP
717 pt_down_device_to_ofp_1 = int(device_timestamp_1) -\
718 int(timestamp_begin_pt_down)
719 pt_down_device_to_ofp_2 = int(device_timestamp_2) -\
720 int(timestamp_begin_pt_down)
721 pt_down_device_to_ofp_3 = int(device_timestamp_3) -\
722 int(timestamp_begin_pt_down)
723
724 #Caluclate average across clusters
725 pt_down_graph_to_ofp_avg =\
726 (int(pt_down_graph_to_ofp_1) +
727 int(pt_down_graph_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500728 int(pt_down_graph_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400729 pt_down_device_to_ofp_avg = \
730 (int(pt_down_device_to_ofp_1) +
731 int(pt_down_device_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500732 int(pt_down_device_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400733
andrewonlabb1998c52014-11-10 13:31:43 -0500734 if pt_down_graph_to_ofp_avg > down_threshold_min and \
735 pt_down_graph_to_ofp_avg < down_threshold_max:
andrewonlab393531a2014-10-27 18:36:26 -0400736 port_down_graph_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500737 pt_down_graph_to_ofp_avg)
738 main.log.info("Port down: graph to ofp avg: "+
739 str(pt_down_graph_to_ofp_avg) + " ms")
andrewonlab393531a2014-10-27 18:36:26 -0400740 else:
741 main.log.info("Average port down graph-to-ofp result" +
742 " exceeded the threshold: "+
743 str(pt_down_graph_to_ofp_avg))
744
andrewonlab3622beb2014-10-28 16:07:56 -0400745 if pt_down_device_to_ofp_avg > 0 and \
746 pt_down_device_to_ofp_avg < 1000:
747 port_down_device_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500748 pt_down_device_to_ofp_avg)
749 main.log.info("Port down: device to ofp avg: "+
750 str(pt_down_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400751 else:
752 main.log.info("Average port down device-to-ofp result" +
753 " exceeded the threshold: "+
754 str(pt_down_device_to_ofp_avg))
755
andrewonlab8d29f122014-10-22 17:15:04 -0400756 #Port up events
757 main.step("Enable port and obtain timestamp")
758 main.step("Starting wireshark capture for port status up")
andrewonlabb1998c52014-11-10 13:31:43 -0500759 main.ONOS1.tshark_grep(tshark_port_status, tshark_port_up)
andrewonlab8790abb2014-11-06 13:51:54 -0500760 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400761
andrewonlabb1998c52014-11-10 13:31:43 -0500762 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400763 interface_config+" up")
andrewonlabb1998c52014-11-10 13:31:43 -0500764 main.Mininet1.handle.expect("mininet>")
andrewonlab8790abb2014-11-06 13:51:54 -0500765
andrewonlabb1998c52014-11-10 13:31:43 -0500766 #Allow time for tshark to capture event
767 time.sleep(3)
andrewonlab8790abb2014-11-06 13:51:54 -0500768 main.ONOS1.tshark_stop()
andrewonlab8d29f122014-10-22 17:15:04 -0400769
andrewonlabb1998c52014-11-10 13:31:43 -0500770 #Obtain metrics shortly afterwards
771 #This timestsamp captures
772 #the epoch time at which the topology graph was updated.
773 main.step("Obtain t1 by REST call")
774 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
775 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
776 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
777
778 json_obj_1 = json.loads(json_str_up_1)
779 json_obj_2 = json.loads(json_str_up_2)
780 json_obj_3 = json.loads(json_str_up_3)
781
andrewonlab8d29f122014-10-22 17:15:04 -0400782 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
783 tshark_port_up+" /tmp/")
784
785 f_port_up = open(tshark_port_up, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400786 f_line = f_port_up.readline()
andrewonlab8d29f122014-10-22 17:15:04 -0400787 obj_up = f_line.split(" ")
788 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500789 timestamp_begin_pt_up = int(float(obj_up[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400790 main.log.info("Port up begin timestamp: "+
791 str(timestamp_begin_pt_up))
andrewonlab8d29f122014-10-22 17:15:04 -0400792 else:
793 main.log.info("Tshark output file returned unexpected"+
794 " results.")
795 timestamp_begin_pt_up = 0
796
andrewonlab393531a2014-10-27 18:36:26 -0400797 f_port_up.close()
798
andrewonlab393531a2014-10-27 18:36:26 -0400799 graph_timestamp_1 = \
800 json_obj_1[graphTimestamp]['value']
801 graph_timestamp_2 = \
802 json_obj_2[graphTimestamp]['value']
803 graph_timestamp_3 = \
804 json_obj_3[graphTimestamp]['value']
805
806 #Obtain device timestamp. This timestamp captures
807 #the epoch time at which the device event happened
808 device_timestamp_1 = \
809 json_obj_1[deviceTimestamp]['value']
810 device_timestamp_2 = \
811 json_obj_2[deviceTimestamp]['value']
812 device_timestamp_3 = \
813 json_obj_3[deviceTimestamp]['value']
814
815 #Get delta between graph event and OFP
816 pt_up_graph_to_ofp_1 = int(graph_timestamp_1) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400817 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400818 pt_up_graph_to_ofp_2 = int(graph_timestamp_2) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400819 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400820 pt_up_graph_to_ofp_3 = int(graph_timestamp_3) -\
821 int(timestamp_begin_pt_up)
822
823 #Get delta between device event and OFP
824 pt_up_device_to_ofp_1 = int(device_timestamp_1) -\
825 int(timestamp_begin_pt_up)
826 pt_up_device_to_ofp_2 = int(device_timestamp_2) -\
827 int(timestamp_begin_pt_up)
828 pt_up_device_to_ofp_3 = int(device_timestamp_3) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400829 int(timestamp_begin_pt_up)
andrewonlab3622beb2014-10-28 16:07:56 -0400830
andrewonlabb1998c52014-11-10 13:31:43 -0500831 main.log.info("ONOS1 delta G2O: "+str(pt_up_graph_to_ofp_1))
832 main.log.info("ONOS2 delta G2O: "+str(pt_up_graph_to_ofp_2))
833 main.log.info("ONOS3 delta G2O: "+str(pt_up_graph_to_ofp_3))
834
835 main.log.info("ONOS1 delta D2O: "+str(pt_up_device_to_ofp_1))
836 main.log.info("ONOS2 delta D2O: "+str(pt_up_device_to_ofp_2))
837 main.log.info("ONOS3 delta D2O: "+str(pt_up_device_to_ofp_3))
838
andrewonlab3622beb2014-10-28 16:07:56 -0400839 pt_up_graph_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500840 (int(pt_up_graph_to_ofp_1) +
841 int(pt_up_graph_to_ofp_2) +
842 int(pt_up_graph_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400843
844 pt_up_device_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500845 (int(pt_up_device_to_ofp_1) +
846 int(pt_up_device_to_ofp_2) +
847 int(pt_up_device_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400848
andrewonlabe5bcef92014-11-06 17:53:20 -0500849 if pt_up_graph_to_ofp_avg > up_threshold_min and \
850 pt_up_graph_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400851 port_up_graph_to_ofp_list.append(
852 pt_up_graph_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500853 main.log.info("Port down: graph to ofp avg: "+
854 str(pt_up_graph_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400855 else:
856 main.log.info("Average port up graph-to-ofp result"+
857 " exceeded the threshold: "+
858 str(pt_up_graph_to_ofp_avg))
859
andrewonlabe5bcef92014-11-06 17:53:20 -0500860 if pt_up_device_to_ofp_avg > up_threshold_min and \
861 pt_up_device_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400862 port_up_device_to_ofp_list.append(
863 pt_up_device_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500864 main.log.info("Port up: device to ofp avg: "+
865 str(pt_up_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400866 else:
andrewonlababb11c32014-11-04 15:03:24 -0500867 main.log.info("Average port up device-to-ofp result"+
andrewonlab3622beb2014-10-28 16:07:56 -0400868 " exceeded the threshold: "+
869 str(pt_up_device_to_ofp_avg))
andrewonlab8d29f122014-10-22 17:15:04 -0400870
andrewonlab3622beb2014-10-28 16:07:56 -0400871 #END ITERATION FOR LOOP
andrewonlab8790abb2014-11-06 13:51:54 -0500872
873 #Check all list for latency existence and set assertion
874 if (port_down_graph_to_ofp_list and port_down_device_to_ofp_list\
875 and port_up_graph_to_ofp_list and port_up_device_to_ofp_list):
876 assertion = main.TRUE
877
andrewonlababb11c32014-11-04 15:03:24 -0500878 #Calculate and report latency measurements
andrewonlab3622beb2014-10-28 16:07:56 -0400879 port_down_graph_to_ofp_min = min(port_down_graph_to_ofp_list)
880 port_down_graph_to_ofp_max = max(port_down_graph_to_ofp_list)
881 port_down_graph_to_ofp_avg = \
882 (sum(port_down_graph_to_ofp_list) /
883 len(port_down_graph_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500884 port_down_graph_to_ofp_std_dev = \
885 str(round(numpy.std(port_down_graph_to_ofp_list),1))
andrewonlab3622beb2014-10-28 16:07:56 -0400886
andrewonlab4f50ec92014-11-11 14:24:45 -0500887 main.log.report("Port down graph-to-ofp "+
888 "Avg: "+str(port_down_graph_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500889 "Std Deviation: "+port_down_graph_to_ofp_std_dev+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500890
891 port_down_device_to_ofp_min = min(port_down_device_to_ofp_list)
892 port_down_device_to_ofp_max = max(port_down_device_to_ofp_list)
893 port_down_device_to_ofp_avg = \
894 (sum(port_down_device_to_ofp_list) /\
895 len(port_down_device_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500896 port_down_device_to_ofp_std_dev = \
897 str(round(numpy.std(port_down_device_to_ofp_list),1))
andrewonlababb11c32014-11-04 15:03:24 -0500898
andrewonlab4f50ec92014-11-11 14:24:45 -0500899 main.log.report("Port down device-to-ofp "+
900 "Avg: "+str(port_down_device_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500901 "Std Deviation: "+port_down_device_to_ofp_std_dev+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500902
903 port_up_graph_to_ofp_min = min(port_up_graph_to_ofp_list)
904 port_up_graph_to_ofp_max = max(port_up_graph_to_ofp_list)
905 port_up_graph_to_ofp_avg = \
906 (sum(port_up_graph_to_ofp_list) /\
907 len(port_up_graph_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500908 port_up_graph_to_ofp_std_dev = \
909 str(round(numpy.std(port_up_graph_to_ofp_list),1))
andrewonlab8790abb2014-11-06 13:51:54 -0500910
andrewonlab4f50ec92014-11-11 14:24:45 -0500911 main.log.report("Port up graph-to-ofp "+
912 "Avg: "+str(port_up_graph_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500913 "Std Deviation: "+port_up_graph_to_ofp_std_dev+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500914
915 port_up_device_to_ofp_min = min(port_up_device_to_ofp_list)
916 port_up_device_to_ofp_max = max(port_up_device_to_ofp_list)
917 port_up_device_to_ofp_avg = \
918 (sum(port_up_device_to_ofp_list) /\
919 len(port_up_device_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500920 port_up_device_to_ofp_std_dev = \
921 str(round(numpy.std(port_up_device_to_ofp_list),1))
andrewonlab8790abb2014-11-06 13:51:54 -0500922
andrewonlab4f50ec92014-11-11 14:24:45 -0500923 main.log.report("Port up device-to-ofp "+
924 "Avg: "+str(port_up_device_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500925 "Std Deviation: "+port_up_device_to_ofp_std_dev+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500926
927 utilities.assert_equals(expect=main.TRUE, actual=assertion,
928 onpass="Port discovery latency calculation successful",
929 onfail="Port discovery test failed")
andrewonlababb11c32014-11-04 15:03:24 -0500930
andrewonlab3622beb2014-10-28 16:07:56 -0400931 def CASE4(self, main):
932 '''
933 Link down event using loss rate 100%
andrewonlab53b641c2014-10-31 19:44:44 -0400934
935 Important:
936 Use a simple 2 switch topology with 1 link between
937 the two switches. Ensure that mac addresses of the
938 switches are 1 / 2 respectively
andrewonlab3622beb2014-10-28 16:07:56 -0400939 '''
940 import time
941 import subprocess
942 import os
943 import requests
944 import json
andrewonlab4f50ec92014-11-11 14:24:45 -0500945 import numpy
946
andrewonlab3622beb2014-10-28 16:07:56 -0400947 ONOS1_ip = main.params['CTRL']['ip1']
948 ONOS2_ip = main.params['CTRL']['ip2']
949 ONOS3_ip = main.params['CTRL']['ip3']
950 ONOS_user = main.params['CTRL']['user']
951
952 default_sw_port = main.params['CTRL']['port1']
953
954 #Number of iterations of case
955 num_iter = main.params['TEST']['numIter']
956
957 #Timestamp 'keys' for json metrics output.
958 #These are subject to change, hence moved into params
959 deviceTimestamp = main.params['JSON']['deviceTimestamp']
960 linkTimestamp = main.params['JSON']['linkTimestamp']
andrewonlab53b641c2014-10-31 19:44:44 -0400961 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500962
963 debug_mode = main.params['TEST']['debugMode']
964
965 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500966 local_time = local_time.replace("/","")
967 local_time = local_time.replace(" ","_")
968 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500969 if debug_mode == 'on':
970 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500971 "/tmp/link_lat_pcap_"+local_time)
andrewonlab53b641c2014-10-31 19:44:44 -0400972
andrewonlabe5bcef92014-11-06 17:53:20 -0500973 #Threshold for this test case
974 up_threshold_str = main.params['TEST']['linkUpThreshold']
975 down_threshold_str = main.params['TEST']['linkDownThreshold']
976
977 up_threshold_obj = up_threshold_str.split(",")
978 down_threshold_obj = down_threshold_str.split(",")
979
980 up_threshold_min = int(up_threshold_obj[0])
981 up_threshold_max = int(up_threshold_obj[1])
982
983 down_threshold_min = int(down_threshold_obj[0])
984 down_threshold_max = int(down_threshold_obj[1])
985
andrewonlab3622beb2014-10-28 16:07:56 -0400986 assertion = main.TRUE
987 #Link event timestamp to system time list
988 link_down_link_to_system_list = []
989 link_up_link_to_system_list = []
990 #Graph event timestamp to system time list
991 link_down_graph_to_system_list = []
992 link_up_graph_to_system_list = []
993
andrewonlab4b5c8b92014-11-10 16:04:33 -0500994 main.log.report("Link up / down discovery latency between "+
andrewonlab3622beb2014-10-28 16:07:56 -0400995 "two switches")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500996 main.log.report("Simulated by setting loss-rate 100%")
997 main.log.report("'tc qdisc add dev <intfs> root netem loss 100%'")
998 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab3622beb2014-10-28 16:07:56 -0400999
1000 main.step("Assign all switches")
1001 main.Mininet1.assign_sw_controller(sw="1",
1002 ip1=ONOS1_ip, port1=default_sw_port)
1003 main.Mininet1.assign_sw_controller(sw="2",
1004 ip1=ONOS1_ip, port1=default_sw_port)
1005
1006 main.step("Verifying switch assignment")
1007 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
1008 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
andrewonlab3622beb2014-10-28 16:07:56 -04001009
1010 #Allow time for events to finish before taking measurements
1011 time.sleep(10)
1012
andrewonlababb11c32014-11-04 15:03:24 -05001013 link_down1 = False
1014 link_down2 = False
1015 link_down3 = False
andrewonlab3622beb2014-10-28 16:07:56 -04001016 #Start iteration of link event test
1017 for i in range(0, int(num_iter)):
1018 main.step("Getting initial system time as t0")
andrewonlab8d29f122014-10-22 17:15:04 -04001019
andrewonlab3622beb2014-10-28 16:07:56 -04001020 timestamp_link_down_t0 = time.time() * 1000
1021 #Link down is simulated by 100% loss rate using traffic
1022 #control command
1023 main.Mininet1.handle.sendline(
1024 "sh tc qdisc add dev s1-eth1 root netem loss 100%")
1025
andrewonlab53b641c2014-10-31 19:44:44 -04001026 #TODO: Iterate through 'links' command to verify that
andrewonlababb11c32014-11-04 15:03:24 -05001027 # link s1 -> s2 went down (loop timeout 30 seconds)
1028 # on all 3 ONOS instances
andrewonlab53b641c2014-10-31 19:44:44 -04001029 main.log.info("Checking ONOS for link update")
1030 loop_count = 0
andrewonlababb11c32014-11-04 15:03:24 -05001031 while( not (link_down1 and link_down2 and link_down3)\
1032 and loop_count < 30 ):
1033 json_str1 = main.ONOS1cli.links()
1034 json_str2 = main.ONOS2cli.links()
1035 json_str3 = main.ONOS3cli.links()
1036
1037 if not (json_str1 and json_str2 and json_str3):
1038 main.log.error("CLI command returned error ")
andrewonlab53b641c2014-10-31 19:44:44 -04001039 break
1040 else:
andrewonlababb11c32014-11-04 15:03:24 -05001041 json_obj1 = json.loads(json_str1)
1042 json_obj2 = json.loads(json_str2)
1043 json_obj3 = json.loads(json_str3)
1044 for obj1 in json_obj1:
1045 if '01' not in obj1['src']['device']:
1046 link_down1 = True
andrewonlabf9828f02014-11-10 14:50:27 -05001047 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001048 "s1 -> s2 on ONOS1 detected")
1049 for obj2 in json_obj2:
1050 if '01' not in obj2['src']['device']:
1051 link_down2 = True
andrewonlabf9828f02014-11-10 14:50:27 -05001052 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001053 "s1 -> s2 on ONOS2 detected")
1054 for obj3 in json_obj3:
1055 if '01' not in obj3['src']['device']:
1056 link_down3 = True
andrewonlabf9828f02014-11-10 14:50:27 -05001057 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001058 "s1 -> s2 on ONOS3 detected")
1059
andrewonlab53b641c2014-10-31 19:44:44 -04001060 loop_count += 1
andrewonlababb11c32014-11-04 15:03:24 -05001061 #If CLI doesn't like the continuous requests
1062 #and exits in this loop, increase the sleep here.
1063 #Consequently, while loop timeout will increase
andrewonlab53b641c2014-10-31 19:44:44 -04001064 time.sleep(1)
1065
1066 #Give time for metrics measurement to catch up
andrewonlababb11c32014-11-04 15:03:24 -05001067 #NOTE: May need to be configured more accurately
andrewonlab53b641c2014-10-31 19:44:44 -04001068 time.sleep(10)
andrewonlababb11c32014-11-04 15:03:24 -05001069 #If we exited the while loop and link down 1,2,3 are still
andrewonlab53b641c2014-10-31 19:44:44 -04001070 #false, then ONOS has failed to discover link down event
andrewonlababb11c32014-11-04 15:03:24 -05001071 if not (link_down1 and link_down2 and link_down3):
andrewonlab53b641c2014-10-31 19:44:44 -04001072 main.log.info("Link down discovery failed")
1073
1074 link_down_lat_graph1 = 0
1075 link_down_lat_graph2 = 0
1076 link_down_lat_graph3 = 0
1077 link_down_lat_device1 = 0
1078 link_down_lat_device2 = 0
1079 link_down_lat_device3 = 0
1080
1081 assertion = main.FALSE
1082 else:
1083 json_topo_metrics_1 =\
1084 main.ONOS1cli.topology_events_metrics()
1085 json_topo_metrics_2 =\
1086 main.ONOS2cli.topology_events_metrics()
1087 json_topo_metrics_3 =\
1088 main.ONOS3cli.topology_events_metrics()
1089 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1090 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1091 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1092
1093 main.log.info("Obtaining graph and device timestamp")
1094 graph_timestamp_1 = \
1095 json_topo_metrics_1[graphTimestamp]['value']
1096 graph_timestamp_2 = \
1097 json_topo_metrics_2[graphTimestamp]['value']
1098 graph_timestamp_3 = \
1099 json_topo_metrics_3[graphTimestamp]['value']
1100
1101 link_timestamp_1 = \
1102 json_topo_metrics_1[linkTimestamp]['value']
1103 link_timestamp_2 = \
1104 json_topo_metrics_2[linkTimestamp]['value']
1105 link_timestamp_3 = \
1106 json_topo_metrics_3[linkTimestamp]['value']
1107
1108 if graph_timestamp_1 and graph_timestamp_2 and\
1109 graph_timestamp_3 and link_timestamp_1 and\
1110 link_timestamp_2 and link_timestamp_3:
1111 link_down_lat_graph1 = int(graph_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001112 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001113 link_down_lat_graph2 = int(graph_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001114 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001115 link_down_lat_graph3 = int(graph_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001116 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001117
1118 link_down_lat_link1 = int(link_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001119 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001120 link_down_lat_link2 = int(link_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001121 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001122 link_down_lat_link3 = int(link_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001123 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001124 else:
1125 main.log.error("There was an error calculating"+
1126 " the delta for link down event")
1127 link_down_lat_graph1 = 0
1128 link_down_lat_graph2 = 0
1129 link_down_lat_graph3 = 0
1130
1131 link_down_lat_device1 = 0
1132 link_down_lat_device2 = 0
1133 link_down_lat_device3 = 0
1134
andrewonlabf9828f02014-11-10 14:50:27 -05001135 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001136 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001137 str(link_down_lat_graph1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001138 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001139 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001140 str(link_down_lat_graph2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001141 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001142 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001143 str(link_down_lat_graph3)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001144
andrewonlabf9828f02014-11-10 14:50:27 -05001145 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001146 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001147 str(link_down_lat_link1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001148 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001149 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001150 str(link_down_lat_link2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001151 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001152 str(i)+" (link-event-to-system-timestamp): "+
1153 str(link_down_lat_link3))
1154
1155 #Calculate avg of node calculations
1156 link_down_lat_graph_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001157 (link_down_lat_graph1 +
1158 link_down_lat_graph2 +
andrewonlab65d73892014-11-10 17:36:00 -05001159 link_down_lat_graph3) / 3
andrewonlab4e124482014-11-04 13:37:25 -05001160 link_down_lat_link_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001161 (link_down_lat_link1 +
1162 link_down_lat_link2 +
andrewonlab65d73892014-11-10 17:36:00 -05001163 link_down_lat_link3) / 3
andrewonlab53b641c2014-10-31 19:44:44 -04001164
andrewonlab4e124482014-11-04 13:37:25 -05001165 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001166 if link_down_lat_graph_avg > down_threshold_min and\
1167 link_down_lat_graph_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001168 link_down_graph_to_system_list.append(
1169 link_down_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001170 else:
1171 main.log.info("Link down latency exceeded threshold")
1172 main.log.info("Results for iteration "+str(i)+
1173 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001174 if link_down_lat_link_avg > down_threshold_min and\
1175 link_down_lat_link_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001176 link_down_link_to_system_list.append(
1177 link_down_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001178 else:
1179 main.log.info("Link down latency exceeded threshold")
1180 main.log.info("Results for iteration "+str(i)+
1181 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001182
1183 #NOTE: To remove loss rate and measure latency:
1184 # 'sh tc qdisc del dev s1-eth1 root'
andrewonlababb11c32014-11-04 15:03:24 -05001185 timestamp_link_up_t0 = time.time() * 1000
andrewonlab53b641c2014-10-31 19:44:44 -04001186 main.Mininet1.handle.sendline("sh tc qdisc del dev "+
1187 "s1-eth1 root")
1188 main.Mininet1.handle.expect("mininet>")
andrewonlababb11c32014-11-04 15:03:24 -05001189
1190 main.log.info("Checking ONOS for link update")
1191
1192 link_down1 = True
1193 link_down2 = True
1194 link_down3 = True
1195 loop_count = 0
1196 while( (link_down1 and link_down2 and link_down3)\
1197 and loop_count < 30 ):
1198 json_str1 = main.ONOS1cli.links()
1199 json_str2 = main.ONOS2cli.links()
1200 json_str3 = main.ONOS3cli.links()
1201 if not (json_str1 and json_str2 and json_str3):
1202 main.log.error("CLI command returned error ")
1203 break
1204 else:
1205 json_obj1 = json.loads(json_str1)
1206 json_obj2 = json.loads(json_str2)
1207 json_obj3 = json.loads(json_str3)
1208
1209 for obj1 in json_obj1:
1210 if '01' in obj1['src']['device']:
1211 link_down1 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001212 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001213 "s1 -> s2 on ONOS1 detected")
1214 for obj2 in json_obj2:
1215 if '01' in obj2['src']['device']:
1216 link_down2 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001217 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001218 "s1 -> s2 on ONOS2 detected")
1219 for obj3 in json_obj3:
1220 if '01' in obj3['src']['device']:
1221 link_down3 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001222 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001223 "s1 -> s2 on ONOS3 detected")
1224
1225 loop_count += 1
1226 time.sleep(1)
1227
1228 if (link_down1 and link_down2 and link_down3):
1229 main.log.info("Link up discovery failed")
1230
1231 link_up_lat_graph1 = 0
1232 link_up_lat_graph2 = 0
1233 link_up_lat_graph3 = 0
1234 link_up_lat_device1 = 0
1235 link_up_lat_device2 = 0
1236 link_up_lat_device3 = 0
1237
1238 assertion = main.FALSE
1239 else:
1240 json_topo_metrics_1 =\
1241 main.ONOS1cli.topology_events_metrics()
1242 json_topo_metrics_2 =\
1243 main.ONOS2cli.topology_events_metrics()
1244 json_topo_metrics_3 =\
1245 main.ONOS3cli.topology_events_metrics()
1246 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1247 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1248 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1249
1250 main.log.info("Obtaining graph and device timestamp")
1251 graph_timestamp_1 = \
1252 json_topo_metrics_1[graphTimestamp]['value']
1253 graph_timestamp_2 = \
1254 json_topo_metrics_2[graphTimestamp]['value']
1255 graph_timestamp_3 = \
1256 json_topo_metrics_3[graphTimestamp]['value']
1257
1258 link_timestamp_1 = \
1259 json_topo_metrics_1[linkTimestamp]['value']
1260 link_timestamp_2 = \
1261 json_topo_metrics_2[linkTimestamp]['value']
1262 link_timestamp_3 = \
1263 json_topo_metrics_3[linkTimestamp]['value']
1264
1265 if graph_timestamp_1 and graph_timestamp_2 and\
1266 graph_timestamp_3 and link_timestamp_1 and\
1267 link_timestamp_2 and link_timestamp_3:
1268 link_up_lat_graph1 = int(graph_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001269 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001270 link_up_lat_graph2 = int(graph_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001271 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001272 link_up_lat_graph3 = int(graph_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001273 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001274
1275 link_up_lat_link1 = int(link_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001276 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001277 link_up_lat_link2 = int(link_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001278 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001279 link_up_lat_link3 = int(link_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001280 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001281 else:
1282 main.log.error("There was an error calculating"+
1283 " the delta for link down event")
1284 link_up_lat_graph1 = 0
1285 link_up_lat_graph2 = 0
1286 link_up_lat_graph3 = 0
1287
1288 link_up_lat_device1 = 0
1289 link_up_lat_device2 = 0
1290 link_up_lat_device3 = 0
andrewonlab58f7d702014-11-07 13:21:19 -05001291
1292 if debug_mode == 'on':
1293 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001294 str(i)+" (end-to-end): "+
1295 str(link_up_lat_graph1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001296 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001297 str(i)+" (end-to-end): "+
1298 str(link_up_lat_graph2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001299 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001300 str(i)+" (end-to-end): "+
1301 str(link_up_lat_graph3)+" ms")
1302
andrewonlab58f7d702014-11-07 13:21:19 -05001303 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001304 str(i)+" (link-event-to-system-timestamp): "+
1305 str(link_up_lat_link1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001306 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001307 str(i)+" (link-event-to-system-timestamp): "+
1308 str(link_up_lat_link2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001309 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001310 str(i)+" (link-event-to-system-timestamp): "+
1311 str(link_up_lat_link3))
1312
1313 #Calculate avg of node calculations
1314 link_up_lat_graph_avg =\
1315 (link_up_lat_graph1 +
1316 link_up_lat_graph2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001317 link_up_lat_graph3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001318 link_up_lat_link_avg =\
1319 (link_up_lat_link1 +
1320 link_up_lat_link2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001321 link_up_lat_link3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001322
1323 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001324 if link_up_lat_graph_avg > up_threshold_min and\
1325 link_up_lat_graph_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001326 link_up_graph_to_system_list.append(
1327 link_up_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001328 else:
1329 main.log.info("Link up latency exceeded threshold")
1330 main.log.info("Results for iteration "+str(i)+
1331 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001332 if link_up_lat_link_avg > up_threshold_min and\
1333 link_up_lat_link_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001334 link_up_link_to_system_list.append(
1335 link_up_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001336 else:
1337 main.log.info("Link up latency exceeded threshold")
1338 main.log.info("Results for iteration "+str(i)+
1339 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001340
andrewonlab4e124482014-11-04 13:37:25 -05001341 #Calculate min, max, avg of list and report
1342 link_down_min = min(link_down_graph_to_system_list)
1343 link_down_max = max(link_down_graph_to_system_list)
1344 link_down_avg = sum(link_down_graph_to_system_list) / \
1345 len(link_down_graph_to_system_list)
andrewonlababb11c32014-11-04 15:03:24 -05001346 link_up_min = min(link_up_graph_to_system_list)
1347 link_up_max = max(link_up_graph_to_system_list)
1348 link_up_avg = sum(link_up_graph_to_system_list) / \
1349 len(link_up_graph_to_system_list)
andrewonlab69864162014-11-11 16:28:48 -05001350 link_down_std_dev = \
1351 str(round(numpy.std(link_down_graph_to_system_list),1))
1352 link_up_std_dev = \
1353 str(round(numpy.std(link_up_graph_to_system_list),1))
andrewonlababb11c32014-11-04 15:03:24 -05001354
andrewonlab4f50ec92014-11-11 14:24:45 -05001355 main.log.report("Link down latency " +
1356 "Avg: "+str(link_down_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -05001357 "Std Deviation: "+link_down_std_dev+" ms")
andrewonlab4f50ec92014-11-11 14:24:45 -05001358 main.log.report("Link up latency "+
1359 "Avg: "+str(link_up_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -05001360 "Std Deviation: "+link_up_std_dev+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001361
andrewonlab8790abb2014-11-06 13:51:54 -05001362 utilities.assert_equals(expect=main.TRUE, actual=assertion,
1363 onpass="Link discovery latency calculation successful",
1364 onfail="Link discovery latency case failed")
1365
andrewonlabb54b85b2014-10-28 18:43:57 -04001366 def CASE5(self, main):
1367 '''
1368 100 Switch discovery latency
1369
1370 Important:
andrewonlab16ce4852014-10-30 13:41:09 -04001371 This test case can be potentially dangerous if
1372 your machine has previously set iptables rules.
1373 One of the steps of the test case will flush
1374 all existing iptables rules.
andrewonlab8790abb2014-11-06 13:51:54 -05001375 Note:
1376 You can specify the number of switches in the
1377 params file to adjust the switch discovery size
1378 (and specify the corresponding topology in Mininet1
1379 .topo file)
andrewonlabb54b85b2014-10-28 18:43:57 -04001380 '''
1381 import time
1382 import subprocess
1383 import os
1384 import requests
1385 import json
1386
1387 ONOS1_ip = main.params['CTRL']['ip1']
1388 ONOS2_ip = main.params['CTRL']['ip2']
1389 ONOS3_ip = main.params['CTRL']['ip3']
1390 MN1_ip = main.params['MN']['ip1']
1391 ONOS_user = main.params['CTRL']['user']
1392
1393 default_sw_port = main.params['CTRL']['port1']
1394
1395 #Number of iterations of case
1396 num_iter = main.params['TEST']['numIter']
andrewonlab16ce4852014-10-30 13:41:09 -04001397 num_sw = main.params['TEST']['numSwitch']
1398
andrewonlabb54b85b2014-10-28 18:43:57 -04001399 #Timestamp 'keys' for json metrics output.
1400 #These are subject to change, hence moved into params
1401 deviceTimestamp = main.params['JSON']['deviceTimestamp']
andrewonlab16ce4852014-10-30 13:41:09 -04001402 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -05001403
1404 debug_mode = main.params['TEST']['debugMode']
1405
andrewonlabb1998c52014-11-10 13:31:43 -05001406 local_time = time.strftime('%X')
1407 local_time = local_time.replace("/","")
1408 local_time = local_time.replace(" ","_")
1409 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -05001410 if debug_mode == 'on':
1411 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -05001412 "/tmp/100_sw_lat_pcap_"+local_time)
andrewonlabe5bcef92014-11-06 17:53:20 -05001413
1414 #Threshold for this test case
1415 sw_disc_threshold_str = main.params['TEST']['swDisc100Threshold']
1416 sw_disc_threshold_obj = sw_disc_threshold_str.split(",")
1417 sw_disc_threshold_min = int(sw_disc_threshold_obj[0])
1418 sw_disc_threshold_max = int(sw_disc_threshold_obj[1])
1419
andrewonlab53b641c2014-10-31 19:44:44 -04001420 tshark_ofp_output = "/tmp/tshark_ofp_"+num_sw+"sw.txt"
1421 tshark_tcp_output = "/tmp/tshark_tcp_"+num_sw+"sw.txt"
1422
1423 tshark_ofp_result_list = []
1424 tshark_tcp_result_list = []
andrewonlabb54b85b2014-10-28 18:43:57 -04001425
andrewonlabe5bcef92014-11-06 17:53:20 -05001426 sw_discovery_lat_list = []
1427
andrewonlab16ce4852014-10-30 13:41:09 -04001428 main.case(num_sw+" Switch discovery latency")
andrewonlabb54b85b2014-10-28 18:43:57 -04001429 main.step("Assigning all switches to ONOS1")
andrewonlab16ce4852014-10-30 13:41:09 -04001430 for i in range(1, int(num_sw)+1):
andrewonlabb54b85b2014-10-28 18:43:57 -04001431 main.Mininet1.assign_sw_controller(
1432 sw=str(i),
1433 ip1=ONOS1_ip,
1434 port1=default_sw_port)
andrewonlab16ce4852014-10-30 13:41:09 -04001435
andrewonlabb54b85b2014-10-28 18:43:57 -04001436 #Ensure that nodes are configured with ptpd
andrewonlab16ce4852014-10-30 13:41:09 -04001437 #Just a warning message
1438 main.log.info("Please check ptpd configuration to ensure"+\
1439 " All nodes' system times are in sync")
1440 time.sleep(5)
andrewonlabb54b85b2014-10-28 18:43:57 -04001441
1442 for i in range(0, int(num_iter)):
andrewonlab8d29f122014-10-22 17:15:04 -04001443
andrewonlabb54b85b2014-10-28 18:43:57 -04001444 main.step("Set iptables rule to block incoming sw connections")
1445 #Set iptables rule to block incoming switch connections
andrewonlab53b641c2014-10-31 19:44:44 -04001446 #The rule description is as follows:
1447 # Append to INPUT rule,
1448 # behavior DROP that matches following:
1449 # * packet type: tcp
1450 # * source IP: MN1_ip
1451 # * destination PORT: 6633
andrewonlabb54b85b2014-10-28 18:43:57 -04001452 main.ONOS1.handle.sendline(
andrewonlab16ce4852014-10-30 13:41:09 -04001453 "sudo iptables -A INPUT -p tcp -s "+MN1_ip+
andrewonlabb54b85b2014-10-28 18:43:57 -04001454 " --dport "+default_sw_port+" -j DROP")
1455 main.ONOS1.handle.expect("\$")
andrewonlab53b641c2014-10-31 19:44:44 -04001456 # Append to OUTPUT rule,
1457 # behavior DROP that matches following:
1458 # * packet type: tcp
1459 # * source IP: MN1_ip
1460 # * destination PORT: 6633
1461 main.ONOS1.handle.sendline(
1462 "sudo iptables -A OUTPUT -p tcp -s "+MN1_ip+
1463 " --dport "+default_sw_port+" -j DROP")
1464 main.ONOS1.handle.expect("\$")
andrewonlabb54b85b2014-10-28 18:43:57 -04001465 #Give time to allow rule to take effect
andrewonlab8790abb2014-11-06 13:51:54 -05001466 #NOTE: Sleep period may need to be configured
1467 # based on the number of switches in the topology
andrewonlab16ce4852014-10-30 13:41:09 -04001468 main.log.info("Please wait for switch connection to "+
1469 "time out")
1470 time.sleep(60)
1471
1472 #Gather vendor OFP with tshark
1473 main.ONOS1.tshark_grep("OFP 86 Vendor",
1474 tshark_ofp_output)
andrewonlab53b641c2014-10-31 19:44:44 -04001475 main.ONOS1.tshark_grep("TCP 74 ",
1476 tshark_tcp_output)
andrewonlabb54b85b2014-10-28 18:43:57 -04001477
andrewonlab16ce4852014-10-30 13:41:09 -04001478 #NOTE: Remove all iptables rule quickly (flush)
andrewonlabb54b85b2014-10-28 18:43:57 -04001479 # Before removal, obtain TestON timestamp at which
andrewonlab16ce4852014-10-30 13:41:09 -04001480 # removal took place
1481 # (ensuring nodes are configured via ptp)
andrewonlabb54b85b2014-10-28 18:43:57 -04001482 # sudo iptables -F
andrewonlab16ce4852014-10-30 13:41:09 -04001483
1484 t0_system = time.time() * 1000
1485 main.ONOS1.handle.sendline(
1486 "sudo iptables -F")
andrewonlabb54b85b2014-10-28 18:43:57 -04001487
andrewonlab16ce4852014-10-30 13:41:09 -04001488 #Counter to track loop count
1489 counter_loop = 0
1490 counter_avail1 = 0
1491 counter_avail2 = 0
1492 counter_avail3 = 0
1493 onos1_dev = False
1494 onos2_dev = False
1495 onos3_dev = False
1496 while counter_loop < 60:
1497 #Continue to check devices for all device
1498 #availability. When all devices in all 3
1499 #ONOS instances indicate that devices are available
1500 #obtain graph event timestamp for t1.
1501 device_str_obj1 = main.ONOS1cli.devices()
1502 device_str_obj2 = main.ONOS2cli.devices()
1503 device_str_obj3 = main.ONOS3cli.devices()
1504
1505 device_json1 = json.loads(device_str_obj1)
1506 device_json2 = json.loads(device_str_obj2)
1507 device_json3 = json.loads(device_str_obj3)
1508
1509 for device1 in device_json1:
1510 if device1['available'] == True:
1511 counter_avail1 += 1
1512 if counter_avail1 == int(num_sw):
1513 onos1_dev = True
1514 main.log.info("All devices have been "+
1515 "discovered on ONOS1")
1516 else:
1517 counter_avail1 = 0
1518 for device2 in device_json2:
1519 if device2['available'] == True:
1520 counter_avail2 += 1
1521 if counter_avail2 == int(num_sw):
1522 onos2_dev = True
1523 main.log.info("All devices have been "+
1524 "discovered on ONOS2")
1525 else:
1526 counter_avail2 = 0
1527 for device3 in device_json3:
1528 if device3['available'] == True:
1529 counter_avail3 += 1
1530 if counter_avail3 == int(num_sw):
1531 onos3_dev = True
1532 main.log.info("All devices have been "+
1533 "discovered on ONOS3")
1534 else:
1535 counter_avail3 = 0
1536
1537 if onos1_dev and onos2_dev and onos3_dev:
1538 main.log.info("All devices have been discovered "+
1539 "on all ONOS instances")
1540 json_str_topology_metrics_1 =\
1541 main.ONOS1cli.topology_events_metrics()
1542 json_str_topology_metrics_2 =\
1543 main.ONOS2cli.topology_events_metrics()
1544 json_str_topology_metrics_3 =\
1545 main.ONOS3cli.topology_events_metrics()
andrewonlab53b641c2014-10-31 19:44:44 -04001546
1547 #Exit while loop if all devices discovered
andrewonlab16ce4852014-10-30 13:41:09 -04001548 break
1549
1550 counter_loop += 1
1551 #Give some time in between CLI calls
1552 #(will not affect measurement)
1553 time.sleep(3)
1554
1555 main.ONOS1.tshark_stop()
1556
1557 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1558 tshark_ofp_output+" /tmp/")
andrewonlab53b641c2014-10-31 19:44:44 -04001559 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1560 tshark_tcp_output+" /tmp/")
andrewonlab16ce4852014-10-30 13:41:09 -04001561
andrewonlab16ce4852014-10-30 13:41:09 -04001562 #TODO: Automate OFP output analysis
andrewonlab58f7d702014-11-07 13:21:19 -05001563 #Debug mode - print out packets captured at runtime
1564 if debug_mode == 'on':
1565 ofp_file = open(tshark_ofp_output, 'r')
1566 main.log.info("Tshark OFP Vendor output: ")
1567 for line in ofp_file:
1568 tshark_ofp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001569 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001570 ofp_file.close()
andrewonlab16ce4852014-10-30 13:41:09 -04001571
andrewonlab58f7d702014-11-07 13:21:19 -05001572 tcp_file = open(tshark_tcp_output, 'r')
1573 main.log.info("Tshark TCP 74 output: ")
1574 for line in tcp_file:
1575 tshark_tcp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001576 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001577 tcp_file.close()
andrewonlab53b641c2014-10-31 19:44:44 -04001578
andrewonlab16ce4852014-10-30 13:41:09 -04001579 json_obj_1 = json.loads(json_str_topology_metrics_1)
1580 json_obj_2 = json.loads(json_str_topology_metrics_2)
1581 json_obj_3 = json.loads(json_str_topology_metrics_3)
1582
1583 graph_timestamp_1 = \
1584 json_obj_1[graphTimestamp]['value']
1585 graph_timestamp_2 = \
1586 json_obj_2[graphTimestamp]['value']
1587 graph_timestamp_3 = \
1588 json_obj_3[graphTimestamp]['value']
1589
andrewonlabe5bcef92014-11-06 17:53:20 -05001590 graph_lat_1 = int(graph_timestamp_1) - int(t0_system)
1591 graph_lat_2 = int(graph_timestamp_2) - int(t0_system)
1592 graph_lat_3 = int(graph_timestamp_3) - int(t0_system)
andrewonlab16ce4852014-10-30 13:41:09 -04001593
andrewonlabe5bcef92014-11-06 17:53:20 -05001594 avg_graph_lat = \
1595 (int(graph_lat_1) +\
1596 int(graph_lat_2) +\
1597 int(graph_lat_3)) / 3
1598
1599 if avg_graph_lat > sw_disc_threshold_min \
1600 and avg_graph_lat < sw_disc_threshold_max:
1601 sw_discovery_lat_list.append(
1602 avg_graph_lat)
1603 else:
1604 main.log.info("100 Switch discovery latency "+
1605 "exceeded the threshold.")
1606
1607 #END ITERATION FOR LOOP
andrewonlab16ce4852014-10-30 13:41:09 -04001608
andrewonlabe5bcef92014-11-06 17:53:20 -05001609 sw_lat_min = min(sw_discovery_lat_list)
1610 sw_lat_max = max(sw_discovery_lat_list)
1611 sw_lat_avg = sum(sw_discovery_lat_list) /\
1612 len(sw_discovery_lat_list)
andrewonlab16ce4852014-10-30 13:41:09 -04001613
andrewonlabf9828f02014-11-10 14:50:27 -05001614 main.log.report("100 Switch discovery lat "+\
1615 "Min: "+str(sw_lat_min)+" ms"+\
1616 "Max: "+str(sw_lat_max)+" ms"+\
1617 "Avg: "+str(sw_lat_avg)+" ms")
andrewonlab16ce4852014-10-30 13:41:09 -04001618
andrewonlabb54b85b2014-10-28 18:43:57 -04001619