blob: 9dd828e87e7cfcde29383144250a060770c6371f [file] [log] [blame]
andrewonlab2a6c9342014-10-16 13:40:15 -04001#TopoPerfNext
2#
3#Topology Performance test for ONOS-next
4#
5#andrew@onlab.us
6
7import time
8import sys
9import os
10import re
11
12class TopoPerfNext:
13 def __init__(self):
14 self.default = ''
15
16 def CASE1(self, main):
17 '''
18 ONOS startup sequence
19 '''
andrewonlabe9fb6722014-10-24 12:20:35 -040020 import time
21
andrewonlab2a6c9342014-10-16 13:40:15 -040022 cell_name = main.params['ENV']['cellName']
23
24 git_pull = main.params['GIT']['autoPull']
25 checkout_branch = main.params['GIT']['checkout']
26
27 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlabba44bcf2014-10-16 16:54:41 -040028 ONOS2_ip = main.params['CTRL']['ip2']
29 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab2a6c9342014-10-16 13:40:15 -040030 MN1_ip = main.params['MN']['ip1']
31 BENCH_ip = main.params['BENCH']['ip']
32
33 main.case("Setting up test environment")
34
35 main.step("Creating cell file")
36 cell_file_result = main.ONOSbench.create_cell_file(
andrewonlabe6745342014-10-17 14:29:13 -040037 BENCH_ip, cell_name, MN1_ip, "onos-core",
andrewonlabba44bcf2014-10-16 16:54:41 -040038 ONOS1_ip, ONOS2_ip, ONOS3_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -040039
40 main.step("Applying cell file to environment")
41 cell_apply_result = main.ONOSbench.set_cell(cell_name)
42 verify_cell_result = main.ONOSbench.verify_cell()
43
44 main.step("Git checkout and pull "+checkout_branch)
45 if git_pull == 'on':
46 checkout_result = \
47 main.ONOSbench.git_checkout(checkout_branch)
48 pull_result = main.ONOSbench.git_pull()
49 else:
50 checkout_result = main.TRUE
51 pull_result = main.TRUE
52 main.log.info("Skipped git checkout and pull")
53
54 main.step("Using mvn clean & install")
andrewonlab8d29f122014-10-22 17:15:04 -040055 #mvn_result = main.ONOSbench.clean_install()
56 mvn_result = main.TRUE
andrewonlab2a6c9342014-10-16 13:40:15 -040057
58 main.step("Creating ONOS package")
59 package_result = main.ONOSbench.onos_package()
60
61 main.step("Installing ONOS package")
andrewonlabe9fb6722014-10-24 12:20:35 -040062 install1_result = main.ONOSbench.onos_install(node=ONOS1_ip)
63 install2_result = main.ONOSbench.onos_install(node=ONOS2_ip)
64 install3_result = main.ONOSbench.onos_install(node=ONOS3_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -040065
andrewonlabe9fb6722014-10-24 12:20:35 -040066 #NOTE: This step may be unnecessary
67 #main.step("Starting ONOS service")
68 #start_result = main.ONOSbench.onos_start(ONOS1_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -040069
andrewonlab867212a2014-10-22 20:13:38 -040070 main.step("Set cell for ONOS cli env")
71 main.ONOS1cli.set_cell(cell_name)
72 main.ONOS2cli.set_cell(cell_name)
73 main.ONOS3cli.set_cell(cell_name)
74
andrewonlabe9fb6722014-10-24 12:20:35 -040075 time.sleep(10)
76
andrewonlab867212a2014-10-22 20:13:38 -040077 main.step("Start onos cli")
andrewonlabe9fb6722014-10-24 12:20:35 -040078 cli1 = main.ONOS1cli.start_onos_cli(ONOS1_ip)
79 cli2 = main.ONOS2cli.start_onos_cli(ONOS2_ip)
80 cli3 = main.ONOS3cli.start_onos_cli(ONOS3_ip)
81
andrewonlab867212a2014-10-22 20:13:38 -040082 main.step("Enable metrics feature")
83 main.ONOS1cli.feature_install("onos-app-metrics-topology")
84 main.ONOS2cli.feature_install("onos-app-metrics-topology")
85 main.ONOS3cli.feature_install("onos-app-metrics-topology")
86
andrewonlab2a6c9342014-10-16 13:40:15 -040087 utilities.assert_equals(expect=main.TRUE,
88 actual= cell_file_result and cell_apply_result and\
89 verify_cell_result and checkout_result and\
90 pull_result and mvn_result and\
andrewonlabe9fb6722014-10-24 12:20:35 -040091 install1_result and install2_result and\
92 install3_result,
andrewonlab8d29f122014-10-22 17:15:04 -040093 onpass="ONOS started successfully",
94 onfail="Failed to start ONOS")
andrewonlab2a6c9342014-10-16 13:40:15 -040095
andrewonlabba44bcf2014-10-16 16:54:41 -040096 def CASE2(self, main):
97 '''
98 Assign s1 to ONOS1 and measure latency
andrewonlab3a7c3c72014-10-24 17:21:03 -040099
100 There are 4 levels of latency measurements to this test:
101 1) End-to-end measurement: Complete end-to-end measurement
102 from TCP (SYN/ACK) handshake to Graph change
103 2) OFP-to-graph measurement: 'ONOS processing' snippet of
104 measurement from OFP Vendor message to Graph change
105 3) OFP-to-device measurement: 'ONOS processing without
106 graph change' snippet of measurement from OFP vendor
107 message to Device change timestamp
108 4) T0-to-device measurement: Measurement that includes
109 the switch handshake to devices timestamp without
110 the graph view change. (TCP handshake -> Device
111 change)
andrewonlabba44bcf2014-10-16 16:54:41 -0400112 '''
113 import time
andrewonlabe6745342014-10-17 14:29:13 -0400114 import subprocess
115 import json
116 import requests
117 import os
andrewonlabba44bcf2014-10-16 16:54:41 -0400118
119 ONOS1_ip = main.params['CTRL']['ip1']
120 ONOS2_ip = main.params['CTRL']['ip2']
121 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlabe6745342014-10-17 14:29:13 -0400122 ONOS_user = main.params['CTRL']['user']
123
andrewonlabba44bcf2014-10-16 16:54:41 -0400124 default_sw_port = main.params['CTRL']['port1']
125
126 #Number of iterations of case
127 num_iter = main.params['TEST']['numIter']
128
andrewonlab226024e2014-10-24 16:01:32 -0400129 #Timestamp 'keys' for json metrics output.
130 #These are subject to change, hence moved into params
131 deviceTimestamp = main.params['JSON']['deviceTimestamp']
132 graphTimestamp = main.params['JSON']['graphTimestamp']
133
andrewonlab58f7d702014-11-07 13:21:19 -0500134 debug_mode = main.params['TEST']['debugMode']
135
andrewonlabe5bcef92014-11-06 17:53:20 -0500136 #Threshold for the test
137 threshold_str = main.params['TEST']['singleSwThreshold']
138 threshold_obj = threshold_str.split(",")
139 threshold_min = int(threshold_obj[0])
140 threshold_max = int(threshold_obj[1])
141
andrewonlab226024e2014-10-24 16:01:32 -0400142 #List of switch add latency collected from
143 #all iterations
144 latency_end_to_end_list = []
145 latency_ofp_to_graph_list = []
146 latency_ofp_to_device_list = []
147 latency_t0_to_device_list = []
148
andrewonlabba44bcf2014-10-16 16:54:41 -0400149 #Directory/file to store tshark results
150 tshark_of_output = "/tmp/tshark_of_topo.txt"
151 tshark_tcp_output = "/tmp/tshark_tcp_topo.txt"
152
153 #String to grep in tshark output
154 tshark_tcp_string = "TCP 74 "+default_sw_port
155 tshark_of_string = "OFP 86 Vendor"
andrewonlabe6745342014-10-17 14:29:13 -0400156
157 #Initialize assertion to TRUE
158 assertion = main.TRUE
andrewonlab58f7d702014-11-07 13:21:19 -0500159
160 local_time = time.strftime('%x %X')
161 if debug_mode == 'on':
162 main.ONOS1.tshark_pcap("eth0",
163 "/tmp/single_sw_lat_pcap"+local_time)
164
andrewonlabba44bcf2014-10-16 16:54:41 -0400165 main.log.report("Latency of adding one switch")
166
167 for i in range(0, int(num_iter)):
168 main.log.info("Starting tshark capture")
169
170 #* TCP [ACK, SYN] is used as t0_a, the
171 # very first "exchange" between ONOS and
172 # the switch for end-to-end measurement
173 #* OFP [Stats Reply] is used for t0_b
174 # the very last OFP message between ONOS
175 # and the switch for ONOS measurement
176 main.ONOS1.tshark_grep(tshark_tcp_string,
177 tshark_tcp_output)
178 main.ONOS1.tshark_grep(tshark_of_string,
179 tshark_of_output)
180
181 #Wait and ensure tshark is started and
182 #capturing
183 time.sleep(10)
184
185 main.log.info("Assigning s1 to controller")
186
187 main.Mininet1.assign_sw_controller(sw="1",
188 ip1=ONOS1_ip, port1=default_sw_port)
189
190 #Wait and ensure switch is assigned
191 #before stopping tshark
andrewonlab867212a2014-10-22 20:13:38 -0400192 time.sleep(30)
andrewonlab226024e2014-10-24 16:01:32 -0400193
194 main.log.info("Stopping all Tshark processes")
andrewonlabba44bcf2014-10-16 16:54:41 -0400195 main.ONOS1.stop_tshark()
196
andrewonlabe6745342014-10-17 14:29:13 -0400197 #tshark output is saved in ONOS. Use subprocess
198 #to copy over files to TestON for parsing
199 main.log.info("Copying over tshark files")
200
201 #TCP CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400202 #Copy the tshark output from ONOS machine to
203 #TestON machine in tshark_tcp_output directory>file
204 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
205 tshark_tcp_output+" /tmp/")
206 tcp_file = open(tshark_tcp_output, 'r')
207 temp_text = tcp_file.readline()
andrewonlabe6745342014-10-17 14:29:13 -0400208 temp_text = temp_text.split(" ")
andrewonlabba44bcf2014-10-16 16:54:41 -0400209
andrewonlabe6745342014-10-17 14:29:13 -0400210 main.log.info("Object read in from TCP capture: "+
211 str(temp_text))
andrewonlab867212a2014-10-22 20:13:38 -0400212 if len(temp_text) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400213 t0_tcp = float(temp_text[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400214 else:
215 main.log.error("Tshark output file for TCP"+
216 " returned unexpected results")
217 t0_tcp = 0
218 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400219
220 tcp_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400221 #****************
andrewonlabba44bcf2014-10-16 16:54:41 -0400222
andrewonlabe6745342014-10-17 14:29:13 -0400223 #OF CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400224 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
225 tshark_of_output+" /tmp/")
226 of_file = open(tshark_of_output, 'r')
227
228 line_ofp = ""
andrewonlab226024e2014-10-24 16:01:32 -0400229 #Read until last line of file
andrewonlabe6745342014-10-17 14:29:13 -0400230 while True:
andrewonlab8d29f122014-10-22 17:15:04 -0400231 temp_text = of_file.readline()
232 if temp_text !='':
andrewonlabe6745342014-10-17 14:29:13 -0400233 line_ofp = temp_text
234 else:
235 break
236 obj = line_ofp.split(" ")
237
238 main.log.info("Object read in from OFP capture: "+
239 str(line_ofp))
240
andrewonlab867212a2014-10-22 20:13:38 -0400241 if len(line_ofp) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400242 t0_ofp = float(obj[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400243 else:
244 main.log.error("Tshark output file for OFP"+
245 " returned unexpected results")
246 t0_ofp = 0
247 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400248
249 of_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400250 #****************
251
andrewonlab867212a2014-10-22 20:13:38 -0400252 json_str_1 = main.ONOS1cli.topology_events_metrics()
253 json_str_2 = main.ONOS2cli.topology_events_metrics()
254 json_str_3 = main.ONOS3cli.topology_events_metrics()
andrewonlab867212a2014-10-22 20:13:38 -0400255
256 json_obj_1 = json.loads(json_str_1)
257 json_obj_2 = json.loads(json_str_2)
258 json_obj_3 = json.loads(json_str_3)
259
andrewonlab226024e2014-10-24 16:01:32 -0400260 #Obtain graph timestamp. This timestsamp captures
261 #the epoch time at which the topology graph was updated.
262 graph_timestamp_1 = \
263 json_obj_1[graphTimestamp]['value']
264 graph_timestamp_2 = \
265 json_obj_2[graphTimestamp]['value']
266 graph_timestamp_3 = \
267 json_obj_3[graphTimestamp]['value']
andrewonlab867212a2014-10-22 20:13:38 -0400268
andrewonlab226024e2014-10-24 16:01:32 -0400269 #Obtain device timestamp. This timestamp captures
270 #the epoch time at which the device event happened
271 device_timestamp_1 = \
272 json_obj_1[deviceTimestamp]['value']
273 device_timestamp_2 = \
274 json_obj_2[deviceTimestamp]['value']
275 device_timestamp_3 = \
276 json_obj_3[deviceTimestamp]['value']
andrewonlabe9fb6722014-10-24 12:20:35 -0400277
andrewonlab226024e2014-10-24 16:01:32 -0400278 #t0 to device processing latency
279 delta_device_1 = int(device_timestamp_1) - int(t0_tcp)
280 delta_device_2 = int(device_timestamp_2) - int(t0_tcp)
281 delta_device_3 = int(device_timestamp_3) - int(t0_tcp)
282
283 #Get average of delta from all instances
284 avg_delta_device = \
285 (int(delta_device_1)+\
286 int(delta_device_2)+\
287 int(delta_device_3)) / 3
andrewonlabba44bcf2014-10-16 16:54:41 -0400288
andrewonlab226024e2014-10-24 16:01:32 -0400289 #Ensure avg delta meets the threshold before appending
290 if avg_delta_device > 0.0 and avg_delta_device < 10000:
291 latency_t0_to_device_list.append(avg_delta_device)
andrewonlabee4efeb2014-10-24 16:44:51 -0400292 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400293 main.log.info("Results for t0-to-device ignored"+\
294 "due to excess in threshold")
andrewonlabee4efeb2014-10-24 16:44:51 -0400295
andrewonlab226024e2014-10-24 16:01:32 -0400296 #t0 to graph processing latency (end-to-end)
297 delta_graph_1 = int(graph_timestamp_1) - int(t0_tcp)
298 delta_graph_2 = int(graph_timestamp_2) - int(t0_tcp)
299 delta_graph_3 = int(graph_timestamp_3) - int(t0_tcp)
300
301 #Get average of delta from all instances
302 avg_delta_graph = \
303 (int(delta_graph_1)+\
304 int(delta_graph_2)+\
305 int(delta_graph_3)) / 3
306
andrewonlab226024e2014-10-24 16:01:32 -0400307 #Ensure avg delta meets the threshold before appending
308 if avg_delta_graph > 0.0 and avg_delta_graph < 10000:
andrewonlab09d973e2014-10-24 18:56:58 -0400309 latency_end_to_end_list.append(avg_delta_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400310 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400311 main.log.info("Results for end-to-end ignored"+\
312 "due to excess in threshold")
andrewonlab226024e2014-10-24 16:01:32 -0400313
314 #ofp to graph processing latency (ONOS processing)
315 delta_ofp_graph_1 = int(graph_timestamp_1) - int(t0_ofp)
316 delta_ofp_graph_2 = int(graph_timestamp_2) - int(t0_ofp)
317 delta_ofp_graph_3 = int(graph_timestamp_3) - int(t0_ofp)
318
319 avg_delta_ofp_graph = \
320 (int(delta_ofp_graph_1)+\
321 int(delta_ofp_graph_2)+\
322 int(delta_ofp_graph_3)) / 3
323
andrewonlabe5bcef92014-11-06 17:53:20 -0500324 if avg_delta_ofp_graph > threshold_min \
325 and avg_delta_ofp_graph < threshold_max:
andrewonlab226024e2014-10-24 16:01:32 -0400326 latency_ofp_to_graph_list.append(avg_delta_ofp_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400327 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400328 main.log.info("Results for ofp-to-graph "+\
329 "ignored due to excess in threshold")
andrewonlabee4efeb2014-10-24 16:44:51 -0400330
andrewonlab226024e2014-10-24 16:01:32 -0400331 #ofp to device processing latency (ONOS processing)
andrewonlabee4efeb2014-10-24 16:44:51 -0400332 delta_ofp_device_1 = float(device_timestamp_1) - float(t0_ofp)
333 delta_ofp_device_2 = float(device_timestamp_2) - float(t0_ofp)
334 delta_ofp_device_3 = float(device_timestamp_3) - float(t0_ofp)
andrewonlab226024e2014-10-24 16:01:32 -0400335
336 avg_delta_ofp_device = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400337 (float(delta_ofp_device_1)+\
338 float(delta_ofp_device_2)+\
339 float(delta_ofp_device_3)) / 3.0
andrewonlab226024e2014-10-24 16:01:32 -0400340
andrewonlabf47993a2014-10-24 17:56:01 -0400341 #NOTE: ofp - delta measurements are occasionally negative
342 # due to system time misalignment.
andrewonlabf47993a2014-10-24 17:56:01 -0400343 latency_ofp_to_device_list.append(avg_delta_ofp_device)
andrewonlabba44bcf2014-10-16 16:54:41 -0400344
andrewonlabe6745342014-10-17 14:29:13 -0400345 #TODO:
346 #Fetch logs upon threshold excess
andrewonlabba44bcf2014-10-16 16:54:41 -0400347
andrewonlab226024e2014-10-24 16:01:32 -0400348 main.log.info("ONOS1 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400349 str(delta_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400350 main.log.info("ONOS2 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400351 str(delta_graph_2) + " ms")
352 main.log.info("ONOS3 delta end-to-end: "+
353 str(delta_graph_3) + " ms")
andrewonlabba44bcf2014-10-16 16:54:41 -0400354
andrewonlab226024e2014-10-24 16:01:32 -0400355 main.log.info("ONOS1 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400356 str(delta_ofp_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400357 main.log.info("ONOS2 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400358 str(delta_ofp_graph_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400359 main.log.info("ONOS3 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400360 str(delta_ofp_graph_3) + " ms")
andrewonlabe6745342014-10-17 14:29:13 -0400361
andrewonlab226024e2014-10-24 16:01:32 -0400362 main.log.info("ONOS1 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400363 str(delta_device_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400364 main.log.info("ONOS2 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400365 str(delta_device_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400366 main.log.info("ONOS3 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400367 str(delta_device_3) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400368
andrewonlab8790abb2014-11-06 13:51:54 -0500369 #main.log.info("ONOS1 delta OFP - device: "+
370 # str(delta_ofp_device_1) + " ms")
371 #main.log.info("ONOS2 delta OFP - device: "+
372 # str(delta_ofp_device_2) + " ms")
373 #main.log.info("ONOS3 delta OFP - device: "+
374 # str(delta_ofp_device_3) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400375
andrewonlab8d29f122014-10-22 17:15:04 -0400376 main.step("Remove switch from controller")
377 main.Mininet1.delete_sw_controller("s1")
andrewonlabba44bcf2014-10-16 16:54:41 -0400378
andrewonlab8d29f122014-10-22 17:15:04 -0400379 time.sleep(5)
andrewonlabba44bcf2014-10-16 16:54:41 -0400380
andrewonlab09d973e2014-10-24 18:56:58 -0400381 #END of for loop iteration
andrewonlabf47993a2014-10-24 17:56:01 -0400382
andrewonlabee4efeb2014-10-24 16:44:51 -0400383 #If there is at least 1 element in each list,
andrewonlabc15c9582014-10-24 16:35:52 -0400384 #pass the test case
385 if len(latency_end_to_end_list) > 0 and\
386 len(latency_ofp_to_graph_list) > 0 and\
387 len(latency_ofp_to_device_list) > 0 and\
388 len(latency_t0_to_device_list) > 0:
389 assertion = main.TRUE
andrewonlabf47993a2014-10-24 17:56:01 -0400390 elif len(latency_end_to_end_list) == 0:
391 #The appending of 0 here is to prevent
392 #the min,max,sum functions from failing
393 #below
394 latency_end_to_end_list.append(0)
395 assertion = main.FALSE
396 elif len(latency_ofp_to_graph_list) == 0:
397 latency_ofp_to_graph_list.append(0)
398 assertion = main.FALSE
399 elif len(latency_ofp_to_device_list) == 0:
400 latency_ofp_to_device_list.append(0)
401 assertion = main.FALSE
402 elif len(latency_t0_to_device_list) == 0:
403 latency_t0_to_device_list.append(0)
404 assertion = main.FALSE
andrewonlabc15c9582014-10-24 16:35:52 -0400405
406 #Calculate min, max, avg of latency lists
407 latency_end_to_end_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400408 int(max(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400409 latency_end_to_end_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400410 int(min(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400411 latency_end_to_end_avg = \
andrewonlabc90667c2014-10-24 16:48:28 -0400412 (int(sum(latency_end_to_end_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400413 len(latency_end_to_end_list))
414
415 latency_ofp_to_graph_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400416 int(max(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400417 latency_ofp_to_graph_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400418 int(min(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400419 latency_ofp_to_graph_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400420 (int(sum(latency_ofp_to_graph_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400421 len(latency_ofp_to_graph_list))
422
423 latency_ofp_to_device_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400424 int(max(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400425 latency_ofp_to_device_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400426 int(min(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400427 latency_ofp_to_device_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400428 (int(sum(latency_ofp_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400429 len(latency_ofp_to_device_list))
430
431 latency_t0_to_device_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400432 float(max(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400433 latency_t0_to_device_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400434 float(min(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400435 latency_t0_to_device_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400436 (float(sum(latency_t0_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400437 len(latency_ofp_to_device_list))
438
439 main.log.report("Switch add - End-to-end latency: \n"+\
andrewonlab58f7d702014-11-07 13:21:19 -0500440 "Min: "+str(latency_end_to_end_min)+" mx\n"+\
441 "Max: "+str(latency_end_to_end_max)+" ms\n"+\
442 "Avg: "+str(latency_end_to_end_avg)+" ms")
andrewonlabc15c9582014-10-24 16:35:52 -0400443 main.log.report("Switch add - OFP-to-Graph latency: \n"+\
andrewonlab58f7d702014-11-07 13:21:19 -0500444 "Min: "+str(latency_ofp_to_graph_min)+" ms \n"+\
445 "Max: "+str(latency_ofp_to_graph_max)+" ms\n"+\
446 "Avg: "+str(latency_ofp_to_graph_avg)+" ms")
andrewonlabc15c9582014-10-24 16:35:52 -0400447 main.log.report("Switch add - t0-to-Device latency: \n"+\
andrewonlab58f7d702014-11-07 13:21:19 -0500448 "Min: "+str(latency_t0_to_device_min)+" ms\n"+\
449 "Max: "+str(latency_t0_to_device_max)+" ms\n"+\
450 "Avg: "+str(latency_t0_to_device_avg)+" ms")
andrewonlab226024e2014-10-24 16:01:32 -0400451
andrewonlab8d29f122014-10-22 17:15:04 -0400452 utilities.assert_equals(expect=main.TRUE, actual=assertion,
453 onpass="Switch latency test successful",
454 onfail="Switch latency test failed")
andrewonlabba44bcf2014-10-16 16:54:41 -0400455
andrewonlab8d29f122014-10-22 17:15:04 -0400456 def CASE3(self, main):
457 '''
458 Bring port up / down and measure latency.
459 Port enable / disable is simulated by ifconfig up / down
andrewonlab393531a2014-10-27 18:36:26 -0400460
461 In ONOS-next, we must ensure that the port we are
462 manipulating is connected to another switch with a valid
463 connection. Otherwise, graph view will not be updated.
andrewonlab8d29f122014-10-22 17:15:04 -0400464 '''
465 import time
466 import subprocess
467 import os
468 import requests
469 import json
andrewonlab2a6c9342014-10-16 13:40:15 -0400470
andrewonlab8d29f122014-10-22 17:15:04 -0400471 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlab393531a2014-10-27 18:36:26 -0400472 ONOS2_ip = main.params['CTRL']['ip2']
473 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab8d29f122014-10-22 17:15:04 -0400474 ONOS_user = main.params['CTRL']['user']
andrewonlab8d29f122014-10-22 17:15:04 -0400475
andrewonlab393531a2014-10-27 18:36:26 -0400476 default_sw_port = main.params['CTRL']['port1']
andrewonlab8790abb2014-11-06 13:51:54 -0500477
478 assertion = main.TRUE
andrewonlab393531a2014-10-27 18:36:26 -0400479 #Number of iterations of case
480 num_iter = main.params['TEST']['numIter']
481
482 #Timestamp 'keys' for json metrics output.
483 #These are subject to change, hence moved into params
484 deviceTimestamp = main.params['JSON']['deviceTimestamp']
485 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500486
487 debug_mode = main.params['TEST']['debugMode']
488
489 local_time = time.strftime('%x %X')
490 if debug_mode == 'on':
491 main.ONOS1.tshark_pcap("eth0",
492 "/tmp/port_lat_pcap"+local_time)
andrewonlab393531a2014-10-27 18:36:26 -0400493
andrewonlabe5bcef92014-11-06 17:53:20 -0500494 #Threshold for this test case
495 up_threshold_str = main.params['TEST']['portUpThreshold']
496 down_threshold_str = main.params['TEST']['portDownThreshold']
497 up_threshold_obj = up_threshold_str.split(",")
498 down_threshold_obj = down_threshold_str.split(",")
499
500 up_threshold_min = int(up_threshold_obj[0])
501 up_threshold_max = int(up_threshold_obj[1])
502
503 down_threshold_min = int(down_threshold_obj[0])
504 down_threshold_max = int(down_threshold_obj[1])
505
andrewonlab393531a2014-10-27 18:36:26 -0400506 #NOTE: Some hardcoded variables you may need to configure
507 # besides the params
508
andrewonlab8d29f122014-10-22 17:15:04 -0400509 tshark_port_status = "OFP 130 Port Status"
510
511 tshark_port_up = "/tmp/tshark_port_up.txt"
512 tshark_port_down = "/tmp/tshark_port_down.txt"
andrewonlab393531a2014-10-27 18:36:26 -0400513 interface_config = "s1-eth1"
andrewonlab8d29f122014-10-22 17:15:04 -0400514
515 main.log.report("Port enable / disable latency")
516
andrewonlab393531a2014-10-27 18:36:26 -0400517 main.step("Assign switches s1 and s2 to controller 1")
andrewonlab8d29f122014-10-22 17:15:04 -0400518 main.Mininet1.assign_sw_controller(sw="1",ip1=ONOS1_ip,
519 port1=default_sw_port)
andrewonlab393531a2014-10-27 18:36:26 -0400520 main.Mininet1.assign_sw_controller(sw="2",ip1=ONOS1_ip,
521 port1=default_sw_port)
andrewonlab8d29f122014-10-22 17:15:04 -0400522
andrewonlab8790abb2014-11-06 13:51:54 -0500523 #Give enough time for metrics to propagate the
524 #assign controller event. Otherwise, these events may
525 #carry over to our measurements
526 time.sleep(10)
527
andrewonlab8d29f122014-10-22 17:15:04 -0400528 main.step("Verify switch is assigned correctly")
529 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
andrewonlab393531a2014-10-27 18:36:26 -0400530 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
531 if result_s1 == main.FALSE or result_s2 == main.FALSE:
andrewonlab8d29f122014-10-22 17:15:04 -0400532 main.log.info("Switch s1 was not assigned correctly")
533 assertion = main.FALSE
534 else:
535 main.log.info("Switch s1 was assigned correctly")
536
andrewonlab393531a2014-10-27 18:36:26 -0400537 port_up_device_to_ofp_list = []
538 port_up_graph_to_ofp_list = []
539 port_down_device_to_ofp_list = []
540 port_down_graph_to_ofp_list = []
541
andrewonlab8d29f122014-10-22 17:15:04 -0400542 for i in range(0, int(num_iter)):
543 main.step("Starting wireshark capture for port status down")
544 main.ONOS1.tshark_grep(tshark_port_status,
545 tshark_port_down)
546
547 time.sleep(10)
548
andrewonlab393531a2014-10-27 18:36:26 -0400549 #Disable interface that is connected to switch 2
550 main.step("Disable port: "+interface_config)
551 main.Mininet2.handle.sendline("sudo ifconfig "+
552 interface_config+" down")
andrewonlab8d29f122014-10-22 17:15:04 -0400553 main.Mininet2.handle.expect("\$")
andrewonlab8790abb2014-11-06 13:51:54 -0500554 time.sleep(10)
andrewonlab8d29f122014-10-22 17:15:04 -0400555
556 main.ONOS1.tshark_stop()
557 time.sleep(5)
558
559 #Copy tshark output file from ONOS to TestON instance
560 #/tmp directory
561 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
562 tshark_port_down+" /tmp/")
563
564 f_port_down = open(tshark_port_down, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400565 #Get first line of port down event from tshark
andrewonlab8d29f122014-10-22 17:15:04 -0400566 f_line = f_port_down.readline()
567 obj_down = f_line.split(" ")
568 if len(f_line) > 0:
andrewonlab393531a2014-10-27 18:36:26 -0400569 timestamp_begin_pt_down = int(float(obj_down[1]))*1000
570 main.log.info("Port down begin timestamp: "+
571 str(timestamp_begin_pt_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400572 else:
573 main.log.info("Tshark output file returned unexpected"+
andrewonlab393531a2014-10-27 18:36:26 -0400574 " results: "+str(obj_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400575 timestamp_begin_pt_down = 0
andrewonlab393531a2014-10-27 18:36:26 -0400576
577 f_port_down.close()
andrewonlab8d29f122014-10-22 17:15:04 -0400578
andrewonlab4e124482014-11-04 13:37:25 -0500579 main.log.info("TEST tshark obj: "+str(obj_down))
580
andrewonlab8d29f122014-10-22 17:15:04 -0400581 main.step("Obtain t1 by REST call")
andrewonlab393531a2014-10-27 18:36:26 -0400582 json_str_1 = main.ONOS1cli.topology_events_metrics()
583 json_str_2 = main.ONOS2cli.topology_events_metrics()
584 json_str_3 = main.ONOS3cli.topology_events_metrics()
andrewonlab8d29f122014-10-22 17:15:04 -0400585
andrewonlab4e124482014-11-04 13:37:25 -0500586 main.log.info("TEST json_str 1: "+str(json_str_1))
587
andrewonlab393531a2014-10-27 18:36:26 -0400588 json_obj_1 = json.loads(json_str_1)
589 json_obj_2 = json.loads(json_str_2)
590 json_obj_3 = json.loads(json_str_3)
andrewonlab8d29f122014-10-22 17:15:04 -0400591
andrewonlab393531a2014-10-27 18:36:26 -0400592 time.sleep(5)
593
594 #Obtain graph timestamp. This timestsamp captures
595 #the epoch time at which the topology graph was updated.
596 graph_timestamp_1 = \
597 json_obj_1[graphTimestamp]['value']
598 graph_timestamp_2 = \
599 json_obj_2[graphTimestamp]['value']
600 graph_timestamp_3 = \
601 json_obj_3[graphTimestamp]['value']
602
andrewonlab393531a2014-10-27 18:36:26 -0400603 #Obtain device timestamp. This timestamp captures
604 #the epoch time at which the device event happened
605 device_timestamp_1 = \
606 json_obj_1[deviceTimestamp]['value']
607 device_timestamp_2 = \
608 json_obj_2[deviceTimestamp]['value']
609 device_timestamp_3 = \
610 json_obj_3[deviceTimestamp]['value']
andrewonlab393531a2014-10-27 18:36:26 -0400611
612 #Get delta between graph event and OFP
613 pt_down_graph_to_ofp_1 = int(graph_timestamp_1) -\
614 int(timestamp_begin_pt_down)
615 pt_down_graph_to_ofp_2 = int(graph_timestamp_2) -\
616 int(timestamp_begin_pt_down)
617 pt_down_graph_to_ofp_3 = int(graph_timestamp_3) -\
618 int(timestamp_begin_pt_down)
619
620 #Get delta between device event and OFP
621 pt_down_device_to_ofp_1 = int(device_timestamp_1) -\
622 int(timestamp_begin_pt_down)
623 pt_down_device_to_ofp_2 = int(device_timestamp_2) -\
624 int(timestamp_begin_pt_down)
625 pt_down_device_to_ofp_3 = int(device_timestamp_3) -\
626 int(timestamp_begin_pt_down)
627
628 #Caluclate average across clusters
629 pt_down_graph_to_ofp_avg =\
630 (int(pt_down_graph_to_ofp_1) +
631 int(pt_down_graph_to_ofp_2) +
andrewonlab8790abb2014-11-06 13:51:54 -0500632 int(pt_down_graph_to_ofp_3)) / 3.0
andrewonlab393531a2014-10-27 18:36:26 -0400633 pt_down_device_to_ofp_avg = \
634 (int(pt_down_device_to_ofp_1) +
635 int(pt_down_device_to_ofp_2) +
andrewonlab8790abb2014-11-06 13:51:54 -0500636 int(pt_down_device_to_ofp_3)) / 3.0
andrewonlab393531a2014-10-27 18:36:26 -0400637
andrewonlab4e124482014-11-04 13:37:25 -0500638 if pt_down_graph_to_ofp_avg > 0.0 and \
andrewonlab393531a2014-10-27 18:36:26 -0400639 pt_down_graph_to_ofp_avg < 1000:
640 port_down_graph_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500641 pt_down_graph_to_ofp_avg)
642 main.log.info("Port down: graph to ofp avg: "+
643 str(pt_down_graph_to_ofp_avg) + " ms")
andrewonlab393531a2014-10-27 18:36:26 -0400644 else:
645 main.log.info("Average port down graph-to-ofp result" +
646 " exceeded the threshold: "+
647 str(pt_down_graph_to_ofp_avg))
648
andrewonlab3622beb2014-10-28 16:07:56 -0400649 if pt_down_device_to_ofp_avg > 0 and \
650 pt_down_device_to_ofp_avg < 1000:
651 port_down_device_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500652 pt_down_device_to_ofp_avg)
653 main.log.info("Port down: device to ofp avg: "+
654 str(pt_down_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400655 else:
656 main.log.info("Average port down device-to-ofp result" +
657 " exceeded the threshold: "+
658 str(pt_down_device_to_ofp_avg))
659
andrewonlab8d29f122014-10-22 17:15:04 -0400660 #Port up events
661 main.step("Enable port and obtain timestamp")
662 main.step("Starting wireshark capture for port status up")
663 main.ONOS1.tshark_grep("OFP 130 Port Status", tshark_port_up)
andrewonlab8790abb2014-11-06 13:51:54 -0500664 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400665
andrewonlab393531a2014-10-27 18:36:26 -0400666 main.Mininet2.handle.sendline("sudo ifconfig "+
667 interface_config+" up")
andrewonlab8d29f122014-10-22 17:15:04 -0400668 main.Mininet2.handle.expect("\$")
andrewonlab8790abb2014-11-06 13:51:54 -0500669 time.sleep(10)
670
671 main.ONOS1.tshark_stop()
andrewonlab8d29f122014-10-22 17:15:04 -0400672
673 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
674 tshark_port_up+" /tmp/")
675
676 f_port_up = open(tshark_port_up, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400677 f_line = f_port_up.readline()
andrewonlab8d29f122014-10-22 17:15:04 -0400678 obj_up = f_line.split(" ")
679 if len(f_line) > 0:
andrewonlab393531a2014-10-27 18:36:26 -0400680 timestamp_begin_pt_up = int(float(obj_up[1]))*1000
681 main.log.info("Port up begin timestamp: "+
682 str(timestamp_begin_pt_up))
andrewonlab8d29f122014-10-22 17:15:04 -0400683 else:
684 main.log.info("Tshark output file returned unexpected"+
685 " results.")
686 timestamp_begin_pt_up = 0
687
andrewonlab393531a2014-10-27 18:36:26 -0400688 f_port_up.close()
689
andrewonlab8d29f122014-10-22 17:15:04 -0400690 main.step("Obtain t1 by REST call")
andrewonlab393531a2014-10-27 18:36:26 -0400691 json_str_1 = main.ONOS1cli.topology_events_metrics()
692 json_str_2 = main.ONOS2cli.topology_events_metrics()
693 json_str_3 = main.ONOS3cli.topology_events_metrics()
andrewonlab8d29f122014-10-22 17:15:04 -0400694
andrewonlab393531a2014-10-27 18:36:26 -0400695 json_obj_1 = json.loads(json_str_1)
696 json_obj_2 = json.loads(json_str_2)
697 json_obj_3 = json.loads(json_str_3)
andrewonlab8d29f122014-10-22 17:15:04 -0400698
andrewonlab393531a2014-10-27 18:36:26 -0400699 #Obtain graph timestamp. This timestsamp captures
700 #the epoch time at which the topology graph was updated.
701 graph_timestamp_1 = \
702 json_obj_1[graphTimestamp]['value']
703 graph_timestamp_2 = \
704 json_obj_2[graphTimestamp]['value']
705 graph_timestamp_3 = \
706 json_obj_3[graphTimestamp]['value']
707
708 #Obtain device timestamp. This timestamp captures
709 #the epoch time at which the device event happened
710 device_timestamp_1 = \
711 json_obj_1[deviceTimestamp]['value']
712 device_timestamp_2 = \
713 json_obj_2[deviceTimestamp]['value']
714 device_timestamp_3 = \
715 json_obj_3[deviceTimestamp]['value']
716
717 #Get delta between graph event and OFP
718 pt_up_graph_to_ofp_1 = int(graph_timestamp_1) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400719 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400720 pt_up_graph_to_ofp_2 = int(graph_timestamp_2) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400721 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400722 pt_up_graph_to_ofp_3 = int(graph_timestamp_3) -\
723 int(timestamp_begin_pt_up)
724
725 #Get delta between device event and OFP
726 pt_up_device_to_ofp_1 = int(device_timestamp_1) -\
727 int(timestamp_begin_pt_up)
728 pt_up_device_to_ofp_2 = int(device_timestamp_2) -\
729 int(timestamp_begin_pt_up)
730 pt_up_device_to_ofp_3 = int(device_timestamp_3) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400731 int(timestamp_begin_pt_up)
andrewonlab3622beb2014-10-28 16:07:56 -0400732
733 pt_up_graph_to_ofp_avg = \
734 (float(pt_up_graph_to_ofp_1) +
735 float(pt_up_graph_to_ofp_2) +
736 float(pt_up_graph_to_ofp_3)) / 3
737
738 pt_up_device_to_ofp_avg = \
739 (float(pt_up_device_to_ofp_1) +
740 float(pt_up_device_to_ofp_2) +
741 float(pt_up_device_to_ofp_3)) / 3
742
andrewonlabe5bcef92014-11-06 17:53:20 -0500743 if pt_up_graph_to_ofp_avg > up_threshold_min and \
744 pt_up_graph_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400745 port_up_graph_to_ofp_list.append(
746 pt_up_graph_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500747 main.log.info("Port down: graph to ofp avg: "+
748 str(pt_up_graph_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400749 else:
750 main.log.info("Average port up graph-to-ofp result"+
751 " exceeded the threshold: "+
752 str(pt_up_graph_to_ofp_avg))
753
andrewonlabe5bcef92014-11-06 17:53:20 -0500754 if pt_up_device_to_ofp_avg > up_threshold_min and \
755 pt_up_device_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400756 port_up_device_to_ofp_list.append(
757 pt_up_device_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500758 main.log.info("Port up: device to ofp avg: "+
759 str(pt_up_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400760 else:
andrewonlababb11c32014-11-04 15:03:24 -0500761 main.log.info("Average port up device-to-ofp result"+
andrewonlab3622beb2014-10-28 16:07:56 -0400762 " exceeded the threshold: "+
763 str(pt_up_device_to_ofp_avg))
andrewonlab8d29f122014-10-22 17:15:04 -0400764
andrewonlab3622beb2014-10-28 16:07:56 -0400765 #END ITERATION FOR LOOP
andrewonlab8790abb2014-11-06 13:51:54 -0500766
767 #Check all list for latency existence and set assertion
768 if (port_down_graph_to_ofp_list and port_down_device_to_ofp_list\
769 and port_up_graph_to_ofp_list and port_up_device_to_ofp_list):
770 assertion = main.TRUE
771
andrewonlababb11c32014-11-04 15:03:24 -0500772 #Calculate and report latency measurements
andrewonlab3622beb2014-10-28 16:07:56 -0400773 port_down_graph_to_ofp_min = min(port_down_graph_to_ofp_list)
774 port_down_graph_to_ofp_max = max(port_down_graph_to_ofp_list)
775 port_down_graph_to_ofp_avg = \
776 (sum(port_down_graph_to_ofp_list) /
777 len(port_down_graph_to_ofp_list))
778
andrewonlab58f7d702014-11-07 13:21:19 -0500779 main.log.report("Port down graph-to-ofp \nMin: "+
780 str(port_down_graph_to_ofp_min)+" ms \nMax: "+
781 str(port_down_graph_to_ofp_max)+" ms \nAvg: "+
782 str(port_down_graph_to_ofp_avg)+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500783
784 port_down_device_to_ofp_min = min(port_down_device_to_ofp_list)
785 port_down_device_to_ofp_max = max(port_down_device_to_ofp_list)
786 port_down_device_to_ofp_avg = \
787 (sum(port_down_device_to_ofp_list) /\
788 len(port_down_device_to_ofp_list))
789
andrewonlab58f7d702014-11-07 13:21:19 -0500790 main.log.report("Port down device-to-ofp \nMin: "+
791 str(port_down_device_to_ofp_min)+" ms \nMax: "+
792 str(port_down_device_to_ofp_max)+" ms \nAvg: "+
793 str(port_down_device_to_ofp_avg)+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500794
795 port_up_graph_to_ofp_min = min(port_up_graph_to_ofp_list)
796 port_up_graph_to_ofp_max = max(port_up_graph_to_ofp_list)
797 port_up_graph_to_ofp_avg = \
798 (sum(port_up_graph_to_ofp_list) /\
799 len(port_up_graph_to_ofp_list))
andrewonlab8790abb2014-11-06 13:51:54 -0500800
andrewonlab58f7d702014-11-07 13:21:19 -0500801 main.log.report("Port up graph-to-ofp \nMin: "+
802 str(port_up_graph_to_ofp_min)+" ms \nMax: "+
803 str(port_up_graph_to_ofp_max)+" ms \nAvg: "+
804 str(port_up_graph_to_ofp_avg)+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500805
806 port_up_device_to_ofp_min = min(port_up_device_to_ofp_list)
807 port_up_device_to_ofp_max = max(port_up_device_to_ofp_list)
808 port_up_device_to_ofp_avg = \
809 (sum(port_up_device_to_ofp_list) /\
810 len(port_up_device_to_ofp_list))
811
andrewonlab58f7d702014-11-07 13:21:19 -0500812 main.log.report("Port up device-to-ofp \nMin: "+
813 str(port_up_device_to_ofp_min)+" ms \nMax: "+
814 str(port_up_device_to_ofp_max)+" ms \nAvg: "+
815 str(port_up_device_to_ofp_avg)+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500816
817 utilities.assert_equals(expect=main.TRUE, actual=assertion,
818 onpass="Port discovery latency calculation successful",
819 onfail="Port discovery test failed")
andrewonlababb11c32014-11-04 15:03:24 -0500820
andrewonlab3622beb2014-10-28 16:07:56 -0400821 def CASE4(self, main):
822 '''
823 Link down event using loss rate 100%
andrewonlab53b641c2014-10-31 19:44:44 -0400824
825 Important:
826 Use a simple 2 switch topology with 1 link between
827 the two switches. Ensure that mac addresses of the
828 switches are 1 / 2 respectively
andrewonlab3622beb2014-10-28 16:07:56 -0400829 '''
830 import time
831 import subprocess
832 import os
833 import requests
834 import json
835
836 ONOS1_ip = main.params['CTRL']['ip1']
837 ONOS2_ip = main.params['CTRL']['ip2']
838 ONOS3_ip = main.params['CTRL']['ip3']
839 ONOS_user = main.params['CTRL']['user']
840
841 default_sw_port = main.params['CTRL']['port1']
842
843 #Number of iterations of case
844 num_iter = main.params['TEST']['numIter']
845
846 #Timestamp 'keys' for json metrics output.
847 #These are subject to change, hence moved into params
848 deviceTimestamp = main.params['JSON']['deviceTimestamp']
849 linkTimestamp = main.params['JSON']['linkTimestamp']
andrewonlab53b641c2014-10-31 19:44:44 -0400850 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500851
852 debug_mode = main.params['TEST']['debugMode']
853
854 local_time = time.strftime('%x %X')
855 if debug_mode == 'on':
856 main.ONOS1.tshark_pcap("eth0",
857 "/tmp/link_lat_pcap"+local_time)
andrewonlab53b641c2014-10-31 19:44:44 -0400858
andrewonlabe5bcef92014-11-06 17:53:20 -0500859 #Threshold for this test case
860 up_threshold_str = main.params['TEST']['linkUpThreshold']
861 down_threshold_str = main.params['TEST']['linkDownThreshold']
862
863 up_threshold_obj = up_threshold_str.split(",")
864 down_threshold_obj = down_threshold_str.split(",")
865
866 up_threshold_min = int(up_threshold_obj[0])
867 up_threshold_max = int(up_threshold_obj[1])
868
869 down_threshold_min = int(down_threshold_obj[0])
870 down_threshold_max = int(down_threshold_obj[1])
871
andrewonlab3622beb2014-10-28 16:07:56 -0400872 assertion = main.TRUE
873 #Link event timestamp to system time list
874 link_down_link_to_system_list = []
875 link_up_link_to_system_list = []
876 #Graph event timestamp to system time list
877 link_down_graph_to_system_list = []
878 link_up_graph_to_system_list = []
879
880 main.log.report("Add / remove link latency between "+
881 "two switches")
882
883 main.step("Assign all switches")
884 main.Mininet1.assign_sw_controller(sw="1",
885 ip1=ONOS1_ip, port1=default_sw_port)
886 main.Mininet1.assign_sw_controller(sw="2",
887 ip1=ONOS1_ip, port1=default_sw_port)
888
889 main.step("Verifying switch assignment")
890 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
891 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
andrewonlab3622beb2014-10-28 16:07:56 -0400892
893 #Allow time for events to finish before taking measurements
894 time.sleep(10)
895
andrewonlababb11c32014-11-04 15:03:24 -0500896 link_down1 = False
897 link_down2 = False
898 link_down3 = False
andrewonlab3622beb2014-10-28 16:07:56 -0400899 #Start iteration of link event test
900 for i in range(0, int(num_iter)):
901 main.step("Getting initial system time as t0")
andrewonlab8d29f122014-10-22 17:15:04 -0400902
andrewonlab3622beb2014-10-28 16:07:56 -0400903 timestamp_link_down_t0 = time.time() * 1000
904 #Link down is simulated by 100% loss rate using traffic
905 #control command
906 main.Mininet1.handle.sendline(
907 "sh tc qdisc add dev s1-eth1 root netem loss 100%")
908
andrewonlab53b641c2014-10-31 19:44:44 -0400909 #TODO: Iterate through 'links' command to verify that
andrewonlababb11c32014-11-04 15:03:24 -0500910 # link s1 -> s2 went down (loop timeout 30 seconds)
911 # on all 3 ONOS instances
andrewonlab53b641c2014-10-31 19:44:44 -0400912 main.log.info("Checking ONOS for link update")
913 loop_count = 0
andrewonlababb11c32014-11-04 15:03:24 -0500914 while( not (link_down1 and link_down2 and link_down3)\
915 and loop_count < 30 ):
916 json_str1 = main.ONOS1cli.links()
917 json_str2 = main.ONOS2cli.links()
918 json_str3 = main.ONOS3cli.links()
919
920 if not (json_str1 and json_str2 and json_str3):
921 main.log.error("CLI command returned error ")
andrewonlab53b641c2014-10-31 19:44:44 -0400922 break
923 else:
andrewonlababb11c32014-11-04 15:03:24 -0500924 json_obj1 = json.loads(json_str1)
925 json_obj2 = json.loads(json_str2)
926 json_obj3 = json.loads(json_str3)
927 for obj1 in json_obj1:
928 if '01' not in obj1['src']['device']:
929 link_down1 = True
andrewonlab53b641c2014-10-31 19:44:44 -0400930 main.log.report("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -0500931 "s1 -> s2 on ONOS1 detected")
932 for obj2 in json_obj2:
933 if '01' not in obj2['src']['device']:
934 link_down2 = True
935 main.log.report("Link down from "+
936 "s1 -> s2 on ONOS2 detected")
937 for obj3 in json_obj3:
938 if '01' not in obj3['src']['device']:
939 link_down3 = True
940 main.log.report("Link down from "+
941 "s1 -> s2 on ONOS3 detected")
942
andrewonlab53b641c2014-10-31 19:44:44 -0400943 loop_count += 1
andrewonlababb11c32014-11-04 15:03:24 -0500944 #If CLI doesn't like the continuous requests
945 #and exits in this loop, increase the sleep here.
946 #Consequently, while loop timeout will increase
andrewonlab53b641c2014-10-31 19:44:44 -0400947 time.sleep(1)
948
949 #Give time for metrics measurement to catch up
andrewonlababb11c32014-11-04 15:03:24 -0500950 #NOTE: May need to be configured more accurately
andrewonlab53b641c2014-10-31 19:44:44 -0400951 time.sleep(10)
andrewonlababb11c32014-11-04 15:03:24 -0500952 #If we exited the while loop and link down 1,2,3 are still
andrewonlab53b641c2014-10-31 19:44:44 -0400953 #false, then ONOS has failed to discover link down event
andrewonlababb11c32014-11-04 15:03:24 -0500954 if not (link_down1 and link_down2 and link_down3):
andrewonlab53b641c2014-10-31 19:44:44 -0400955 main.log.info("Link down discovery failed")
956
957 link_down_lat_graph1 = 0
958 link_down_lat_graph2 = 0
959 link_down_lat_graph3 = 0
960 link_down_lat_device1 = 0
961 link_down_lat_device2 = 0
962 link_down_lat_device3 = 0
963
964 assertion = main.FALSE
965 else:
966 json_topo_metrics_1 =\
967 main.ONOS1cli.topology_events_metrics()
968 json_topo_metrics_2 =\
969 main.ONOS2cli.topology_events_metrics()
970 json_topo_metrics_3 =\
971 main.ONOS3cli.topology_events_metrics()
972 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
973 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
974 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
975
976 main.log.info("Obtaining graph and device timestamp")
977 graph_timestamp_1 = \
978 json_topo_metrics_1[graphTimestamp]['value']
979 graph_timestamp_2 = \
980 json_topo_metrics_2[graphTimestamp]['value']
981 graph_timestamp_3 = \
982 json_topo_metrics_3[graphTimestamp]['value']
983
984 link_timestamp_1 = \
985 json_topo_metrics_1[linkTimestamp]['value']
986 link_timestamp_2 = \
987 json_topo_metrics_2[linkTimestamp]['value']
988 link_timestamp_3 = \
989 json_topo_metrics_3[linkTimestamp]['value']
990
991 if graph_timestamp_1 and graph_timestamp_2 and\
992 graph_timestamp_3 and link_timestamp_1 and\
993 link_timestamp_2 and link_timestamp_3:
994 link_down_lat_graph1 = int(graph_timestamp_1) -\
995 timestamp_link_down_t0
996 link_down_lat_graph2 = int(graph_timestamp_2) -\
997 timestamp_link_down_t0
998 link_down_lat_graph3 = int(graph_timestamp_3) -\
999 timestamp_link_down_t0
1000
1001 link_down_lat_link1 = int(link_timestamp_1) -\
1002 timestamp_link_down_t0
1003 link_down_lat_link2 = int(link_timestamp_2) -\
1004 timestamp_link_down_t0
1005 link_down_lat_link3 = int(link_timestamp_3) -\
1006 timestamp_link_down_t0
1007 else:
1008 main.log.error("There was an error calculating"+
1009 " the delta for link down event")
1010 link_down_lat_graph1 = 0
1011 link_down_lat_graph2 = 0
1012 link_down_lat_graph3 = 0
1013
1014 link_down_lat_device1 = 0
1015 link_down_lat_device2 = 0
1016 link_down_lat_device3 = 0
1017
andrewonlab4e124482014-11-04 13:37:25 -05001018 main.log.report("Link down latency ONOS1 iteration "+
1019 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001020 str(link_down_lat_graph1)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001021 main.log.report("Link down latency ONOS2 iteration "+
1022 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001023 str(link_down_lat_graph2)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001024 main.log.report("Link down latency ONOS3 iteration "+
1025 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001026 str(link_down_lat_graph3)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001027
1028 main.log.report("Link down latency ONOS1 iteration "+
1029 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001030 str(link_down_lat_link1)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001031 main.log.report("Link down latency ONOS2 iteration "+
1032 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001033 str(link_down_lat_link2)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001034 main.log.report("Link down latency ONOS3 iteration "+
1035 str(i)+" (link-event-to-system-timestamp): "+
1036 str(link_down_lat_link3))
1037
1038 #Calculate avg of node calculations
1039 link_down_lat_graph_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001040 (link_down_lat_graph1 +
1041 link_down_lat_graph2 +
1042 link_down_lat_graph3) / 3.0
andrewonlab4e124482014-11-04 13:37:25 -05001043 link_down_lat_link_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001044 (link_down_lat_link1 +
1045 link_down_lat_link2 +
1046 link_down_lat_link3) / 3.0
andrewonlab53b641c2014-10-31 19:44:44 -04001047
andrewonlab4e124482014-11-04 13:37:25 -05001048 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001049 if link_down_lat_graph_avg > down_threshold_min and\
1050 link_down_lat_graph_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001051 link_down_graph_to_system_list.append(
1052 link_down_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001053 else:
1054 main.log.info("Link down latency exceeded threshold")
1055 main.log.info("Results for iteration "+str(i)+
1056 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001057 if link_down_lat_link_avg > down_threshold_min and\
1058 link_down_lat_link_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001059 link_down_link_to_system_list.append(
1060 link_down_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001061 else:
1062 main.log.info("Link down latency exceeded threshold")
1063 main.log.info("Results for iteration "+str(i)+
1064 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001065
1066 #NOTE: To remove loss rate and measure latency:
1067 # 'sh tc qdisc del dev s1-eth1 root'
andrewonlababb11c32014-11-04 15:03:24 -05001068 timestamp_link_up_t0 = time.time() * 1000
andrewonlab53b641c2014-10-31 19:44:44 -04001069 main.Mininet1.handle.sendline("sh tc qdisc del dev "+
1070 "s1-eth1 root")
1071 main.Mininet1.handle.expect("mininet>")
andrewonlababb11c32014-11-04 15:03:24 -05001072
1073 main.log.info("Checking ONOS for link update")
1074
1075 link_down1 = True
1076 link_down2 = True
1077 link_down3 = True
1078 loop_count = 0
1079 while( (link_down1 and link_down2 and link_down3)\
1080 and loop_count < 30 ):
1081 json_str1 = main.ONOS1cli.links()
1082 json_str2 = main.ONOS2cli.links()
1083 json_str3 = main.ONOS3cli.links()
1084 if not (json_str1 and json_str2 and json_str3):
1085 main.log.error("CLI command returned error ")
1086 break
1087 else:
1088 json_obj1 = json.loads(json_str1)
1089 json_obj2 = json.loads(json_str2)
1090 json_obj3 = json.loads(json_str3)
1091
1092 for obj1 in json_obj1:
1093 if '01' in obj1['src']['device']:
1094 link_down1 = False
1095 main.log.report("Link up from "+
1096 "s1 -> s2 on ONOS1 detected")
1097 for obj2 in json_obj2:
1098 if '01' in obj2['src']['device']:
1099 link_down2 = False
1100 main.log.report("Link up from "+
1101 "s1 -> s2 on ONOS2 detected")
1102 for obj3 in json_obj3:
1103 if '01' in obj3['src']['device']:
1104 link_down3 = False
1105 main.log.report("Link up from "+
1106 "s1 -> s2 on ONOS3 detected")
1107
1108 loop_count += 1
1109 time.sleep(1)
1110
1111 if (link_down1 and link_down2 and link_down3):
1112 main.log.info("Link up discovery failed")
1113
1114 link_up_lat_graph1 = 0
1115 link_up_lat_graph2 = 0
1116 link_up_lat_graph3 = 0
1117 link_up_lat_device1 = 0
1118 link_up_lat_device2 = 0
1119 link_up_lat_device3 = 0
1120
1121 assertion = main.FALSE
1122 else:
1123 json_topo_metrics_1 =\
1124 main.ONOS1cli.topology_events_metrics()
1125 json_topo_metrics_2 =\
1126 main.ONOS2cli.topology_events_metrics()
1127 json_topo_metrics_3 =\
1128 main.ONOS3cli.topology_events_metrics()
1129 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1130 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1131 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1132
1133 main.log.info("Obtaining graph and device timestamp")
1134 graph_timestamp_1 = \
1135 json_topo_metrics_1[graphTimestamp]['value']
1136 graph_timestamp_2 = \
1137 json_topo_metrics_2[graphTimestamp]['value']
1138 graph_timestamp_3 = \
1139 json_topo_metrics_3[graphTimestamp]['value']
1140
1141 link_timestamp_1 = \
1142 json_topo_metrics_1[linkTimestamp]['value']
1143 link_timestamp_2 = \
1144 json_topo_metrics_2[linkTimestamp]['value']
1145 link_timestamp_3 = \
1146 json_topo_metrics_3[linkTimestamp]['value']
1147
1148 if graph_timestamp_1 and graph_timestamp_2 and\
1149 graph_timestamp_3 and link_timestamp_1 and\
1150 link_timestamp_2 and link_timestamp_3:
1151 link_up_lat_graph1 = int(graph_timestamp_1) -\
1152 timestamp_link_up_t0
1153 link_up_lat_graph2 = int(graph_timestamp_2) -\
1154 timestamp_link_up_t0
1155 link_up_lat_graph3 = int(graph_timestamp_3) -\
1156 timestamp_link_up_t0
1157
1158 link_up_lat_link1 = int(link_timestamp_1) -\
1159 timestamp_link_up_t0
1160 link_up_lat_link2 = int(link_timestamp_2) -\
1161 timestamp_link_up_t0
1162 link_up_lat_link3 = int(link_timestamp_3) -\
1163 timestamp_link_up_t0
1164 else:
1165 main.log.error("There was an error calculating"+
1166 " the delta for link down event")
1167 link_up_lat_graph1 = 0
1168 link_up_lat_graph2 = 0
1169 link_up_lat_graph3 = 0
1170
1171 link_up_lat_device1 = 0
1172 link_up_lat_device2 = 0
1173 link_up_lat_device3 = 0
andrewonlab58f7d702014-11-07 13:21:19 -05001174
1175 if debug_mode == 'on':
1176 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001177 str(i)+" (end-to-end): "+
1178 str(link_up_lat_graph1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001179 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001180 str(i)+" (end-to-end): "+
1181 str(link_up_lat_graph2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001182 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001183 str(i)+" (end-to-end): "+
1184 str(link_up_lat_graph3)+" ms")
1185
andrewonlab58f7d702014-11-07 13:21:19 -05001186 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001187 str(i)+" (link-event-to-system-timestamp): "+
1188 str(link_up_lat_link1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001189 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001190 str(i)+" (link-event-to-system-timestamp): "+
1191 str(link_up_lat_link2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001192 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001193 str(i)+" (link-event-to-system-timestamp): "+
1194 str(link_up_lat_link3))
1195
1196 #Calculate avg of node calculations
1197 link_up_lat_graph_avg =\
1198 (link_up_lat_graph1 +
1199 link_up_lat_graph2 +
1200 link_up_lat_graph3) / 3.0
1201 link_up_lat_link_avg =\
1202 (link_up_lat_link1 +
1203 link_up_lat_link2 +
1204 link_up_lat_link3) / 3.0
1205
1206 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001207 if link_up_lat_graph_avg > up_threshold_min and\
1208 link_up_lat_graph_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001209 link_up_graph_to_system_list.append(
1210 link_up_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001211 else:
1212 main.log.info("Link up latency exceeded threshold")
1213 main.log.info("Results for iteration "+str(i)+
1214 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001215 if link_up_lat_link_avg > up_threshold_min and\
1216 link_up_lat_link_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001217 link_up_link_to_system_list.append(
1218 link_up_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001219 else:
1220 main.log.info("Link up latency exceeded threshold")
1221 main.log.info("Results for iteration "+str(i)+
1222 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001223
andrewonlab4e124482014-11-04 13:37:25 -05001224 #Calculate min, max, avg of list and report
1225 link_down_min = min(link_down_graph_to_system_list)
1226 link_down_max = max(link_down_graph_to_system_list)
1227 link_down_avg = sum(link_down_graph_to_system_list) / \
1228 len(link_down_graph_to_system_list)
andrewonlababb11c32014-11-04 15:03:24 -05001229 link_up_min = min(link_up_graph_to_system_list)
1230 link_up_max = max(link_up_graph_to_system_list)
1231 link_up_avg = sum(link_up_graph_to_system_list) / \
1232 len(link_up_graph_to_system_list)
1233
andrewonlab58f7d702014-11-07 13:21:19 -05001234 main.log.report("Link down latency - \nMin: "+
1235 str(link_down_min)+" ms \nMax: "+
1236 str(link_down_max)+" ms \nAvg: "+
1237 str(link_down_avg)+" ms")
1238 main.log.report("Link up latency - \nMin: "+
1239 str(link_up_min)+" ms \nMax: "+
1240 str(link_up_max)+" ms \nAvg: "+
1241 str(link_up_avg)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001242
andrewonlab8790abb2014-11-06 13:51:54 -05001243 utilities.assert_equals(expect=main.TRUE, actual=assertion,
1244 onpass="Link discovery latency calculation successful",
1245 onfail="Link discovery latency case failed")
1246
andrewonlabb54b85b2014-10-28 18:43:57 -04001247 def CASE5(self, main):
1248 '''
1249 100 Switch discovery latency
1250
1251 Important:
andrewonlab16ce4852014-10-30 13:41:09 -04001252 This test case can be potentially dangerous if
1253 your machine has previously set iptables rules.
1254 One of the steps of the test case will flush
1255 all existing iptables rules.
andrewonlab8790abb2014-11-06 13:51:54 -05001256 Note:
1257 You can specify the number of switches in the
1258 params file to adjust the switch discovery size
1259 (and specify the corresponding topology in Mininet1
1260 .topo file)
andrewonlabb54b85b2014-10-28 18:43:57 -04001261 '''
1262 import time
1263 import subprocess
1264 import os
1265 import requests
1266 import json
1267
1268 ONOS1_ip = main.params['CTRL']['ip1']
1269 ONOS2_ip = main.params['CTRL']['ip2']
1270 ONOS3_ip = main.params['CTRL']['ip3']
1271 MN1_ip = main.params['MN']['ip1']
1272 ONOS_user = main.params['CTRL']['user']
1273
1274 default_sw_port = main.params['CTRL']['port1']
1275
1276 #Number of iterations of case
1277 num_iter = main.params['TEST']['numIter']
andrewonlab16ce4852014-10-30 13:41:09 -04001278 num_sw = main.params['TEST']['numSwitch']
1279
andrewonlabb54b85b2014-10-28 18:43:57 -04001280 #Timestamp 'keys' for json metrics output.
1281 #These are subject to change, hence moved into params
1282 deviceTimestamp = main.params['JSON']['deviceTimestamp']
andrewonlab16ce4852014-10-30 13:41:09 -04001283 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -05001284
1285 debug_mode = main.params['TEST']['debugMode']
1286
1287 local_time = time.strftime('%x %X')
1288 if debug_mode == 'on':
1289 main.ONOS1.tshark_pcap("eth0",
1290 "/tmp/100_sw_lat_pcap"+local_time)
andrewonlabe5bcef92014-11-06 17:53:20 -05001291
1292 #Threshold for this test case
1293 sw_disc_threshold_str = main.params['TEST']['swDisc100Threshold']
1294 sw_disc_threshold_obj = sw_disc_threshold_str.split(",")
1295 sw_disc_threshold_min = int(sw_disc_threshold_obj[0])
1296 sw_disc_threshold_max = int(sw_disc_threshold_obj[1])
1297
andrewonlab53b641c2014-10-31 19:44:44 -04001298 tshark_ofp_output = "/tmp/tshark_ofp_"+num_sw+"sw.txt"
1299 tshark_tcp_output = "/tmp/tshark_tcp_"+num_sw+"sw.txt"
1300
1301 tshark_ofp_result_list = []
1302 tshark_tcp_result_list = []
andrewonlabb54b85b2014-10-28 18:43:57 -04001303
andrewonlabe5bcef92014-11-06 17:53:20 -05001304 sw_discovery_lat_list = []
1305
andrewonlab16ce4852014-10-30 13:41:09 -04001306 main.case(num_sw+" Switch discovery latency")
andrewonlabb54b85b2014-10-28 18:43:57 -04001307 main.step("Assigning all switches to ONOS1")
andrewonlab16ce4852014-10-30 13:41:09 -04001308 for i in range(1, int(num_sw)+1):
andrewonlabb54b85b2014-10-28 18:43:57 -04001309 main.Mininet1.assign_sw_controller(
1310 sw=str(i),
1311 ip1=ONOS1_ip,
1312 port1=default_sw_port)
andrewonlab16ce4852014-10-30 13:41:09 -04001313
andrewonlabb54b85b2014-10-28 18:43:57 -04001314 #Ensure that nodes are configured with ptpd
andrewonlab16ce4852014-10-30 13:41:09 -04001315 #Just a warning message
1316 main.log.info("Please check ptpd configuration to ensure"+\
1317 " All nodes' system times are in sync")
1318 time.sleep(5)
andrewonlabb54b85b2014-10-28 18:43:57 -04001319
1320 for i in range(0, int(num_iter)):
andrewonlab8d29f122014-10-22 17:15:04 -04001321
andrewonlabb54b85b2014-10-28 18:43:57 -04001322 main.step("Set iptables rule to block incoming sw connections")
1323 #Set iptables rule to block incoming switch connections
andrewonlab53b641c2014-10-31 19:44:44 -04001324 #The rule description is as follows:
1325 # Append to INPUT rule,
1326 # behavior DROP that matches following:
1327 # * packet type: tcp
1328 # * source IP: MN1_ip
1329 # * destination PORT: 6633
andrewonlabb54b85b2014-10-28 18:43:57 -04001330 main.ONOS1.handle.sendline(
andrewonlab16ce4852014-10-30 13:41:09 -04001331 "sudo iptables -A INPUT -p tcp -s "+MN1_ip+
andrewonlabb54b85b2014-10-28 18:43:57 -04001332 " --dport "+default_sw_port+" -j DROP")
1333 main.ONOS1.handle.expect("\$")
andrewonlab53b641c2014-10-31 19:44:44 -04001334 # Append to OUTPUT rule,
1335 # behavior DROP that matches following:
1336 # * packet type: tcp
1337 # * source IP: MN1_ip
1338 # * destination PORT: 6633
1339 main.ONOS1.handle.sendline(
1340 "sudo iptables -A OUTPUT -p tcp -s "+MN1_ip+
1341 " --dport "+default_sw_port+" -j DROP")
1342 main.ONOS1.handle.expect("\$")
andrewonlabb54b85b2014-10-28 18:43:57 -04001343 #Give time to allow rule to take effect
andrewonlab8790abb2014-11-06 13:51:54 -05001344 #NOTE: Sleep period may need to be configured
1345 # based on the number of switches in the topology
andrewonlab16ce4852014-10-30 13:41:09 -04001346 main.log.info("Please wait for switch connection to "+
1347 "time out")
1348 time.sleep(60)
1349
1350 #Gather vendor OFP with tshark
1351 main.ONOS1.tshark_grep("OFP 86 Vendor",
1352 tshark_ofp_output)
andrewonlab53b641c2014-10-31 19:44:44 -04001353 main.ONOS1.tshark_grep("TCP 74 ",
1354 tshark_tcp_output)
andrewonlabb54b85b2014-10-28 18:43:57 -04001355
andrewonlab16ce4852014-10-30 13:41:09 -04001356 #NOTE: Remove all iptables rule quickly (flush)
andrewonlabb54b85b2014-10-28 18:43:57 -04001357 # Before removal, obtain TestON timestamp at which
andrewonlab16ce4852014-10-30 13:41:09 -04001358 # removal took place
1359 # (ensuring nodes are configured via ptp)
andrewonlabb54b85b2014-10-28 18:43:57 -04001360 # sudo iptables -F
andrewonlab16ce4852014-10-30 13:41:09 -04001361
1362 t0_system = time.time() * 1000
1363 main.ONOS1.handle.sendline(
1364 "sudo iptables -F")
andrewonlabb54b85b2014-10-28 18:43:57 -04001365
andrewonlab16ce4852014-10-30 13:41:09 -04001366 #Counter to track loop count
1367 counter_loop = 0
1368 counter_avail1 = 0
1369 counter_avail2 = 0
1370 counter_avail3 = 0
1371 onos1_dev = False
1372 onos2_dev = False
1373 onos3_dev = False
1374 while counter_loop < 60:
1375 #Continue to check devices for all device
1376 #availability. When all devices in all 3
1377 #ONOS instances indicate that devices are available
1378 #obtain graph event timestamp for t1.
1379 device_str_obj1 = main.ONOS1cli.devices()
1380 device_str_obj2 = main.ONOS2cli.devices()
1381 device_str_obj3 = main.ONOS3cli.devices()
1382
1383 device_json1 = json.loads(device_str_obj1)
1384 device_json2 = json.loads(device_str_obj2)
1385 device_json3 = json.loads(device_str_obj3)
1386
1387 for device1 in device_json1:
1388 if device1['available'] == True:
1389 counter_avail1 += 1
1390 if counter_avail1 == int(num_sw):
1391 onos1_dev = True
1392 main.log.info("All devices have been "+
1393 "discovered on ONOS1")
1394 else:
1395 counter_avail1 = 0
1396 for device2 in device_json2:
1397 if device2['available'] == True:
1398 counter_avail2 += 1
1399 if counter_avail2 == int(num_sw):
1400 onos2_dev = True
1401 main.log.info("All devices have been "+
1402 "discovered on ONOS2")
1403 else:
1404 counter_avail2 = 0
1405 for device3 in device_json3:
1406 if device3['available'] == True:
1407 counter_avail3 += 1
1408 if counter_avail3 == int(num_sw):
1409 onos3_dev = True
1410 main.log.info("All devices have been "+
1411 "discovered on ONOS3")
1412 else:
1413 counter_avail3 = 0
1414
1415 if onos1_dev and onos2_dev and onos3_dev:
1416 main.log.info("All devices have been discovered "+
1417 "on all ONOS instances")
1418 json_str_topology_metrics_1 =\
1419 main.ONOS1cli.topology_events_metrics()
1420 json_str_topology_metrics_2 =\
1421 main.ONOS2cli.topology_events_metrics()
1422 json_str_topology_metrics_3 =\
1423 main.ONOS3cli.topology_events_metrics()
andrewonlab53b641c2014-10-31 19:44:44 -04001424
1425 #Exit while loop if all devices discovered
andrewonlab16ce4852014-10-30 13:41:09 -04001426 break
1427
1428 counter_loop += 1
1429 #Give some time in between CLI calls
1430 #(will not affect measurement)
1431 time.sleep(3)
1432
1433 main.ONOS1.tshark_stop()
1434
1435 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1436 tshark_ofp_output+" /tmp/")
andrewonlab53b641c2014-10-31 19:44:44 -04001437 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1438 tshark_tcp_output+" /tmp/")
andrewonlab16ce4852014-10-30 13:41:09 -04001439
andrewonlab16ce4852014-10-30 13:41:09 -04001440 #TODO: Automate OFP output analysis
andrewonlab58f7d702014-11-07 13:21:19 -05001441 #Debug mode - print out packets captured at runtime
1442 if debug_mode == 'on':
1443 ofp_file = open(tshark_ofp_output, 'r')
1444 main.log.info("Tshark OFP Vendor output: ")
1445 for line in ofp_file:
1446 tshark_ofp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001447 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001448 ofp_file.close()
andrewonlab16ce4852014-10-30 13:41:09 -04001449
andrewonlab58f7d702014-11-07 13:21:19 -05001450 tcp_file = open(tshark_tcp_output, 'r')
1451 main.log.info("Tshark TCP 74 output: ")
1452 for line in tcp_file:
1453 tshark_tcp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001454 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001455 tcp_file.close()
andrewonlab53b641c2014-10-31 19:44:44 -04001456
andrewonlab16ce4852014-10-30 13:41:09 -04001457 json_obj_1 = json.loads(json_str_topology_metrics_1)
1458 json_obj_2 = json.loads(json_str_topology_metrics_2)
1459 json_obj_3 = json.loads(json_str_topology_metrics_3)
1460
1461 graph_timestamp_1 = \
1462 json_obj_1[graphTimestamp]['value']
1463 graph_timestamp_2 = \
1464 json_obj_2[graphTimestamp]['value']
1465 graph_timestamp_3 = \
1466 json_obj_3[graphTimestamp]['value']
1467
andrewonlabe5bcef92014-11-06 17:53:20 -05001468 graph_lat_1 = int(graph_timestamp_1) - int(t0_system)
1469 graph_lat_2 = int(graph_timestamp_2) - int(t0_system)
1470 graph_lat_3 = int(graph_timestamp_3) - int(t0_system)
andrewonlab16ce4852014-10-30 13:41:09 -04001471
andrewonlabe5bcef92014-11-06 17:53:20 -05001472 avg_graph_lat = \
1473 (int(graph_lat_1) +\
1474 int(graph_lat_2) +\
1475 int(graph_lat_3)) / 3
1476
1477 if avg_graph_lat > sw_disc_threshold_min \
1478 and avg_graph_lat < sw_disc_threshold_max:
1479 sw_discovery_lat_list.append(
1480 avg_graph_lat)
1481 else:
1482 main.log.info("100 Switch discovery latency "+
1483 "exceeded the threshold.")
1484
1485 #END ITERATION FOR LOOP
andrewonlab16ce4852014-10-30 13:41:09 -04001486
andrewonlabe5bcef92014-11-06 17:53:20 -05001487 sw_lat_min = min(sw_discovery_lat_list)
1488 sw_lat_max = max(sw_discovery_lat_list)
1489 sw_lat_avg = sum(sw_discovery_lat_list) /\
1490 len(sw_discovery_lat_list)
andrewonlab16ce4852014-10-30 13:41:09 -04001491
andrewonlabe5bcef92014-11-06 17:53:20 -05001492 main.log.report("100 Switch discovery lat - \n"+\
1493 "Min: "+str(sw_lat_min)+" ms\n"+\
1494 "Max: "+str(sw_lat_max)+" ms\n"+\
1495 "Avg: "+str(sw_lat_avg)+" ms\n")
andrewonlab16ce4852014-10-30 13:41:09 -04001496
andrewonlabb54b85b2014-10-28 18:43:57 -04001497