blob: b21270571629804e5198906324b6c8f43fa5eac6 [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")
andrewonlabf9828f02014-11-10 14:50:27 -050034 main.log.report("Setting up test environment")
andrewonlab2a6c9342014-10-16 13:40:15 -040035
36 main.step("Creating cell file")
37 cell_file_result = main.ONOSbench.create_cell_file(
andrewonlabe6745342014-10-17 14:29:13 -040038 BENCH_ip, cell_name, MN1_ip, "onos-core",
andrewonlabba44bcf2014-10-16 16:54:41 -040039 ONOS1_ip, ONOS2_ip, ONOS3_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -040040
41 main.step("Applying cell file to environment")
42 cell_apply_result = main.ONOSbench.set_cell(cell_name)
43 verify_cell_result = main.ONOSbench.verify_cell()
44
45 main.step("Git checkout and pull "+checkout_branch)
46 if git_pull == 'on':
47 checkout_result = \
48 main.ONOSbench.git_checkout(checkout_branch)
49 pull_result = main.ONOSbench.git_pull()
50 else:
51 checkout_result = main.TRUE
52 pull_result = main.TRUE
53 main.log.info("Skipped git checkout and pull")
54
55 main.step("Using mvn clean & install")
andrewonlab8d29f122014-10-22 17:15:04 -040056 #mvn_result = main.ONOSbench.clean_install()
57 mvn_result = main.TRUE
andrewonlab2a6c9342014-10-16 13:40:15 -040058
andrewonlabb1998c52014-11-10 13:31:43 -050059 main.step("Set cell for ONOS cli env")
60 main.ONOS1cli.set_cell(cell_name)
61 main.ONOS2cli.set_cell(cell_name)
62 main.ONOS3cli.set_cell(cell_name)
63
andrewonlab2a6c9342014-10-16 13:40:15 -040064 main.step("Creating ONOS package")
65 package_result = main.ONOSbench.onos_package()
66
67 main.step("Installing ONOS package")
andrewonlabe9fb6722014-10-24 12:20:35 -040068 install1_result = main.ONOSbench.onos_install(node=ONOS1_ip)
69 install2_result = main.ONOSbench.onos_install(node=ONOS2_ip)
70 install3_result = main.ONOSbench.onos_install(node=ONOS3_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -040071
andrewonlabe9fb6722014-10-24 12:20:35 -040072 time.sleep(10)
73
andrewonlab867212a2014-10-22 20:13:38 -040074 main.step("Start onos cli")
andrewonlabe9fb6722014-10-24 12:20:35 -040075 cli1 = main.ONOS1cli.start_onos_cli(ONOS1_ip)
76 cli2 = main.ONOS2cli.start_onos_cli(ONOS2_ip)
77 cli3 = main.ONOS3cli.start_onos_cli(ONOS3_ip)
78
andrewonlab867212a2014-10-22 20:13:38 -040079 main.step("Enable metrics feature")
andrewonlabb1998c52014-11-10 13:31:43 -050080 main.ONOS1cli.feature_install("onos-app-metrics")
81 main.ONOS2cli.feature_install("onos-app-metrics")
82 main.ONOS3cli.feature_install("onos-app-metrics")
andrewonlab867212a2014-10-22 20:13:38 -040083
andrewonlab2a6c9342014-10-16 13:40:15 -040084 utilities.assert_equals(expect=main.TRUE,
85 actual= cell_file_result and cell_apply_result and\
86 verify_cell_result and checkout_result and\
87 pull_result and mvn_result and\
andrewonlabe9fb6722014-10-24 12:20:35 -040088 install1_result and install2_result and\
89 install3_result,
andrewonlabf9828f02014-11-10 14:50:27 -050090 onpass="Test Environment setup successful",
91 onfail="Failed to setup test environment")
andrewonlab2a6c9342014-10-16 13:40:15 -040092
andrewonlabba44bcf2014-10-16 16:54:41 -040093 def CASE2(self, main):
94 '''
95 Assign s1 to ONOS1 and measure latency
andrewonlab3a7c3c72014-10-24 17:21:03 -040096
97 There are 4 levels of latency measurements to this test:
98 1) End-to-end measurement: Complete end-to-end measurement
99 from TCP (SYN/ACK) handshake to Graph change
100 2) OFP-to-graph measurement: 'ONOS processing' snippet of
101 measurement from OFP Vendor message to Graph change
102 3) OFP-to-device measurement: 'ONOS processing without
103 graph change' snippet of measurement from OFP vendor
104 message to Device change timestamp
105 4) T0-to-device measurement: Measurement that includes
106 the switch handshake to devices timestamp without
107 the graph view change. (TCP handshake -> Device
108 change)
andrewonlabba44bcf2014-10-16 16:54:41 -0400109 '''
110 import time
andrewonlabe6745342014-10-17 14:29:13 -0400111 import subprocess
112 import json
113 import requests
114 import os
andrewonlabba44bcf2014-10-16 16:54:41 -0400115
116 ONOS1_ip = main.params['CTRL']['ip1']
117 ONOS2_ip = main.params['CTRL']['ip2']
118 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlabe6745342014-10-17 14:29:13 -0400119 ONOS_user = main.params['CTRL']['user']
120
andrewonlabba44bcf2014-10-16 16:54:41 -0400121 default_sw_port = main.params['CTRL']['port1']
122
123 #Number of iterations of case
124 num_iter = main.params['TEST']['numIter']
125
andrewonlab226024e2014-10-24 16:01:32 -0400126 #Timestamp 'keys' for json metrics output.
127 #These are subject to change, hence moved into params
128 deviceTimestamp = main.params['JSON']['deviceTimestamp']
129 graphTimestamp = main.params['JSON']['graphTimestamp']
130
andrewonlab58f7d702014-11-07 13:21:19 -0500131 debug_mode = main.params['TEST']['debugMode']
andrewonlabb1998c52014-11-10 13:31:43 -0500132 onos_log = main.params['TEST']['onosLogFile']
andrewonlab58f7d702014-11-07 13:21:19 -0500133
andrewonlabe5bcef92014-11-06 17:53:20 -0500134 #Threshold for the test
135 threshold_str = main.params['TEST']['singleSwThreshold']
136 threshold_obj = threshold_str.split(",")
137 threshold_min = int(threshold_obj[0])
138 threshold_max = int(threshold_obj[1])
139
andrewonlab226024e2014-10-24 16:01:32 -0400140 #List of switch add latency collected from
141 #all iterations
142 latency_end_to_end_list = []
143 latency_ofp_to_graph_list = []
144 latency_ofp_to_device_list = []
145 latency_t0_to_device_list = []
146
andrewonlabba44bcf2014-10-16 16:54:41 -0400147 #Directory/file to store tshark results
148 tshark_of_output = "/tmp/tshark_of_topo.txt"
149 tshark_tcp_output = "/tmp/tshark_tcp_topo.txt"
150
151 #String to grep in tshark output
152 tshark_tcp_string = "TCP 74 "+default_sw_port
153 tshark_of_string = "OFP 86 Vendor"
andrewonlabe6745342014-10-17 14:29:13 -0400154
155 #Initialize assertion to TRUE
156 assertion = main.TRUE
andrewonlab58f7d702014-11-07 13:21:19 -0500157
158 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500159 local_time = local_time.replace("/","")
160 local_time = local_time.replace(" ","_")
161 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500162 if debug_mode == 'on':
163 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500164 "/tmp/single_sw_lat_pcap_"+local_time)
165
166 main.log.info("TEST")
andrewonlab58f7d702014-11-07 13:21:19 -0500167
andrewonlabba44bcf2014-10-16 16:54:41 -0400168 main.log.report("Latency of adding one switch")
169
170 for i in range(0, int(num_iter)):
171 main.log.info("Starting tshark capture")
172
173 #* TCP [ACK, SYN] is used as t0_a, the
174 # very first "exchange" between ONOS and
175 # the switch for end-to-end measurement
176 #* OFP [Stats Reply] is used for t0_b
177 # the very last OFP message between ONOS
178 # and the switch for ONOS measurement
179 main.ONOS1.tshark_grep(tshark_tcp_string,
180 tshark_tcp_output)
181 main.ONOS1.tshark_grep(tshark_of_string,
182 tshark_of_output)
183
184 #Wait and ensure tshark is started and
185 #capturing
186 time.sleep(10)
187
188 main.log.info("Assigning s1 to controller")
189
190 main.Mininet1.assign_sw_controller(sw="1",
191 ip1=ONOS1_ip, port1=default_sw_port)
192
193 #Wait and ensure switch is assigned
194 #before stopping tshark
andrewonlab867212a2014-10-22 20:13:38 -0400195 time.sleep(30)
andrewonlab226024e2014-10-24 16:01:32 -0400196
197 main.log.info("Stopping all Tshark processes")
andrewonlabba44bcf2014-10-16 16:54:41 -0400198 main.ONOS1.stop_tshark()
199
andrewonlabe6745342014-10-17 14:29:13 -0400200 #tshark output is saved in ONOS. Use subprocess
201 #to copy over files to TestON for parsing
202 main.log.info("Copying over tshark files")
203
204 #TCP CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400205 #Copy the tshark output from ONOS machine to
206 #TestON machine in tshark_tcp_output directory>file
207 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
208 tshark_tcp_output+" /tmp/")
209 tcp_file = open(tshark_tcp_output, 'r')
210 temp_text = tcp_file.readline()
andrewonlabe6745342014-10-17 14:29:13 -0400211 temp_text = temp_text.split(" ")
andrewonlabba44bcf2014-10-16 16:54:41 -0400212
andrewonlabe6745342014-10-17 14:29:13 -0400213 main.log.info("Object read in from TCP capture: "+
214 str(temp_text))
andrewonlab867212a2014-10-22 20:13:38 -0400215 if len(temp_text) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400216 t0_tcp = float(temp_text[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400217 else:
218 main.log.error("Tshark output file for TCP"+
219 " returned unexpected results")
220 t0_tcp = 0
221 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400222
223 tcp_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400224 #****************
andrewonlabba44bcf2014-10-16 16:54:41 -0400225
andrewonlabe6745342014-10-17 14:29:13 -0400226 #OF CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400227 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
228 tshark_of_output+" /tmp/")
229 of_file = open(tshark_of_output, 'r')
230
231 line_ofp = ""
andrewonlab226024e2014-10-24 16:01:32 -0400232 #Read until last line of file
andrewonlabe6745342014-10-17 14:29:13 -0400233 while True:
andrewonlab8d29f122014-10-22 17:15:04 -0400234 temp_text = of_file.readline()
235 if temp_text !='':
andrewonlabe6745342014-10-17 14:29:13 -0400236 line_ofp = temp_text
237 else:
238 break
239 obj = line_ofp.split(" ")
240
241 main.log.info("Object read in from OFP capture: "+
242 str(line_ofp))
243
andrewonlab867212a2014-10-22 20:13:38 -0400244 if len(line_ofp) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400245 t0_ofp = float(obj[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400246 else:
247 main.log.error("Tshark output file for OFP"+
248 " returned unexpected results")
249 t0_ofp = 0
250 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400251
252 of_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400253 #****************
254
andrewonlab867212a2014-10-22 20:13:38 -0400255 json_str_1 = main.ONOS1cli.topology_events_metrics()
256 json_str_2 = main.ONOS2cli.topology_events_metrics()
257 json_str_3 = main.ONOS3cli.topology_events_metrics()
andrewonlab867212a2014-10-22 20:13:38 -0400258
259 json_obj_1 = json.loads(json_str_1)
260 json_obj_2 = json.loads(json_str_2)
261 json_obj_3 = json.loads(json_str_3)
262
andrewonlab226024e2014-10-24 16:01:32 -0400263 #Obtain graph timestamp. This timestsamp captures
264 #the epoch time at which the topology graph was updated.
265 graph_timestamp_1 = \
266 json_obj_1[graphTimestamp]['value']
267 graph_timestamp_2 = \
268 json_obj_2[graphTimestamp]['value']
269 graph_timestamp_3 = \
270 json_obj_3[graphTimestamp]['value']
andrewonlab867212a2014-10-22 20:13:38 -0400271
andrewonlab226024e2014-10-24 16:01:32 -0400272 #Obtain device timestamp. This timestamp captures
273 #the epoch time at which the device event happened
274 device_timestamp_1 = \
275 json_obj_1[deviceTimestamp]['value']
276 device_timestamp_2 = \
277 json_obj_2[deviceTimestamp]['value']
278 device_timestamp_3 = \
279 json_obj_3[deviceTimestamp]['value']
andrewonlabe9fb6722014-10-24 12:20:35 -0400280
andrewonlab226024e2014-10-24 16:01:32 -0400281 #t0 to device processing latency
282 delta_device_1 = int(device_timestamp_1) - int(t0_tcp)
283 delta_device_2 = int(device_timestamp_2) - int(t0_tcp)
284 delta_device_3 = int(device_timestamp_3) - int(t0_tcp)
285
286 #Get average of delta from all instances
287 avg_delta_device = \
288 (int(delta_device_1)+\
289 int(delta_device_2)+\
290 int(delta_device_3)) / 3
andrewonlabba44bcf2014-10-16 16:54:41 -0400291
andrewonlab226024e2014-10-24 16:01:32 -0400292 #Ensure avg delta meets the threshold before appending
293 if avg_delta_device > 0.0 and avg_delta_device < 10000:
294 latency_t0_to_device_list.append(avg_delta_device)
andrewonlabee4efeb2014-10-24 16:44:51 -0400295 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400296 main.log.info("Results for t0-to-device ignored"+\
297 "due to excess in threshold")
andrewonlabee4efeb2014-10-24 16:44:51 -0400298
andrewonlab226024e2014-10-24 16:01:32 -0400299 #t0 to graph processing latency (end-to-end)
300 delta_graph_1 = int(graph_timestamp_1) - int(t0_tcp)
301 delta_graph_2 = int(graph_timestamp_2) - int(t0_tcp)
302 delta_graph_3 = int(graph_timestamp_3) - int(t0_tcp)
303
304 #Get average of delta from all instances
305 avg_delta_graph = \
306 (int(delta_graph_1)+\
307 int(delta_graph_2)+\
308 int(delta_graph_3)) / 3
309
andrewonlab226024e2014-10-24 16:01:32 -0400310 #Ensure avg delta meets the threshold before appending
311 if avg_delta_graph > 0.0 and avg_delta_graph < 10000:
andrewonlab09d973e2014-10-24 18:56:58 -0400312 latency_end_to_end_list.append(avg_delta_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400313 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400314 main.log.info("Results for end-to-end ignored"+\
315 "due to excess in threshold")
andrewonlab226024e2014-10-24 16:01:32 -0400316
317 #ofp to graph processing latency (ONOS processing)
318 delta_ofp_graph_1 = int(graph_timestamp_1) - int(t0_ofp)
319 delta_ofp_graph_2 = int(graph_timestamp_2) - int(t0_ofp)
320 delta_ofp_graph_3 = int(graph_timestamp_3) - int(t0_ofp)
321
322 avg_delta_ofp_graph = \
323 (int(delta_ofp_graph_1)+\
324 int(delta_ofp_graph_2)+\
325 int(delta_ofp_graph_3)) / 3
326
andrewonlabe5bcef92014-11-06 17:53:20 -0500327 if avg_delta_ofp_graph > threshold_min \
328 and avg_delta_ofp_graph < threshold_max:
andrewonlab226024e2014-10-24 16:01:32 -0400329 latency_ofp_to_graph_list.append(avg_delta_ofp_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400330 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400331 main.log.info("Results for ofp-to-graph "+\
332 "ignored due to excess in threshold")
andrewonlabee4efeb2014-10-24 16:44:51 -0400333
andrewonlab226024e2014-10-24 16:01:32 -0400334 #ofp to device processing latency (ONOS processing)
andrewonlabee4efeb2014-10-24 16:44:51 -0400335 delta_ofp_device_1 = float(device_timestamp_1) - float(t0_ofp)
336 delta_ofp_device_2 = float(device_timestamp_2) - float(t0_ofp)
337 delta_ofp_device_3 = float(device_timestamp_3) - float(t0_ofp)
andrewonlab226024e2014-10-24 16:01:32 -0400338
339 avg_delta_ofp_device = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400340 (float(delta_ofp_device_1)+\
341 float(delta_ofp_device_2)+\
342 float(delta_ofp_device_3)) / 3.0
andrewonlab226024e2014-10-24 16:01:32 -0400343
andrewonlabf47993a2014-10-24 17:56:01 -0400344 #NOTE: ofp - delta measurements are occasionally negative
345 # due to system time misalignment.
andrewonlabf47993a2014-10-24 17:56:01 -0400346 latency_ofp_to_device_list.append(avg_delta_ofp_device)
andrewonlabba44bcf2014-10-16 16:54:41 -0400347
andrewonlabe6745342014-10-17 14:29:13 -0400348 #TODO:
349 #Fetch logs upon threshold excess
andrewonlabba44bcf2014-10-16 16:54:41 -0400350
andrewonlab226024e2014-10-24 16:01:32 -0400351 main.log.info("ONOS1 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400352 str(delta_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400353 main.log.info("ONOS2 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400354 str(delta_graph_2) + " ms")
355 main.log.info("ONOS3 delta end-to-end: "+
356 str(delta_graph_3) + " ms")
andrewonlabba44bcf2014-10-16 16:54:41 -0400357
andrewonlab226024e2014-10-24 16:01:32 -0400358 main.log.info("ONOS1 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400359 str(delta_ofp_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400360 main.log.info("ONOS2 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400361 str(delta_ofp_graph_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400362 main.log.info("ONOS3 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400363 str(delta_ofp_graph_3) + " ms")
andrewonlabe6745342014-10-17 14:29:13 -0400364
andrewonlab226024e2014-10-24 16:01:32 -0400365 main.log.info("ONOS1 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400366 str(delta_device_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400367 main.log.info("ONOS2 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400368 str(delta_device_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400369 main.log.info("ONOS3 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400370 str(delta_device_3) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400371
andrewonlab8790abb2014-11-06 13:51:54 -0500372 #main.log.info("ONOS1 delta OFP - device: "+
373 # str(delta_ofp_device_1) + " ms")
374 #main.log.info("ONOS2 delta OFP - device: "+
375 # str(delta_ofp_device_2) + " ms")
376 #main.log.info("ONOS3 delta OFP - device: "+
377 # str(delta_ofp_device_3) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400378
andrewonlab8d29f122014-10-22 17:15:04 -0400379 main.step("Remove switch from controller")
380 main.Mininet1.delete_sw_controller("s1")
andrewonlabba44bcf2014-10-16 16:54:41 -0400381
andrewonlab8d29f122014-10-22 17:15:04 -0400382 time.sleep(5)
andrewonlabba44bcf2014-10-16 16:54:41 -0400383
andrewonlab09d973e2014-10-24 18:56:58 -0400384 #END of for loop iteration
andrewonlabf47993a2014-10-24 17:56:01 -0400385
andrewonlabee4efeb2014-10-24 16:44:51 -0400386 #If there is at least 1 element in each list,
andrewonlabc15c9582014-10-24 16:35:52 -0400387 #pass the test case
388 if len(latency_end_to_end_list) > 0 and\
389 len(latency_ofp_to_graph_list) > 0 and\
390 len(latency_ofp_to_device_list) > 0 and\
391 len(latency_t0_to_device_list) > 0:
392 assertion = main.TRUE
andrewonlabf47993a2014-10-24 17:56:01 -0400393 elif len(latency_end_to_end_list) == 0:
394 #The appending of 0 here is to prevent
395 #the min,max,sum functions from failing
396 #below
397 latency_end_to_end_list.append(0)
398 assertion = main.FALSE
399 elif len(latency_ofp_to_graph_list) == 0:
400 latency_ofp_to_graph_list.append(0)
401 assertion = main.FALSE
402 elif len(latency_ofp_to_device_list) == 0:
403 latency_ofp_to_device_list.append(0)
404 assertion = main.FALSE
405 elif len(latency_t0_to_device_list) == 0:
406 latency_t0_to_device_list.append(0)
407 assertion = main.FALSE
andrewonlabc15c9582014-10-24 16:35:52 -0400408
409 #Calculate min, max, avg of latency lists
410 latency_end_to_end_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400411 int(max(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400412 latency_end_to_end_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400413 int(min(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400414 latency_end_to_end_avg = \
andrewonlabc90667c2014-10-24 16:48:28 -0400415 (int(sum(latency_end_to_end_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400416 len(latency_end_to_end_list))
417
418 latency_ofp_to_graph_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400419 int(max(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400420 latency_ofp_to_graph_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400421 int(min(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400422 latency_ofp_to_graph_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400423 (int(sum(latency_ofp_to_graph_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400424 len(latency_ofp_to_graph_list))
425
426 latency_ofp_to_device_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400427 int(max(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400428 latency_ofp_to_device_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400429 int(min(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400430 latency_ofp_to_device_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400431 (int(sum(latency_ofp_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400432 len(latency_ofp_to_device_list))
433
434 latency_t0_to_device_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400435 float(max(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400436 latency_t0_to_device_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400437 float(min(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400438 latency_t0_to_device_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400439 (float(sum(latency_t0_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400440 len(latency_ofp_to_device_list))
441
andrewonlabf9828f02014-11-10 14:50:27 -0500442 main.log.report("Switch add - End-to-end latency: "+\
443 "Min: "+str(latency_end_to_end_min)+" mx "+\
444 "Max: "+str(latency_end_to_end_max)+" ms "+\
andrewonlab58f7d702014-11-07 13:21:19 -0500445 "Avg: "+str(latency_end_to_end_avg)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -0500446 main.log.report("Switch add - OFP-to-Graph latency: "+\
447 "Min: "+str(latency_ofp_to_graph_min)+" ms "+\
448 "Max: "+str(latency_ofp_to_graph_max)+" ms "+\
andrewonlab58f7d702014-11-07 13:21:19 -0500449 "Avg: "+str(latency_ofp_to_graph_avg)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -0500450 main.log.report("Switch add - t0-to-Device latency: "+\
451 "Min: "+str(latency_t0_to_device_min)+" ms"+\
452 "Max: "+str(latency_t0_to_device_max)+" ms"+\
andrewonlab58f7d702014-11-07 13:21:19 -0500453 "Avg: "+str(latency_t0_to_device_avg)+" ms")
andrewonlab226024e2014-10-24 16:01:32 -0400454
andrewonlabb1998c52014-11-10 13:31:43 -0500455 if debug_mode == 'on':
456 main.ONOS1.cp_logs_to_dir("/opt/onos/log/karaf.log",
457 "/tmp/", copy_file_name="sw_lat_karaf")
458
andrewonlab8d29f122014-10-22 17:15:04 -0400459 utilities.assert_equals(expect=main.TRUE, actual=assertion,
460 onpass="Switch latency test successful",
461 onfail="Switch latency test failed")
andrewonlabba44bcf2014-10-16 16:54:41 -0400462
andrewonlab8d29f122014-10-22 17:15:04 -0400463 def CASE3(self, main):
464 '''
465 Bring port up / down and measure latency.
466 Port enable / disable is simulated by ifconfig up / down
andrewonlab393531a2014-10-27 18:36:26 -0400467
468 In ONOS-next, we must ensure that the port we are
469 manipulating is connected to another switch with a valid
470 connection. Otherwise, graph view will not be updated.
andrewonlab8d29f122014-10-22 17:15:04 -0400471 '''
472 import time
473 import subprocess
474 import os
475 import requests
476 import json
andrewonlab2a6c9342014-10-16 13:40:15 -0400477
andrewonlab8d29f122014-10-22 17:15:04 -0400478 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlab393531a2014-10-27 18:36:26 -0400479 ONOS2_ip = main.params['CTRL']['ip2']
480 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab8d29f122014-10-22 17:15:04 -0400481 ONOS_user = main.params['CTRL']['user']
andrewonlab8d29f122014-10-22 17:15:04 -0400482
andrewonlab393531a2014-10-27 18:36:26 -0400483 default_sw_port = main.params['CTRL']['port1']
andrewonlab8790abb2014-11-06 13:51:54 -0500484
485 assertion = main.TRUE
andrewonlab393531a2014-10-27 18:36:26 -0400486 #Number of iterations of case
487 num_iter = main.params['TEST']['numIter']
488
489 #Timestamp 'keys' for json metrics output.
490 #These are subject to change, hence moved into params
491 deviceTimestamp = main.params['JSON']['deviceTimestamp']
492 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500493
494 debug_mode = main.params['TEST']['debugMode']
495
496 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500497 local_time = local_time.replace("/","")
498 local_time = local_time.replace(" ","_")
499 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500500 if debug_mode == 'on':
501 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500502 "/tmp/port_lat_pcap_"+local_time)
andrewonlab393531a2014-10-27 18:36:26 -0400503
andrewonlabe5bcef92014-11-06 17:53:20 -0500504 #Threshold for this test case
505 up_threshold_str = main.params['TEST']['portUpThreshold']
506 down_threshold_str = main.params['TEST']['portDownThreshold']
andrewonlabb1998c52014-11-10 13:31:43 -0500507
andrewonlabe5bcef92014-11-06 17:53:20 -0500508 up_threshold_obj = up_threshold_str.split(",")
509 down_threshold_obj = down_threshold_str.split(",")
510
511 up_threshold_min = int(up_threshold_obj[0])
512 up_threshold_max = int(up_threshold_obj[1])
513
514 down_threshold_min = int(down_threshold_obj[0])
515 down_threshold_max = int(down_threshold_obj[1])
516
andrewonlab393531a2014-10-27 18:36:26 -0400517 #NOTE: Some hardcoded variables you may need to configure
518 # besides the params
519
andrewonlab8d29f122014-10-22 17:15:04 -0400520 tshark_port_status = "OFP 130 Port Status"
521
522 tshark_port_up = "/tmp/tshark_port_up.txt"
523 tshark_port_down = "/tmp/tshark_port_down.txt"
andrewonlab393531a2014-10-27 18:36:26 -0400524 interface_config = "s1-eth1"
andrewonlab8d29f122014-10-22 17:15:04 -0400525
526 main.log.report("Port enable / disable latency")
527
andrewonlab393531a2014-10-27 18:36:26 -0400528 main.step("Assign switches s1 and s2 to controller 1")
andrewonlab8d29f122014-10-22 17:15:04 -0400529 main.Mininet1.assign_sw_controller(sw="1",ip1=ONOS1_ip,
530 port1=default_sw_port)
andrewonlab393531a2014-10-27 18:36:26 -0400531 main.Mininet1.assign_sw_controller(sw="2",ip1=ONOS1_ip,
532 port1=default_sw_port)
andrewonlab8d29f122014-10-22 17:15:04 -0400533
andrewonlab8790abb2014-11-06 13:51:54 -0500534 #Give enough time for metrics to propagate the
535 #assign controller event. Otherwise, these events may
536 #carry over to our measurements
andrewonlabb1998c52014-11-10 13:31:43 -0500537 time.sleep(15)
andrewonlab8d29f122014-10-22 17:15:04 -0400538
andrewonlab393531a2014-10-27 18:36:26 -0400539 port_up_device_to_ofp_list = []
540 port_up_graph_to_ofp_list = []
541 port_down_device_to_ofp_list = []
542 port_down_graph_to_ofp_list = []
543
andrewonlab8d29f122014-10-22 17:15:04 -0400544 for i in range(0, int(num_iter)):
545 main.step("Starting wireshark capture for port status down")
546 main.ONOS1.tshark_grep(tshark_port_status,
547 tshark_port_down)
548
andrewonlabb1998c52014-11-10 13:31:43 -0500549 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400550
andrewonlab393531a2014-10-27 18:36:26 -0400551 #Disable interface that is connected to switch 2
552 main.step("Disable port: "+interface_config)
andrewonlabb1998c52014-11-10 13:31:43 -0500553 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400554 interface_config+" down")
andrewonlabb1998c52014-11-10 13:31:43 -0500555 main.Mininet1.handle.expect("mininet>")
andrewonlab8d29f122014-10-22 17:15:04 -0400556
andrewonlabb1998c52014-11-10 13:31:43 -0500557 time.sleep(3)
andrewonlab8d29f122014-10-22 17:15:04 -0400558 main.ONOS1.tshark_stop()
andrewonlabb1998c52014-11-10 13:31:43 -0500559
560 main.step("Obtain t1 by metrics call")
561 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
562 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
563 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
564
565 json_obj_1 = json.loads(json_str_up_1)
566 json_obj_2 = json.loads(json_str_up_2)
567 json_obj_3 = json.loads(json_str_up_3)
andrewonlab8d29f122014-10-22 17:15:04 -0400568
569 #Copy tshark output file from ONOS to TestON instance
570 #/tmp directory
571 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
572 tshark_port_down+" /tmp/")
573
574 f_port_down = open(tshark_port_down, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400575 #Get first line of port down event from tshark
andrewonlab8d29f122014-10-22 17:15:04 -0400576 f_line = f_port_down.readline()
577 obj_down = f_line.split(" ")
578 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500579 timestamp_begin_pt_down = int(float(obj_down[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400580 main.log.info("Port down begin timestamp: "+
581 str(timestamp_begin_pt_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400582 else:
583 main.log.info("Tshark output file returned unexpected"+
andrewonlab393531a2014-10-27 18:36:26 -0400584 " results: "+str(obj_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400585 timestamp_begin_pt_down = 0
andrewonlab393531a2014-10-27 18:36:26 -0400586
587 f_port_down.close()
andrewonlab8d29f122014-10-22 17:15:04 -0400588
andrewonlab4e124482014-11-04 13:37:25 -0500589 main.log.info("TEST tshark obj: "+str(obj_down))
590
andrewonlabb1998c52014-11-10 13:31:43 -0500591 time.sleep(3)
andrewonlab393531a2014-10-27 18:36:26 -0400592
593 #Obtain graph timestamp. This timestsamp captures
594 #the epoch time at which the topology graph was updated.
595 graph_timestamp_1 = \
596 json_obj_1[graphTimestamp]['value']
597 graph_timestamp_2 = \
598 json_obj_2[graphTimestamp]['value']
599 graph_timestamp_3 = \
600 json_obj_3[graphTimestamp]['value']
601
andrewonlabb1998c52014-11-10 13:31:43 -0500602 main.log.info("TEST graph timestamp ONOS1: "+
603 str(graph_timestamp_1))
604
andrewonlab393531a2014-10-27 18:36:26 -0400605 #Obtain device timestamp. This timestamp captures
606 #the epoch time at which the device event happened
607 device_timestamp_1 = \
608 json_obj_1[deviceTimestamp]['value']
609 device_timestamp_2 = \
610 json_obj_2[deviceTimestamp]['value']
611 device_timestamp_3 = \
612 json_obj_3[deviceTimestamp]['value']
andrewonlab393531a2014-10-27 18:36:26 -0400613
614 #Get delta between graph event and OFP
615 pt_down_graph_to_ofp_1 = int(graph_timestamp_1) -\
616 int(timestamp_begin_pt_down)
617 pt_down_graph_to_ofp_2 = int(graph_timestamp_2) -\
618 int(timestamp_begin_pt_down)
619 pt_down_graph_to_ofp_3 = int(graph_timestamp_3) -\
620 int(timestamp_begin_pt_down)
621
622 #Get delta between device event and OFP
623 pt_down_device_to_ofp_1 = int(device_timestamp_1) -\
624 int(timestamp_begin_pt_down)
625 pt_down_device_to_ofp_2 = int(device_timestamp_2) -\
626 int(timestamp_begin_pt_down)
627 pt_down_device_to_ofp_3 = int(device_timestamp_3) -\
628 int(timestamp_begin_pt_down)
629
630 #Caluclate average across clusters
631 pt_down_graph_to_ofp_avg =\
632 (int(pt_down_graph_to_ofp_1) +
633 int(pt_down_graph_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500634 int(pt_down_graph_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400635 pt_down_device_to_ofp_avg = \
636 (int(pt_down_device_to_ofp_1) +
637 int(pt_down_device_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500638 int(pt_down_device_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400639
andrewonlabb1998c52014-11-10 13:31:43 -0500640 if pt_down_graph_to_ofp_avg > down_threshold_min and \
641 pt_down_graph_to_ofp_avg < down_threshold_max:
andrewonlab393531a2014-10-27 18:36:26 -0400642 port_down_graph_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500643 pt_down_graph_to_ofp_avg)
644 main.log.info("Port down: graph to ofp avg: "+
645 str(pt_down_graph_to_ofp_avg) + " ms")
andrewonlab393531a2014-10-27 18:36:26 -0400646 else:
647 main.log.info("Average port down graph-to-ofp result" +
648 " exceeded the threshold: "+
649 str(pt_down_graph_to_ofp_avg))
650
andrewonlab3622beb2014-10-28 16:07:56 -0400651 if pt_down_device_to_ofp_avg > 0 and \
652 pt_down_device_to_ofp_avg < 1000:
653 port_down_device_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500654 pt_down_device_to_ofp_avg)
655 main.log.info("Port down: device to ofp avg: "+
656 str(pt_down_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400657 else:
658 main.log.info("Average port down device-to-ofp result" +
659 " exceeded the threshold: "+
660 str(pt_down_device_to_ofp_avg))
661
andrewonlab8d29f122014-10-22 17:15:04 -0400662 #Port up events
663 main.step("Enable port and obtain timestamp")
664 main.step("Starting wireshark capture for port status up")
andrewonlabb1998c52014-11-10 13:31:43 -0500665 main.ONOS1.tshark_grep(tshark_port_status, tshark_port_up)
andrewonlab8790abb2014-11-06 13:51:54 -0500666 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400667
andrewonlabb1998c52014-11-10 13:31:43 -0500668 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400669 interface_config+" up")
andrewonlabb1998c52014-11-10 13:31:43 -0500670 main.Mininet1.handle.expect("mininet>")
andrewonlab8790abb2014-11-06 13:51:54 -0500671
andrewonlabb1998c52014-11-10 13:31:43 -0500672 #Allow time for tshark to capture event
673 time.sleep(3)
andrewonlab8790abb2014-11-06 13:51:54 -0500674 main.ONOS1.tshark_stop()
andrewonlab8d29f122014-10-22 17:15:04 -0400675
andrewonlabb1998c52014-11-10 13:31:43 -0500676 #Obtain metrics shortly afterwards
677 #This timestsamp captures
678 #the epoch time at which the topology graph was updated.
679 main.step("Obtain t1 by REST call")
680 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
681 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
682 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
683
684 json_obj_1 = json.loads(json_str_up_1)
685 json_obj_2 = json.loads(json_str_up_2)
686 json_obj_3 = json.loads(json_str_up_3)
687
andrewonlab8d29f122014-10-22 17:15:04 -0400688 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
689 tshark_port_up+" /tmp/")
690
691 f_port_up = open(tshark_port_up, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400692 f_line = f_port_up.readline()
andrewonlab8d29f122014-10-22 17:15:04 -0400693 obj_up = f_line.split(" ")
694 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500695 timestamp_begin_pt_up = int(float(obj_up[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400696 main.log.info("Port up begin timestamp: "+
697 str(timestamp_begin_pt_up))
andrewonlab8d29f122014-10-22 17:15:04 -0400698 else:
699 main.log.info("Tshark output file returned unexpected"+
700 " results.")
701 timestamp_begin_pt_up = 0
702
andrewonlab393531a2014-10-27 18:36:26 -0400703 f_port_up.close()
704
andrewonlab393531a2014-10-27 18:36:26 -0400705 graph_timestamp_1 = \
706 json_obj_1[graphTimestamp]['value']
707 graph_timestamp_2 = \
708 json_obj_2[graphTimestamp]['value']
709 graph_timestamp_3 = \
710 json_obj_3[graphTimestamp]['value']
711
712 #Obtain device timestamp. This timestamp captures
713 #the epoch time at which the device event happened
714 device_timestamp_1 = \
715 json_obj_1[deviceTimestamp]['value']
716 device_timestamp_2 = \
717 json_obj_2[deviceTimestamp]['value']
718 device_timestamp_3 = \
719 json_obj_3[deviceTimestamp]['value']
720
721 #Get delta between graph event and OFP
722 pt_up_graph_to_ofp_1 = int(graph_timestamp_1) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400723 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400724 pt_up_graph_to_ofp_2 = int(graph_timestamp_2) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400725 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400726 pt_up_graph_to_ofp_3 = int(graph_timestamp_3) -\
727 int(timestamp_begin_pt_up)
728
729 #Get delta between device event and OFP
730 pt_up_device_to_ofp_1 = int(device_timestamp_1) -\
731 int(timestamp_begin_pt_up)
732 pt_up_device_to_ofp_2 = int(device_timestamp_2) -\
733 int(timestamp_begin_pt_up)
734 pt_up_device_to_ofp_3 = int(device_timestamp_3) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400735 int(timestamp_begin_pt_up)
andrewonlab3622beb2014-10-28 16:07:56 -0400736
andrewonlabb1998c52014-11-10 13:31:43 -0500737 main.log.info("ONOS1 delta G2O: "+str(pt_up_graph_to_ofp_1))
738 main.log.info("ONOS2 delta G2O: "+str(pt_up_graph_to_ofp_2))
739 main.log.info("ONOS3 delta G2O: "+str(pt_up_graph_to_ofp_3))
740
741 main.log.info("ONOS1 delta D2O: "+str(pt_up_device_to_ofp_1))
742 main.log.info("ONOS2 delta D2O: "+str(pt_up_device_to_ofp_2))
743 main.log.info("ONOS3 delta D2O: "+str(pt_up_device_to_ofp_3))
744
andrewonlab3622beb2014-10-28 16:07:56 -0400745 pt_up_graph_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500746 (int(pt_up_graph_to_ofp_1) +
747 int(pt_up_graph_to_ofp_2) +
748 int(pt_up_graph_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400749
750 pt_up_device_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500751 (int(pt_up_device_to_ofp_1) +
752 int(pt_up_device_to_ofp_2) +
753 int(pt_up_device_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400754
andrewonlabe5bcef92014-11-06 17:53:20 -0500755 if pt_up_graph_to_ofp_avg > up_threshold_min and \
756 pt_up_graph_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400757 port_up_graph_to_ofp_list.append(
758 pt_up_graph_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500759 main.log.info("Port down: graph to ofp avg: "+
760 str(pt_up_graph_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400761 else:
762 main.log.info("Average port up graph-to-ofp result"+
763 " exceeded the threshold: "+
764 str(pt_up_graph_to_ofp_avg))
765
andrewonlabe5bcef92014-11-06 17:53:20 -0500766 if pt_up_device_to_ofp_avg > up_threshold_min and \
767 pt_up_device_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400768 port_up_device_to_ofp_list.append(
769 pt_up_device_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500770 main.log.info("Port up: device to ofp avg: "+
771 str(pt_up_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400772 else:
andrewonlababb11c32014-11-04 15:03:24 -0500773 main.log.info("Average port up device-to-ofp result"+
andrewonlab3622beb2014-10-28 16:07:56 -0400774 " exceeded the threshold: "+
775 str(pt_up_device_to_ofp_avg))
andrewonlab8d29f122014-10-22 17:15:04 -0400776
andrewonlab3622beb2014-10-28 16:07:56 -0400777 #END ITERATION FOR LOOP
andrewonlab8790abb2014-11-06 13:51:54 -0500778
779 #Check all list for latency existence and set assertion
780 if (port_down_graph_to_ofp_list and port_down_device_to_ofp_list\
781 and port_up_graph_to_ofp_list and port_up_device_to_ofp_list):
782 assertion = main.TRUE
783
andrewonlababb11c32014-11-04 15:03:24 -0500784 #Calculate and report latency measurements
andrewonlab3622beb2014-10-28 16:07:56 -0400785 port_down_graph_to_ofp_min = min(port_down_graph_to_ofp_list)
786 port_down_graph_to_ofp_max = max(port_down_graph_to_ofp_list)
787 port_down_graph_to_ofp_avg = \
788 (sum(port_down_graph_to_ofp_list) /
789 len(port_down_graph_to_ofp_list))
790
andrewonlabf9828f02014-11-10 14:50:27 -0500791 main.log.report("Port down graph-to-ofp Min: "+
792 str(port_down_graph_to_ofp_min)+" ms Max: "+
793 str(port_down_graph_to_ofp_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -0500794 str(port_down_graph_to_ofp_avg)+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500795
796 port_down_device_to_ofp_min = min(port_down_device_to_ofp_list)
797 port_down_device_to_ofp_max = max(port_down_device_to_ofp_list)
798 port_down_device_to_ofp_avg = \
799 (sum(port_down_device_to_ofp_list) /\
800 len(port_down_device_to_ofp_list))
801
andrewonlabf9828f02014-11-10 14:50:27 -0500802 main.log.report("Port down device-to-ofp Min: "+
803 str(port_down_device_to_ofp_min)+" ms Max: "+
804 str(port_down_device_to_ofp_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -0500805 str(port_down_device_to_ofp_avg)+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500806
807 port_up_graph_to_ofp_min = min(port_up_graph_to_ofp_list)
808 port_up_graph_to_ofp_max = max(port_up_graph_to_ofp_list)
809 port_up_graph_to_ofp_avg = \
810 (sum(port_up_graph_to_ofp_list) /\
811 len(port_up_graph_to_ofp_list))
andrewonlab8790abb2014-11-06 13:51:54 -0500812
andrewonlabf9828f02014-11-10 14:50:27 -0500813 main.log.report("Port up graph-to-ofp Min: "+
814 str(port_up_graph_to_ofp_min)+" ms Max: "+
815 str(port_up_graph_to_ofp_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -0500816 str(port_up_graph_to_ofp_avg)+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500817
818 port_up_device_to_ofp_min = min(port_up_device_to_ofp_list)
819 port_up_device_to_ofp_max = max(port_up_device_to_ofp_list)
820 port_up_device_to_ofp_avg = \
821 (sum(port_up_device_to_ofp_list) /\
822 len(port_up_device_to_ofp_list))
823
andrewonlabf9828f02014-11-10 14:50:27 -0500824 main.log.report("Port up device-to-ofp Min: "+
825 str(port_up_device_to_ofp_min)+" ms Max: "+
826 str(port_up_device_to_ofp_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -0500827 str(port_up_device_to_ofp_avg)+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500828
829 utilities.assert_equals(expect=main.TRUE, actual=assertion,
830 onpass="Port discovery latency calculation successful",
831 onfail="Port discovery test failed")
andrewonlababb11c32014-11-04 15:03:24 -0500832
andrewonlab3622beb2014-10-28 16:07:56 -0400833 def CASE4(self, main):
834 '''
835 Link down event using loss rate 100%
andrewonlab53b641c2014-10-31 19:44:44 -0400836
837 Important:
838 Use a simple 2 switch topology with 1 link between
839 the two switches. Ensure that mac addresses of the
840 switches are 1 / 2 respectively
andrewonlab3622beb2014-10-28 16:07:56 -0400841 '''
842 import time
843 import subprocess
844 import os
845 import requests
846 import json
847
848 ONOS1_ip = main.params['CTRL']['ip1']
849 ONOS2_ip = main.params['CTRL']['ip2']
850 ONOS3_ip = main.params['CTRL']['ip3']
851 ONOS_user = main.params['CTRL']['user']
852
853 default_sw_port = main.params['CTRL']['port1']
854
855 #Number of iterations of case
856 num_iter = main.params['TEST']['numIter']
857
858 #Timestamp 'keys' for json metrics output.
859 #These are subject to change, hence moved into params
860 deviceTimestamp = main.params['JSON']['deviceTimestamp']
861 linkTimestamp = main.params['JSON']['linkTimestamp']
andrewonlab53b641c2014-10-31 19:44:44 -0400862 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500863
864 debug_mode = main.params['TEST']['debugMode']
865
866 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500867 local_time = local_time.replace("/","")
868 local_time = local_time.replace(" ","_")
869 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500870 if debug_mode == 'on':
871 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500872 "/tmp/link_lat_pcap_"+local_time)
andrewonlab53b641c2014-10-31 19:44:44 -0400873
andrewonlabe5bcef92014-11-06 17:53:20 -0500874 #Threshold for this test case
875 up_threshold_str = main.params['TEST']['linkUpThreshold']
876 down_threshold_str = main.params['TEST']['linkDownThreshold']
877
878 up_threshold_obj = up_threshold_str.split(",")
879 down_threshold_obj = down_threshold_str.split(",")
880
881 up_threshold_min = int(up_threshold_obj[0])
882 up_threshold_max = int(up_threshold_obj[1])
883
884 down_threshold_min = int(down_threshold_obj[0])
885 down_threshold_max = int(down_threshold_obj[1])
886
andrewonlab3622beb2014-10-28 16:07:56 -0400887 assertion = main.TRUE
888 #Link event timestamp to system time list
889 link_down_link_to_system_list = []
890 link_up_link_to_system_list = []
891 #Graph event timestamp to system time list
892 link_down_graph_to_system_list = []
893 link_up_graph_to_system_list = []
894
895 main.log.report("Add / remove link latency between "+
896 "two switches")
897
898 main.step("Assign all switches")
899 main.Mininet1.assign_sw_controller(sw="1",
900 ip1=ONOS1_ip, port1=default_sw_port)
901 main.Mininet1.assign_sw_controller(sw="2",
902 ip1=ONOS1_ip, port1=default_sw_port)
903
904 main.step("Verifying switch assignment")
905 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
906 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
andrewonlab3622beb2014-10-28 16:07:56 -0400907
908 #Allow time for events to finish before taking measurements
909 time.sleep(10)
910
andrewonlababb11c32014-11-04 15:03:24 -0500911 link_down1 = False
912 link_down2 = False
913 link_down3 = False
andrewonlab3622beb2014-10-28 16:07:56 -0400914 #Start iteration of link event test
915 for i in range(0, int(num_iter)):
916 main.step("Getting initial system time as t0")
andrewonlab8d29f122014-10-22 17:15:04 -0400917
andrewonlab3622beb2014-10-28 16:07:56 -0400918 timestamp_link_down_t0 = time.time() * 1000
919 #Link down is simulated by 100% loss rate using traffic
920 #control command
921 main.Mininet1.handle.sendline(
922 "sh tc qdisc add dev s1-eth1 root netem loss 100%")
923
andrewonlab53b641c2014-10-31 19:44:44 -0400924 #TODO: Iterate through 'links' command to verify that
andrewonlababb11c32014-11-04 15:03:24 -0500925 # link s1 -> s2 went down (loop timeout 30 seconds)
926 # on all 3 ONOS instances
andrewonlab53b641c2014-10-31 19:44:44 -0400927 main.log.info("Checking ONOS for link update")
928 loop_count = 0
andrewonlababb11c32014-11-04 15:03:24 -0500929 while( not (link_down1 and link_down2 and link_down3)\
930 and loop_count < 30 ):
931 json_str1 = main.ONOS1cli.links()
932 json_str2 = main.ONOS2cli.links()
933 json_str3 = main.ONOS3cli.links()
934
935 if not (json_str1 and json_str2 and json_str3):
936 main.log.error("CLI command returned error ")
andrewonlab53b641c2014-10-31 19:44:44 -0400937 break
938 else:
andrewonlababb11c32014-11-04 15:03:24 -0500939 json_obj1 = json.loads(json_str1)
940 json_obj2 = json.loads(json_str2)
941 json_obj3 = json.loads(json_str3)
942 for obj1 in json_obj1:
943 if '01' not in obj1['src']['device']:
944 link_down1 = True
andrewonlabf9828f02014-11-10 14:50:27 -0500945 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -0500946 "s1 -> s2 on ONOS1 detected")
947 for obj2 in json_obj2:
948 if '01' not in obj2['src']['device']:
949 link_down2 = True
andrewonlabf9828f02014-11-10 14:50:27 -0500950 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -0500951 "s1 -> s2 on ONOS2 detected")
952 for obj3 in json_obj3:
953 if '01' not in obj3['src']['device']:
954 link_down3 = True
andrewonlabf9828f02014-11-10 14:50:27 -0500955 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -0500956 "s1 -> s2 on ONOS3 detected")
957
andrewonlab53b641c2014-10-31 19:44:44 -0400958 loop_count += 1
andrewonlababb11c32014-11-04 15:03:24 -0500959 #If CLI doesn't like the continuous requests
960 #and exits in this loop, increase the sleep here.
961 #Consequently, while loop timeout will increase
andrewonlab53b641c2014-10-31 19:44:44 -0400962 time.sleep(1)
963
964 #Give time for metrics measurement to catch up
andrewonlababb11c32014-11-04 15:03:24 -0500965 #NOTE: May need to be configured more accurately
andrewonlab53b641c2014-10-31 19:44:44 -0400966 time.sleep(10)
andrewonlababb11c32014-11-04 15:03:24 -0500967 #If we exited the while loop and link down 1,2,3 are still
andrewonlab53b641c2014-10-31 19:44:44 -0400968 #false, then ONOS has failed to discover link down event
andrewonlababb11c32014-11-04 15:03:24 -0500969 if not (link_down1 and link_down2 and link_down3):
andrewonlab53b641c2014-10-31 19:44:44 -0400970 main.log.info("Link down discovery failed")
971
972 link_down_lat_graph1 = 0
973 link_down_lat_graph2 = 0
974 link_down_lat_graph3 = 0
975 link_down_lat_device1 = 0
976 link_down_lat_device2 = 0
977 link_down_lat_device3 = 0
978
979 assertion = main.FALSE
980 else:
981 json_topo_metrics_1 =\
982 main.ONOS1cli.topology_events_metrics()
983 json_topo_metrics_2 =\
984 main.ONOS2cli.topology_events_metrics()
985 json_topo_metrics_3 =\
986 main.ONOS3cli.topology_events_metrics()
987 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
988 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
989 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
990
991 main.log.info("Obtaining graph and device timestamp")
992 graph_timestamp_1 = \
993 json_topo_metrics_1[graphTimestamp]['value']
994 graph_timestamp_2 = \
995 json_topo_metrics_2[graphTimestamp]['value']
996 graph_timestamp_3 = \
997 json_topo_metrics_3[graphTimestamp]['value']
998
999 link_timestamp_1 = \
1000 json_topo_metrics_1[linkTimestamp]['value']
1001 link_timestamp_2 = \
1002 json_topo_metrics_2[linkTimestamp]['value']
1003 link_timestamp_3 = \
1004 json_topo_metrics_3[linkTimestamp]['value']
1005
1006 if graph_timestamp_1 and graph_timestamp_2 and\
1007 graph_timestamp_3 and link_timestamp_1 and\
1008 link_timestamp_2 and link_timestamp_3:
1009 link_down_lat_graph1 = int(graph_timestamp_1) -\
1010 timestamp_link_down_t0
1011 link_down_lat_graph2 = int(graph_timestamp_2) -\
1012 timestamp_link_down_t0
1013 link_down_lat_graph3 = int(graph_timestamp_3) -\
1014 timestamp_link_down_t0
1015
1016 link_down_lat_link1 = int(link_timestamp_1) -\
1017 timestamp_link_down_t0
1018 link_down_lat_link2 = int(link_timestamp_2) -\
1019 timestamp_link_down_t0
1020 link_down_lat_link3 = int(link_timestamp_3) -\
1021 timestamp_link_down_t0
1022 else:
1023 main.log.error("There was an error calculating"+
1024 " the delta for link down event")
1025 link_down_lat_graph1 = 0
1026 link_down_lat_graph2 = 0
1027 link_down_lat_graph3 = 0
1028
1029 link_down_lat_device1 = 0
1030 link_down_lat_device2 = 0
1031 link_down_lat_device3 = 0
1032
andrewonlabf9828f02014-11-10 14:50:27 -05001033 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001034 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001035 str(link_down_lat_graph1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001036 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001037 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001038 str(link_down_lat_graph2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001039 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001040 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001041 str(link_down_lat_graph3)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001042
andrewonlabf9828f02014-11-10 14:50:27 -05001043 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001044 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001045 str(link_down_lat_link1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001046 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001047 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001048 str(link_down_lat_link2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001049 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001050 str(i)+" (link-event-to-system-timestamp): "+
1051 str(link_down_lat_link3))
1052
1053 #Calculate avg of node calculations
1054 link_down_lat_graph_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001055 (link_down_lat_graph1 +
1056 link_down_lat_graph2 +
1057 link_down_lat_graph3) / 3.0
andrewonlab4e124482014-11-04 13:37:25 -05001058 link_down_lat_link_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001059 (link_down_lat_link1 +
1060 link_down_lat_link2 +
1061 link_down_lat_link3) / 3.0
andrewonlab53b641c2014-10-31 19:44:44 -04001062
andrewonlab4e124482014-11-04 13:37:25 -05001063 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001064 if link_down_lat_graph_avg > down_threshold_min and\
1065 link_down_lat_graph_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001066 link_down_graph_to_system_list.append(
1067 link_down_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001068 else:
1069 main.log.info("Link down latency exceeded threshold")
1070 main.log.info("Results for iteration "+str(i)+
1071 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001072 if link_down_lat_link_avg > down_threshold_min and\
1073 link_down_lat_link_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001074 link_down_link_to_system_list.append(
1075 link_down_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001076 else:
1077 main.log.info("Link down latency exceeded threshold")
1078 main.log.info("Results for iteration "+str(i)+
1079 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001080
1081 #NOTE: To remove loss rate and measure latency:
1082 # 'sh tc qdisc del dev s1-eth1 root'
andrewonlababb11c32014-11-04 15:03:24 -05001083 timestamp_link_up_t0 = time.time() * 1000
andrewonlab53b641c2014-10-31 19:44:44 -04001084 main.Mininet1.handle.sendline("sh tc qdisc del dev "+
1085 "s1-eth1 root")
1086 main.Mininet1.handle.expect("mininet>")
andrewonlababb11c32014-11-04 15:03:24 -05001087
1088 main.log.info("Checking ONOS for link update")
1089
1090 link_down1 = True
1091 link_down2 = True
1092 link_down3 = True
1093 loop_count = 0
1094 while( (link_down1 and link_down2 and link_down3)\
1095 and loop_count < 30 ):
1096 json_str1 = main.ONOS1cli.links()
1097 json_str2 = main.ONOS2cli.links()
1098 json_str3 = main.ONOS3cli.links()
1099 if not (json_str1 and json_str2 and json_str3):
1100 main.log.error("CLI command returned error ")
1101 break
1102 else:
1103 json_obj1 = json.loads(json_str1)
1104 json_obj2 = json.loads(json_str2)
1105 json_obj3 = json.loads(json_str3)
1106
1107 for obj1 in json_obj1:
1108 if '01' in obj1['src']['device']:
1109 link_down1 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001110 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001111 "s1 -> s2 on ONOS1 detected")
1112 for obj2 in json_obj2:
1113 if '01' in obj2['src']['device']:
1114 link_down2 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001115 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001116 "s1 -> s2 on ONOS2 detected")
1117 for obj3 in json_obj3:
1118 if '01' in obj3['src']['device']:
1119 link_down3 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001120 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001121 "s1 -> s2 on ONOS3 detected")
1122
1123 loop_count += 1
1124 time.sleep(1)
1125
1126 if (link_down1 and link_down2 and link_down3):
1127 main.log.info("Link up discovery failed")
1128
1129 link_up_lat_graph1 = 0
1130 link_up_lat_graph2 = 0
1131 link_up_lat_graph3 = 0
1132 link_up_lat_device1 = 0
1133 link_up_lat_device2 = 0
1134 link_up_lat_device3 = 0
1135
1136 assertion = main.FALSE
1137 else:
1138 json_topo_metrics_1 =\
1139 main.ONOS1cli.topology_events_metrics()
1140 json_topo_metrics_2 =\
1141 main.ONOS2cli.topology_events_metrics()
1142 json_topo_metrics_3 =\
1143 main.ONOS3cli.topology_events_metrics()
1144 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1145 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1146 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1147
1148 main.log.info("Obtaining graph and device timestamp")
1149 graph_timestamp_1 = \
1150 json_topo_metrics_1[graphTimestamp]['value']
1151 graph_timestamp_2 = \
1152 json_topo_metrics_2[graphTimestamp]['value']
1153 graph_timestamp_3 = \
1154 json_topo_metrics_3[graphTimestamp]['value']
1155
1156 link_timestamp_1 = \
1157 json_topo_metrics_1[linkTimestamp]['value']
1158 link_timestamp_2 = \
1159 json_topo_metrics_2[linkTimestamp]['value']
1160 link_timestamp_3 = \
1161 json_topo_metrics_3[linkTimestamp]['value']
1162
1163 if graph_timestamp_1 and graph_timestamp_2 and\
1164 graph_timestamp_3 and link_timestamp_1 and\
1165 link_timestamp_2 and link_timestamp_3:
1166 link_up_lat_graph1 = int(graph_timestamp_1) -\
1167 timestamp_link_up_t0
1168 link_up_lat_graph2 = int(graph_timestamp_2) -\
1169 timestamp_link_up_t0
1170 link_up_lat_graph3 = int(graph_timestamp_3) -\
1171 timestamp_link_up_t0
1172
1173 link_up_lat_link1 = int(link_timestamp_1) -\
1174 timestamp_link_up_t0
1175 link_up_lat_link2 = int(link_timestamp_2) -\
1176 timestamp_link_up_t0
1177 link_up_lat_link3 = int(link_timestamp_3) -\
1178 timestamp_link_up_t0
1179 else:
1180 main.log.error("There was an error calculating"+
1181 " the delta for link down event")
1182 link_up_lat_graph1 = 0
1183 link_up_lat_graph2 = 0
1184 link_up_lat_graph3 = 0
1185
1186 link_up_lat_device1 = 0
1187 link_up_lat_device2 = 0
1188 link_up_lat_device3 = 0
andrewonlab58f7d702014-11-07 13:21:19 -05001189
1190 if debug_mode == 'on':
1191 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001192 str(i)+" (end-to-end): "+
1193 str(link_up_lat_graph1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001194 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001195 str(i)+" (end-to-end): "+
1196 str(link_up_lat_graph2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001197 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001198 str(i)+" (end-to-end): "+
1199 str(link_up_lat_graph3)+" ms")
1200
andrewonlab58f7d702014-11-07 13:21:19 -05001201 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001202 str(i)+" (link-event-to-system-timestamp): "+
1203 str(link_up_lat_link1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001204 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001205 str(i)+" (link-event-to-system-timestamp): "+
1206 str(link_up_lat_link2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001207 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001208 str(i)+" (link-event-to-system-timestamp): "+
1209 str(link_up_lat_link3))
1210
1211 #Calculate avg of node calculations
1212 link_up_lat_graph_avg =\
1213 (link_up_lat_graph1 +
1214 link_up_lat_graph2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001215 link_up_lat_graph3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001216 link_up_lat_link_avg =\
1217 (link_up_lat_link1 +
1218 link_up_lat_link2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001219 link_up_lat_link3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001220
1221 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001222 if link_up_lat_graph_avg > up_threshold_min and\
1223 link_up_lat_graph_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001224 link_up_graph_to_system_list.append(
1225 link_up_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001226 else:
1227 main.log.info("Link up latency exceeded threshold")
1228 main.log.info("Results for iteration "+str(i)+
1229 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001230 if link_up_lat_link_avg > up_threshold_min and\
1231 link_up_lat_link_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001232 link_up_link_to_system_list.append(
1233 link_up_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001234 else:
1235 main.log.info("Link up latency exceeded threshold")
1236 main.log.info("Results for iteration "+str(i)+
1237 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001238
andrewonlab4e124482014-11-04 13:37:25 -05001239 #Calculate min, max, avg of list and report
1240 link_down_min = min(link_down_graph_to_system_list)
1241 link_down_max = max(link_down_graph_to_system_list)
1242 link_down_avg = sum(link_down_graph_to_system_list) / \
1243 len(link_down_graph_to_system_list)
andrewonlababb11c32014-11-04 15:03:24 -05001244 link_up_min = min(link_up_graph_to_system_list)
1245 link_up_max = max(link_up_graph_to_system_list)
1246 link_up_avg = sum(link_up_graph_to_system_list) / \
1247 len(link_up_graph_to_system_list)
1248
andrewonlabf9828f02014-11-10 14:50:27 -05001249 main.log.report("Link down latency - Min: "+
1250 str(link_down_min)+" ms Max: "+
1251 str(link_down_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -05001252 str(link_down_avg)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001253 main.log.report("Link up latency - Min: "+
1254 str(link_up_min)+" ms Max: "+
1255 str(link_up_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -05001256 str(link_up_avg)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001257
andrewonlab8790abb2014-11-06 13:51:54 -05001258 utilities.assert_equals(expect=main.TRUE, actual=assertion,
1259 onpass="Link discovery latency calculation successful",
1260 onfail="Link discovery latency case failed")
1261
andrewonlabb54b85b2014-10-28 18:43:57 -04001262 def CASE5(self, main):
1263 '''
1264 100 Switch discovery latency
1265
1266 Important:
andrewonlab16ce4852014-10-30 13:41:09 -04001267 This test case can be potentially dangerous if
1268 your machine has previously set iptables rules.
1269 One of the steps of the test case will flush
1270 all existing iptables rules.
andrewonlab8790abb2014-11-06 13:51:54 -05001271 Note:
1272 You can specify the number of switches in the
1273 params file to adjust the switch discovery size
1274 (and specify the corresponding topology in Mininet1
1275 .topo file)
andrewonlabb54b85b2014-10-28 18:43:57 -04001276 '''
1277 import time
1278 import subprocess
1279 import os
1280 import requests
1281 import json
1282
1283 ONOS1_ip = main.params['CTRL']['ip1']
1284 ONOS2_ip = main.params['CTRL']['ip2']
1285 ONOS3_ip = main.params['CTRL']['ip3']
1286 MN1_ip = main.params['MN']['ip1']
1287 ONOS_user = main.params['CTRL']['user']
1288
1289 default_sw_port = main.params['CTRL']['port1']
1290
1291 #Number of iterations of case
1292 num_iter = main.params['TEST']['numIter']
andrewonlab16ce4852014-10-30 13:41:09 -04001293 num_sw = main.params['TEST']['numSwitch']
1294
andrewonlabb54b85b2014-10-28 18:43:57 -04001295 #Timestamp 'keys' for json metrics output.
1296 #These are subject to change, hence moved into params
1297 deviceTimestamp = main.params['JSON']['deviceTimestamp']
andrewonlab16ce4852014-10-30 13:41:09 -04001298 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -05001299
1300 debug_mode = main.params['TEST']['debugMode']
1301
andrewonlabb1998c52014-11-10 13:31:43 -05001302 local_time = time.strftime('%X')
1303 local_time = local_time.replace("/","")
1304 local_time = local_time.replace(" ","_")
1305 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -05001306 if debug_mode == 'on':
1307 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -05001308 "/tmp/100_sw_lat_pcap_"+local_time)
andrewonlabe5bcef92014-11-06 17:53:20 -05001309
1310 #Threshold for this test case
1311 sw_disc_threshold_str = main.params['TEST']['swDisc100Threshold']
1312 sw_disc_threshold_obj = sw_disc_threshold_str.split(",")
1313 sw_disc_threshold_min = int(sw_disc_threshold_obj[0])
1314 sw_disc_threshold_max = int(sw_disc_threshold_obj[1])
1315
andrewonlab53b641c2014-10-31 19:44:44 -04001316 tshark_ofp_output = "/tmp/tshark_ofp_"+num_sw+"sw.txt"
1317 tshark_tcp_output = "/tmp/tshark_tcp_"+num_sw+"sw.txt"
1318
1319 tshark_ofp_result_list = []
1320 tshark_tcp_result_list = []
andrewonlabb54b85b2014-10-28 18:43:57 -04001321
andrewonlabe5bcef92014-11-06 17:53:20 -05001322 sw_discovery_lat_list = []
1323
andrewonlab16ce4852014-10-30 13:41:09 -04001324 main.case(num_sw+" Switch discovery latency")
andrewonlabb54b85b2014-10-28 18:43:57 -04001325 main.step("Assigning all switches to ONOS1")
andrewonlab16ce4852014-10-30 13:41:09 -04001326 for i in range(1, int(num_sw)+1):
andrewonlabb54b85b2014-10-28 18:43:57 -04001327 main.Mininet1.assign_sw_controller(
1328 sw=str(i),
1329 ip1=ONOS1_ip,
1330 port1=default_sw_port)
andrewonlab16ce4852014-10-30 13:41:09 -04001331
andrewonlabb54b85b2014-10-28 18:43:57 -04001332 #Ensure that nodes are configured with ptpd
andrewonlab16ce4852014-10-30 13:41:09 -04001333 #Just a warning message
1334 main.log.info("Please check ptpd configuration to ensure"+\
1335 " All nodes' system times are in sync")
1336 time.sleep(5)
andrewonlabb54b85b2014-10-28 18:43:57 -04001337
1338 for i in range(0, int(num_iter)):
andrewonlab8d29f122014-10-22 17:15:04 -04001339
andrewonlabb54b85b2014-10-28 18:43:57 -04001340 main.step("Set iptables rule to block incoming sw connections")
1341 #Set iptables rule to block incoming switch connections
andrewonlab53b641c2014-10-31 19:44:44 -04001342 #The rule description is as follows:
1343 # Append to INPUT rule,
1344 # behavior DROP that matches following:
1345 # * packet type: tcp
1346 # * source IP: MN1_ip
1347 # * destination PORT: 6633
andrewonlabb54b85b2014-10-28 18:43:57 -04001348 main.ONOS1.handle.sendline(
andrewonlab16ce4852014-10-30 13:41:09 -04001349 "sudo iptables -A INPUT -p tcp -s "+MN1_ip+
andrewonlabb54b85b2014-10-28 18:43:57 -04001350 " --dport "+default_sw_port+" -j DROP")
1351 main.ONOS1.handle.expect("\$")
andrewonlab53b641c2014-10-31 19:44:44 -04001352 # Append to OUTPUT rule,
1353 # behavior DROP that matches following:
1354 # * packet type: tcp
1355 # * source IP: MN1_ip
1356 # * destination PORT: 6633
1357 main.ONOS1.handle.sendline(
1358 "sudo iptables -A OUTPUT -p tcp -s "+MN1_ip+
1359 " --dport "+default_sw_port+" -j DROP")
1360 main.ONOS1.handle.expect("\$")
andrewonlabb54b85b2014-10-28 18:43:57 -04001361 #Give time to allow rule to take effect
andrewonlab8790abb2014-11-06 13:51:54 -05001362 #NOTE: Sleep period may need to be configured
1363 # based on the number of switches in the topology
andrewonlab16ce4852014-10-30 13:41:09 -04001364 main.log.info("Please wait for switch connection to "+
1365 "time out")
1366 time.sleep(60)
1367
1368 #Gather vendor OFP with tshark
1369 main.ONOS1.tshark_grep("OFP 86 Vendor",
1370 tshark_ofp_output)
andrewonlab53b641c2014-10-31 19:44:44 -04001371 main.ONOS1.tshark_grep("TCP 74 ",
1372 tshark_tcp_output)
andrewonlabb54b85b2014-10-28 18:43:57 -04001373
andrewonlab16ce4852014-10-30 13:41:09 -04001374 #NOTE: Remove all iptables rule quickly (flush)
andrewonlabb54b85b2014-10-28 18:43:57 -04001375 # Before removal, obtain TestON timestamp at which
andrewonlab16ce4852014-10-30 13:41:09 -04001376 # removal took place
1377 # (ensuring nodes are configured via ptp)
andrewonlabb54b85b2014-10-28 18:43:57 -04001378 # sudo iptables -F
andrewonlab16ce4852014-10-30 13:41:09 -04001379
1380 t0_system = time.time() * 1000
1381 main.ONOS1.handle.sendline(
1382 "sudo iptables -F")
andrewonlabb54b85b2014-10-28 18:43:57 -04001383
andrewonlab16ce4852014-10-30 13:41:09 -04001384 #Counter to track loop count
1385 counter_loop = 0
1386 counter_avail1 = 0
1387 counter_avail2 = 0
1388 counter_avail3 = 0
1389 onos1_dev = False
1390 onos2_dev = False
1391 onos3_dev = False
1392 while counter_loop < 60:
1393 #Continue to check devices for all device
1394 #availability. When all devices in all 3
1395 #ONOS instances indicate that devices are available
1396 #obtain graph event timestamp for t1.
1397 device_str_obj1 = main.ONOS1cli.devices()
1398 device_str_obj2 = main.ONOS2cli.devices()
1399 device_str_obj3 = main.ONOS3cli.devices()
1400
1401 device_json1 = json.loads(device_str_obj1)
1402 device_json2 = json.loads(device_str_obj2)
1403 device_json3 = json.loads(device_str_obj3)
1404
1405 for device1 in device_json1:
1406 if device1['available'] == True:
1407 counter_avail1 += 1
1408 if counter_avail1 == int(num_sw):
1409 onos1_dev = True
1410 main.log.info("All devices have been "+
1411 "discovered on ONOS1")
1412 else:
1413 counter_avail1 = 0
1414 for device2 in device_json2:
1415 if device2['available'] == True:
1416 counter_avail2 += 1
1417 if counter_avail2 == int(num_sw):
1418 onos2_dev = True
1419 main.log.info("All devices have been "+
1420 "discovered on ONOS2")
1421 else:
1422 counter_avail2 = 0
1423 for device3 in device_json3:
1424 if device3['available'] == True:
1425 counter_avail3 += 1
1426 if counter_avail3 == int(num_sw):
1427 onos3_dev = True
1428 main.log.info("All devices have been "+
1429 "discovered on ONOS3")
1430 else:
1431 counter_avail3 = 0
1432
1433 if onos1_dev and onos2_dev and onos3_dev:
1434 main.log.info("All devices have been discovered "+
1435 "on all ONOS instances")
1436 json_str_topology_metrics_1 =\
1437 main.ONOS1cli.topology_events_metrics()
1438 json_str_topology_metrics_2 =\
1439 main.ONOS2cli.topology_events_metrics()
1440 json_str_topology_metrics_3 =\
1441 main.ONOS3cli.topology_events_metrics()
andrewonlab53b641c2014-10-31 19:44:44 -04001442
1443 #Exit while loop if all devices discovered
andrewonlab16ce4852014-10-30 13:41:09 -04001444 break
1445
1446 counter_loop += 1
1447 #Give some time in between CLI calls
1448 #(will not affect measurement)
1449 time.sleep(3)
1450
1451 main.ONOS1.tshark_stop()
1452
1453 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1454 tshark_ofp_output+" /tmp/")
andrewonlab53b641c2014-10-31 19:44:44 -04001455 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1456 tshark_tcp_output+" /tmp/")
andrewonlab16ce4852014-10-30 13:41:09 -04001457
andrewonlab16ce4852014-10-30 13:41:09 -04001458 #TODO: Automate OFP output analysis
andrewonlab58f7d702014-11-07 13:21:19 -05001459 #Debug mode - print out packets captured at runtime
1460 if debug_mode == 'on':
1461 ofp_file = open(tshark_ofp_output, 'r')
1462 main.log.info("Tshark OFP Vendor output: ")
1463 for line in ofp_file:
1464 tshark_ofp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001465 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001466 ofp_file.close()
andrewonlab16ce4852014-10-30 13:41:09 -04001467
andrewonlab58f7d702014-11-07 13:21:19 -05001468 tcp_file = open(tshark_tcp_output, 'r')
1469 main.log.info("Tshark TCP 74 output: ")
1470 for line in tcp_file:
1471 tshark_tcp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001472 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001473 tcp_file.close()
andrewonlab53b641c2014-10-31 19:44:44 -04001474
andrewonlab16ce4852014-10-30 13:41:09 -04001475 json_obj_1 = json.loads(json_str_topology_metrics_1)
1476 json_obj_2 = json.loads(json_str_topology_metrics_2)
1477 json_obj_3 = json.loads(json_str_topology_metrics_3)
1478
1479 graph_timestamp_1 = \
1480 json_obj_1[graphTimestamp]['value']
1481 graph_timestamp_2 = \
1482 json_obj_2[graphTimestamp]['value']
1483 graph_timestamp_3 = \
1484 json_obj_3[graphTimestamp]['value']
1485
andrewonlabe5bcef92014-11-06 17:53:20 -05001486 graph_lat_1 = int(graph_timestamp_1) - int(t0_system)
1487 graph_lat_2 = int(graph_timestamp_2) - int(t0_system)
1488 graph_lat_3 = int(graph_timestamp_3) - int(t0_system)
andrewonlab16ce4852014-10-30 13:41:09 -04001489
andrewonlabe5bcef92014-11-06 17:53:20 -05001490 avg_graph_lat = \
1491 (int(graph_lat_1) +\
1492 int(graph_lat_2) +\
1493 int(graph_lat_3)) / 3
1494
1495 if avg_graph_lat > sw_disc_threshold_min \
1496 and avg_graph_lat < sw_disc_threshold_max:
1497 sw_discovery_lat_list.append(
1498 avg_graph_lat)
1499 else:
1500 main.log.info("100 Switch discovery latency "+
1501 "exceeded the threshold.")
1502
1503 #END ITERATION FOR LOOP
andrewonlab16ce4852014-10-30 13:41:09 -04001504
andrewonlabe5bcef92014-11-06 17:53:20 -05001505 sw_lat_min = min(sw_discovery_lat_list)
1506 sw_lat_max = max(sw_discovery_lat_list)
1507 sw_lat_avg = sum(sw_discovery_lat_list) /\
1508 len(sw_discovery_lat_list)
andrewonlab16ce4852014-10-30 13:41:09 -04001509
andrewonlabf9828f02014-11-10 14:50:27 -05001510 main.log.report("100 Switch discovery lat "+\
1511 "Min: "+str(sw_lat_min)+" ms"+\
1512 "Max: "+str(sw_lat_max)+" ms"+\
1513 "Avg: "+str(sw_lat_avg)+" ms")
andrewonlab16ce4852014-10-30 13:41:09 -04001514
andrewonlabb54b85b2014-10-28 18:43:57 -04001515