blob: b25f3f516e994f7ee26d4c0859abbc925547b6d7 [file] [log] [blame]
andrewonlab2a6c9342014-10-16 13:40:15 -04001#TopoPerfNext
2#
3#Topology Performance test for ONOS-next
4#
5#andrew@onlab.us
andrewonlab4f50ec92014-11-11 14:24:45 -05006#
7#If your machine does not come with numpy
8#run the following command:
9#sudo apt-get install python-numpy python-scipy
andrewonlab2a6c9342014-10-16 13:40:15 -040010
11import time
12import sys
13import os
14import re
15
16class TopoPerfNext:
17 def __init__(self):
18 self.default = ''
19
20 def CASE1(self, main):
21 '''
22 ONOS startup sequence
23 '''
andrewonlabe9fb6722014-10-24 12:20:35 -040024 import time
25
andrewonlab2a6c9342014-10-16 13:40:15 -040026 cell_name = main.params['ENV']['cellName']
27
28 git_pull = main.params['GIT']['autoPull']
29 checkout_branch = main.params['GIT']['checkout']
30
31 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlabba44bcf2014-10-16 16:54:41 -040032 ONOS2_ip = main.params['CTRL']['ip2']
33 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab2a6c9342014-10-16 13:40:15 -040034 MN1_ip = main.params['MN']['ip1']
35 BENCH_ip = main.params['BENCH']['ip']
36
37 main.case("Setting up test environment")
andrewonlabf9828f02014-11-10 14:50:27 -050038 main.log.report("Setting up test environment")
andrewonlab2a6c9342014-10-16 13:40:15 -040039
40 main.step("Creating cell file")
41 cell_file_result = main.ONOSbench.create_cell_file(
andrewonlabe6745342014-10-17 14:29:13 -040042 BENCH_ip, cell_name, MN1_ip, "onos-core",
andrewonlabba44bcf2014-10-16 16:54:41 -040043 ONOS1_ip, ONOS2_ip, ONOS3_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -040044
45 main.step("Applying cell file to environment")
46 cell_apply_result = main.ONOSbench.set_cell(cell_name)
47 verify_cell_result = main.ONOSbench.verify_cell()
48
49 main.step("Git checkout and pull "+checkout_branch)
50 if git_pull == 'on':
51 checkout_result = \
52 main.ONOSbench.git_checkout(checkout_branch)
53 pull_result = main.ONOSbench.git_pull()
54 else:
55 checkout_result = main.TRUE
56 pull_result = main.TRUE
57 main.log.info("Skipped git checkout and pull")
58
59 main.step("Using mvn clean & install")
andrewonlab8d29f122014-10-22 17:15:04 -040060 #mvn_result = main.ONOSbench.clean_install()
61 mvn_result = main.TRUE
andrewonlab2a6c9342014-10-16 13:40:15 -040062
andrewonlabb1998c52014-11-10 13:31:43 -050063 main.step("Set cell for ONOS cli env")
64 main.ONOS1cli.set_cell(cell_name)
65 main.ONOS2cli.set_cell(cell_name)
66 main.ONOS3cli.set_cell(cell_name)
67
andrewonlab2a6c9342014-10-16 13:40:15 -040068 main.step("Creating ONOS package")
69 package_result = main.ONOSbench.onos_package()
70
71 main.step("Installing ONOS package")
andrewonlabe9fb6722014-10-24 12:20:35 -040072 install1_result = main.ONOSbench.onos_install(node=ONOS1_ip)
73 install2_result = main.ONOSbench.onos_install(node=ONOS2_ip)
74 install3_result = main.ONOSbench.onos_install(node=ONOS3_ip)
andrewonlab2a6c9342014-10-16 13:40:15 -040075
andrewonlabe9fb6722014-10-24 12:20:35 -040076 time.sleep(10)
77
andrewonlab867212a2014-10-22 20:13:38 -040078 main.step("Start onos cli")
andrewonlabe9fb6722014-10-24 12:20:35 -040079 cli1 = main.ONOS1cli.start_onos_cli(ONOS1_ip)
80 cli2 = main.ONOS2cli.start_onos_cli(ONOS2_ip)
81 cli3 = main.ONOS3cli.start_onos_cli(ONOS3_ip)
82
andrewonlab867212a2014-10-22 20:13:38 -040083 main.step("Enable metrics feature")
andrewonlabb1998c52014-11-10 13:31:43 -050084 main.ONOS1cli.feature_install("onos-app-metrics")
85 main.ONOS2cli.feature_install("onos-app-metrics")
86 main.ONOS3cli.feature_install("onos-app-metrics")
andrewonlab867212a2014-10-22 20:13:38 -040087
andrewonlab2a6c9342014-10-16 13:40:15 -040088 utilities.assert_equals(expect=main.TRUE,
89 actual= cell_file_result and cell_apply_result and\
90 verify_cell_result and checkout_result and\
91 pull_result and mvn_result and\
andrewonlabe9fb6722014-10-24 12:20:35 -040092 install1_result and install2_result and\
93 install3_result,
andrewonlabf9828f02014-11-10 14:50:27 -050094 onpass="Test Environment setup successful",
95 onfail="Failed to setup test environment")
andrewonlab2a6c9342014-10-16 13:40:15 -040096
andrewonlabba44bcf2014-10-16 16:54:41 -040097 def CASE2(self, main):
98 '''
99 Assign s1 to ONOS1 and measure latency
andrewonlab3a7c3c72014-10-24 17:21:03 -0400100
101 There are 4 levels of latency measurements to this test:
102 1) End-to-end measurement: Complete end-to-end measurement
103 from TCP (SYN/ACK) handshake to Graph change
104 2) OFP-to-graph measurement: 'ONOS processing' snippet of
105 measurement from OFP Vendor message to Graph change
106 3) OFP-to-device measurement: 'ONOS processing without
107 graph change' snippet of measurement from OFP vendor
108 message to Device change timestamp
109 4) T0-to-device measurement: Measurement that includes
110 the switch handshake to devices timestamp without
111 the graph view change. (TCP handshake -> Device
112 change)
andrewonlabba44bcf2014-10-16 16:54:41 -0400113 '''
114 import time
andrewonlabe6745342014-10-17 14:29:13 -0400115 import subprocess
116 import json
117 import requests
118 import os
andrewonlab4f50ec92014-11-11 14:24:45 -0500119 import numpy
andrewonlabba44bcf2014-10-16 16:54:41 -0400120
121 ONOS1_ip = main.params['CTRL']['ip1']
122 ONOS2_ip = main.params['CTRL']['ip2']
123 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlabe6745342014-10-17 14:29:13 -0400124 ONOS_user = main.params['CTRL']['user']
125
andrewonlabba44bcf2014-10-16 16:54:41 -0400126 default_sw_port = main.params['CTRL']['port1']
127
128 #Number of iterations of case
129 num_iter = main.params['TEST']['numIter']
andrewonlab4b5c8b92014-11-10 16:04:33 -0500130 #Number of first 'x' iterations to ignore:
131 iter_ignore = int(main.params['TEST']['iterIgnore'])
132
andrewonlab226024e2014-10-24 16:01:32 -0400133 #Timestamp 'keys' for json metrics output.
134 #These are subject to change, hence moved into params
135 deviceTimestamp = main.params['JSON']['deviceTimestamp']
136 graphTimestamp = main.params['JSON']['graphTimestamp']
137
andrewonlab58f7d702014-11-07 13:21:19 -0500138 debug_mode = main.params['TEST']['debugMode']
andrewonlabb1998c52014-11-10 13:31:43 -0500139 onos_log = main.params['TEST']['onosLogFile']
andrewonlab58f7d702014-11-07 13:21:19 -0500140
andrewonlabe5bcef92014-11-06 17:53:20 -0500141 #Threshold for the test
142 threshold_str = main.params['TEST']['singleSwThreshold']
143 threshold_obj = threshold_str.split(",")
144 threshold_min = int(threshold_obj[0])
145 threshold_max = int(threshold_obj[1])
146
andrewonlab226024e2014-10-24 16:01:32 -0400147 #List of switch add latency collected from
148 #all iterations
149 latency_end_to_end_list = []
150 latency_ofp_to_graph_list = []
151 latency_ofp_to_device_list = []
152 latency_t0_to_device_list = []
andrewonlab65d73892014-11-10 17:36:00 -0500153 latency_tcp_to_ofp_list = []
andrewonlab226024e2014-10-24 16:01:32 -0400154
andrewonlabba44bcf2014-10-16 16:54:41 -0400155 #Directory/file to store tshark results
156 tshark_of_output = "/tmp/tshark_of_topo.txt"
157 tshark_tcp_output = "/tmp/tshark_tcp_topo.txt"
158
159 #String to grep in tshark output
160 tshark_tcp_string = "TCP 74 "+default_sw_port
161 tshark_of_string = "OFP 86 Vendor"
andrewonlabe6745342014-10-17 14:29:13 -0400162
163 #Initialize assertion to TRUE
164 assertion = main.TRUE
andrewonlab58f7d702014-11-07 13:21:19 -0500165
166 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500167 local_time = local_time.replace("/","")
168 local_time = local_time.replace(" ","_")
169 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500170 if debug_mode == 'on':
171 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500172 "/tmp/single_sw_lat_pcap_"+local_time)
173
174 main.log.info("TEST")
andrewonlab58f7d702014-11-07 13:21:19 -0500175
andrewonlab4b5c8b92014-11-10 16:04:33 -0500176 main.log.report("Latency of adding one switch to controller")
177 main.log.report("First "+str(iter_ignore)+" iterations ignored"+
178 " for jvm warmup time")
179 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlabba44bcf2014-10-16 16:54:41 -0400180
181 for i in range(0, int(num_iter)):
182 main.log.info("Starting tshark capture")
183
184 #* TCP [ACK, SYN] is used as t0_a, the
185 # very first "exchange" between ONOS and
186 # the switch for end-to-end measurement
187 #* OFP [Stats Reply] is used for t0_b
188 # the very last OFP message between ONOS
189 # and the switch for ONOS measurement
190 main.ONOS1.tshark_grep(tshark_tcp_string,
191 tshark_tcp_output)
192 main.ONOS1.tshark_grep(tshark_of_string,
193 tshark_of_output)
194
195 #Wait and ensure tshark is started and
196 #capturing
197 time.sleep(10)
198
199 main.log.info("Assigning s1 to controller")
200
201 main.Mininet1.assign_sw_controller(sw="1",
202 ip1=ONOS1_ip, port1=default_sw_port)
203
204 #Wait and ensure switch is assigned
205 #before stopping tshark
andrewonlab867212a2014-10-22 20:13:38 -0400206 time.sleep(30)
andrewonlab226024e2014-10-24 16:01:32 -0400207
208 main.log.info("Stopping all Tshark processes")
andrewonlabba44bcf2014-10-16 16:54:41 -0400209 main.ONOS1.stop_tshark()
210
andrewonlabe6745342014-10-17 14:29:13 -0400211 #tshark output is saved in ONOS. Use subprocess
212 #to copy over files to TestON for parsing
213 main.log.info("Copying over tshark files")
214
215 #TCP CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400216 #Copy the tshark output from ONOS machine to
217 #TestON machine in tshark_tcp_output directory>file
218 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
219 tshark_tcp_output+" /tmp/")
220 tcp_file = open(tshark_tcp_output, 'r')
221 temp_text = tcp_file.readline()
andrewonlabe6745342014-10-17 14:29:13 -0400222 temp_text = temp_text.split(" ")
andrewonlabba44bcf2014-10-16 16:54:41 -0400223
andrewonlabe6745342014-10-17 14:29:13 -0400224 main.log.info("Object read in from TCP capture: "+
225 str(temp_text))
andrewonlab867212a2014-10-22 20:13:38 -0400226 if len(temp_text) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400227 t0_tcp = float(temp_text[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400228 else:
229 main.log.error("Tshark output file for TCP"+
230 " returned unexpected results")
231 t0_tcp = 0
232 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400233
234 tcp_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400235 #****************
andrewonlabba44bcf2014-10-16 16:54:41 -0400236
andrewonlabe6745342014-10-17 14:29:13 -0400237 #OF CAPTURE ****
andrewonlab8d29f122014-10-22 17:15:04 -0400238 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
239 tshark_of_output+" /tmp/")
240 of_file = open(tshark_of_output, 'r')
241
242 line_ofp = ""
andrewonlab226024e2014-10-24 16:01:32 -0400243 #Read until last line of file
andrewonlabe6745342014-10-17 14:29:13 -0400244 while True:
andrewonlab8d29f122014-10-22 17:15:04 -0400245 temp_text = of_file.readline()
246 if temp_text !='':
andrewonlabe6745342014-10-17 14:29:13 -0400247 line_ofp = temp_text
248 else:
249 break
250 obj = line_ofp.split(" ")
251
252 main.log.info("Object read in from OFP capture: "+
253 str(line_ofp))
254
andrewonlab867212a2014-10-22 20:13:38 -0400255 if len(line_ofp) > 1:
andrewonlab3a7c3c72014-10-24 17:21:03 -0400256 t0_ofp = float(obj[1])*1000.0
andrewonlabe6745342014-10-17 14:29:13 -0400257 else:
258 main.log.error("Tshark output file for OFP"+
259 " returned unexpected results")
260 t0_ofp = 0
261 assertion = main.FALSE
andrewonlab8d29f122014-10-22 17:15:04 -0400262
263 of_file.close()
andrewonlabe6745342014-10-17 14:29:13 -0400264 #****************
265
andrewonlab867212a2014-10-22 20:13:38 -0400266 json_str_1 = main.ONOS1cli.topology_events_metrics()
267 json_str_2 = main.ONOS2cli.topology_events_metrics()
268 json_str_3 = main.ONOS3cli.topology_events_metrics()
andrewonlab867212a2014-10-22 20:13:38 -0400269
270 json_obj_1 = json.loads(json_str_1)
271 json_obj_2 = json.loads(json_str_2)
272 json_obj_3 = json.loads(json_str_3)
273
andrewonlab226024e2014-10-24 16:01:32 -0400274 #Obtain graph timestamp. This timestsamp captures
275 #the epoch time at which the topology graph was updated.
276 graph_timestamp_1 = \
277 json_obj_1[graphTimestamp]['value']
278 graph_timestamp_2 = \
279 json_obj_2[graphTimestamp]['value']
280 graph_timestamp_3 = \
281 json_obj_3[graphTimestamp]['value']
andrewonlab867212a2014-10-22 20:13:38 -0400282
andrewonlab226024e2014-10-24 16:01:32 -0400283 #Obtain device timestamp. This timestamp captures
284 #the epoch time at which the device event happened
285 device_timestamp_1 = \
286 json_obj_1[deviceTimestamp]['value']
287 device_timestamp_2 = \
288 json_obj_2[deviceTimestamp]['value']
289 device_timestamp_3 = \
290 json_obj_3[deviceTimestamp]['value']
andrewonlabe9fb6722014-10-24 12:20:35 -0400291
andrewonlab226024e2014-10-24 16:01:32 -0400292 #t0 to device processing latency
293 delta_device_1 = int(device_timestamp_1) - int(t0_tcp)
294 delta_device_2 = int(device_timestamp_2) - int(t0_tcp)
295 delta_device_3 = int(device_timestamp_3) - int(t0_tcp)
296
297 #Get average of delta from all instances
298 avg_delta_device = \
299 (int(delta_device_1)+\
300 int(delta_device_2)+\
301 int(delta_device_3)) / 3
andrewonlabba44bcf2014-10-16 16:54:41 -0400302
andrewonlab226024e2014-10-24 16:01:32 -0400303 #Ensure avg delta meets the threshold before appending
andrewonlab4b5c8b92014-11-10 16:04:33 -0500304 if avg_delta_device > 0.0 and avg_delta_device < 10000\
andrewonlab65d73892014-11-10 17:36:00 -0500305 and int(i) > iter_ignore:
andrewonlab226024e2014-10-24 16:01:32 -0400306 latency_t0_to_device_list.append(avg_delta_device)
andrewonlabee4efeb2014-10-24 16:44:51 -0400307 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400308 main.log.info("Results for t0-to-device ignored"+\
andrewonlab4b5c8b92014-11-10 16:04:33 -0500309 "due to excess in threshold / warmup iteration.")
andrewonlabee4efeb2014-10-24 16:44:51 -0400310
andrewonlab226024e2014-10-24 16:01:32 -0400311 #t0 to graph processing latency (end-to-end)
312 delta_graph_1 = int(graph_timestamp_1) - int(t0_tcp)
313 delta_graph_2 = int(graph_timestamp_2) - int(t0_tcp)
314 delta_graph_3 = int(graph_timestamp_3) - int(t0_tcp)
315
316 #Get average of delta from all instances
317 avg_delta_graph = \
318 (int(delta_graph_1)+\
319 int(delta_graph_2)+\
320 int(delta_graph_3)) / 3
321
andrewonlab226024e2014-10-24 16:01:32 -0400322 #Ensure avg delta meets the threshold before appending
andrewonlab4b5c8b92014-11-10 16:04:33 -0500323 if avg_delta_graph > 0.0 and avg_delta_graph < 10000\
andrewonlab65d73892014-11-10 17:36:00 -0500324 and int(i) > iter_ignore:
andrewonlab09d973e2014-10-24 18:56:58 -0400325 latency_end_to_end_list.append(avg_delta_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400326 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400327 main.log.info("Results for end-to-end ignored"+\
328 "due to excess in threshold")
andrewonlab226024e2014-10-24 16:01:32 -0400329
330 #ofp to graph processing latency (ONOS processing)
331 delta_ofp_graph_1 = int(graph_timestamp_1) - int(t0_ofp)
332 delta_ofp_graph_2 = int(graph_timestamp_2) - int(t0_ofp)
333 delta_ofp_graph_3 = int(graph_timestamp_3) - int(t0_ofp)
334
335 avg_delta_ofp_graph = \
336 (int(delta_ofp_graph_1)+\
337 int(delta_ofp_graph_2)+\
338 int(delta_ofp_graph_3)) / 3
339
andrewonlabe5bcef92014-11-06 17:53:20 -0500340 if avg_delta_ofp_graph > threshold_min \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500341 and avg_delta_ofp_graph < threshold_max\
andrewonlab65d73892014-11-10 17:36:00 -0500342 and int(i) > iter_ignore:
andrewonlab226024e2014-10-24 16:01:32 -0400343 latency_ofp_to_graph_list.append(avg_delta_ofp_graph)
andrewonlabee4efeb2014-10-24 16:44:51 -0400344 else:
andrewonlab09d973e2014-10-24 18:56:58 -0400345 main.log.info("Results for ofp-to-graph "+\
346 "ignored due to excess in threshold")
andrewonlabee4efeb2014-10-24 16:44:51 -0400347
andrewonlab226024e2014-10-24 16:01:32 -0400348 #ofp to device processing latency (ONOS processing)
andrewonlabee4efeb2014-10-24 16:44:51 -0400349 delta_ofp_device_1 = float(device_timestamp_1) - float(t0_ofp)
350 delta_ofp_device_2 = float(device_timestamp_2) - float(t0_ofp)
351 delta_ofp_device_3 = float(device_timestamp_3) - float(t0_ofp)
andrewonlab226024e2014-10-24 16:01:32 -0400352
353 avg_delta_ofp_device = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400354 (float(delta_ofp_device_1)+\
355 float(delta_ofp_device_2)+\
andrewonlab4b5c8b92014-11-10 16:04:33 -0500356 float(delta_ofp_device_3)) / 3
andrewonlab226024e2014-10-24 16:01:32 -0400357
andrewonlabf47993a2014-10-24 17:56:01 -0400358 #NOTE: ofp - delta measurements are occasionally negative
359 # due to system time misalignment.
andrewonlabf47993a2014-10-24 17:56:01 -0400360 latency_ofp_to_device_list.append(avg_delta_ofp_device)
andrewonlabba44bcf2014-10-16 16:54:41 -0400361
andrewonlab65d73892014-11-10 17:36:00 -0500362 delta_ofp_tcp = int(t0_ofp) - int(t0_tcp)
363 if delta_ofp_tcp > threshold_min \
364 and delta_ofp_tcp < threshold_max and\
365 int(i) > iter_ignore:
366 latency_tcp_to_ofp_list.append(delta_ofp_tcp)
367 else:
368 main.log.info("Results fo tcp-to-ofp "+\
369 "ignored due to excess in threshold")
370
andrewonlabe6745342014-10-17 14:29:13 -0400371 #TODO:
372 #Fetch logs upon threshold excess
andrewonlabba44bcf2014-10-16 16:54:41 -0400373
andrewonlab226024e2014-10-24 16:01:32 -0400374 main.log.info("ONOS1 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400375 str(delta_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400376 main.log.info("ONOS2 delta end-to-end: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400377 str(delta_graph_2) + " ms")
378 main.log.info("ONOS3 delta end-to-end: "+
379 str(delta_graph_3) + " ms")
andrewonlabba44bcf2014-10-16 16:54:41 -0400380
andrewonlab226024e2014-10-24 16:01:32 -0400381 main.log.info("ONOS1 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400382 str(delta_ofp_graph_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400383 main.log.info("ONOS2 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400384 str(delta_ofp_graph_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400385 main.log.info("ONOS3 delta OFP - graph: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400386 str(delta_ofp_graph_3) + " ms")
andrewonlabe6745342014-10-17 14:29:13 -0400387
andrewonlab226024e2014-10-24 16:01:32 -0400388 main.log.info("ONOS1 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400389 str(delta_device_1) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400390 main.log.info("ONOS2 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400391 str(delta_device_2) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400392 main.log.info("ONOS3 delta device - t0: "+
andrewonlab09d973e2014-10-24 18:56:58 -0400393 str(delta_device_3) + " ms")
andrewonlab65d73892014-11-10 17:36:00 -0500394
395 main.log.info("TCP to OFP delta: "+
396 str(delta_ofp_tcp) + " ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500397 #main.log.info("ONOS1 delta OFP - device: "+
398 # str(delta_ofp_device_1) + " ms")
399 #main.log.info("ONOS2 delta OFP - device: "+
400 # str(delta_ofp_device_2) + " ms")
401 #main.log.info("ONOS3 delta OFP - device: "+
402 # str(delta_ofp_device_3) + " ms")
andrewonlab226024e2014-10-24 16:01:32 -0400403
andrewonlab8d29f122014-10-22 17:15:04 -0400404 main.step("Remove switch from controller")
405 main.Mininet1.delete_sw_controller("s1")
andrewonlabba44bcf2014-10-16 16:54:41 -0400406
andrewonlab8d29f122014-10-22 17:15:04 -0400407 time.sleep(5)
andrewonlabba44bcf2014-10-16 16:54:41 -0400408
andrewonlab09d973e2014-10-24 18:56:58 -0400409 #END of for loop iteration
andrewonlabf47993a2014-10-24 17:56:01 -0400410
andrewonlabee4efeb2014-10-24 16:44:51 -0400411 #If there is at least 1 element in each list,
andrewonlabc15c9582014-10-24 16:35:52 -0400412 #pass the test case
413 if len(latency_end_to_end_list) > 0 and\
414 len(latency_ofp_to_graph_list) > 0 and\
415 len(latency_ofp_to_device_list) > 0 and\
andrewonlab65d73892014-11-10 17:36:00 -0500416 len(latency_t0_to_device_list) > 0 and\
417 len(latency_tcp_to_ofp_list) > 0:
andrewonlabc15c9582014-10-24 16:35:52 -0400418 assertion = main.TRUE
andrewonlabf47993a2014-10-24 17:56:01 -0400419 elif len(latency_end_to_end_list) == 0:
420 #The appending of 0 here is to prevent
421 #the min,max,sum functions from failing
422 #below
423 latency_end_to_end_list.append(0)
424 assertion = main.FALSE
425 elif len(latency_ofp_to_graph_list) == 0:
426 latency_ofp_to_graph_list.append(0)
427 assertion = main.FALSE
428 elif len(latency_ofp_to_device_list) == 0:
429 latency_ofp_to_device_list.append(0)
430 assertion = main.FALSE
431 elif len(latency_t0_to_device_list) == 0:
432 latency_t0_to_device_list.append(0)
433 assertion = main.FALSE
andrewonlab65d73892014-11-10 17:36:00 -0500434 elif len(latency_tcp_to_ofp_list) == 0:
435 latency_tcp_to_ofp_list.append(0)
436 assertion = main.FALSE
andrewonlabc15c9582014-10-24 16:35:52 -0400437
438 #Calculate min, max, avg of latency lists
439 latency_end_to_end_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400440 int(max(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400441 latency_end_to_end_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400442 int(min(latency_end_to_end_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400443 latency_end_to_end_avg = \
andrewonlabc90667c2014-10-24 16:48:28 -0400444 (int(sum(latency_end_to_end_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400445 len(latency_end_to_end_list))
446
447 latency_ofp_to_graph_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400448 int(max(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400449 latency_ofp_to_graph_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400450 int(min(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400451 latency_ofp_to_graph_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400452 (int(sum(latency_ofp_to_graph_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400453 len(latency_ofp_to_graph_list))
454
455 latency_ofp_to_device_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400456 int(max(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400457 latency_ofp_to_device_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400458 int(min(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400459 latency_ofp_to_device_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400460 (int(sum(latency_ofp_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400461 len(latency_ofp_to_device_list))
462
463 latency_t0_to_device_max = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500464 int(max(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400465 latency_t0_to_device_min = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500466 int(min(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400467 latency_t0_to_device_avg = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500468 (int(sum(latency_t0_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400469 len(latency_ofp_to_device_list))
470
andrewonlab65d73892014-11-10 17:36:00 -0500471 latency_tcp_to_ofp_max = \
472 int(max(latency_tcp_to_ofp_list))
473 latency_tcp_to_ofp_min = \
474 int(min(latency_tcp_to_ofp_list))
475 latency_tcp_to_ofp_avg = \
476 (int(sum(latency_tcp_to_ofp_list)) / \
477 len(latency_tcp_to_ofp_list))
478
andrewonlabf9828f02014-11-10 14:50:27 -0500479 main.log.report("Switch add - End-to-end latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500480 "Avg: "+str(latency_end_to_end_avg)+" ms "+
481 "Std Deviation: "+
482 str(numpy.std(latency_end_to_end_list)))
andrewonlabf9828f02014-11-10 14:50:27 -0500483 main.log.report("Switch add - OFP-to-Graph latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500484 "Avg: "+str(latency_ofp_to_graph_avg)+" ms "+
485 "Std Deviation: "+
486 str(numpy.std(latency_ofp_to_graph_list)))
andrewonlab65d73892014-11-10 17:36:00 -0500487 main.log.report("Switch add - TCP-to-OFP latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500488 "Avg: "+str(latency_tcp_to_ofp_avg)+" ms "+
489 "Std Deviation: "+
490 str(numpy.std(latency_tcp_to_ofp_list)))
andrewonlab226024e2014-10-24 16:01:32 -0400491
andrewonlabb1998c52014-11-10 13:31:43 -0500492 if debug_mode == 'on':
493 main.ONOS1.cp_logs_to_dir("/opt/onos/log/karaf.log",
494 "/tmp/", copy_file_name="sw_lat_karaf")
495
andrewonlab8d29f122014-10-22 17:15:04 -0400496 utilities.assert_equals(expect=main.TRUE, actual=assertion,
497 onpass="Switch latency test successful",
498 onfail="Switch latency test failed")
andrewonlabba44bcf2014-10-16 16:54:41 -0400499
andrewonlab8d29f122014-10-22 17:15:04 -0400500 def CASE3(self, main):
501 '''
502 Bring port up / down and measure latency.
503 Port enable / disable is simulated by ifconfig up / down
andrewonlab393531a2014-10-27 18:36:26 -0400504
505 In ONOS-next, we must ensure that the port we are
506 manipulating is connected to another switch with a valid
507 connection. Otherwise, graph view will not be updated.
andrewonlab8d29f122014-10-22 17:15:04 -0400508 '''
509 import time
510 import subprocess
511 import os
512 import requests
513 import json
andrewonlab4f50ec92014-11-11 14:24:45 -0500514 import numpy
andrewonlab2a6c9342014-10-16 13:40:15 -0400515
andrewonlab8d29f122014-10-22 17:15:04 -0400516 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlab393531a2014-10-27 18:36:26 -0400517 ONOS2_ip = main.params['CTRL']['ip2']
518 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab8d29f122014-10-22 17:15:04 -0400519 ONOS_user = main.params['CTRL']['user']
andrewonlab8d29f122014-10-22 17:15:04 -0400520
andrewonlab393531a2014-10-27 18:36:26 -0400521 default_sw_port = main.params['CTRL']['port1']
andrewonlab8790abb2014-11-06 13:51:54 -0500522
523 assertion = main.TRUE
andrewonlab393531a2014-10-27 18:36:26 -0400524 #Number of iterations of case
525 num_iter = main.params['TEST']['numIter']
526
527 #Timestamp 'keys' for json metrics output.
528 #These are subject to change, hence moved into params
529 deviceTimestamp = main.params['JSON']['deviceTimestamp']
530 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500531
532 debug_mode = main.params['TEST']['debugMode']
533
534 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500535 local_time = local_time.replace("/","")
536 local_time = local_time.replace(" ","_")
537 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500538 if debug_mode == 'on':
539 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500540 "/tmp/port_lat_pcap_"+local_time)
andrewonlab393531a2014-10-27 18:36:26 -0400541
andrewonlabe5bcef92014-11-06 17:53:20 -0500542 #Threshold for this test case
543 up_threshold_str = main.params['TEST']['portUpThreshold']
544 down_threshold_str = main.params['TEST']['portDownThreshold']
andrewonlabb1998c52014-11-10 13:31:43 -0500545
andrewonlabe5bcef92014-11-06 17:53:20 -0500546 up_threshold_obj = up_threshold_str.split(",")
547 down_threshold_obj = down_threshold_str.split(",")
548
549 up_threshold_min = int(up_threshold_obj[0])
550 up_threshold_max = int(up_threshold_obj[1])
551
552 down_threshold_min = int(down_threshold_obj[0])
553 down_threshold_max = int(down_threshold_obj[1])
554
andrewonlab393531a2014-10-27 18:36:26 -0400555 #NOTE: Some hardcoded variables you may need to configure
556 # besides the params
557
andrewonlab8d29f122014-10-22 17:15:04 -0400558 tshark_port_status = "OFP 130 Port Status"
559
560 tshark_port_up = "/tmp/tshark_port_up.txt"
561 tshark_port_down = "/tmp/tshark_port_down.txt"
andrewonlab393531a2014-10-27 18:36:26 -0400562 interface_config = "s1-eth1"
andrewonlab8d29f122014-10-22 17:15:04 -0400563
564 main.log.report("Port enable / disable latency")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500565 main.log.report("Simulated by ifconfig up / down")
566 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab8d29f122014-10-22 17:15:04 -0400567
andrewonlab393531a2014-10-27 18:36:26 -0400568 main.step("Assign switches s1 and s2 to controller 1")
andrewonlab8d29f122014-10-22 17:15:04 -0400569 main.Mininet1.assign_sw_controller(sw="1",ip1=ONOS1_ip,
570 port1=default_sw_port)
andrewonlab393531a2014-10-27 18:36:26 -0400571 main.Mininet1.assign_sw_controller(sw="2",ip1=ONOS1_ip,
572 port1=default_sw_port)
andrewonlab8d29f122014-10-22 17:15:04 -0400573
andrewonlab8790abb2014-11-06 13:51:54 -0500574 #Give enough time for metrics to propagate the
575 #assign controller event. Otherwise, these events may
576 #carry over to our measurements
andrewonlabb1998c52014-11-10 13:31:43 -0500577 time.sleep(15)
andrewonlab8d29f122014-10-22 17:15:04 -0400578
andrewonlab393531a2014-10-27 18:36:26 -0400579 port_up_device_to_ofp_list = []
580 port_up_graph_to_ofp_list = []
581 port_down_device_to_ofp_list = []
582 port_down_graph_to_ofp_list = []
583
andrewonlab8d29f122014-10-22 17:15:04 -0400584 for i in range(0, int(num_iter)):
585 main.step("Starting wireshark capture for port status down")
586 main.ONOS1.tshark_grep(tshark_port_status,
587 tshark_port_down)
588
andrewonlabb1998c52014-11-10 13:31:43 -0500589 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400590
andrewonlab393531a2014-10-27 18:36:26 -0400591 #Disable interface that is connected to switch 2
592 main.step("Disable port: "+interface_config)
andrewonlabb1998c52014-11-10 13:31:43 -0500593 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400594 interface_config+" down")
andrewonlabb1998c52014-11-10 13:31:43 -0500595 main.Mininet1.handle.expect("mininet>")
andrewonlab8d29f122014-10-22 17:15:04 -0400596
andrewonlabb1998c52014-11-10 13:31:43 -0500597 time.sleep(3)
andrewonlab8d29f122014-10-22 17:15:04 -0400598 main.ONOS1.tshark_stop()
andrewonlabb1998c52014-11-10 13:31:43 -0500599
600 main.step("Obtain t1 by metrics call")
601 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
602 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
603 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
604
605 json_obj_1 = json.loads(json_str_up_1)
606 json_obj_2 = json.loads(json_str_up_2)
607 json_obj_3 = json.loads(json_str_up_3)
andrewonlab8d29f122014-10-22 17:15:04 -0400608
609 #Copy tshark output file from ONOS to TestON instance
610 #/tmp directory
611 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
612 tshark_port_down+" /tmp/")
613
614 f_port_down = open(tshark_port_down, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400615 #Get first line of port down event from tshark
andrewonlab8d29f122014-10-22 17:15:04 -0400616 f_line = f_port_down.readline()
617 obj_down = f_line.split(" ")
618 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500619 timestamp_begin_pt_down = int(float(obj_down[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400620 main.log.info("Port down begin timestamp: "+
621 str(timestamp_begin_pt_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400622 else:
623 main.log.info("Tshark output file returned unexpected"+
andrewonlab393531a2014-10-27 18:36:26 -0400624 " results: "+str(obj_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400625 timestamp_begin_pt_down = 0
andrewonlab393531a2014-10-27 18:36:26 -0400626
627 f_port_down.close()
andrewonlab8d29f122014-10-22 17:15:04 -0400628
andrewonlab4e124482014-11-04 13:37:25 -0500629 main.log.info("TEST tshark obj: "+str(obj_down))
630
andrewonlabb1998c52014-11-10 13:31:43 -0500631 time.sleep(3)
andrewonlab393531a2014-10-27 18:36:26 -0400632
633 #Obtain graph timestamp. This timestsamp captures
634 #the epoch time at which the topology graph was updated.
635 graph_timestamp_1 = \
636 json_obj_1[graphTimestamp]['value']
637 graph_timestamp_2 = \
638 json_obj_2[graphTimestamp]['value']
639 graph_timestamp_3 = \
640 json_obj_3[graphTimestamp]['value']
641
andrewonlabb1998c52014-11-10 13:31:43 -0500642 main.log.info("TEST graph timestamp ONOS1: "+
643 str(graph_timestamp_1))
644
andrewonlab393531a2014-10-27 18:36:26 -0400645 #Obtain device timestamp. This timestamp captures
646 #the epoch time at which the device event happened
647 device_timestamp_1 = \
648 json_obj_1[deviceTimestamp]['value']
649 device_timestamp_2 = \
650 json_obj_2[deviceTimestamp]['value']
651 device_timestamp_3 = \
652 json_obj_3[deviceTimestamp]['value']
andrewonlab393531a2014-10-27 18:36:26 -0400653
654 #Get delta between graph event and OFP
655 pt_down_graph_to_ofp_1 = int(graph_timestamp_1) -\
656 int(timestamp_begin_pt_down)
657 pt_down_graph_to_ofp_2 = int(graph_timestamp_2) -\
658 int(timestamp_begin_pt_down)
659 pt_down_graph_to_ofp_3 = int(graph_timestamp_3) -\
660 int(timestamp_begin_pt_down)
661
662 #Get delta between device event and OFP
663 pt_down_device_to_ofp_1 = int(device_timestamp_1) -\
664 int(timestamp_begin_pt_down)
665 pt_down_device_to_ofp_2 = int(device_timestamp_2) -\
666 int(timestamp_begin_pt_down)
667 pt_down_device_to_ofp_3 = int(device_timestamp_3) -\
668 int(timestamp_begin_pt_down)
669
670 #Caluclate average across clusters
671 pt_down_graph_to_ofp_avg =\
672 (int(pt_down_graph_to_ofp_1) +
673 int(pt_down_graph_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500674 int(pt_down_graph_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400675 pt_down_device_to_ofp_avg = \
676 (int(pt_down_device_to_ofp_1) +
677 int(pt_down_device_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500678 int(pt_down_device_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400679
andrewonlabb1998c52014-11-10 13:31:43 -0500680 if pt_down_graph_to_ofp_avg > down_threshold_min and \
681 pt_down_graph_to_ofp_avg < down_threshold_max:
andrewonlab393531a2014-10-27 18:36:26 -0400682 port_down_graph_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500683 pt_down_graph_to_ofp_avg)
684 main.log.info("Port down: graph to ofp avg: "+
685 str(pt_down_graph_to_ofp_avg) + " ms")
andrewonlab393531a2014-10-27 18:36:26 -0400686 else:
687 main.log.info("Average port down graph-to-ofp result" +
688 " exceeded the threshold: "+
689 str(pt_down_graph_to_ofp_avg))
690
andrewonlab3622beb2014-10-28 16:07:56 -0400691 if pt_down_device_to_ofp_avg > 0 and \
692 pt_down_device_to_ofp_avg < 1000:
693 port_down_device_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500694 pt_down_device_to_ofp_avg)
695 main.log.info("Port down: device to ofp avg: "+
696 str(pt_down_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400697 else:
698 main.log.info("Average port down device-to-ofp result" +
699 " exceeded the threshold: "+
700 str(pt_down_device_to_ofp_avg))
701
andrewonlab8d29f122014-10-22 17:15:04 -0400702 #Port up events
703 main.step("Enable port and obtain timestamp")
704 main.step("Starting wireshark capture for port status up")
andrewonlabb1998c52014-11-10 13:31:43 -0500705 main.ONOS1.tshark_grep(tshark_port_status, tshark_port_up)
andrewonlab8790abb2014-11-06 13:51:54 -0500706 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400707
andrewonlabb1998c52014-11-10 13:31:43 -0500708 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400709 interface_config+" up")
andrewonlabb1998c52014-11-10 13:31:43 -0500710 main.Mininet1.handle.expect("mininet>")
andrewonlab8790abb2014-11-06 13:51:54 -0500711
andrewonlabb1998c52014-11-10 13:31:43 -0500712 #Allow time for tshark to capture event
713 time.sleep(3)
andrewonlab8790abb2014-11-06 13:51:54 -0500714 main.ONOS1.tshark_stop()
andrewonlab8d29f122014-10-22 17:15:04 -0400715
andrewonlabb1998c52014-11-10 13:31:43 -0500716 #Obtain metrics shortly afterwards
717 #This timestsamp captures
718 #the epoch time at which the topology graph was updated.
719 main.step("Obtain t1 by REST call")
720 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
721 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
722 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
723
724 json_obj_1 = json.loads(json_str_up_1)
725 json_obj_2 = json.loads(json_str_up_2)
726 json_obj_3 = json.loads(json_str_up_3)
727
andrewonlab8d29f122014-10-22 17:15:04 -0400728 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
729 tshark_port_up+" /tmp/")
730
731 f_port_up = open(tshark_port_up, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400732 f_line = f_port_up.readline()
andrewonlab8d29f122014-10-22 17:15:04 -0400733 obj_up = f_line.split(" ")
734 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500735 timestamp_begin_pt_up = int(float(obj_up[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400736 main.log.info("Port up begin timestamp: "+
737 str(timestamp_begin_pt_up))
andrewonlab8d29f122014-10-22 17:15:04 -0400738 else:
739 main.log.info("Tshark output file returned unexpected"+
740 " results.")
741 timestamp_begin_pt_up = 0
742
andrewonlab393531a2014-10-27 18:36:26 -0400743 f_port_up.close()
744
andrewonlab393531a2014-10-27 18:36:26 -0400745 graph_timestamp_1 = \
746 json_obj_1[graphTimestamp]['value']
747 graph_timestamp_2 = \
748 json_obj_2[graphTimestamp]['value']
749 graph_timestamp_3 = \
750 json_obj_3[graphTimestamp]['value']
751
752 #Obtain device timestamp. This timestamp captures
753 #the epoch time at which the device event happened
754 device_timestamp_1 = \
755 json_obj_1[deviceTimestamp]['value']
756 device_timestamp_2 = \
757 json_obj_2[deviceTimestamp]['value']
758 device_timestamp_3 = \
759 json_obj_3[deviceTimestamp]['value']
760
761 #Get delta between graph event and OFP
762 pt_up_graph_to_ofp_1 = int(graph_timestamp_1) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400763 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400764 pt_up_graph_to_ofp_2 = int(graph_timestamp_2) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400765 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400766 pt_up_graph_to_ofp_3 = int(graph_timestamp_3) -\
767 int(timestamp_begin_pt_up)
768
769 #Get delta between device event and OFP
770 pt_up_device_to_ofp_1 = int(device_timestamp_1) -\
771 int(timestamp_begin_pt_up)
772 pt_up_device_to_ofp_2 = int(device_timestamp_2) -\
773 int(timestamp_begin_pt_up)
774 pt_up_device_to_ofp_3 = int(device_timestamp_3) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400775 int(timestamp_begin_pt_up)
andrewonlab3622beb2014-10-28 16:07:56 -0400776
andrewonlabb1998c52014-11-10 13:31:43 -0500777 main.log.info("ONOS1 delta G2O: "+str(pt_up_graph_to_ofp_1))
778 main.log.info("ONOS2 delta G2O: "+str(pt_up_graph_to_ofp_2))
779 main.log.info("ONOS3 delta G2O: "+str(pt_up_graph_to_ofp_3))
780
781 main.log.info("ONOS1 delta D2O: "+str(pt_up_device_to_ofp_1))
782 main.log.info("ONOS2 delta D2O: "+str(pt_up_device_to_ofp_2))
783 main.log.info("ONOS3 delta D2O: "+str(pt_up_device_to_ofp_3))
784
andrewonlab3622beb2014-10-28 16:07:56 -0400785 pt_up_graph_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500786 (int(pt_up_graph_to_ofp_1) +
787 int(pt_up_graph_to_ofp_2) +
788 int(pt_up_graph_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400789
790 pt_up_device_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500791 (int(pt_up_device_to_ofp_1) +
792 int(pt_up_device_to_ofp_2) +
793 int(pt_up_device_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400794
andrewonlabe5bcef92014-11-06 17:53:20 -0500795 if pt_up_graph_to_ofp_avg > up_threshold_min and \
796 pt_up_graph_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400797 port_up_graph_to_ofp_list.append(
798 pt_up_graph_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500799 main.log.info("Port down: graph to ofp avg: "+
800 str(pt_up_graph_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400801 else:
802 main.log.info("Average port up graph-to-ofp result"+
803 " exceeded the threshold: "+
804 str(pt_up_graph_to_ofp_avg))
805
andrewonlabe5bcef92014-11-06 17:53:20 -0500806 if pt_up_device_to_ofp_avg > up_threshold_min and \
807 pt_up_device_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400808 port_up_device_to_ofp_list.append(
809 pt_up_device_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500810 main.log.info("Port up: device to ofp avg: "+
811 str(pt_up_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400812 else:
andrewonlababb11c32014-11-04 15:03:24 -0500813 main.log.info("Average port up device-to-ofp result"+
andrewonlab3622beb2014-10-28 16:07:56 -0400814 " exceeded the threshold: "+
815 str(pt_up_device_to_ofp_avg))
andrewonlab8d29f122014-10-22 17:15:04 -0400816
andrewonlab3622beb2014-10-28 16:07:56 -0400817 #END ITERATION FOR LOOP
andrewonlab8790abb2014-11-06 13:51:54 -0500818
819 #Check all list for latency existence and set assertion
820 if (port_down_graph_to_ofp_list and port_down_device_to_ofp_list\
821 and port_up_graph_to_ofp_list and port_up_device_to_ofp_list):
822 assertion = main.TRUE
823
andrewonlababb11c32014-11-04 15:03:24 -0500824 #Calculate and report latency measurements
andrewonlab3622beb2014-10-28 16:07:56 -0400825 port_down_graph_to_ofp_min = min(port_down_graph_to_ofp_list)
826 port_down_graph_to_ofp_max = max(port_down_graph_to_ofp_list)
827 port_down_graph_to_ofp_avg = \
828 (sum(port_down_graph_to_ofp_list) /
829 len(port_down_graph_to_ofp_list))
830
andrewonlab4f50ec92014-11-11 14:24:45 -0500831 main.log.report("Port down graph-to-ofp "+
832 "Avg: "+str(port_down_graph_to_ofp_avg)+" ms "+
833 "Std Deviation: "+
834 str(numpy.std(port_down_graph_to_ofp_list)))
andrewonlababb11c32014-11-04 15:03:24 -0500835
836 port_down_device_to_ofp_min = min(port_down_device_to_ofp_list)
837 port_down_device_to_ofp_max = max(port_down_device_to_ofp_list)
838 port_down_device_to_ofp_avg = \
839 (sum(port_down_device_to_ofp_list) /\
840 len(port_down_device_to_ofp_list))
841
andrewonlab4f50ec92014-11-11 14:24:45 -0500842 main.log.report("Port down device-to-ofp "+
843 "Avg: "+str(port_down_device_to_ofp_avg)+" ms "+
844 "Std Deviation: "+
845 str(numpy.std(port_down_device_to_ofp_list)))
andrewonlababb11c32014-11-04 15:03:24 -0500846
847 port_up_graph_to_ofp_min = min(port_up_graph_to_ofp_list)
848 port_up_graph_to_ofp_max = max(port_up_graph_to_ofp_list)
849 port_up_graph_to_ofp_avg = \
850 (sum(port_up_graph_to_ofp_list) /\
851 len(port_up_graph_to_ofp_list))
andrewonlab8790abb2014-11-06 13:51:54 -0500852
andrewonlab4f50ec92014-11-11 14:24:45 -0500853 main.log.report("Port up graph-to-ofp "+
854 "Avg: "+str(port_up_graph_to_ofp_avg)+" ms "+
855 "Std Deviation: "+
856 str(numpy.std(port_up_graph_to_ofp_list)))
andrewonlab8790abb2014-11-06 13:51:54 -0500857
858 port_up_device_to_ofp_min = min(port_up_device_to_ofp_list)
859 port_up_device_to_ofp_max = max(port_up_device_to_ofp_list)
860 port_up_device_to_ofp_avg = \
861 (sum(port_up_device_to_ofp_list) /\
862 len(port_up_device_to_ofp_list))
863
andrewonlab4f50ec92014-11-11 14:24:45 -0500864 main.log.report("Port up device-to-ofp "+
865 "Avg: "+str(port_up_device_to_ofp_avg)+" ms "+
866 "Std Deviation: "+
867 str(numpy.std(port_up_device_to_ofp_list)))
andrewonlab8790abb2014-11-06 13:51:54 -0500868
869 utilities.assert_equals(expect=main.TRUE, actual=assertion,
870 onpass="Port discovery latency calculation successful",
871 onfail="Port discovery test failed")
andrewonlababb11c32014-11-04 15:03:24 -0500872
andrewonlab3622beb2014-10-28 16:07:56 -0400873 def CASE4(self, main):
874 '''
875 Link down event using loss rate 100%
andrewonlab53b641c2014-10-31 19:44:44 -0400876
877 Important:
878 Use a simple 2 switch topology with 1 link between
879 the two switches. Ensure that mac addresses of the
880 switches are 1 / 2 respectively
andrewonlab3622beb2014-10-28 16:07:56 -0400881 '''
882 import time
883 import subprocess
884 import os
885 import requests
886 import json
andrewonlab4f50ec92014-11-11 14:24:45 -0500887 import numpy
888
andrewonlab3622beb2014-10-28 16:07:56 -0400889 ONOS1_ip = main.params['CTRL']['ip1']
890 ONOS2_ip = main.params['CTRL']['ip2']
891 ONOS3_ip = main.params['CTRL']['ip3']
892 ONOS_user = main.params['CTRL']['user']
893
894 default_sw_port = main.params['CTRL']['port1']
895
896 #Number of iterations of case
897 num_iter = main.params['TEST']['numIter']
898
899 #Timestamp 'keys' for json metrics output.
900 #These are subject to change, hence moved into params
901 deviceTimestamp = main.params['JSON']['deviceTimestamp']
902 linkTimestamp = main.params['JSON']['linkTimestamp']
andrewonlab53b641c2014-10-31 19:44:44 -0400903 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500904
905 debug_mode = main.params['TEST']['debugMode']
906
907 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500908 local_time = local_time.replace("/","")
909 local_time = local_time.replace(" ","_")
910 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500911 if debug_mode == 'on':
912 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500913 "/tmp/link_lat_pcap_"+local_time)
andrewonlab53b641c2014-10-31 19:44:44 -0400914
andrewonlabe5bcef92014-11-06 17:53:20 -0500915 #Threshold for this test case
916 up_threshold_str = main.params['TEST']['linkUpThreshold']
917 down_threshold_str = main.params['TEST']['linkDownThreshold']
918
919 up_threshold_obj = up_threshold_str.split(",")
920 down_threshold_obj = down_threshold_str.split(",")
921
922 up_threshold_min = int(up_threshold_obj[0])
923 up_threshold_max = int(up_threshold_obj[1])
924
925 down_threshold_min = int(down_threshold_obj[0])
926 down_threshold_max = int(down_threshold_obj[1])
927
andrewonlab3622beb2014-10-28 16:07:56 -0400928 assertion = main.TRUE
929 #Link event timestamp to system time list
930 link_down_link_to_system_list = []
931 link_up_link_to_system_list = []
932 #Graph event timestamp to system time list
933 link_down_graph_to_system_list = []
934 link_up_graph_to_system_list = []
935
andrewonlab4b5c8b92014-11-10 16:04:33 -0500936 main.log.report("Link up / down discovery latency between "+
andrewonlab3622beb2014-10-28 16:07:56 -0400937 "two switches")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500938 main.log.report("Simulated by setting loss-rate 100%")
939 main.log.report("'tc qdisc add dev <intfs> root netem loss 100%'")
940 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab3622beb2014-10-28 16:07:56 -0400941
942 main.step("Assign all switches")
943 main.Mininet1.assign_sw_controller(sw="1",
944 ip1=ONOS1_ip, port1=default_sw_port)
945 main.Mininet1.assign_sw_controller(sw="2",
946 ip1=ONOS1_ip, port1=default_sw_port)
947
948 main.step("Verifying switch assignment")
949 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
950 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
andrewonlab3622beb2014-10-28 16:07:56 -0400951
952 #Allow time for events to finish before taking measurements
953 time.sleep(10)
954
andrewonlababb11c32014-11-04 15:03:24 -0500955 link_down1 = False
956 link_down2 = False
957 link_down3 = False
andrewonlab3622beb2014-10-28 16:07:56 -0400958 #Start iteration of link event test
959 for i in range(0, int(num_iter)):
960 main.step("Getting initial system time as t0")
andrewonlab8d29f122014-10-22 17:15:04 -0400961
andrewonlab3622beb2014-10-28 16:07:56 -0400962 timestamp_link_down_t0 = time.time() * 1000
963 #Link down is simulated by 100% loss rate using traffic
964 #control command
965 main.Mininet1.handle.sendline(
966 "sh tc qdisc add dev s1-eth1 root netem loss 100%")
967
andrewonlab53b641c2014-10-31 19:44:44 -0400968 #TODO: Iterate through 'links' command to verify that
andrewonlababb11c32014-11-04 15:03:24 -0500969 # link s1 -> s2 went down (loop timeout 30 seconds)
970 # on all 3 ONOS instances
andrewonlab53b641c2014-10-31 19:44:44 -0400971 main.log.info("Checking ONOS for link update")
972 loop_count = 0
andrewonlababb11c32014-11-04 15:03:24 -0500973 while( not (link_down1 and link_down2 and link_down3)\
974 and loop_count < 30 ):
975 json_str1 = main.ONOS1cli.links()
976 json_str2 = main.ONOS2cli.links()
977 json_str3 = main.ONOS3cli.links()
978
979 if not (json_str1 and json_str2 and json_str3):
980 main.log.error("CLI command returned error ")
andrewonlab53b641c2014-10-31 19:44:44 -0400981 break
982 else:
andrewonlababb11c32014-11-04 15:03:24 -0500983 json_obj1 = json.loads(json_str1)
984 json_obj2 = json.loads(json_str2)
985 json_obj3 = json.loads(json_str3)
986 for obj1 in json_obj1:
987 if '01' not in obj1['src']['device']:
988 link_down1 = True
andrewonlabf9828f02014-11-10 14:50:27 -0500989 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -0500990 "s1 -> s2 on ONOS1 detected")
991 for obj2 in json_obj2:
992 if '01' not in obj2['src']['device']:
993 link_down2 = True
andrewonlabf9828f02014-11-10 14:50:27 -0500994 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -0500995 "s1 -> s2 on ONOS2 detected")
996 for obj3 in json_obj3:
997 if '01' not in obj3['src']['device']:
998 link_down3 = True
andrewonlabf9828f02014-11-10 14:50:27 -0500999 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001000 "s1 -> s2 on ONOS3 detected")
1001
andrewonlab53b641c2014-10-31 19:44:44 -04001002 loop_count += 1
andrewonlababb11c32014-11-04 15:03:24 -05001003 #If CLI doesn't like the continuous requests
1004 #and exits in this loop, increase the sleep here.
1005 #Consequently, while loop timeout will increase
andrewonlab53b641c2014-10-31 19:44:44 -04001006 time.sleep(1)
1007
1008 #Give time for metrics measurement to catch up
andrewonlababb11c32014-11-04 15:03:24 -05001009 #NOTE: May need to be configured more accurately
andrewonlab53b641c2014-10-31 19:44:44 -04001010 time.sleep(10)
andrewonlababb11c32014-11-04 15:03:24 -05001011 #If we exited the while loop and link down 1,2,3 are still
andrewonlab53b641c2014-10-31 19:44:44 -04001012 #false, then ONOS has failed to discover link down event
andrewonlababb11c32014-11-04 15:03:24 -05001013 if not (link_down1 and link_down2 and link_down3):
andrewonlab53b641c2014-10-31 19:44:44 -04001014 main.log.info("Link down discovery failed")
1015
1016 link_down_lat_graph1 = 0
1017 link_down_lat_graph2 = 0
1018 link_down_lat_graph3 = 0
1019 link_down_lat_device1 = 0
1020 link_down_lat_device2 = 0
1021 link_down_lat_device3 = 0
1022
1023 assertion = main.FALSE
1024 else:
1025 json_topo_metrics_1 =\
1026 main.ONOS1cli.topology_events_metrics()
1027 json_topo_metrics_2 =\
1028 main.ONOS2cli.topology_events_metrics()
1029 json_topo_metrics_3 =\
1030 main.ONOS3cli.topology_events_metrics()
1031 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1032 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1033 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1034
1035 main.log.info("Obtaining graph and device timestamp")
1036 graph_timestamp_1 = \
1037 json_topo_metrics_1[graphTimestamp]['value']
1038 graph_timestamp_2 = \
1039 json_topo_metrics_2[graphTimestamp]['value']
1040 graph_timestamp_3 = \
1041 json_topo_metrics_3[graphTimestamp]['value']
1042
1043 link_timestamp_1 = \
1044 json_topo_metrics_1[linkTimestamp]['value']
1045 link_timestamp_2 = \
1046 json_topo_metrics_2[linkTimestamp]['value']
1047 link_timestamp_3 = \
1048 json_topo_metrics_3[linkTimestamp]['value']
1049
1050 if graph_timestamp_1 and graph_timestamp_2 and\
1051 graph_timestamp_3 and link_timestamp_1 and\
1052 link_timestamp_2 and link_timestamp_3:
1053 link_down_lat_graph1 = int(graph_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001054 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001055 link_down_lat_graph2 = int(graph_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001056 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001057 link_down_lat_graph3 = int(graph_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001058 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001059
1060 link_down_lat_link1 = int(link_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001061 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001062 link_down_lat_link2 = int(link_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001063 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001064 link_down_lat_link3 = int(link_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001065 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001066 else:
1067 main.log.error("There was an error calculating"+
1068 " the delta for link down event")
1069 link_down_lat_graph1 = 0
1070 link_down_lat_graph2 = 0
1071 link_down_lat_graph3 = 0
1072
1073 link_down_lat_device1 = 0
1074 link_down_lat_device2 = 0
1075 link_down_lat_device3 = 0
1076
andrewonlabf9828f02014-11-10 14:50:27 -05001077 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001078 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001079 str(link_down_lat_graph1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001080 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001081 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001082 str(link_down_lat_graph2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001083 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001084 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001085 str(link_down_lat_graph3)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001086
andrewonlabf9828f02014-11-10 14:50:27 -05001087 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001088 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001089 str(link_down_lat_link1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001090 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001091 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001092 str(link_down_lat_link2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001093 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001094 str(i)+" (link-event-to-system-timestamp): "+
1095 str(link_down_lat_link3))
1096
1097 #Calculate avg of node calculations
1098 link_down_lat_graph_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001099 (link_down_lat_graph1 +
1100 link_down_lat_graph2 +
andrewonlab65d73892014-11-10 17:36:00 -05001101 link_down_lat_graph3) / 3
andrewonlab4e124482014-11-04 13:37:25 -05001102 link_down_lat_link_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001103 (link_down_lat_link1 +
1104 link_down_lat_link2 +
andrewonlab65d73892014-11-10 17:36:00 -05001105 link_down_lat_link3) / 3
andrewonlab53b641c2014-10-31 19:44:44 -04001106
andrewonlab4e124482014-11-04 13:37:25 -05001107 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001108 if link_down_lat_graph_avg > down_threshold_min and\
1109 link_down_lat_graph_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001110 link_down_graph_to_system_list.append(
1111 link_down_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001112 else:
1113 main.log.info("Link down latency exceeded threshold")
1114 main.log.info("Results for iteration "+str(i)+
1115 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001116 if link_down_lat_link_avg > down_threshold_min and\
1117 link_down_lat_link_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001118 link_down_link_to_system_list.append(
1119 link_down_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001120 else:
1121 main.log.info("Link down latency exceeded threshold")
1122 main.log.info("Results for iteration "+str(i)+
1123 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001124
1125 #NOTE: To remove loss rate and measure latency:
1126 # 'sh tc qdisc del dev s1-eth1 root'
andrewonlababb11c32014-11-04 15:03:24 -05001127 timestamp_link_up_t0 = time.time() * 1000
andrewonlab53b641c2014-10-31 19:44:44 -04001128 main.Mininet1.handle.sendline("sh tc qdisc del dev "+
1129 "s1-eth1 root")
1130 main.Mininet1.handle.expect("mininet>")
andrewonlababb11c32014-11-04 15:03:24 -05001131
1132 main.log.info("Checking ONOS for link update")
1133
1134 link_down1 = True
1135 link_down2 = True
1136 link_down3 = True
1137 loop_count = 0
1138 while( (link_down1 and link_down2 and link_down3)\
1139 and loop_count < 30 ):
1140 json_str1 = main.ONOS1cli.links()
1141 json_str2 = main.ONOS2cli.links()
1142 json_str3 = main.ONOS3cli.links()
1143 if not (json_str1 and json_str2 and json_str3):
1144 main.log.error("CLI command returned error ")
1145 break
1146 else:
1147 json_obj1 = json.loads(json_str1)
1148 json_obj2 = json.loads(json_str2)
1149 json_obj3 = json.loads(json_str3)
1150
1151 for obj1 in json_obj1:
1152 if '01' in obj1['src']['device']:
1153 link_down1 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001154 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001155 "s1 -> s2 on ONOS1 detected")
1156 for obj2 in json_obj2:
1157 if '01' in obj2['src']['device']:
1158 link_down2 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001159 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001160 "s1 -> s2 on ONOS2 detected")
1161 for obj3 in json_obj3:
1162 if '01' in obj3['src']['device']:
1163 link_down3 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001164 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001165 "s1 -> s2 on ONOS3 detected")
1166
1167 loop_count += 1
1168 time.sleep(1)
1169
1170 if (link_down1 and link_down2 and link_down3):
1171 main.log.info("Link up discovery failed")
1172
1173 link_up_lat_graph1 = 0
1174 link_up_lat_graph2 = 0
1175 link_up_lat_graph3 = 0
1176 link_up_lat_device1 = 0
1177 link_up_lat_device2 = 0
1178 link_up_lat_device3 = 0
1179
1180 assertion = main.FALSE
1181 else:
1182 json_topo_metrics_1 =\
1183 main.ONOS1cli.topology_events_metrics()
1184 json_topo_metrics_2 =\
1185 main.ONOS2cli.topology_events_metrics()
1186 json_topo_metrics_3 =\
1187 main.ONOS3cli.topology_events_metrics()
1188 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1189 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1190 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1191
1192 main.log.info("Obtaining graph and device timestamp")
1193 graph_timestamp_1 = \
1194 json_topo_metrics_1[graphTimestamp]['value']
1195 graph_timestamp_2 = \
1196 json_topo_metrics_2[graphTimestamp]['value']
1197 graph_timestamp_3 = \
1198 json_topo_metrics_3[graphTimestamp]['value']
1199
1200 link_timestamp_1 = \
1201 json_topo_metrics_1[linkTimestamp]['value']
1202 link_timestamp_2 = \
1203 json_topo_metrics_2[linkTimestamp]['value']
1204 link_timestamp_3 = \
1205 json_topo_metrics_3[linkTimestamp]['value']
1206
1207 if graph_timestamp_1 and graph_timestamp_2 and\
1208 graph_timestamp_3 and link_timestamp_1 and\
1209 link_timestamp_2 and link_timestamp_3:
1210 link_up_lat_graph1 = int(graph_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001211 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001212 link_up_lat_graph2 = int(graph_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001213 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001214 link_up_lat_graph3 = int(graph_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001215 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001216
1217 link_up_lat_link1 = int(link_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001218 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001219 link_up_lat_link2 = int(link_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001220 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001221 link_up_lat_link3 = int(link_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001222 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001223 else:
1224 main.log.error("There was an error calculating"+
1225 " the delta for link down event")
1226 link_up_lat_graph1 = 0
1227 link_up_lat_graph2 = 0
1228 link_up_lat_graph3 = 0
1229
1230 link_up_lat_device1 = 0
1231 link_up_lat_device2 = 0
1232 link_up_lat_device3 = 0
andrewonlab58f7d702014-11-07 13:21:19 -05001233
1234 if debug_mode == 'on':
1235 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001236 str(i)+" (end-to-end): "+
1237 str(link_up_lat_graph1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001238 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001239 str(i)+" (end-to-end): "+
1240 str(link_up_lat_graph2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001241 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001242 str(i)+" (end-to-end): "+
1243 str(link_up_lat_graph3)+" ms")
1244
andrewonlab58f7d702014-11-07 13:21:19 -05001245 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001246 str(i)+" (link-event-to-system-timestamp): "+
1247 str(link_up_lat_link1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001248 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001249 str(i)+" (link-event-to-system-timestamp): "+
1250 str(link_up_lat_link2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001251 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001252 str(i)+" (link-event-to-system-timestamp): "+
1253 str(link_up_lat_link3))
1254
1255 #Calculate avg of node calculations
1256 link_up_lat_graph_avg =\
1257 (link_up_lat_graph1 +
1258 link_up_lat_graph2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001259 link_up_lat_graph3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001260 link_up_lat_link_avg =\
1261 (link_up_lat_link1 +
1262 link_up_lat_link2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001263 link_up_lat_link3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001264
1265 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001266 if link_up_lat_graph_avg > up_threshold_min and\
1267 link_up_lat_graph_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001268 link_up_graph_to_system_list.append(
1269 link_up_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001270 else:
1271 main.log.info("Link up latency exceeded threshold")
1272 main.log.info("Results for iteration "+str(i)+
1273 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001274 if link_up_lat_link_avg > up_threshold_min and\
1275 link_up_lat_link_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001276 link_up_link_to_system_list.append(
1277 link_up_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001278 else:
1279 main.log.info("Link up latency exceeded threshold")
1280 main.log.info("Results for iteration "+str(i)+
1281 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001282
andrewonlab4e124482014-11-04 13:37:25 -05001283 #Calculate min, max, avg of list and report
1284 link_down_min = min(link_down_graph_to_system_list)
1285 link_down_max = max(link_down_graph_to_system_list)
1286 link_down_avg = sum(link_down_graph_to_system_list) / \
1287 len(link_down_graph_to_system_list)
andrewonlababb11c32014-11-04 15:03:24 -05001288 link_up_min = min(link_up_graph_to_system_list)
1289 link_up_max = max(link_up_graph_to_system_list)
1290 link_up_avg = sum(link_up_graph_to_system_list) / \
1291 len(link_up_graph_to_system_list)
andrewonlab4f50ec92014-11-11 14:24:45 -05001292 link_down_std_dev = str(numpy.std(link_down_graph_to_system_list))
1293 link_up_std_dev = str(numpy.std(link_up_graph_to_system_list))
andrewonlababb11c32014-11-04 15:03:24 -05001294
andrewonlab4f50ec92014-11-11 14:24:45 -05001295 main.log.report("Link down latency " +
1296 "Avg: "+str(link_down_avg)+" ms "+
1297 "Std Deviation: "+link_down_std_dev)
1298 main.log.report("Link up latency "+
1299 "Avg: "+str(link_up_avg)+" ms "+
1300 "Std Deviation: "+link_up_std_dev)
andrewonlab4e124482014-11-04 13:37:25 -05001301
andrewonlab8790abb2014-11-06 13:51:54 -05001302 utilities.assert_equals(expect=main.TRUE, actual=assertion,
1303 onpass="Link discovery latency calculation successful",
1304 onfail="Link discovery latency case failed")
1305
andrewonlabb54b85b2014-10-28 18:43:57 -04001306 def CASE5(self, main):
1307 '''
1308 100 Switch discovery latency
1309
1310 Important:
andrewonlab16ce4852014-10-30 13:41:09 -04001311 This test case can be potentially dangerous if
1312 your machine has previously set iptables rules.
1313 One of the steps of the test case will flush
1314 all existing iptables rules.
andrewonlab8790abb2014-11-06 13:51:54 -05001315 Note:
1316 You can specify the number of switches in the
1317 params file to adjust the switch discovery size
1318 (and specify the corresponding topology in Mininet1
1319 .topo file)
andrewonlabb54b85b2014-10-28 18:43:57 -04001320 '''
1321 import time
1322 import subprocess
1323 import os
1324 import requests
1325 import json
1326
1327 ONOS1_ip = main.params['CTRL']['ip1']
1328 ONOS2_ip = main.params['CTRL']['ip2']
1329 ONOS3_ip = main.params['CTRL']['ip3']
1330 MN1_ip = main.params['MN']['ip1']
1331 ONOS_user = main.params['CTRL']['user']
1332
1333 default_sw_port = main.params['CTRL']['port1']
1334
1335 #Number of iterations of case
1336 num_iter = main.params['TEST']['numIter']
andrewonlab16ce4852014-10-30 13:41:09 -04001337 num_sw = main.params['TEST']['numSwitch']
1338
andrewonlabb54b85b2014-10-28 18:43:57 -04001339 #Timestamp 'keys' for json metrics output.
1340 #These are subject to change, hence moved into params
1341 deviceTimestamp = main.params['JSON']['deviceTimestamp']
andrewonlab16ce4852014-10-30 13:41:09 -04001342 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -05001343
1344 debug_mode = main.params['TEST']['debugMode']
1345
andrewonlabb1998c52014-11-10 13:31:43 -05001346 local_time = time.strftime('%X')
1347 local_time = local_time.replace("/","")
1348 local_time = local_time.replace(" ","_")
1349 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -05001350 if debug_mode == 'on':
1351 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -05001352 "/tmp/100_sw_lat_pcap_"+local_time)
andrewonlabe5bcef92014-11-06 17:53:20 -05001353
1354 #Threshold for this test case
1355 sw_disc_threshold_str = main.params['TEST']['swDisc100Threshold']
1356 sw_disc_threshold_obj = sw_disc_threshold_str.split(",")
1357 sw_disc_threshold_min = int(sw_disc_threshold_obj[0])
1358 sw_disc_threshold_max = int(sw_disc_threshold_obj[1])
1359
andrewonlab53b641c2014-10-31 19:44:44 -04001360 tshark_ofp_output = "/tmp/tshark_ofp_"+num_sw+"sw.txt"
1361 tshark_tcp_output = "/tmp/tshark_tcp_"+num_sw+"sw.txt"
1362
1363 tshark_ofp_result_list = []
1364 tshark_tcp_result_list = []
andrewonlabb54b85b2014-10-28 18:43:57 -04001365
andrewonlabe5bcef92014-11-06 17:53:20 -05001366 sw_discovery_lat_list = []
1367
andrewonlab16ce4852014-10-30 13:41:09 -04001368 main.case(num_sw+" Switch discovery latency")
andrewonlabb54b85b2014-10-28 18:43:57 -04001369 main.step("Assigning all switches to ONOS1")
andrewonlab16ce4852014-10-30 13:41:09 -04001370 for i in range(1, int(num_sw)+1):
andrewonlabb54b85b2014-10-28 18:43:57 -04001371 main.Mininet1.assign_sw_controller(
1372 sw=str(i),
1373 ip1=ONOS1_ip,
1374 port1=default_sw_port)
andrewonlab16ce4852014-10-30 13:41:09 -04001375
andrewonlabb54b85b2014-10-28 18:43:57 -04001376 #Ensure that nodes are configured with ptpd
andrewonlab16ce4852014-10-30 13:41:09 -04001377 #Just a warning message
1378 main.log.info("Please check ptpd configuration to ensure"+\
1379 " All nodes' system times are in sync")
1380 time.sleep(5)
andrewonlabb54b85b2014-10-28 18:43:57 -04001381
1382 for i in range(0, int(num_iter)):
andrewonlab8d29f122014-10-22 17:15:04 -04001383
andrewonlabb54b85b2014-10-28 18:43:57 -04001384 main.step("Set iptables rule to block incoming sw connections")
1385 #Set iptables rule to block incoming switch connections
andrewonlab53b641c2014-10-31 19:44:44 -04001386 #The rule description is as follows:
1387 # Append to INPUT rule,
1388 # behavior DROP that matches following:
1389 # * packet type: tcp
1390 # * source IP: MN1_ip
1391 # * destination PORT: 6633
andrewonlabb54b85b2014-10-28 18:43:57 -04001392 main.ONOS1.handle.sendline(
andrewonlab16ce4852014-10-30 13:41:09 -04001393 "sudo iptables -A INPUT -p tcp -s "+MN1_ip+
andrewonlabb54b85b2014-10-28 18:43:57 -04001394 " --dport "+default_sw_port+" -j DROP")
1395 main.ONOS1.handle.expect("\$")
andrewonlab53b641c2014-10-31 19:44:44 -04001396 # Append to OUTPUT rule,
1397 # behavior DROP that matches following:
1398 # * packet type: tcp
1399 # * source IP: MN1_ip
1400 # * destination PORT: 6633
1401 main.ONOS1.handle.sendline(
1402 "sudo iptables -A OUTPUT -p tcp -s "+MN1_ip+
1403 " --dport "+default_sw_port+" -j DROP")
1404 main.ONOS1.handle.expect("\$")
andrewonlabb54b85b2014-10-28 18:43:57 -04001405 #Give time to allow rule to take effect
andrewonlab8790abb2014-11-06 13:51:54 -05001406 #NOTE: Sleep period may need to be configured
1407 # based on the number of switches in the topology
andrewonlab16ce4852014-10-30 13:41:09 -04001408 main.log.info("Please wait for switch connection to "+
1409 "time out")
1410 time.sleep(60)
1411
1412 #Gather vendor OFP with tshark
1413 main.ONOS1.tshark_grep("OFP 86 Vendor",
1414 tshark_ofp_output)
andrewonlab53b641c2014-10-31 19:44:44 -04001415 main.ONOS1.tshark_grep("TCP 74 ",
1416 tshark_tcp_output)
andrewonlabb54b85b2014-10-28 18:43:57 -04001417
andrewonlab16ce4852014-10-30 13:41:09 -04001418 #NOTE: Remove all iptables rule quickly (flush)
andrewonlabb54b85b2014-10-28 18:43:57 -04001419 # Before removal, obtain TestON timestamp at which
andrewonlab16ce4852014-10-30 13:41:09 -04001420 # removal took place
1421 # (ensuring nodes are configured via ptp)
andrewonlabb54b85b2014-10-28 18:43:57 -04001422 # sudo iptables -F
andrewonlab16ce4852014-10-30 13:41:09 -04001423
1424 t0_system = time.time() * 1000
1425 main.ONOS1.handle.sendline(
1426 "sudo iptables -F")
andrewonlabb54b85b2014-10-28 18:43:57 -04001427
andrewonlab16ce4852014-10-30 13:41:09 -04001428 #Counter to track loop count
1429 counter_loop = 0
1430 counter_avail1 = 0
1431 counter_avail2 = 0
1432 counter_avail3 = 0
1433 onos1_dev = False
1434 onos2_dev = False
1435 onos3_dev = False
1436 while counter_loop < 60:
1437 #Continue to check devices for all device
1438 #availability. When all devices in all 3
1439 #ONOS instances indicate that devices are available
1440 #obtain graph event timestamp for t1.
1441 device_str_obj1 = main.ONOS1cli.devices()
1442 device_str_obj2 = main.ONOS2cli.devices()
1443 device_str_obj3 = main.ONOS3cli.devices()
1444
1445 device_json1 = json.loads(device_str_obj1)
1446 device_json2 = json.loads(device_str_obj2)
1447 device_json3 = json.loads(device_str_obj3)
1448
1449 for device1 in device_json1:
1450 if device1['available'] == True:
1451 counter_avail1 += 1
1452 if counter_avail1 == int(num_sw):
1453 onos1_dev = True
1454 main.log.info("All devices have been "+
1455 "discovered on ONOS1")
1456 else:
1457 counter_avail1 = 0
1458 for device2 in device_json2:
1459 if device2['available'] == True:
1460 counter_avail2 += 1
1461 if counter_avail2 == int(num_sw):
1462 onos2_dev = True
1463 main.log.info("All devices have been "+
1464 "discovered on ONOS2")
1465 else:
1466 counter_avail2 = 0
1467 for device3 in device_json3:
1468 if device3['available'] == True:
1469 counter_avail3 += 1
1470 if counter_avail3 == int(num_sw):
1471 onos3_dev = True
1472 main.log.info("All devices have been "+
1473 "discovered on ONOS3")
1474 else:
1475 counter_avail3 = 0
1476
1477 if onos1_dev and onos2_dev and onos3_dev:
1478 main.log.info("All devices have been discovered "+
1479 "on all ONOS instances")
1480 json_str_topology_metrics_1 =\
1481 main.ONOS1cli.topology_events_metrics()
1482 json_str_topology_metrics_2 =\
1483 main.ONOS2cli.topology_events_metrics()
1484 json_str_topology_metrics_3 =\
1485 main.ONOS3cli.topology_events_metrics()
andrewonlab53b641c2014-10-31 19:44:44 -04001486
1487 #Exit while loop if all devices discovered
andrewonlab16ce4852014-10-30 13:41:09 -04001488 break
1489
1490 counter_loop += 1
1491 #Give some time in between CLI calls
1492 #(will not affect measurement)
1493 time.sleep(3)
1494
1495 main.ONOS1.tshark_stop()
1496
1497 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1498 tshark_ofp_output+" /tmp/")
andrewonlab53b641c2014-10-31 19:44:44 -04001499 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1500 tshark_tcp_output+" /tmp/")
andrewonlab16ce4852014-10-30 13:41:09 -04001501
andrewonlab16ce4852014-10-30 13:41:09 -04001502 #TODO: Automate OFP output analysis
andrewonlab58f7d702014-11-07 13:21:19 -05001503 #Debug mode - print out packets captured at runtime
1504 if debug_mode == 'on':
1505 ofp_file = open(tshark_ofp_output, 'r')
1506 main.log.info("Tshark OFP Vendor output: ")
1507 for line in ofp_file:
1508 tshark_ofp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001509 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001510 ofp_file.close()
andrewonlab16ce4852014-10-30 13:41:09 -04001511
andrewonlab58f7d702014-11-07 13:21:19 -05001512 tcp_file = open(tshark_tcp_output, 'r')
1513 main.log.info("Tshark TCP 74 output: ")
1514 for line in tcp_file:
1515 tshark_tcp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001516 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001517 tcp_file.close()
andrewonlab53b641c2014-10-31 19:44:44 -04001518
andrewonlab16ce4852014-10-30 13:41:09 -04001519 json_obj_1 = json.loads(json_str_topology_metrics_1)
1520 json_obj_2 = json.loads(json_str_topology_metrics_2)
1521 json_obj_3 = json.loads(json_str_topology_metrics_3)
1522
1523 graph_timestamp_1 = \
1524 json_obj_1[graphTimestamp]['value']
1525 graph_timestamp_2 = \
1526 json_obj_2[graphTimestamp]['value']
1527 graph_timestamp_3 = \
1528 json_obj_3[graphTimestamp]['value']
1529
andrewonlabe5bcef92014-11-06 17:53:20 -05001530 graph_lat_1 = int(graph_timestamp_1) - int(t0_system)
1531 graph_lat_2 = int(graph_timestamp_2) - int(t0_system)
1532 graph_lat_3 = int(graph_timestamp_3) - int(t0_system)
andrewonlab16ce4852014-10-30 13:41:09 -04001533
andrewonlabe5bcef92014-11-06 17:53:20 -05001534 avg_graph_lat = \
1535 (int(graph_lat_1) +\
1536 int(graph_lat_2) +\
1537 int(graph_lat_3)) / 3
1538
1539 if avg_graph_lat > sw_disc_threshold_min \
1540 and avg_graph_lat < sw_disc_threshold_max:
1541 sw_discovery_lat_list.append(
1542 avg_graph_lat)
1543 else:
1544 main.log.info("100 Switch discovery latency "+
1545 "exceeded the threshold.")
1546
1547 #END ITERATION FOR LOOP
andrewonlab16ce4852014-10-30 13:41:09 -04001548
andrewonlabe5bcef92014-11-06 17:53:20 -05001549 sw_lat_min = min(sw_discovery_lat_list)
1550 sw_lat_max = max(sw_discovery_lat_list)
1551 sw_lat_avg = sum(sw_discovery_lat_list) /\
1552 len(sw_discovery_lat_list)
andrewonlab16ce4852014-10-30 13:41:09 -04001553
andrewonlabf9828f02014-11-10 14:50:27 -05001554 main.log.report("100 Switch discovery lat "+\
1555 "Min: "+str(sw_lat_min)+" ms"+\
1556 "Max: "+str(sw_lat_max)+" ms"+\
1557 "Avg: "+str(sw_lat_avg)+" ms")
andrewonlab16ce4852014-10-30 13:41:09 -04001558
andrewonlabb54b85b2014-10-28 18:43:57 -04001559