blob: 63ba8dfc13f05fb35b570dd6c56fbd4821adea09 [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']
andrewonlab4b5c8b92014-11-10 16:04:33 -0500125 #Number of first 'x' iterations to ignore:
126 iter_ignore = int(main.params['TEST']['iterIgnore'])
127
andrewonlab226024e2014-10-24 16:01:32 -0400128 #Timestamp 'keys' for json metrics output.
129 #These are subject to change, hence moved into params
130 deviceTimestamp = main.params['JSON']['deviceTimestamp']
131 graphTimestamp = main.params['JSON']['graphTimestamp']
132
andrewonlab58f7d702014-11-07 13:21:19 -0500133 debug_mode = main.params['TEST']['debugMode']
andrewonlabb1998c52014-11-10 13:31:43 -0500134 onos_log = main.params['TEST']['onosLogFile']
andrewonlab58f7d702014-11-07 13:21:19 -0500135
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 = []
andrewonlab65d73892014-11-10 17:36:00 -0500148 latency_tcp_to_ofp_list = []
andrewonlab226024e2014-10-24 16:01:32 -0400149
andrewonlabba44bcf2014-10-16 16:54:41 -0400150 #Directory/file to store tshark results
151 tshark_of_output = "/tmp/tshark_of_topo.txt"
152 tshark_tcp_output = "/tmp/tshark_tcp_topo.txt"
153
154 #String to grep in tshark output
155 tshark_tcp_string = "TCP 74 "+default_sw_port
156 tshark_of_string = "OFP 86 Vendor"
andrewonlabe6745342014-10-17 14:29:13 -0400157
158 #Initialize assertion to TRUE
159 assertion = main.TRUE
andrewonlab58f7d702014-11-07 13:21:19 -0500160
161 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500162 local_time = local_time.replace("/","")
163 local_time = local_time.replace(" ","_")
164 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500165 if debug_mode == 'on':
166 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500167 "/tmp/single_sw_lat_pcap_"+local_time)
168
169 main.log.info("TEST")
andrewonlab58f7d702014-11-07 13:21:19 -0500170
andrewonlab4b5c8b92014-11-10 16:04:33 -0500171 main.log.report("Latency of adding one switch to controller")
172 main.log.report("First "+str(iter_ignore)+" iterations ignored"+
173 " for jvm warmup time")
174 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlabba44bcf2014-10-16 16:54:41 -0400175
176 for i in range(0, int(num_iter)):
177 main.log.info("Starting tshark capture")
178
179 #* TCP [ACK, SYN] is used as t0_a, the
180 # very first "exchange" between ONOS and
181 # the switch for end-to-end measurement
182 #* OFP [Stats Reply] is used for t0_b
183 # the very last OFP message between ONOS
184 # and the switch for ONOS measurement
185 main.ONOS1.tshark_grep(tshark_tcp_string,
186 tshark_tcp_output)
187 main.ONOS1.tshark_grep(tshark_of_string,
188 tshark_of_output)
189
190 #Wait and ensure tshark is started and
191 #capturing
192 time.sleep(10)
193
194 main.log.info("Assigning s1 to controller")
195
196 main.Mininet1.assign_sw_controller(sw="1",
197 ip1=ONOS1_ip, port1=default_sw_port)
198
199 #Wait and ensure switch is assigned
200 #before stopping tshark
andrewonlab867212a2014-10-22 20:13:38 -0400201 time.sleep(30)
andrewonlab226024e2014-10-24 16:01:32 -0400202
203 main.log.info("Stopping all Tshark processes")
andrewonlabba44bcf2014-10-16 16:54:41 -0400204 main.ONOS1.stop_tshark()
205
andrewonlabe6745342014-10-17 14:29:13 -0400206 #tshark output is saved in ONOS. Use subprocess
207 #to copy over files to TestON for parsing
208 main.log.info("Copying over tshark files")
209
210 #TCP CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400211 #Copy the tshark output from ONOS machine to
212 #TestON machine in tshark_tcp_output directory>file
213 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
214 tshark_tcp_output+" /tmp/")
215 tcp_file = open(tshark_tcp_output, 'r')
216 temp_text = tcp_file.readline()
andrewonlabe6745342014-10-17 14:29:13 -0400217 temp_text = temp_text.split(" ")
andrewonlabba44bcf2014-10-16 16:54:41 -0400218
andrewonlabe6745342014-10-17 14:29:13 -0400219 main.log.info("Object read in from TCP capture: "+
220 str(temp_text))
andrewonlab867212a2014-10-22 20:13:38 -0400221 if len(temp_text) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400222 t0_tcp = float(temp_text[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400223 else:
224 main.log.error("Tshark output file for TCP"+
225 " returned unexpected results")
226 t0_tcp = 0
227 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400228
229 tcp_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400230 #****************
andrewonlabba44bcf2014-10-16 16:54:41 -0400231
andrewonlabe6745342014-10-17 14:29:13 -0400232 #OF CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400233 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
234 tshark_of_output+" /tmp/")
235 of_file = open(tshark_of_output, 'r')
236
237 line_ofp = ""
andrewonlab226024e2014-10-24 16:01:32 -0400238 #Read until last line of file
andrewonlabe6745342014-10-17 14:29:13 -0400239 while True:
andrewonlab8d29f122014-10-22 17:15:04 -0400240 temp_text = of_file.readline()
241 if temp_text !='':
andrewonlabe6745342014-10-17 14:29:13 -0400242 line_ofp = temp_text
243 else:
244 break
245 obj = line_ofp.split(" ")
246
247 main.log.info("Object read in from OFP capture: "+
248 str(line_ofp))
249
andrewonlab867212a2014-10-22 20:13:38 -0400250 if len(line_ofp) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400251 t0_ofp = float(obj[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400252 else:
253 main.log.error("Tshark output file for OFP"+
254 " returned unexpected results")
255 t0_ofp = 0
256 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400257
258 of_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400259 #****************
260
andrewonlab867212a2014-10-22 20:13:38 -0400261 json_str_1 = main.ONOS1cli.topology_events_metrics()
262 json_str_2 = main.ONOS2cli.topology_events_metrics()
263 json_str_3 = main.ONOS3cli.topology_events_metrics()
andrewonlab867212a2014-10-22 20:13:38 -0400264
265 json_obj_1 = json.loads(json_str_1)
266 json_obj_2 = json.loads(json_str_2)
267 json_obj_3 = json.loads(json_str_3)
268
andrewonlab226024e2014-10-24 16:01:32 -0400269 #Obtain graph timestamp. This timestsamp captures
270 #the epoch time at which the topology graph was updated.
271 graph_timestamp_1 = \
272 json_obj_1[graphTimestamp]['value']
273 graph_timestamp_2 = \
274 json_obj_2[graphTimestamp]['value']
275 graph_timestamp_3 = \
276 json_obj_3[graphTimestamp]['value']
andrewonlab867212a2014-10-22 20:13:38 -0400277
andrewonlab226024e2014-10-24 16:01:32 -0400278 #Obtain device timestamp. This timestamp captures
279 #the epoch time at which the device event happened
280 device_timestamp_1 = \
281 json_obj_1[deviceTimestamp]['value']
282 device_timestamp_2 = \
283 json_obj_2[deviceTimestamp]['value']
284 device_timestamp_3 = \
285 json_obj_3[deviceTimestamp]['value']
andrewonlabe9fb6722014-10-24 12:20:35 -0400286
andrewonlab226024e2014-10-24 16:01:32 -0400287 #t0 to device processing latency
288 delta_device_1 = int(device_timestamp_1) - int(t0_tcp)
289 delta_device_2 = int(device_timestamp_2) - int(t0_tcp)
290 delta_device_3 = int(device_timestamp_3) - int(t0_tcp)
291
292 #Get average of delta from all instances
293 avg_delta_device = \
294 (int(delta_device_1)+\
295 int(delta_device_2)+\
296 int(delta_device_3)) / 3
andrewonlabba44bcf2014-10-16 16:54:41 -0400297
andrewonlab226024e2014-10-24 16:01:32 -0400298 #Ensure avg delta meets the threshold before appending
andrewonlab4b5c8b92014-11-10 16:04:33 -0500299 if avg_delta_device > 0.0 and avg_delta_device < 10000\
andrewonlab65d73892014-11-10 17:36:00 -0500300 and int(i) > iter_ignore:
andrewonlab226024e2014-10-24 16:01:32 -0400301 latency_t0_to_device_list.append(avg_delta_device)
andrewonlabee4efeb2014-10-24 16:44:51 -0400302 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400303 main.log.info("Results for t0-to-device ignored"+\
andrewonlab4b5c8b92014-11-10 16:04:33 -0500304 "due to excess in threshold / warmup iteration.")
andrewonlabee4efeb2014-10-24 16:44:51 -0400305
andrewonlab226024e2014-10-24 16:01:32 -0400306 #t0 to graph processing latency (end-to-end)
307 delta_graph_1 = int(graph_timestamp_1) - int(t0_tcp)
308 delta_graph_2 = int(graph_timestamp_2) - int(t0_tcp)
309 delta_graph_3 = int(graph_timestamp_3) - int(t0_tcp)
310
311 #Get average of delta from all instances
312 avg_delta_graph = \
313 (int(delta_graph_1)+\
314 int(delta_graph_2)+\
315 int(delta_graph_3)) / 3
316
andrewonlab226024e2014-10-24 16:01:32 -0400317 #Ensure avg delta meets the threshold before appending
andrewonlab4b5c8b92014-11-10 16:04:33 -0500318 if avg_delta_graph > 0.0 and avg_delta_graph < 10000\
andrewonlab65d73892014-11-10 17:36:00 -0500319 and int(i) > iter_ignore:
andrewonlab09d973e2014-10-24 18:56:58 -0400320 latency_end_to_end_list.append(avg_delta_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400321 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400322 main.log.info("Results for end-to-end ignored"+\
323 "due to excess in threshold")
andrewonlab226024e2014-10-24 16:01:32 -0400324
325 #ofp to graph processing latency (ONOS processing)
326 delta_ofp_graph_1 = int(graph_timestamp_1) - int(t0_ofp)
327 delta_ofp_graph_2 = int(graph_timestamp_2) - int(t0_ofp)
328 delta_ofp_graph_3 = int(graph_timestamp_3) - int(t0_ofp)
329
330 avg_delta_ofp_graph = \
331 (int(delta_ofp_graph_1)+\
332 int(delta_ofp_graph_2)+\
333 int(delta_ofp_graph_3)) / 3
334
andrewonlabe5bcef92014-11-06 17:53:20 -0500335 if avg_delta_ofp_graph > threshold_min \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500336 and avg_delta_ofp_graph < threshold_max\
andrewonlab65d73892014-11-10 17:36:00 -0500337 and int(i) > iter_ignore:
andrewonlab226024e2014-10-24 16:01:32 -0400338 latency_ofp_to_graph_list.append(avg_delta_ofp_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400339 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400340 main.log.info("Results for ofp-to-graph "+\
341 "ignored due to excess in threshold")
andrewonlabee4efeb2014-10-24 16:44:51 -0400342
andrewonlab226024e2014-10-24 16:01:32 -0400343 #ofp to device processing latency (ONOS processing)
andrewonlabee4efeb2014-10-24 16:44:51 -0400344 delta_ofp_device_1 = float(device_timestamp_1) - float(t0_ofp)
345 delta_ofp_device_2 = float(device_timestamp_2) - float(t0_ofp)
346 delta_ofp_device_3 = float(device_timestamp_3) - float(t0_ofp)
andrewonlab226024e2014-10-24 16:01:32 -0400347
348 avg_delta_ofp_device = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400349 (float(delta_ofp_device_1)+\
350 float(delta_ofp_device_2)+\
andrewonlab4b5c8b92014-11-10 16:04:33 -0500351 float(delta_ofp_device_3)) / 3
andrewonlab226024e2014-10-24 16:01:32 -0400352
andrewonlabf47993a2014-10-24 17:56:01 -0400353 #NOTE: ofp - delta measurements are occasionally negative
354 # due to system time misalignment.
andrewonlabf47993a2014-10-24 17:56:01 -0400355 latency_ofp_to_device_list.append(avg_delta_ofp_device)
andrewonlabba44bcf2014-10-16 16:54:41 -0400356
andrewonlab65d73892014-11-10 17:36:00 -0500357 delta_ofp_tcp = int(t0_ofp) - int(t0_tcp)
358 if delta_ofp_tcp > threshold_min \
359 and delta_ofp_tcp < threshold_max and\
360 int(i) > iter_ignore:
361 latency_tcp_to_ofp_list.append(delta_ofp_tcp)
362 else:
363 main.log.info("Results fo tcp-to-ofp "+\
364 "ignored due to excess in threshold")
365
andrewonlabe6745342014-10-17 14:29:13 -0400366 #TODO:
367 #Fetch logs upon threshold excess
andrewonlabba44bcf2014-10-16 16:54:41 -0400368
andrewonlab226024e2014-10-24 16:01:32 -0400369 main.log.info("ONOS1 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400370 str(delta_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400371 main.log.info("ONOS2 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400372 str(delta_graph_2) + " ms")
373 main.log.info("ONOS3 delta end-to-end: "+
374 str(delta_graph_3) + " ms")
andrewonlabba44bcf2014-10-16 16:54:41 -0400375
andrewonlab226024e2014-10-24 16:01:32 -0400376 main.log.info("ONOS1 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400377 str(delta_ofp_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400378 main.log.info("ONOS2 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400379 str(delta_ofp_graph_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400380 main.log.info("ONOS3 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400381 str(delta_ofp_graph_3) + " ms")
andrewonlabe6745342014-10-17 14:29:13 -0400382
andrewonlab226024e2014-10-24 16:01:32 -0400383 main.log.info("ONOS1 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400384 str(delta_device_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400385 main.log.info("ONOS2 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400386 str(delta_device_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400387 main.log.info("ONOS3 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400388 str(delta_device_3) + " ms")
andrewonlab65d73892014-11-10 17:36:00 -0500389
390 main.log.info("TCP to OFP delta: "+
391 str(delta_ofp_tcp) + " ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500392 #main.log.info("ONOS1 delta OFP - device: "+
393 # str(delta_ofp_device_1) + " ms")
394 #main.log.info("ONOS2 delta OFP - device: "+
395 # str(delta_ofp_device_2) + " ms")
396 #main.log.info("ONOS3 delta OFP - device: "+
397 # str(delta_ofp_device_3) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400398
andrewonlab8d29f122014-10-22 17:15:04 -0400399 main.step("Remove switch from controller")
400 main.Mininet1.delete_sw_controller("s1")
andrewonlabba44bcf2014-10-16 16:54:41 -0400401
andrewonlab8d29f122014-10-22 17:15:04 -0400402 time.sleep(5)
andrewonlabba44bcf2014-10-16 16:54:41 -0400403
andrewonlab09d973e2014-10-24 18:56:58 -0400404 #END of for loop iteration
andrewonlabf47993a2014-10-24 17:56:01 -0400405
andrewonlabee4efeb2014-10-24 16:44:51 -0400406 #If there is at least 1 element in each list,
andrewonlabc15c9582014-10-24 16:35:52 -0400407 #pass the test case
408 if len(latency_end_to_end_list) > 0 and\
409 len(latency_ofp_to_graph_list) > 0 and\
410 len(latency_ofp_to_device_list) > 0 and\
andrewonlab65d73892014-11-10 17:36:00 -0500411 len(latency_t0_to_device_list) > 0 and\
412 len(latency_tcp_to_ofp_list) > 0:
andrewonlabc15c9582014-10-24 16:35:52 -0400413 assertion = main.TRUE
andrewonlabf47993a2014-10-24 17:56:01 -0400414 elif len(latency_end_to_end_list) == 0:
415 #The appending of 0 here is to prevent
416 #the min,max,sum functions from failing
417 #below
418 latency_end_to_end_list.append(0)
419 assertion = main.FALSE
420 elif len(latency_ofp_to_graph_list) == 0:
421 latency_ofp_to_graph_list.append(0)
422 assertion = main.FALSE
423 elif len(latency_ofp_to_device_list) == 0:
424 latency_ofp_to_device_list.append(0)
425 assertion = main.FALSE
426 elif len(latency_t0_to_device_list) == 0:
427 latency_t0_to_device_list.append(0)
428 assertion = main.FALSE
andrewonlab65d73892014-11-10 17:36:00 -0500429 elif len(latency_tcp_to_ofp_list) == 0:
430 latency_tcp_to_ofp_list.append(0)
431 assertion = main.FALSE
andrewonlabc15c9582014-10-24 16:35:52 -0400432
433 #Calculate min, max, avg of latency lists
434 latency_end_to_end_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400435 int(max(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400436 latency_end_to_end_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400437 int(min(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400438 latency_end_to_end_avg = \
andrewonlabc90667c2014-10-24 16:48:28 -0400439 (int(sum(latency_end_to_end_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400440 len(latency_end_to_end_list))
441
442 latency_ofp_to_graph_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400443 int(max(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400444 latency_ofp_to_graph_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400445 int(min(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400446 latency_ofp_to_graph_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400447 (int(sum(latency_ofp_to_graph_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400448 len(latency_ofp_to_graph_list))
449
450 latency_ofp_to_device_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400451 int(max(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400452 latency_ofp_to_device_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400453 int(min(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400454 latency_ofp_to_device_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400455 (int(sum(latency_ofp_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400456 len(latency_ofp_to_device_list))
457
458 latency_t0_to_device_max = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500459 int(max(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400460 latency_t0_to_device_min = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500461 int(min(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400462 latency_t0_to_device_avg = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500463 (int(sum(latency_t0_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400464 len(latency_ofp_to_device_list))
465
andrewonlab65d73892014-11-10 17:36:00 -0500466 latency_tcp_to_ofp_max = \
467 int(max(latency_tcp_to_ofp_list))
468 latency_tcp_to_ofp_min = \
469 int(min(latency_tcp_to_ofp_list))
470 latency_tcp_to_ofp_avg = \
471 (int(sum(latency_tcp_to_ofp_list)) / \
472 len(latency_tcp_to_ofp_list))
473
andrewonlabf9828f02014-11-10 14:50:27 -0500474 main.log.report("Switch add - End-to-end latency: "+\
andrewonlab4b5c8b92014-11-10 16:04:33 -0500475 "Min: "+str(latency_end_to_end_min)+" ms "+\
andrewonlabf9828f02014-11-10 14:50:27 -0500476 "Max: "+str(latency_end_to_end_max)+" ms "+\
andrewonlab65d73892014-11-10 17:36:00 -0500477 "Avg: "+str(latency_end_to_end_avg)+" ms ")
andrewonlabf9828f02014-11-10 14:50:27 -0500478 main.log.report("Switch add - OFP-to-Graph latency: "+\
479 "Min: "+str(latency_ofp_to_graph_min)+" ms "+\
480 "Max: "+str(latency_ofp_to_graph_max)+" ms "+\
andrewonlab65d73892014-11-10 17:36:00 -0500481 "Avg: "+str(latency_ofp_to_graph_avg)+" ms ")
482 main.log.report("Switch add - TCP-to-OFP latency: "+\
483 "Min: "+str(latency_tcp_to_ofp_min)+" ms "+\
484 "Max: "+str(latency_tcp_to_ofp_max)+" ms "+\
485 "Avg: "+str(latency_tcp_to_ofp_avg)+" ms ")
andrewonlab226024e2014-10-24 16:01:32 -0400486
andrewonlabb1998c52014-11-10 13:31:43 -0500487 if debug_mode == 'on':
488 main.ONOS1.cp_logs_to_dir("/opt/onos/log/karaf.log",
489 "/tmp/", copy_file_name="sw_lat_karaf")
490
andrewonlab8d29f122014-10-22 17:15:04 -0400491 utilities.assert_equals(expect=main.TRUE, actual=assertion,
492 onpass="Switch latency test successful",
493 onfail="Switch latency test failed")
andrewonlabba44bcf2014-10-16 16:54:41 -0400494
andrewonlab8d29f122014-10-22 17:15:04 -0400495 def CASE3(self, main):
496 '''
497 Bring port up / down and measure latency.
498 Port enable / disable is simulated by ifconfig up / down
andrewonlab393531a2014-10-27 18:36:26 -0400499
500 In ONOS-next, we must ensure that the port we are
501 manipulating is connected to another switch with a valid
502 connection. Otherwise, graph view will not be updated.
andrewonlab8d29f122014-10-22 17:15:04 -0400503 '''
504 import time
505 import subprocess
506 import os
507 import requests
508 import json
andrewonlab2a6c9342014-10-16 13:40:15 -0400509
andrewonlab8d29f122014-10-22 17:15:04 -0400510 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlab393531a2014-10-27 18:36:26 -0400511 ONOS2_ip = main.params['CTRL']['ip2']
512 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab8d29f122014-10-22 17:15:04 -0400513 ONOS_user = main.params['CTRL']['user']
andrewonlab8d29f122014-10-22 17:15:04 -0400514
andrewonlab393531a2014-10-27 18:36:26 -0400515 default_sw_port = main.params['CTRL']['port1']
andrewonlab8790abb2014-11-06 13:51:54 -0500516
517 assertion = main.TRUE
andrewonlab393531a2014-10-27 18:36:26 -0400518 #Number of iterations of case
519 num_iter = main.params['TEST']['numIter']
520
521 #Timestamp 'keys' for json metrics output.
522 #These are subject to change, hence moved into params
523 deviceTimestamp = main.params['JSON']['deviceTimestamp']
524 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500525
526 debug_mode = main.params['TEST']['debugMode']
527
528 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500529 local_time = local_time.replace("/","")
530 local_time = local_time.replace(" ","_")
531 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500532 if debug_mode == 'on':
533 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500534 "/tmp/port_lat_pcap_"+local_time)
andrewonlab393531a2014-10-27 18:36:26 -0400535
andrewonlabe5bcef92014-11-06 17:53:20 -0500536 #Threshold for this test case
537 up_threshold_str = main.params['TEST']['portUpThreshold']
538 down_threshold_str = main.params['TEST']['portDownThreshold']
andrewonlabb1998c52014-11-10 13:31:43 -0500539
andrewonlabe5bcef92014-11-06 17:53:20 -0500540 up_threshold_obj = up_threshold_str.split(",")
541 down_threshold_obj = down_threshold_str.split(",")
542
543 up_threshold_min = int(up_threshold_obj[0])
544 up_threshold_max = int(up_threshold_obj[1])
545
546 down_threshold_min = int(down_threshold_obj[0])
547 down_threshold_max = int(down_threshold_obj[1])
548
andrewonlab393531a2014-10-27 18:36:26 -0400549 #NOTE: Some hardcoded variables you may need to configure
550 # besides the params
551
andrewonlab8d29f122014-10-22 17:15:04 -0400552 tshark_port_status = "OFP 130 Port Status"
553
554 tshark_port_up = "/tmp/tshark_port_up.txt"
555 tshark_port_down = "/tmp/tshark_port_down.txt"
andrewonlab393531a2014-10-27 18:36:26 -0400556 interface_config = "s1-eth1"
andrewonlab8d29f122014-10-22 17:15:04 -0400557
558 main.log.report("Port enable / disable latency")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500559 main.log.report("Simulated by ifconfig up / down")
560 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab8d29f122014-10-22 17:15:04 -0400561
andrewonlab393531a2014-10-27 18:36:26 -0400562 main.step("Assign switches s1 and s2 to controller 1")
andrewonlab8d29f122014-10-22 17:15:04 -0400563 main.Mininet1.assign_sw_controller(sw="1",ip1=ONOS1_ip,
564 port1=default_sw_port)
andrewonlab393531a2014-10-27 18:36:26 -0400565 main.Mininet1.assign_sw_controller(sw="2",ip1=ONOS1_ip,
566 port1=default_sw_port)
andrewonlab8d29f122014-10-22 17:15:04 -0400567
andrewonlab8790abb2014-11-06 13:51:54 -0500568 #Give enough time for metrics to propagate the
569 #assign controller event. Otherwise, these events may
570 #carry over to our measurements
andrewonlabb1998c52014-11-10 13:31:43 -0500571 time.sleep(15)
andrewonlab8d29f122014-10-22 17:15:04 -0400572
andrewonlab393531a2014-10-27 18:36:26 -0400573 port_up_device_to_ofp_list = []
574 port_up_graph_to_ofp_list = []
575 port_down_device_to_ofp_list = []
576 port_down_graph_to_ofp_list = []
577
andrewonlab8d29f122014-10-22 17:15:04 -0400578 for i in range(0, int(num_iter)):
579 main.step("Starting wireshark capture for port status down")
580 main.ONOS1.tshark_grep(tshark_port_status,
581 tshark_port_down)
582
andrewonlabb1998c52014-11-10 13:31:43 -0500583 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400584
andrewonlab393531a2014-10-27 18:36:26 -0400585 #Disable interface that is connected to switch 2
586 main.step("Disable port: "+interface_config)
andrewonlabb1998c52014-11-10 13:31:43 -0500587 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400588 interface_config+" down")
andrewonlabb1998c52014-11-10 13:31:43 -0500589 main.Mininet1.handle.expect("mininet>")
andrewonlab8d29f122014-10-22 17:15:04 -0400590
andrewonlabb1998c52014-11-10 13:31:43 -0500591 time.sleep(3)
andrewonlab8d29f122014-10-22 17:15:04 -0400592 main.ONOS1.tshark_stop()
andrewonlabb1998c52014-11-10 13:31:43 -0500593
594 main.step("Obtain t1 by metrics call")
595 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
596 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
597 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
598
599 json_obj_1 = json.loads(json_str_up_1)
600 json_obj_2 = json.loads(json_str_up_2)
601 json_obj_3 = json.loads(json_str_up_3)
andrewonlab8d29f122014-10-22 17:15:04 -0400602
603 #Copy tshark output file from ONOS to TestON instance
604 #/tmp directory
605 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
606 tshark_port_down+" /tmp/")
607
608 f_port_down = open(tshark_port_down, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400609 #Get first line of port down event from tshark
andrewonlab8d29f122014-10-22 17:15:04 -0400610 f_line = f_port_down.readline()
611 obj_down = f_line.split(" ")
612 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500613 timestamp_begin_pt_down = int(float(obj_down[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400614 main.log.info("Port down begin timestamp: "+
615 str(timestamp_begin_pt_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400616 else:
617 main.log.info("Tshark output file returned unexpected"+
andrewonlab393531a2014-10-27 18:36:26 -0400618 " results: "+str(obj_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400619 timestamp_begin_pt_down = 0
andrewonlab393531a2014-10-27 18:36:26 -0400620
621 f_port_down.close()
andrewonlab8d29f122014-10-22 17:15:04 -0400622
andrewonlab4e124482014-11-04 13:37:25 -0500623 main.log.info("TEST tshark obj: "+str(obj_down))
624
andrewonlabb1998c52014-11-10 13:31:43 -0500625 time.sleep(3)
andrewonlab393531a2014-10-27 18:36:26 -0400626
627 #Obtain graph timestamp. This timestsamp captures
628 #the epoch time at which the topology graph was updated.
629 graph_timestamp_1 = \
630 json_obj_1[graphTimestamp]['value']
631 graph_timestamp_2 = \
632 json_obj_2[graphTimestamp]['value']
633 graph_timestamp_3 = \
634 json_obj_3[graphTimestamp]['value']
635
andrewonlabb1998c52014-11-10 13:31:43 -0500636 main.log.info("TEST graph timestamp ONOS1: "+
637 str(graph_timestamp_1))
638
andrewonlab393531a2014-10-27 18:36:26 -0400639 #Obtain device timestamp. This timestamp captures
640 #the epoch time at which the device event happened
641 device_timestamp_1 = \
642 json_obj_1[deviceTimestamp]['value']
643 device_timestamp_2 = \
644 json_obj_2[deviceTimestamp]['value']
645 device_timestamp_3 = \
646 json_obj_3[deviceTimestamp]['value']
andrewonlab393531a2014-10-27 18:36:26 -0400647
648 #Get delta between graph event and OFP
649 pt_down_graph_to_ofp_1 = int(graph_timestamp_1) -\
650 int(timestamp_begin_pt_down)
651 pt_down_graph_to_ofp_2 = int(graph_timestamp_2) -\
652 int(timestamp_begin_pt_down)
653 pt_down_graph_to_ofp_3 = int(graph_timestamp_3) -\
654 int(timestamp_begin_pt_down)
655
656 #Get delta between device event and OFP
657 pt_down_device_to_ofp_1 = int(device_timestamp_1) -\
658 int(timestamp_begin_pt_down)
659 pt_down_device_to_ofp_2 = int(device_timestamp_2) -\
660 int(timestamp_begin_pt_down)
661 pt_down_device_to_ofp_3 = int(device_timestamp_3) -\
662 int(timestamp_begin_pt_down)
663
664 #Caluclate average across clusters
665 pt_down_graph_to_ofp_avg =\
666 (int(pt_down_graph_to_ofp_1) +
667 int(pt_down_graph_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500668 int(pt_down_graph_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400669 pt_down_device_to_ofp_avg = \
670 (int(pt_down_device_to_ofp_1) +
671 int(pt_down_device_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500672 int(pt_down_device_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400673
andrewonlabb1998c52014-11-10 13:31:43 -0500674 if pt_down_graph_to_ofp_avg > down_threshold_min and \
675 pt_down_graph_to_ofp_avg < down_threshold_max:
andrewonlab393531a2014-10-27 18:36:26 -0400676 port_down_graph_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500677 pt_down_graph_to_ofp_avg)
678 main.log.info("Port down: graph to ofp avg: "+
679 str(pt_down_graph_to_ofp_avg) + " ms")
andrewonlab393531a2014-10-27 18:36:26 -0400680 else:
681 main.log.info("Average port down graph-to-ofp result" +
682 " exceeded the threshold: "+
683 str(pt_down_graph_to_ofp_avg))
684
andrewonlab3622beb2014-10-28 16:07:56 -0400685 if pt_down_device_to_ofp_avg > 0 and \
686 pt_down_device_to_ofp_avg < 1000:
687 port_down_device_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500688 pt_down_device_to_ofp_avg)
689 main.log.info("Port down: device to ofp avg: "+
690 str(pt_down_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400691 else:
692 main.log.info("Average port down device-to-ofp result" +
693 " exceeded the threshold: "+
694 str(pt_down_device_to_ofp_avg))
695
andrewonlab8d29f122014-10-22 17:15:04 -0400696 #Port up events
697 main.step("Enable port and obtain timestamp")
698 main.step("Starting wireshark capture for port status up")
andrewonlabb1998c52014-11-10 13:31:43 -0500699 main.ONOS1.tshark_grep(tshark_port_status, tshark_port_up)
andrewonlab8790abb2014-11-06 13:51:54 -0500700 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400701
andrewonlabb1998c52014-11-10 13:31:43 -0500702 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400703 interface_config+" up")
andrewonlabb1998c52014-11-10 13:31:43 -0500704 main.Mininet1.handle.expect("mininet>")
andrewonlab8790abb2014-11-06 13:51:54 -0500705
andrewonlabb1998c52014-11-10 13:31:43 -0500706 #Allow time for tshark to capture event
707 time.sleep(3)
andrewonlab8790abb2014-11-06 13:51:54 -0500708 main.ONOS1.tshark_stop()
andrewonlab8d29f122014-10-22 17:15:04 -0400709
andrewonlabb1998c52014-11-10 13:31:43 -0500710 #Obtain metrics shortly afterwards
711 #This timestsamp captures
712 #the epoch time at which the topology graph was updated.
713 main.step("Obtain t1 by REST call")
714 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
715 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
716 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
717
718 json_obj_1 = json.loads(json_str_up_1)
719 json_obj_2 = json.loads(json_str_up_2)
720 json_obj_3 = json.loads(json_str_up_3)
721
andrewonlab8d29f122014-10-22 17:15:04 -0400722 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
723 tshark_port_up+" /tmp/")
724
725 f_port_up = open(tshark_port_up, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400726 f_line = f_port_up.readline()
andrewonlab8d29f122014-10-22 17:15:04 -0400727 obj_up = f_line.split(" ")
728 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500729 timestamp_begin_pt_up = int(float(obj_up[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400730 main.log.info("Port up begin timestamp: "+
731 str(timestamp_begin_pt_up))
andrewonlab8d29f122014-10-22 17:15:04 -0400732 else:
733 main.log.info("Tshark output file returned unexpected"+
734 " results.")
735 timestamp_begin_pt_up = 0
736
andrewonlab393531a2014-10-27 18:36:26 -0400737 f_port_up.close()
738
andrewonlab393531a2014-10-27 18:36:26 -0400739 graph_timestamp_1 = \
740 json_obj_1[graphTimestamp]['value']
741 graph_timestamp_2 = \
742 json_obj_2[graphTimestamp]['value']
743 graph_timestamp_3 = \
744 json_obj_3[graphTimestamp]['value']
745
746 #Obtain device timestamp. This timestamp captures
747 #the epoch time at which the device event happened
748 device_timestamp_1 = \
749 json_obj_1[deviceTimestamp]['value']
750 device_timestamp_2 = \
751 json_obj_2[deviceTimestamp]['value']
752 device_timestamp_3 = \
753 json_obj_3[deviceTimestamp]['value']
754
755 #Get delta between graph event and OFP
756 pt_up_graph_to_ofp_1 = int(graph_timestamp_1) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400757 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400758 pt_up_graph_to_ofp_2 = int(graph_timestamp_2) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400759 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400760 pt_up_graph_to_ofp_3 = int(graph_timestamp_3) -\
761 int(timestamp_begin_pt_up)
762
763 #Get delta between device event and OFP
764 pt_up_device_to_ofp_1 = int(device_timestamp_1) -\
765 int(timestamp_begin_pt_up)
766 pt_up_device_to_ofp_2 = int(device_timestamp_2) -\
767 int(timestamp_begin_pt_up)
768 pt_up_device_to_ofp_3 = int(device_timestamp_3) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400769 int(timestamp_begin_pt_up)
andrewonlab3622beb2014-10-28 16:07:56 -0400770
andrewonlabb1998c52014-11-10 13:31:43 -0500771 main.log.info("ONOS1 delta G2O: "+str(pt_up_graph_to_ofp_1))
772 main.log.info("ONOS2 delta G2O: "+str(pt_up_graph_to_ofp_2))
773 main.log.info("ONOS3 delta G2O: "+str(pt_up_graph_to_ofp_3))
774
775 main.log.info("ONOS1 delta D2O: "+str(pt_up_device_to_ofp_1))
776 main.log.info("ONOS2 delta D2O: "+str(pt_up_device_to_ofp_2))
777 main.log.info("ONOS3 delta D2O: "+str(pt_up_device_to_ofp_3))
778
andrewonlab3622beb2014-10-28 16:07:56 -0400779 pt_up_graph_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500780 (int(pt_up_graph_to_ofp_1) +
781 int(pt_up_graph_to_ofp_2) +
782 int(pt_up_graph_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400783
784 pt_up_device_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500785 (int(pt_up_device_to_ofp_1) +
786 int(pt_up_device_to_ofp_2) +
787 int(pt_up_device_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400788
andrewonlabe5bcef92014-11-06 17:53:20 -0500789 if pt_up_graph_to_ofp_avg > up_threshold_min and \
790 pt_up_graph_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400791 port_up_graph_to_ofp_list.append(
792 pt_up_graph_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500793 main.log.info("Port down: graph to ofp avg: "+
794 str(pt_up_graph_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400795 else:
796 main.log.info("Average port up graph-to-ofp result"+
797 " exceeded the threshold: "+
798 str(pt_up_graph_to_ofp_avg))
799
andrewonlabe5bcef92014-11-06 17:53:20 -0500800 if pt_up_device_to_ofp_avg > up_threshold_min and \
801 pt_up_device_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400802 port_up_device_to_ofp_list.append(
803 pt_up_device_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500804 main.log.info("Port up: device to ofp avg: "+
805 str(pt_up_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400806 else:
andrewonlababb11c32014-11-04 15:03:24 -0500807 main.log.info("Average port up device-to-ofp result"+
andrewonlab3622beb2014-10-28 16:07:56 -0400808 " exceeded the threshold: "+
809 str(pt_up_device_to_ofp_avg))
andrewonlab8d29f122014-10-22 17:15:04 -0400810
andrewonlab3622beb2014-10-28 16:07:56 -0400811 #END ITERATION FOR LOOP
andrewonlab8790abb2014-11-06 13:51:54 -0500812
813 #Check all list for latency existence and set assertion
814 if (port_down_graph_to_ofp_list and port_down_device_to_ofp_list\
815 and port_up_graph_to_ofp_list and port_up_device_to_ofp_list):
816 assertion = main.TRUE
817
andrewonlababb11c32014-11-04 15:03:24 -0500818 #Calculate and report latency measurements
andrewonlab3622beb2014-10-28 16:07:56 -0400819 port_down_graph_to_ofp_min = min(port_down_graph_to_ofp_list)
820 port_down_graph_to_ofp_max = max(port_down_graph_to_ofp_list)
821 port_down_graph_to_ofp_avg = \
822 (sum(port_down_graph_to_ofp_list) /
823 len(port_down_graph_to_ofp_list))
824
andrewonlabf9828f02014-11-10 14:50:27 -0500825 main.log.report("Port down graph-to-ofp Min: "+
826 str(port_down_graph_to_ofp_min)+" ms Max: "+
827 str(port_down_graph_to_ofp_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -0500828 str(port_down_graph_to_ofp_avg)+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500829
830 port_down_device_to_ofp_min = min(port_down_device_to_ofp_list)
831 port_down_device_to_ofp_max = max(port_down_device_to_ofp_list)
832 port_down_device_to_ofp_avg = \
833 (sum(port_down_device_to_ofp_list) /\
834 len(port_down_device_to_ofp_list))
835
andrewonlabf9828f02014-11-10 14:50:27 -0500836 main.log.report("Port down device-to-ofp Min: "+
837 str(port_down_device_to_ofp_min)+" ms Max: "+
838 str(port_down_device_to_ofp_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -0500839 str(port_down_device_to_ofp_avg)+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500840
841 port_up_graph_to_ofp_min = min(port_up_graph_to_ofp_list)
842 port_up_graph_to_ofp_max = max(port_up_graph_to_ofp_list)
843 port_up_graph_to_ofp_avg = \
844 (sum(port_up_graph_to_ofp_list) /\
845 len(port_up_graph_to_ofp_list))
andrewonlab8790abb2014-11-06 13:51:54 -0500846
andrewonlabf9828f02014-11-10 14:50:27 -0500847 main.log.report("Port up graph-to-ofp Min: "+
848 str(port_up_graph_to_ofp_min)+" ms Max: "+
849 str(port_up_graph_to_ofp_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -0500850 str(port_up_graph_to_ofp_avg)+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500851
852 port_up_device_to_ofp_min = min(port_up_device_to_ofp_list)
853 port_up_device_to_ofp_max = max(port_up_device_to_ofp_list)
854 port_up_device_to_ofp_avg = \
855 (sum(port_up_device_to_ofp_list) /\
856 len(port_up_device_to_ofp_list))
857
andrewonlabf9828f02014-11-10 14:50:27 -0500858 main.log.report("Port up device-to-ofp Min: "+
859 str(port_up_device_to_ofp_min)+" ms Max: "+
860 str(port_up_device_to_ofp_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -0500861 str(port_up_device_to_ofp_avg)+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500862
863 utilities.assert_equals(expect=main.TRUE, actual=assertion,
864 onpass="Port discovery latency calculation successful",
865 onfail="Port discovery test failed")
andrewonlababb11c32014-11-04 15:03:24 -0500866
andrewonlab3622beb2014-10-28 16:07:56 -0400867 def CASE4(self, main):
868 '''
869 Link down event using loss rate 100%
andrewonlab53b641c2014-10-31 19:44:44 -0400870
871 Important:
872 Use a simple 2 switch topology with 1 link between
873 the two switches. Ensure that mac addresses of the
874 switches are 1 / 2 respectively
andrewonlab3622beb2014-10-28 16:07:56 -0400875 '''
876 import time
877 import subprocess
878 import os
879 import requests
880 import json
881
882 ONOS1_ip = main.params['CTRL']['ip1']
883 ONOS2_ip = main.params['CTRL']['ip2']
884 ONOS3_ip = main.params['CTRL']['ip3']
885 ONOS_user = main.params['CTRL']['user']
886
887 default_sw_port = main.params['CTRL']['port1']
888
889 #Number of iterations of case
890 num_iter = main.params['TEST']['numIter']
891
892 #Timestamp 'keys' for json metrics output.
893 #These are subject to change, hence moved into params
894 deviceTimestamp = main.params['JSON']['deviceTimestamp']
895 linkTimestamp = main.params['JSON']['linkTimestamp']
andrewonlab53b641c2014-10-31 19:44:44 -0400896 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500897
898 debug_mode = main.params['TEST']['debugMode']
899
900 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500901 local_time = local_time.replace("/","")
902 local_time = local_time.replace(" ","_")
903 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500904 if debug_mode == 'on':
905 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500906 "/tmp/link_lat_pcap_"+local_time)
andrewonlab53b641c2014-10-31 19:44:44 -0400907
andrewonlabe5bcef92014-11-06 17:53:20 -0500908 #Threshold for this test case
909 up_threshold_str = main.params['TEST']['linkUpThreshold']
910 down_threshold_str = main.params['TEST']['linkDownThreshold']
911
912 up_threshold_obj = up_threshold_str.split(",")
913 down_threshold_obj = down_threshold_str.split(",")
914
915 up_threshold_min = int(up_threshold_obj[0])
916 up_threshold_max = int(up_threshold_obj[1])
917
918 down_threshold_min = int(down_threshold_obj[0])
919 down_threshold_max = int(down_threshold_obj[1])
920
andrewonlab3622beb2014-10-28 16:07:56 -0400921 assertion = main.TRUE
922 #Link event timestamp to system time list
923 link_down_link_to_system_list = []
924 link_up_link_to_system_list = []
925 #Graph event timestamp to system time list
926 link_down_graph_to_system_list = []
927 link_up_graph_to_system_list = []
928
andrewonlab4b5c8b92014-11-10 16:04:33 -0500929 main.log.report("Link up / down discovery latency between "+
andrewonlab3622beb2014-10-28 16:07:56 -0400930 "two switches")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500931 main.log.report("Simulated by setting loss-rate 100%")
932 main.log.report("'tc qdisc add dev <intfs> root netem loss 100%'")
933 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab3622beb2014-10-28 16:07:56 -0400934
935 main.step("Assign all switches")
936 main.Mininet1.assign_sw_controller(sw="1",
937 ip1=ONOS1_ip, port1=default_sw_port)
938 main.Mininet1.assign_sw_controller(sw="2",
939 ip1=ONOS1_ip, port1=default_sw_port)
940
941 main.step("Verifying switch assignment")
942 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
943 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
andrewonlab3622beb2014-10-28 16:07:56 -0400944
945 #Allow time for events to finish before taking measurements
946 time.sleep(10)
947
andrewonlababb11c32014-11-04 15:03:24 -0500948 link_down1 = False
949 link_down2 = False
950 link_down3 = False
andrewonlab3622beb2014-10-28 16:07:56 -0400951 #Start iteration of link event test
952 for i in range(0, int(num_iter)):
953 main.step("Getting initial system time as t0")
andrewonlab8d29f122014-10-22 17:15:04 -0400954
andrewonlab3622beb2014-10-28 16:07:56 -0400955 timestamp_link_down_t0 = time.time() * 1000
956 #Link down is simulated by 100% loss rate using traffic
957 #control command
958 main.Mininet1.handle.sendline(
959 "sh tc qdisc add dev s1-eth1 root netem loss 100%")
960
andrewonlab53b641c2014-10-31 19:44:44 -0400961 #TODO: Iterate through 'links' command to verify that
andrewonlababb11c32014-11-04 15:03:24 -0500962 # link s1 -> s2 went down (loop timeout 30 seconds)
963 # on all 3 ONOS instances
andrewonlab53b641c2014-10-31 19:44:44 -0400964 main.log.info("Checking ONOS for link update")
965 loop_count = 0
andrewonlababb11c32014-11-04 15:03:24 -0500966 while( not (link_down1 and link_down2 and link_down3)\
967 and loop_count < 30 ):
968 json_str1 = main.ONOS1cli.links()
969 json_str2 = main.ONOS2cli.links()
970 json_str3 = main.ONOS3cli.links()
971
972 if not (json_str1 and json_str2 and json_str3):
973 main.log.error("CLI command returned error ")
andrewonlab53b641c2014-10-31 19:44:44 -0400974 break
975 else:
andrewonlababb11c32014-11-04 15:03:24 -0500976 json_obj1 = json.loads(json_str1)
977 json_obj2 = json.loads(json_str2)
978 json_obj3 = json.loads(json_str3)
979 for obj1 in json_obj1:
980 if '01' not in obj1['src']['device']:
981 link_down1 = True
andrewonlabf9828f02014-11-10 14:50:27 -0500982 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -0500983 "s1 -> s2 on ONOS1 detected")
984 for obj2 in json_obj2:
985 if '01' not in obj2['src']['device']:
986 link_down2 = True
andrewonlabf9828f02014-11-10 14:50:27 -0500987 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -0500988 "s1 -> s2 on ONOS2 detected")
989 for obj3 in json_obj3:
990 if '01' not in obj3['src']['device']:
991 link_down3 = True
andrewonlabf9828f02014-11-10 14:50:27 -0500992 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -0500993 "s1 -> s2 on ONOS3 detected")
994
andrewonlab53b641c2014-10-31 19:44:44 -0400995 loop_count += 1
andrewonlababb11c32014-11-04 15:03:24 -0500996 #If CLI doesn't like the continuous requests
997 #and exits in this loop, increase the sleep here.
998 #Consequently, while loop timeout will increase
andrewonlab53b641c2014-10-31 19:44:44 -0400999 time.sleep(1)
1000
1001 #Give time for metrics measurement to catch up
andrewonlababb11c32014-11-04 15:03:24 -05001002 #NOTE: May need to be configured more accurately
andrewonlab53b641c2014-10-31 19:44:44 -04001003 time.sleep(10)
andrewonlababb11c32014-11-04 15:03:24 -05001004 #If we exited the while loop and link down 1,2,3 are still
andrewonlab53b641c2014-10-31 19:44:44 -04001005 #false, then ONOS has failed to discover link down event
andrewonlababb11c32014-11-04 15:03:24 -05001006 if not (link_down1 and link_down2 and link_down3):
andrewonlab53b641c2014-10-31 19:44:44 -04001007 main.log.info("Link down discovery failed")
1008
1009 link_down_lat_graph1 = 0
1010 link_down_lat_graph2 = 0
1011 link_down_lat_graph3 = 0
1012 link_down_lat_device1 = 0
1013 link_down_lat_device2 = 0
1014 link_down_lat_device3 = 0
1015
1016 assertion = main.FALSE
1017 else:
1018 json_topo_metrics_1 =\
1019 main.ONOS1cli.topology_events_metrics()
1020 json_topo_metrics_2 =\
1021 main.ONOS2cli.topology_events_metrics()
1022 json_topo_metrics_3 =\
1023 main.ONOS3cli.topology_events_metrics()
1024 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1025 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1026 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1027
1028 main.log.info("Obtaining graph and device timestamp")
1029 graph_timestamp_1 = \
1030 json_topo_metrics_1[graphTimestamp]['value']
1031 graph_timestamp_2 = \
1032 json_topo_metrics_2[graphTimestamp]['value']
1033 graph_timestamp_3 = \
1034 json_topo_metrics_3[graphTimestamp]['value']
1035
1036 link_timestamp_1 = \
1037 json_topo_metrics_1[linkTimestamp]['value']
1038 link_timestamp_2 = \
1039 json_topo_metrics_2[linkTimestamp]['value']
1040 link_timestamp_3 = \
1041 json_topo_metrics_3[linkTimestamp]['value']
1042
1043 if graph_timestamp_1 and graph_timestamp_2 and\
1044 graph_timestamp_3 and link_timestamp_1 and\
1045 link_timestamp_2 and link_timestamp_3:
1046 link_down_lat_graph1 = int(graph_timestamp_1) -\
1047 timestamp_link_down_t0
1048 link_down_lat_graph2 = int(graph_timestamp_2) -\
1049 timestamp_link_down_t0
1050 link_down_lat_graph3 = int(graph_timestamp_3) -\
1051 timestamp_link_down_t0
1052
1053 link_down_lat_link1 = int(link_timestamp_1) -\
1054 timestamp_link_down_t0
1055 link_down_lat_link2 = int(link_timestamp_2) -\
1056 timestamp_link_down_t0
1057 link_down_lat_link3 = int(link_timestamp_3) -\
1058 timestamp_link_down_t0
1059 else:
1060 main.log.error("There was an error calculating"+
1061 " the delta for link down event")
1062 link_down_lat_graph1 = 0
1063 link_down_lat_graph2 = 0
1064 link_down_lat_graph3 = 0
1065
1066 link_down_lat_device1 = 0
1067 link_down_lat_device2 = 0
1068 link_down_lat_device3 = 0
1069
andrewonlabf9828f02014-11-10 14:50:27 -05001070 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001071 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001072 str(link_down_lat_graph1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001073 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001074 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001075 str(link_down_lat_graph2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001076 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001077 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001078 str(link_down_lat_graph3)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001079
andrewonlabf9828f02014-11-10 14:50:27 -05001080 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001081 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001082 str(link_down_lat_link1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001083 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001084 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001085 str(link_down_lat_link2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001086 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001087 str(i)+" (link-event-to-system-timestamp): "+
1088 str(link_down_lat_link3))
1089
1090 #Calculate avg of node calculations
1091 link_down_lat_graph_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001092 (link_down_lat_graph1 +
1093 link_down_lat_graph2 +
andrewonlab65d73892014-11-10 17:36:00 -05001094 link_down_lat_graph3) / 3
andrewonlab4e124482014-11-04 13:37:25 -05001095 link_down_lat_link_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001096 (link_down_lat_link1 +
1097 link_down_lat_link2 +
andrewonlab65d73892014-11-10 17:36:00 -05001098 link_down_lat_link3) / 3
andrewonlab53b641c2014-10-31 19:44:44 -04001099
andrewonlab4e124482014-11-04 13:37:25 -05001100 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001101 if link_down_lat_graph_avg > down_threshold_min and\
1102 link_down_lat_graph_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001103 link_down_graph_to_system_list.append(
1104 link_down_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001105 else:
1106 main.log.info("Link down latency exceeded threshold")
1107 main.log.info("Results for iteration "+str(i)+
1108 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001109 if link_down_lat_link_avg > down_threshold_min and\
1110 link_down_lat_link_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001111 link_down_link_to_system_list.append(
1112 link_down_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001113 else:
1114 main.log.info("Link down latency exceeded threshold")
1115 main.log.info("Results for iteration "+str(i)+
1116 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001117
1118 #NOTE: To remove loss rate and measure latency:
1119 # 'sh tc qdisc del dev s1-eth1 root'
andrewonlababb11c32014-11-04 15:03:24 -05001120 timestamp_link_up_t0 = time.time() * 1000
andrewonlab53b641c2014-10-31 19:44:44 -04001121 main.Mininet1.handle.sendline("sh tc qdisc del dev "+
1122 "s1-eth1 root")
1123 main.Mininet1.handle.expect("mininet>")
andrewonlababb11c32014-11-04 15:03:24 -05001124
1125 main.log.info("Checking ONOS for link update")
1126
1127 link_down1 = True
1128 link_down2 = True
1129 link_down3 = True
1130 loop_count = 0
1131 while( (link_down1 and link_down2 and link_down3)\
1132 and loop_count < 30 ):
1133 json_str1 = main.ONOS1cli.links()
1134 json_str2 = main.ONOS2cli.links()
1135 json_str3 = main.ONOS3cli.links()
1136 if not (json_str1 and json_str2 and json_str3):
1137 main.log.error("CLI command returned error ")
1138 break
1139 else:
1140 json_obj1 = json.loads(json_str1)
1141 json_obj2 = json.loads(json_str2)
1142 json_obj3 = json.loads(json_str3)
1143
1144 for obj1 in json_obj1:
1145 if '01' in obj1['src']['device']:
1146 link_down1 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001147 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001148 "s1 -> s2 on ONOS1 detected")
1149 for obj2 in json_obj2:
1150 if '01' in obj2['src']['device']:
1151 link_down2 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001152 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001153 "s1 -> s2 on ONOS2 detected")
1154 for obj3 in json_obj3:
1155 if '01' in obj3['src']['device']:
1156 link_down3 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001157 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001158 "s1 -> s2 on ONOS3 detected")
1159
1160 loop_count += 1
1161 time.sleep(1)
1162
1163 if (link_down1 and link_down2 and link_down3):
1164 main.log.info("Link up discovery failed")
1165
1166 link_up_lat_graph1 = 0
1167 link_up_lat_graph2 = 0
1168 link_up_lat_graph3 = 0
1169 link_up_lat_device1 = 0
1170 link_up_lat_device2 = 0
1171 link_up_lat_device3 = 0
1172
1173 assertion = main.FALSE
1174 else:
1175 json_topo_metrics_1 =\
1176 main.ONOS1cli.topology_events_metrics()
1177 json_topo_metrics_2 =\
1178 main.ONOS2cli.topology_events_metrics()
1179 json_topo_metrics_3 =\
1180 main.ONOS3cli.topology_events_metrics()
1181 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1182 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1183 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1184
1185 main.log.info("Obtaining graph and device timestamp")
1186 graph_timestamp_1 = \
1187 json_topo_metrics_1[graphTimestamp]['value']
1188 graph_timestamp_2 = \
1189 json_topo_metrics_2[graphTimestamp]['value']
1190 graph_timestamp_3 = \
1191 json_topo_metrics_3[graphTimestamp]['value']
1192
1193 link_timestamp_1 = \
1194 json_topo_metrics_1[linkTimestamp]['value']
1195 link_timestamp_2 = \
1196 json_topo_metrics_2[linkTimestamp]['value']
1197 link_timestamp_3 = \
1198 json_topo_metrics_3[linkTimestamp]['value']
1199
1200 if graph_timestamp_1 and graph_timestamp_2 and\
1201 graph_timestamp_3 and link_timestamp_1 and\
1202 link_timestamp_2 and link_timestamp_3:
1203 link_up_lat_graph1 = int(graph_timestamp_1) -\
1204 timestamp_link_up_t0
1205 link_up_lat_graph2 = int(graph_timestamp_2) -\
1206 timestamp_link_up_t0
1207 link_up_lat_graph3 = int(graph_timestamp_3) -\
1208 timestamp_link_up_t0
1209
1210 link_up_lat_link1 = int(link_timestamp_1) -\
1211 timestamp_link_up_t0
1212 link_up_lat_link2 = int(link_timestamp_2) -\
1213 timestamp_link_up_t0
1214 link_up_lat_link3 = int(link_timestamp_3) -\
1215 timestamp_link_up_t0
1216 else:
1217 main.log.error("There was an error calculating"+
1218 " the delta for link down event")
1219 link_up_lat_graph1 = 0
1220 link_up_lat_graph2 = 0
1221 link_up_lat_graph3 = 0
1222
1223 link_up_lat_device1 = 0
1224 link_up_lat_device2 = 0
1225 link_up_lat_device3 = 0
andrewonlab58f7d702014-11-07 13:21:19 -05001226
1227 if debug_mode == 'on':
1228 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001229 str(i)+" (end-to-end): "+
1230 str(link_up_lat_graph1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001231 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001232 str(i)+" (end-to-end): "+
1233 str(link_up_lat_graph2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001234 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001235 str(i)+" (end-to-end): "+
1236 str(link_up_lat_graph3)+" ms")
1237
andrewonlab58f7d702014-11-07 13:21:19 -05001238 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001239 str(i)+" (link-event-to-system-timestamp): "+
1240 str(link_up_lat_link1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001241 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001242 str(i)+" (link-event-to-system-timestamp): "+
1243 str(link_up_lat_link2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001244 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001245 str(i)+" (link-event-to-system-timestamp): "+
1246 str(link_up_lat_link3))
1247
1248 #Calculate avg of node calculations
1249 link_up_lat_graph_avg =\
1250 (link_up_lat_graph1 +
1251 link_up_lat_graph2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001252 link_up_lat_graph3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001253 link_up_lat_link_avg =\
1254 (link_up_lat_link1 +
1255 link_up_lat_link2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001256 link_up_lat_link3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001257
1258 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001259 if link_up_lat_graph_avg > up_threshold_min and\
1260 link_up_lat_graph_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001261 link_up_graph_to_system_list.append(
1262 link_up_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001263 else:
1264 main.log.info("Link up latency exceeded threshold")
1265 main.log.info("Results for iteration "+str(i)+
1266 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001267 if link_up_lat_link_avg > up_threshold_min and\
1268 link_up_lat_link_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001269 link_up_link_to_system_list.append(
1270 link_up_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001271 else:
1272 main.log.info("Link up latency exceeded threshold")
1273 main.log.info("Results for iteration "+str(i)+
1274 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001275
andrewonlab4e124482014-11-04 13:37:25 -05001276 #Calculate min, max, avg of list and report
1277 link_down_min = min(link_down_graph_to_system_list)
1278 link_down_max = max(link_down_graph_to_system_list)
1279 link_down_avg = sum(link_down_graph_to_system_list) / \
1280 len(link_down_graph_to_system_list)
andrewonlababb11c32014-11-04 15:03:24 -05001281 link_up_min = min(link_up_graph_to_system_list)
1282 link_up_max = max(link_up_graph_to_system_list)
1283 link_up_avg = sum(link_up_graph_to_system_list) / \
1284 len(link_up_graph_to_system_list)
1285
andrewonlabf9828f02014-11-10 14:50:27 -05001286 main.log.report("Link down latency - Min: "+
1287 str(link_down_min)+" ms Max: "+
1288 str(link_down_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -05001289 str(link_down_avg)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001290 main.log.report("Link up latency - Min: "+
1291 str(link_up_min)+" ms Max: "+
1292 str(link_up_max)+" ms Avg: "+
andrewonlab58f7d702014-11-07 13:21:19 -05001293 str(link_up_avg)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001294
andrewonlab8790abb2014-11-06 13:51:54 -05001295 utilities.assert_equals(expect=main.TRUE, actual=assertion,
1296 onpass="Link discovery latency calculation successful",
1297 onfail="Link discovery latency case failed")
1298
andrewonlabb54b85b2014-10-28 18:43:57 -04001299 def CASE5(self, main):
1300 '''
1301 100 Switch discovery latency
1302
1303 Important:
andrewonlab16ce4852014-10-30 13:41:09 -04001304 This test case can be potentially dangerous if
1305 your machine has previously set iptables rules.
1306 One of the steps of the test case will flush
1307 all existing iptables rules.
andrewonlab8790abb2014-11-06 13:51:54 -05001308 Note:
1309 You can specify the number of switches in the
1310 params file to adjust the switch discovery size
1311 (and specify the corresponding topology in Mininet1
1312 .topo file)
andrewonlabb54b85b2014-10-28 18:43:57 -04001313 '''
1314 import time
1315 import subprocess
1316 import os
1317 import requests
1318 import json
1319
1320 ONOS1_ip = main.params['CTRL']['ip1']
1321 ONOS2_ip = main.params['CTRL']['ip2']
1322 ONOS3_ip = main.params['CTRL']['ip3']
1323 MN1_ip = main.params['MN']['ip1']
1324 ONOS_user = main.params['CTRL']['user']
1325
1326 default_sw_port = main.params['CTRL']['port1']
1327
1328 #Number of iterations of case
1329 num_iter = main.params['TEST']['numIter']
andrewonlab16ce4852014-10-30 13:41:09 -04001330 num_sw = main.params['TEST']['numSwitch']
1331
andrewonlabb54b85b2014-10-28 18:43:57 -04001332 #Timestamp 'keys' for json metrics output.
1333 #These are subject to change, hence moved into params
1334 deviceTimestamp = main.params['JSON']['deviceTimestamp']
andrewonlab16ce4852014-10-30 13:41:09 -04001335 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -05001336
1337 debug_mode = main.params['TEST']['debugMode']
1338
andrewonlabb1998c52014-11-10 13:31:43 -05001339 local_time = time.strftime('%X')
1340 local_time = local_time.replace("/","")
1341 local_time = local_time.replace(" ","_")
1342 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -05001343 if debug_mode == 'on':
1344 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -05001345 "/tmp/100_sw_lat_pcap_"+local_time)
andrewonlabe5bcef92014-11-06 17:53:20 -05001346
1347 #Threshold for this test case
1348 sw_disc_threshold_str = main.params['TEST']['swDisc100Threshold']
1349 sw_disc_threshold_obj = sw_disc_threshold_str.split(",")
1350 sw_disc_threshold_min = int(sw_disc_threshold_obj[0])
1351 sw_disc_threshold_max = int(sw_disc_threshold_obj[1])
1352
andrewonlab53b641c2014-10-31 19:44:44 -04001353 tshark_ofp_output = "/tmp/tshark_ofp_"+num_sw+"sw.txt"
1354 tshark_tcp_output = "/tmp/tshark_tcp_"+num_sw+"sw.txt"
1355
1356 tshark_ofp_result_list = []
1357 tshark_tcp_result_list = []
andrewonlabb54b85b2014-10-28 18:43:57 -04001358
andrewonlabe5bcef92014-11-06 17:53:20 -05001359 sw_discovery_lat_list = []
1360
andrewonlab16ce4852014-10-30 13:41:09 -04001361 main.case(num_sw+" Switch discovery latency")
andrewonlabb54b85b2014-10-28 18:43:57 -04001362 main.step("Assigning all switches to ONOS1")
andrewonlab16ce4852014-10-30 13:41:09 -04001363 for i in range(1, int(num_sw)+1):
andrewonlabb54b85b2014-10-28 18:43:57 -04001364 main.Mininet1.assign_sw_controller(
1365 sw=str(i),
1366 ip1=ONOS1_ip,
1367 port1=default_sw_port)
andrewonlab16ce4852014-10-30 13:41:09 -04001368
andrewonlabb54b85b2014-10-28 18:43:57 -04001369 #Ensure that nodes are configured with ptpd
andrewonlab16ce4852014-10-30 13:41:09 -04001370 #Just a warning message
1371 main.log.info("Please check ptpd configuration to ensure"+\
1372 " All nodes' system times are in sync")
1373 time.sleep(5)
andrewonlabb54b85b2014-10-28 18:43:57 -04001374
1375 for i in range(0, int(num_iter)):
andrewonlab8d29f122014-10-22 17:15:04 -04001376
andrewonlabb54b85b2014-10-28 18:43:57 -04001377 main.step("Set iptables rule to block incoming sw connections")
1378 #Set iptables rule to block incoming switch connections
andrewonlab53b641c2014-10-31 19:44:44 -04001379 #The rule description is as follows:
1380 # Append to INPUT rule,
1381 # behavior DROP that matches following:
1382 # * packet type: tcp
1383 # * source IP: MN1_ip
1384 # * destination PORT: 6633
andrewonlabb54b85b2014-10-28 18:43:57 -04001385 main.ONOS1.handle.sendline(
andrewonlab16ce4852014-10-30 13:41:09 -04001386 "sudo iptables -A INPUT -p tcp -s "+MN1_ip+
andrewonlabb54b85b2014-10-28 18:43:57 -04001387 " --dport "+default_sw_port+" -j DROP")
1388 main.ONOS1.handle.expect("\$")
andrewonlab53b641c2014-10-31 19:44:44 -04001389 # Append to OUTPUT rule,
1390 # behavior DROP that matches following:
1391 # * packet type: tcp
1392 # * source IP: MN1_ip
1393 # * destination PORT: 6633
1394 main.ONOS1.handle.sendline(
1395 "sudo iptables -A OUTPUT -p tcp -s "+MN1_ip+
1396 " --dport "+default_sw_port+" -j DROP")
1397 main.ONOS1.handle.expect("\$")
andrewonlabb54b85b2014-10-28 18:43:57 -04001398 #Give time to allow rule to take effect
andrewonlab8790abb2014-11-06 13:51:54 -05001399 #NOTE: Sleep period may need to be configured
1400 # based on the number of switches in the topology
andrewonlab16ce4852014-10-30 13:41:09 -04001401 main.log.info("Please wait for switch connection to "+
1402 "time out")
1403 time.sleep(60)
1404
1405 #Gather vendor OFP with tshark
1406 main.ONOS1.tshark_grep("OFP 86 Vendor",
1407 tshark_ofp_output)
andrewonlab53b641c2014-10-31 19:44:44 -04001408 main.ONOS1.tshark_grep("TCP 74 ",
1409 tshark_tcp_output)
andrewonlabb54b85b2014-10-28 18:43:57 -04001410
andrewonlab16ce4852014-10-30 13:41:09 -04001411 #NOTE: Remove all iptables rule quickly (flush)
andrewonlabb54b85b2014-10-28 18:43:57 -04001412 # Before removal, obtain TestON timestamp at which
andrewonlab16ce4852014-10-30 13:41:09 -04001413 # removal took place
1414 # (ensuring nodes are configured via ptp)
andrewonlabb54b85b2014-10-28 18:43:57 -04001415 # sudo iptables -F
andrewonlab16ce4852014-10-30 13:41:09 -04001416
1417 t0_system = time.time() * 1000
1418 main.ONOS1.handle.sendline(
1419 "sudo iptables -F")
andrewonlabb54b85b2014-10-28 18:43:57 -04001420
andrewonlab16ce4852014-10-30 13:41:09 -04001421 #Counter to track loop count
1422 counter_loop = 0
1423 counter_avail1 = 0
1424 counter_avail2 = 0
1425 counter_avail3 = 0
1426 onos1_dev = False
1427 onos2_dev = False
1428 onos3_dev = False
1429 while counter_loop < 60:
1430 #Continue to check devices for all device
1431 #availability. When all devices in all 3
1432 #ONOS instances indicate that devices are available
1433 #obtain graph event timestamp for t1.
1434 device_str_obj1 = main.ONOS1cli.devices()
1435 device_str_obj2 = main.ONOS2cli.devices()
1436 device_str_obj3 = main.ONOS3cli.devices()
1437
1438 device_json1 = json.loads(device_str_obj1)
1439 device_json2 = json.loads(device_str_obj2)
1440 device_json3 = json.loads(device_str_obj3)
1441
1442 for device1 in device_json1:
1443 if device1['available'] == True:
1444 counter_avail1 += 1
1445 if counter_avail1 == int(num_sw):
1446 onos1_dev = True
1447 main.log.info("All devices have been "+
1448 "discovered on ONOS1")
1449 else:
1450 counter_avail1 = 0
1451 for device2 in device_json2:
1452 if device2['available'] == True:
1453 counter_avail2 += 1
1454 if counter_avail2 == int(num_sw):
1455 onos2_dev = True
1456 main.log.info("All devices have been "+
1457 "discovered on ONOS2")
1458 else:
1459 counter_avail2 = 0
1460 for device3 in device_json3:
1461 if device3['available'] == True:
1462 counter_avail3 += 1
1463 if counter_avail3 == int(num_sw):
1464 onos3_dev = True
1465 main.log.info("All devices have been "+
1466 "discovered on ONOS3")
1467 else:
1468 counter_avail3 = 0
1469
1470 if onos1_dev and onos2_dev and onos3_dev:
1471 main.log.info("All devices have been discovered "+
1472 "on all ONOS instances")
1473 json_str_topology_metrics_1 =\
1474 main.ONOS1cli.topology_events_metrics()
1475 json_str_topology_metrics_2 =\
1476 main.ONOS2cli.topology_events_metrics()
1477 json_str_topology_metrics_3 =\
1478 main.ONOS3cli.topology_events_metrics()
andrewonlab53b641c2014-10-31 19:44:44 -04001479
1480 #Exit while loop if all devices discovered
andrewonlab16ce4852014-10-30 13:41:09 -04001481 break
1482
1483 counter_loop += 1
1484 #Give some time in between CLI calls
1485 #(will not affect measurement)
1486 time.sleep(3)
1487
1488 main.ONOS1.tshark_stop()
1489
1490 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1491 tshark_ofp_output+" /tmp/")
andrewonlab53b641c2014-10-31 19:44:44 -04001492 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1493 tshark_tcp_output+" /tmp/")
andrewonlab16ce4852014-10-30 13:41:09 -04001494
andrewonlab16ce4852014-10-30 13:41:09 -04001495 #TODO: Automate OFP output analysis
andrewonlab58f7d702014-11-07 13:21:19 -05001496 #Debug mode - print out packets captured at runtime
1497 if debug_mode == 'on':
1498 ofp_file = open(tshark_ofp_output, 'r')
1499 main.log.info("Tshark OFP Vendor output: ")
1500 for line in ofp_file:
1501 tshark_ofp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001502 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001503 ofp_file.close()
andrewonlab16ce4852014-10-30 13:41:09 -04001504
andrewonlab58f7d702014-11-07 13:21:19 -05001505 tcp_file = open(tshark_tcp_output, 'r')
1506 main.log.info("Tshark TCP 74 output: ")
1507 for line in tcp_file:
1508 tshark_tcp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001509 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001510 tcp_file.close()
andrewonlab53b641c2014-10-31 19:44:44 -04001511
andrewonlab16ce4852014-10-30 13:41:09 -04001512 json_obj_1 = json.loads(json_str_topology_metrics_1)
1513 json_obj_2 = json.loads(json_str_topology_metrics_2)
1514 json_obj_3 = json.loads(json_str_topology_metrics_3)
1515
1516 graph_timestamp_1 = \
1517 json_obj_1[graphTimestamp]['value']
1518 graph_timestamp_2 = \
1519 json_obj_2[graphTimestamp]['value']
1520 graph_timestamp_3 = \
1521 json_obj_3[graphTimestamp]['value']
1522
andrewonlabe5bcef92014-11-06 17:53:20 -05001523 graph_lat_1 = int(graph_timestamp_1) - int(t0_system)
1524 graph_lat_2 = int(graph_timestamp_2) - int(t0_system)
1525 graph_lat_3 = int(graph_timestamp_3) - int(t0_system)
andrewonlab16ce4852014-10-30 13:41:09 -04001526
andrewonlabe5bcef92014-11-06 17:53:20 -05001527 avg_graph_lat = \
1528 (int(graph_lat_1) +\
1529 int(graph_lat_2) +\
1530 int(graph_lat_3)) / 3
1531
1532 if avg_graph_lat > sw_disc_threshold_min \
1533 and avg_graph_lat < sw_disc_threshold_max:
1534 sw_discovery_lat_list.append(
1535 avg_graph_lat)
1536 else:
1537 main.log.info("100 Switch discovery latency "+
1538 "exceeded the threshold.")
1539
1540 #END ITERATION FOR LOOP
andrewonlab16ce4852014-10-30 13:41:09 -04001541
andrewonlabe5bcef92014-11-06 17:53:20 -05001542 sw_lat_min = min(sw_discovery_lat_list)
1543 sw_lat_max = max(sw_discovery_lat_list)
1544 sw_lat_avg = sum(sw_discovery_lat_list) /\
1545 len(sw_discovery_lat_list)
andrewonlab16ce4852014-10-30 13:41:09 -04001546
andrewonlabf9828f02014-11-10 14:50:27 -05001547 main.log.report("100 Switch discovery lat "+\
1548 "Min: "+str(sw_lat_min)+" ms"+\
1549 "Max: "+str(sw_lat_max)+" ms"+\
1550 "Avg: "+str(sw_lat_avg)+" ms")
andrewonlab16ce4852014-10-30 13:41:09 -04001551
andrewonlabb54b85b2014-10-28 18:43:57 -04001552