blob: 147ebef4ef3186b029d44a5df55009bed15e4d70 [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))
andrewonlab69864162014-11-11 16:28:48 -0500446 latency_end_to_end_std_dev = \
447 str(round(numpy.std(latency_end_to_end_list),1))
448
andrewonlabc15c9582014-10-24 16:35:52 -0400449 latency_ofp_to_graph_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400450 int(max(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400451 latency_ofp_to_graph_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400452 int(min(latency_ofp_to_graph_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400453 latency_ofp_to_graph_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400454 (int(sum(latency_ofp_to_graph_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400455 len(latency_ofp_to_graph_list))
andrewonlab69864162014-11-11 16:28:48 -0500456 latency_ofp_to_graph_std_dev = \
457 str(round(numpy.std(latency_ofp_to_graph_list),1))
andrewonlabc15c9582014-10-24 16:35:52 -0400458
459 latency_ofp_to_device_max = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400460 int(max(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400461 latency_ofp_to_device_min = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400462 int(min(latency_ofp_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400463 latency_ofp_to_device_avg = \
andrewonlabee4efeb2014-10-24 16:44:51 -0400464 (int(sum(latency_ofp_to_device_list)) / \
andrewonlabc15c9582014-10-24 16:35:52 -0400465 len(latency_ofp_to_device_list))
andrewonlab69864162014-11-11 16:28:48 -0500466 latency_ofp_to_device_std_dev = \
467 str(round(numpy.std(latency_ofp_to_device_list),1))
andrewonlabc15c9582014-10-24 16:35:52 -0400468
469 latency_t0_to_device_max = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500470 int(max(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400471 latency_t0_to_device_min = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500472 int(min(latency_t0_to_device_list))
andrewonlabc15c9582014-10-24 16:35:52 -0400473 latency_t0_to_device_avg = \
andrewonlab4b5c8b92014-11-10 16:04:33 -0500474 (int(sum(latency_t0_to_device_list)) / \
andrewonlab69864162014-11-11 16:28:48 -0500475 len(latency_t0_to_device_list))
476 latency_ofp_to_device_std_dev = \
477 str(round(numpy.std(latency_t0_to_device_list),1))
andrewonlabc15c9582014-10-24 16:35:52 -0400478
andrewonlab65d73892014-11-10 17:36:00 -0500479 latency_tcp_to_ofp_max = \
480 int(max(latency_tcp_to_ofp_list))
481 latency_tcp_to_ofp_min = \
482 int(min(latency_tcp_to_ofp_list))
483 latency_tcp_to_ofp_avg = \
484 (int(sum(latency_tcp_to_ofp_list)) / \
485 len(latency_tcp_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500486 latency_tcp_to_ofp_std_dev = \
487 str(round(numpy.std(latency_tcp_to_ofp_list),1))
andrewonlab65d73892014-11-10 17:36:00 -0500488
andrewonlabf9828f02014-11-10 14:50:27 -0500489 main.log.report("Switch add - End-to-end latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500490 "Avg: "+str(latency_end_to_end_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500491 "Std Deviation: "+latency_end_to_end_std_dev+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -0500492 main.log.report("Switch add - OFP-to-Graph latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500493 "Avg: "+str(latency_ofp_to_graph_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500494 "Std Deviation: "+latency_ofp_to_graph_std_dev+" ms")
andrewonlab65d73892014-11-10 17:36:00 -0500495 main.log.report("Switch add - TCP-to-OFP latency: "+\
andrewonlab4f50ec92014-11-11 14:24:45 -0500496 "Avg: "+str(latency_tcp_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500497 "Std Deviation: "+latency_tcp_to_ofp_std_dev+" ms")
andrewonlab226024e2014-10-24 16:01:32 -0400498
andrewonlabb1998c52014-11-10 13:31:43 -0500499 if debug_mode == 'on':
500 main.ONOS1.cp_logs_to_dir("/opt/onos/log/karaf.log",
501 "/tmp/", copy_file_name="sw_lat_karaf")
502
andrewonlab8d29f122014-10-22 17:15:04 -0400503 utilities.assert_equals(expect=main.TRUE, actual=assertion,
504 onpass="Switch latency test successful",
505 onfail="Switch latency test failed")
andrewonlabba44bcf2014-10-16 16:54:41 -0400506
andrewonlab8d29f122014-10-22 17:15:04 -0400507 def CASE3(self, main):
508 '''
509 Bring port up / down and measure latency.
510 Port enable / disable is simulated by ifconfig up / down
andrewonlab393531a2014-10-27 18:36:26 -0400511
512 In ONOS-next, we must ensure that the port we are
513 manipulating is connected to another switch with a valid
514 connection. Otherwise, graph view will not be updated.
andrewonlab8d29f122014-10-22 17:15:04 -0400515 '''
516 import time
517 import subprocess
518 import os
519 import requests
520 import json
andrewonlab4f50ec92014-11-11 14:24:45 -0500521 import numpy
andrewonlab2a6c9342014-10-16 13:40:15 -0400522
andrewonlab8d29f122014-10-22 17:15:04 -0400523 ONOS1_ip = main.params['CTRL']['ip1']
andrewonlab393531a2014-10-27 18:36:26 -0400524 ONOS2_ip = main.params['CTRL']['ip2']
525 ONOS3_ip = main.params['CTRL']['ip3']
andrewonlab8d29f122014-10-22 17:15:04 -0400526 ONOS_user = main.params['CTRL']['user']
andrewonlab8d29f122014-10-22 17:15:04 -0400527
andrewonlab393531a2014-10-27 18:36:26 -0400528 default_sw_port = main.params['CTRL']['port1']
andrewonlab8790abb2014-11-06 13:51:54 -0500529
530 assertion = main.TRUE
andrewonlab393531a2014-10-27 18:36:26 -0400531 #Number of iterations of case
532 num_iter = main.params['TEST']['numIter']
533
534 #Timestamp 'keys' for json metrics output.
535 #These are subject to change, hence moved into params
536 deviceTimestamp = main.params['JSON']['deviceTimestamp']
537 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500538
539 debug_mode = main.params['TEST']['debugMode']
540
541 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500542 local_time = local_time.replace("/","")
543 local_time = local_time.replace(" ","_")
544 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500545 if debug_mode == 'on':
546 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500547 "/tmp/port_lat_pcap_"+local_time)
andrewonlab393531a2014-10-27 18:36:26 -0400548
andrewonlabe5bcef92014-11-06 17:53:20 -0500549 #Threshold for this test case
550 up_threshold_str = main.params['TEST']['portUpThreshold']
551 down_threshold_str = main.params['TEST']['portDownThreshold']
andrewonlabb1998c52014-11-10 13:31:43 -0500552
andrewonlabe5bcef92014-11-06 17:53:20 -0500553 up_threshold_obj = up_threshold_str.split(",")
554 down_threshold_obj = down_threshold_str.split(",")
555
556 up_threshold_min = int(up_threshold_obj[0])
557 up_threshold_max = int(up_threshold_obj[1])
558
559 down_threshold_min = int(down_threshold_obj[0])
560 down_threshold_max = int(down_threshold_obj[1])
561
andrewonlab393531a2014-10-27 18:36:26 -0400562 #NOTE: Some hardcoded variables you may need to configure
563 # besides the params
564
andrewonlab8d29f122014-10-22 17:15:04 -0400565 tshark_port_status = "OFP 130 Port Status"
566
567 tshark_port_up = "/tmp/tshark_port_up.txt"
568 tshark_port_down = "/tmp/tshark_port_down.txt"
andrewonlab393531a2014-10-27 18:36:26 -0400569 interface_config = "s1-eth1"
andrewonlab8d29f122014-10-22 17:15:04 -0400570
571 main.log.report("Port enable / disable latency")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500572 main.log.report("Simulated by ifconfig up / down")
573 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab8d29f122014-10-22 17:15:04 -0400574
andrewonlab393531a2014-10-27 18:36:26 -0400575 main.step("Assign switches s1 and s2 to controller 1")
andrewonlab8d29f122014-10-22 17:15:04 -0400576 main.Mininet1.assign_sw_controller(sw="1",ip1=ONOS1_ip,
577 port1=default_sw_port)
andrewonlab393531a2014-10-27 18:36:26 -0400578 main.Mininet1.assign_sw_controller(sw="2",ip1=ONOS1_ip,
579 port1=default_sw_port)
andrewonlab8d29f122014-10-22 17:15:04 -0400580
andrewonlab8790abb2014-11-06 13:51:54 -0500581 #Give enough time for metrics to propagate the
582 #assign controller event. Otherwise, these events may
583 #carry over to our measurements
andrewonlabb1998c52014-11-10 13:31:43 -0500584 time.sleep(15)
andrewonlab8d29f122014-10-22 17:15:04 -0400585
andrewonlab393531a2014-10-27 18:36:26 -0400586 port_up_device_to_ofp_list = []
587 port_up_graph_to_ofp_list = []
588 port_down_device_to_ofp_list = []
589 port_down_graph_to_ofp_list = []
590
andrewonlab8d29f122014-10-22 17:15:04 -0400591 for i in range(0, int(num_iter)):
592 main.step("Starting wireshark capture for port status down")
593 main.ONOS1.tshark_grep(tshark_port_status,
594 tshark_port_down)
595
andrewonlabb1998c52014-11-10 13:31:43 -0500596 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400597
andrewonlab393531a2014-10-27 18:36:26 -0400598 #Disable interface that is connected to switch 2
599 main.step("Disable port: "+interface_config)
andrewonlabb1998c52014-11-10 13:31:43 -0500600 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400601 interface_config+" down")
andrewonlabb1998c52014-11-10 13:31:43 -0500602 main.Mininet1.handle.expect("mininet>")
andrewonlab8d29f122014-10-22 17:15:04 -0400603
andrewonlabb1998c52014-11-10 13:31:43 -0500604 time.sleep(3)
andrewonlab8d29f122014-10-22 17:15:04 -0400605 main.ONOS1.tshark_stop()
andrewonlabb1998c52014-11-10 13:31:43 -0500606
607 main.step("Obtain t1 by metrics call")
608 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
609 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
610 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
611
612 json_obj_1 = json.loads(json_str_up_1)
613 json_obj_2 = json.loads(json_str_up_2)
614 json_obj_3 = json.loads(json_str_up_3)
andrewonlab8d29f122014-10-22 17:15:04 -0400615
616 #Copy tshark output file from ONOS to TestON instance
617 #/tmp directory
618 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
619 tshark_port_down+" /tmp/")
620
621 f_port_down = open(tshark_port_down, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400622 #Get first line of port down event from tshark
andrewonlab8d29f122014-10-22 17:15:04 -0400623 f_line = f_port_down.readline()
624 obj_down = f_line.split(" ")
625 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500626 timestamp_begin_pt_down = int(float(obj_down[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400627 main.log.info("Port down begin timestamp: "+
628 str(timestamp_begin_pt_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400629 else:
630 main.log.info("Tshark output file returned unexpected"+
andrewonlab393531a2014-10-27 18:36:26 -0400631 " results: "+str(obj_down))
andrewonlab8d29f122014-10-22 17:15:04 -0400632 timestamp_begin_pt_down = 0
andrewonlab393531a2014-10-27 18:36:26 -0400633
634 f_port_down.close()
andrewonlab8d29f122014-10-22 17:15:04 -0400635
andrewonlab4e124482014-11-04 13:37:25 -0500636 main.log.info("TEST tshark obj: "+str(obj_down))
637
andrewonlabb1998c52014-11-10 13:31:43 -0500638 time.sleep(3)
andrewonlab393531a2014-10-27 18:36:26 -0400639
640 #Obtain graph timestamp. This timestsamp captures
641 #the epoch time at which the topology graph was updated.
642 graph_timestamp_1 = \
643 json_obj_1[graphTimestamp]['value']
644 graph_timestamp_2 = \
645 json_obj_2[graphTimestamp]['value']
646 graph_timestamp_3 = \
647 json_obj_3[graphTimestamp]['value']
648
andrewonlabb1998c52014-11-10 13:31:43 -0500649 main.log.info("TEST graph timestamp ONOS1: "+
650 str(graph_timestamp_1))
651
andrewonlab393531a2014-10-27 18:36:26 -0400652 #Obtain device timestamp. This timestamp captures
653 #the epoch time at which the device event happened
654 device_timestamp_1 = \
655 json_obj_1[deviceTimestamp]['value']
656 device_timestamp_2 = \
657 json_obj_2[deviceTimestamp]['value']
658 device_timestamp_3 = \
659 json_obj_3[deviceTimestamp]['value']
andrewonlab393531a2014-10-27 18:36:26 -0400660
661 #Get delta between graph event and OFP
662 pt_down_graph_to_ofp_1 = int(graph_timestamp_1) -\
663 int(timestamp_begin_pt_down)
664 pt_down_graph_to_ofp_2 = int(graph_timestamp_2) -\
665 int(timestamp_begin_pt_down)
666 pt_down_graph_to_ofp_3 = int(graph_timestamp_3) -\
667 int(timestamp_begin_pt_down)
668
669 #Get delta between device event and OFP
670 pt_down_device_to_ofp_1 = int(device_timestamp_1) -\
671 int(timestamp_begin_pt_down)
672 pt_down_device_to_ofp_2 = int(device_timestamp_2) -\
673 int(timestamp_begin_pt_down)
674 pt_down_device_to_ofp_3 = int(device_timestamp_3) -\
675 int(timestamp_begin_pt_down)
676
677 #Caluclate average across clusters
678 pt_down_graph_to_ofp_avg =\
679 (int(pt_down_graph_to_ofp_1) +
680 int(pt_down_graph_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500681 int(pt_down_graph_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400682 pt_down_device_to_ofp_avg = \
683 (int(pt_down_device_to_ofp_1) +
684 int(pt_down_device_to_ofp_2) +
andrewonlabf9828f02014-11-10 14:50:27 -0500685 int(pt_down_device_to_ofp_3)) / 3
andrewonlab393531a2014-10-27 18:36:26 -0400686
andrewonlabb1998c52014-11-10 13:31:43 -0500687 if pt_down_graph_to_ofp_avg > down_threshold_min and \
688 pt_down_graph_to_ofp_avg < down_threshold_max:
andrewonlab393531a2014-10-27 18:36:26 -0400689 port_down_graph_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500690 pt_down_graph_to_ofp_avg)
691 main.log.info("Port down: graph to ofp avg: "+
692 str(pt_down_graph_to_ofp_avg) + " ms")
andrewonlab393531a2014-10-27 18:36:26 -0400693 else:
694 main.log.info("Average port down graph-to-ofp result" +
695 " exceeded the threshold: "+
696 str(pt_down_graph_to_ofp_avg))
697
andrewonlab3622beb2014-10-28 16:07:56 -0400698 if pt_down_device_to_ofp_avg > 0 and \
699 pt_down_device_to_ofp_avg < 1000:
700 port_down_device_to_ofp_list.append(
andrewonlababb11c32014-11-04 15:03:24 -0500701 pt_down_device_to_ofp_avg)
702 main.log.info("Port down: device to ofp avg: "+
703 str(pt_down_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400704 else:
705 main.log.info("Average port down device-to-ofp result" +
706 " exceeded the threshold: "+
707 str(pt_down_device_to_ofp_avg))
708
andrewonlab8d29f122014-10-22 17:15:04 -0400709 #Port up events
710 main.step("Enable port and obtain timestamp")
711 main.step("Starting wireshark capture for port status up")
andrewonlabb1998c52014-11-10 13:31:43 -0500712 main.ONOS1.tshark_grep(tshark_port_status, tshark_port_up)
andrewonlab8790abb2014-11-06 13:51:54 -0500713 time.sleep(5)
andrewonlab8d29f122014-10-22 17:15:04 -0400714
andrewonlabb1998c52014-11-10 13:31:43 -0500715 main.Mininet1.handle.sendline("sh ifconfig "+
andrewonlab393531a2014-10-27 18:36:26 -0400716 interface_config+" up")
andrewonlabb1998c52014-11-10 13:31:43 -0500717 main.Mininet1.handle.expect("mininet>")
andrewonlab8790abb2014-11-06 13:51:54 -0500718
andrewonlabb1998c52014-11-10 13:31:43 -0500719 #Allow time for tshark to capture event
720 time.sleep(3)
andrewonlab8790abb2014-11-06 13:51:54 -0500721 main.ONOS1.tshark_stop()
andrewonlab8d29f122014-10-22 17:15:04 -0400722
andrewonlabb1998c52014-11-10 13:31:43 -0500723 #Obtain metrics shortly afterwards
724 #This timestsamp captures
725 #the epoch time at which the topology graph was updated.
726 main.step("Obtain t1 by REST call")
727 json_str_up_1 = main.ONOS1cli.topology_events_metrics()
728 json_str_up_2 = main.ONOS2cli.topology_events_metrics()
729 json_str_up_3 = main.ONOS3cli.topology_events_metrics()
730
731 json_obj_1 = json.loads(json_str_up_1)
732 json_obj_2 = json.loads(json_str_up_2)
733 json_obj_3 = json.loads(json_str_up_3)
734
andrewonlab8d29f122014-10-22 17:15:04 -0400735 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
736 tshark_port_up+" /tmp/")
737
738 f_port_up = open(tshark_port_up, 'r')
andrewonlab393531a2014-10-27 18:36:26 -0400739 f_line = f_port_up.readline()
andrewonlab8d29f122014-10-22 17:15:04 -0400740 obj_up = f_line.split(" ")
741 if len(f_line) > 0:
andrewonlabb1998c52014-11-10 13:31:43 -0500742 timestamp_begin_pt_up = int(float(obj_up[1])*1000)
andrewonlab393531a2014-10-27 18:36:26 -0400743 main.log.info("Port up begin timestamp: "+
744 str(timestamp_begin_pt_up))
andrewonlab8d29f122014-10-22 17:15:04 -0400745 else:
746 main.log.info("Tshark output file returned unexpected"+
747 " results.")
748 timestamp_begin_pt_up = 0
749
andrewonlab393531a2014-10-27 18:36:26 -0400750 f_port_up.close()
751
andrewonlab393531a2014-10-27 18:36:26 -0400752 graph_timestamp_1 = \
753 json_obj_1[graphTimestamp]['value']
754 graph_timestamp_2 = \
755 json_obj_2[graphTimestamp]['value']
756 graph_timestamp_3 = \
757 json_obj_3[graphTimestamp]['value']
758
759 #Obtain device timestamp. This timestamp captures
760 #the epoch time at which the device event happened
761 device_timestamp_1 = \
762 json_obj_1[deviceTimestamp]['value']
763 device_timestamp_2 = \
764 json_obj_2[deviceTimestamp]['value']
765 device_timestamp_3 = \
766 json_obj_3[deviceTimestamp]['value']
767
768 #Get delta between graph event and OFP
769 pt_up_graph_to_ofp_1 = int(graph_timestamp_1) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400770 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400771 pt_up_graph_to_ofp_2 = int(graph_timestamp_2) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400772 int(timestamp_begin_pt_up)
andrewonlab393531a2014-10-27 18:36:26 -0400773 pt_up_graph_to_ofp_3 = int(graph_timestamp_3) -\
774 int(timestamp_begin_pt_up)
775
776 #Get delta between device event and OFP
777 pt_up_device_to_ofp_1 = int(device_timestamp_1) -\
778 int(timestamp_begin_pt_up)
779 pt_up_device_to_ofp_2 = int(device_timestamp_2) -\
780 int(timestamp_begin_pt_up)
781 pt_up_device_to_ofp_3 = int(device_timestamp_3) -\
andrewonlab8d29f122014-10-22 17:15:04 -0400782 int(timestamp_begin_pt_up)
andrewonlab3622beb2014-10-28 16:07:56 -0400783
andrewonlabb1998c52014-11-10 13:31:43 -0500784 main.log.info("ONOS1 delta G2O: "+str(pt_up_graph_to_ofp_1))
785 main.log.info("ONOS2 delta G2O: "+str(pt_up_graph_to_ofp_2))
786 main.log.info("ONOS3 delta G2O: "+str(pt_up_graph_to_ofp_3))
787
788 main.log.info("ONOS1 delta D2O: "+str(pt_up_device_to_ofp_1))
789 main.log.info("ONOS2 delta D2O: "+str(pt_up_device_to_ofp_2))
790 main.log.info("ONOS3 delta D2O: "+str(pt_up_device_to_ofp_3))
791
andrewonlab3622beb2014-10-28 16:07:56 -0400792 pt_up_graph_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500793 (int(pt_up_graph_to_ofp_1) +
794 int(pt_up_graph_to_ofp_2) +
795 int(pt_up_graph_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400796
797 pt_up_device_to_ofp_avg = \
andrewonlabf9828f02014-11-10 14:50:27 -0500798 (int(pt_up_device_to_ofp_1) +
799 int(pt_up_device_to_ofp_2) +
800 int(pt_up_device_to_ofp_3)) / 3
andrewonlab3622beb2014-10-28 16:07:56 -0400801
andrewonlabe5bcef92014-11-06 17:53:20 -0500802 if pt_up_graph_to_ofp_avg > up_threshold_min and \
803 pt_up_graph_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400804 port_up_graph_to_ofp_list.append(
805 pt_up_graph_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500806 main.log.info("Port down: graph to ofp avg: "+
807 str(pt_up_graph_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400808 else:
809 main.log.info("Average port up graph-to-ofp result"+
810 " exceeded the threshold: "+
811 str(pt_up_graph_to_ofp_avg))
812
andrewonlabe5bcef92014-11-06 17:53:20 -0500813 if pt_up_device_to_ofp_avg > up_threshold_min and \
814 pt_up_device_to_ofp_avg < up_threshold_max:
andrewonlab3622beb2014-10-28 16:07:56 -0400815 port_up_device_to_ofp_list.append(
816 pt_up_device_to_ofp_avg)
andrewonlababb11c32014-11-04 15:03:24 -0500817 main.log.info("Port up: device to ofp avg: "+
818 str(pt_up_device_to_ofp_avg) + " ms")
andrewonlab3622beb2014-10-28 16:07:56 -0400819 else:
andrewonlababb11c32014-11-04 15:03:24 -0500820 main.log.info("Average port up device-to-ofp result"+
andrewonlab3622beb2014-10-28 16:07:56 -0400821 " exceeded the threshold: "+
822 str(pt_up_device_to_ofp_avg))
andrewonlab8d29f122014-10-22 17:15:04 -0400823
andrewonlab3622beb2014-10-28 16:07:56 -0400824 #END ITERATION FOR LOOP
andrewonlab8790abb2014-11-06 13:51:54 -0500825
826 #Check all list for latency existence and set assertion
827 if (port_down_graph_to_ofp_list and port_down_device_to_ofp_list\
828 and port_up_graph_to_ofp_list and port_up_device_to_ofp_list):
829 assertion = main.TRUE
830
andrewonlababb11c32014-11-04 15:03:24 -0500831 #Calculate and report latency measurements
andrewonlab3622beb2014-10-28 16:07:56 -0400832 port_down_graph_to_ofp_min = min(port_down_graph_to_ofp_list)
833 port_down_graph_to_ofp_max = max(port_down_graph_to_ofp_list)
834 port_down_graph_to_ofp_avg = \
835 (sum(port_down_graph_to_ofp_list) /
836 len(port_down_graph_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500837 port_down_graph_to_ofp_std_dev = \
838 str(round(numpy.std(port_down_graph_to_ofp_list),1))
andrewonlab3622beb2014-10-28 16:07:56 -0400839
andrewonlab4f50ec92014-11-11 14:24:45 -0500840 main.log.report("Port down graph-to-ofp "+
841 "Avg: "+str(port_down_graph_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500842 "Std Deviation: "+port_down_graph_to_ofp_std_dev+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500843
844 port_down_device_to_ofp_min = min(port_down_device_to_ofp_list)
845 port_down_device_to_ofp_max = max(port_down_device_to_ofp_list)
846 port_down_device_to_ofp_avg = \
847 (sum(port_down_device_to_ofp_list) /\
848 len(port_down_device_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500849 port_down_device_to_ofp_std_dev = \
850 str(round(numpy.std(port_down_device_to_ofp_list),1))
andrewonlababb11c32014-11-04 15:03:24 -0500851
andrewonlab4f50ec92014-11-11 14:24:45 -0500852 main.log.report("Port down device-to-ofp "+
853 "Avg: "+str(port_down_device_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500854 "Std Deviation: "+port_down_device_to_ofp_std_dev+" ms")
andrewonlababb11c32014-11-04 15:03:24 -0500855
856 port_up_graph_to_ofp_min = min(port_up_graph_to_ofp_list)
857 port_up_graph_to_ofp_max = max(port_up_graph_to_ofp_list)
858 port_up_graph_to_ofp_avg = \
859 (sum(port_up_graph_to_ofp_list) /\
860 len(port_up_graph_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500861 port_up_graph_to_ofp_std_dev = \
862 str(round(numpy.std(port_up_graph_to_ofp_list),1))
andrewonlab8790abb2014-11-06 13:51:54 -0500863
andrewonlab4f50ec92014-11-11 14:24:45 -0500864 main.log.report("Port up graph-to-ofp "+
865 "Avg: "+str(port_up_graph_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500866 "Std Deviation: "+port_up_graph_to_ofp_std_dev+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500867
868 port_up_device_to_ofp_min = min(port_up_device_to_ofp_list)
869 port_up_device_to_ofp_max = max(port_up_device_to_ofp_list)
870 port_up_device_to_ofp_avg = \
871 (sum(port_up_device_to_ofp_list) /\
872 len(port_up_device_to_ofp_list))
andrewonlab69864162014-11-11 16:28:48 -0500873 port_up_device_to_ofp_std_dev = \
874 str(round(numpy.std(port_up_device_to_ofp_list),1))
andrewonlab8790abb2014-11-06 13:51:54 -0500875
andrewonlab4f50ec92014-11-11 14:24:45 -0500876 main.log.report("Port up device-to-ofp "+
877 "Avg: "+str(port_up_device_to_ofp_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -0500878 "Std Deviation: "+port_up_device_to_ofp_std_dev+" ms")
andrewonlab8790abb2014-11-06 13:51:54 -0500879
880 utilities.assert_equals(expect=main.TRUE, actual=assertion,
881 onpass="Port discovery latency calculation successful",
882 onfail="Port discovery test failed")
andrewonlababb11c32014-11-04 15:03:24 -0500883
andrewonlab3622beb2014-10-28 16:07:56 -0400884 def CASE4(self, main):
885 '''
886 Link down event using loss rate 100%
andrewonlab53b641c2014-10-31 19:44:44 -0400887
888 Important:
889 Use a simple 2 switch topology with 1 link between
890 the two switches. Ensure that mac addresses of the
891 switches are 1 / 2 respectively
andrewonlab3622beb2014-10-28 16:07:56 -0400892 '''
893 import time
894 import subprocess
895 import os
896 import requests
897 import json
andrewonlab4f50ec92014-11-11 14:24:45 -0500898 import numpy
899
andrewonlab3622beb2014-10-28 16:07:56 -0400900 ONOS1_ip = main.params['CTRL']['ip1']
901 ONOS2_ip = main.params['CTRL']['ip2']
902 ONOS3_ip = main.params['CTRL']['ip3']
903 ONOS_user = main.params['CTRL']['user']
904
905 default_sw_port = main.params['CTRL']['port1']
906
907 #Number of iterations of case
908 num_iter = main.params['TEST']['numIter']
909
910 #Timestamp 'keys' for json metrics output.
911 #These are subject to change, hence moved into params
912 deviceTimestamp = main.params['JSON']['deviceTimestamp']
913 linkTimestamp = main.params['JSON']['linkTimestamp']
andrewonlab53b641c2014-10-31 19:44:44 -0400914 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -0500915
916 debug_mode = main.params['TEST']['debugMode']
917
918 local_time = time.strftime('%x %X')
andrewonlabb1998c52014-11-10 13:31:43 -0500919 local_time = local_time.replace("/","")
920 local_time = local_time.replace(" ","_")
921 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -0500922 if debug_mode == 'on':
923 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -0500924 "/tmp/link_lat_pcap_"+local_time)
andrewonlab53b641c2014-10-31 19:44:44 -0400925
andrewonlabe5bcef92014-11-06 17:53:20 -0500926 #Threshold for this test case
927 up_threshold_str = main.params['TEST']['linkUpThreshold']
928 down_threshold_str = main.params['TEST']['linkDownThreshold']
929
930 up_threshold_obj = up_threshold_str.split(",")
931 down_threshold_obj = down_threshold_str.split(",")
932
933 up_threshold_min = int(up_threshold_obj[0])
934 up_threshold_max = int(up_threshold_obj[1])
935
936 down_threshold_min = int(down_threshold_obj[0])
937 down_threshold_max = int(down_threshold_obj[1])
938
andrewonlab3622beb2014-10-28 16:07:56 -0400939 assertion = main.TRUE
940 #Link event timestamp to system time list
941 link_down_link_to_system_list = []
942 link_up_link_to_system_list = []
943 #Graph event timestamp to system time list
944 link_down_graph_to_system_list = []
945 link_up_graph_to_system_list = []
946
andrewonlab4b5c8b92014-11-10 16:04:33 -0500947 main.log.report("Link up / down discovery latency between "+
andrewonlab3622beb2014-10-28 16:07:56 -0400948 "two switches")
andrewonlab4b5c8b92014-11-10 16:04:33 -0500949 main.log.report("Simulated by setting loss-rate 100%")
950 main.log.report("'tc qdisc add dev <intfs> root netem loss 100%'")
951 main.log.report("Total iterations of test: "+str(num_iter))
andrewonlab3622beb2014-10-28 16:07:56 -0400952
953 main.step("Assign all switches")
954 main.Mininet1.assign_sw_controller(sw="1",
955 ip1=ONOS1_ip, port1=default_sw_port)
956 main.Mininet1.assign_sw_controller(sw="2",
957 ip1=ONOS1_ip, port1=default_sw_port)
958
959 main.step("Verifying switch assignment")
960 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
961 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
andrewonlab3622beb2014-10-28 16:07:56 -0400962
963 #Allow time for events to finish before taking measurements
964 time.sleep(10)
965
andrewonlababb11c32014-11-04 15:03:24 -0500966 link_down1 = False
967 link_down2 = False
968 link_down3 = False
andrewonlab3622beb2014-10-28 16:07:56 -0400969 #Start iteration of link event test
970 for i in range(0, int(num_iter)):
971 main.step("Getting initial system time as t0")
andrewonlab8d29f122014-10-22 17:15:04 -0400972
andrewonlab3622beb2014-10-28 16:07:56 -0400973 timestamp_link_down_t0 = time.time() * 1000
974 #Link down is simulated by 100% loss rate using traffic
975 #control command
976 main.Mininet1.handle.sendline(
977 "sh tc qdisc add dev s1-eth1 root netem loss 100%")
978
andrewonlab53b641c2014-10-31 19:44:44 -0400979 #TODO: Iterate through 'links' command to verify that
andrewonlababb11c32014-11-04 15:03:24 -0500980 # link s1 -> s2 went down (loop timeout 30 seconds)
981 # on all 3 ONOS instances
andrewonlab53b641c2014-10-31 19:44:44 -0400982 main.log.info("Checking ONOS for link update")
983 loop_count = 0
andrewonlababb11c32014-11-04 15:03:24 -0500984 while( not (link_down1 and link_down2 and link_down3)\
985 and loop_count < 30 ):
986 json_str1 = main.ONOS1cli.links()
987 json_str2 = main.ONOS2cli.links()
988 json_str3 = main.ONOS3cli.links()
989
990 if not (json_str1 and json_str2 and json_str3):
991 main.log.error("CLI command returned error ")
andrewonlab53b641c2014-10-31 19:44:44 -0400992 break
993 else:
andrewonlababb11c32014-11-04 15:03:24 -0500994 json_obj1 = json.loads(json_str1)
995 json_obj2 = json.loads(json_str2)
996 json_obj3 = json.loads(json_str3)
997 for obj1 in json_obj1:
998 if '01' not in obj1['src']['device']:
999 link_down1 = True
andrewonlabf9828f02014-11-10 14:50:27 -05001000 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001001 "s1 -> s2 on ONOS1 detected")
1002 for obj2 in json_obj2:
1003 if '01' not in obj2['src']['device']:
1004 link_down2 = True
andrewonlabf9828f02014-11-10 14:50:27 -05001005 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001006 "s1 -> s2 on ONOS2 detected")
1007 for obj3 in json_obj3:
1008 if '01' not in obj3['src']['device']:
1009 link_down3 = True
andrewonlabf9828f02014-11-10 14:50:27 -05001010 main.log.info("Link down from "+
andrewonlababb11c32014-11-04 15:03:24 -05001011 "s1 -> s2 on ONOS3 detected")
1012
andrewonlab53b641c2014-10-31 19:44:44 -04001013 loop_count += 1
andrewonlababb11c32014-11-04 15:03:24 -05001014 #If CLI doesn't like the continuous requests
1015 #and exits in this loop, increase the sleep here.
1016 #Consequently, while loop timeout will increase
andrewonlab53b641c2014-10-31 19:44:44 -04001017 time.sleep(1)
1018
1019 #Give time for metrics measurement to catch up
andrewonlababb11c32014-11-04 15:03:24 -05001020 #NOTE: May need to be configured more accurately
andrewonlab53b641c2014-10-31 19:44:44 -04001021 time.sleep(10)
andrewonlababb11c32014-11-04 15:03:24 -05001022 #If we exited the while loop and link down 1,2,3 are still
andrewonlab53b641c2014-10-31 19:44:44 -04001023 #false, then ONOS has failed to discover link down event
andrewonlababb11c32014-11-04 15:03:24 -05001024 if not (link_down1 and link_down2 and link_down3):
andrewonlab53b641c2014-10-31 19:44:44 -04001025 main.log.info("Link down discovery failed")
1026
1027 link_down_lat_graph1 = 0
1028 link_down_lat_graph2 = 0
1029 link_down_lat_graph3 = 0
1030 link_down_lat_device1 = 0
1031 link_down_lat_device2 = 0
1032 link_down_lat_device3 = 0
1033
1034 assertion = main.FALSE
1035 else:
1036 json_topo_metrics_1 =\
1037 main.ONOS1cli.topology_events_metrics()
1038 json_topo_metrics_2 =\
1039 main.ONOS2cli.topology_events_metrics()
1040 json_topo_metrics_3 =\
1041 main.ONOS3cli.topology_events_metrics()
1042 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1043 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1044 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1045
1046 main.log.info("Obtaining graph and device timestamp")
1047 graph_timestamp_1 = \
1048 json_topo_metrics_1[graphTimestamp]['value']
1049 graph_timestamp_2 = \
1050 json_topo_metrics_2[graphTimestamp]['value']
1051 graph_timestamp_3 = \
1052 json_topo_metrics_3[graphTimestamp]['value']
1053
1054 link_timestamp_1 = \
1055 json_topo_metrics_1[linkTimestamp]['value']
1056 link_timestamp_2 = \
1057 json_topo_metrics_2[linkTimestamp]['value']
1058 link_timestamp_3 = \
1059 json_topo_metrics_3[linkTimestamp]['value']
1060
1061 if graph_timestamp_1 and graph_timestamp_2 and\
1062 graph_timestamp_3 and link_timestamp_1 and\
1063 link_timestamp_2 and link_timestamp_3:
1064 link_down_lat_graph1 = int(graph_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001065 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001066 link_down_lat_graph2 = int(graph_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001067 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001068 link_down_lat_graph3 = int(graph_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001069 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001070
1071 link_down_lat_link1 = int(link_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001072 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001073 link_down_lat_link2 = int(link_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001074 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001075 link_down_lat_link3 = int(link_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001076 int(timestamp_link_down_t0)
andrewonlab53b641c2014-10-31 19:44:44 -04001077 else:
1078 main.log.error("There was an error calculating"+
1079 " the delta for link down event")
1080 link_down_lat_graph1 = 0
1081 link_down_lat_graph2 = 0
1082 link_down_lat_graph3 = 0
1083
1084 link_down_lat_device1 = 0
1085 link_down_lat_device2 = 0
1086 link_down_lat_device3 = 0
1087
andrewonlabf9828f02014-11-10 14:50:27 -05001088 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001089 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001090 str(link_down_lat_graph1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001091 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001092 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001093 str(link_down_lat_graph2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001094 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001095 str(i)+" (end-to-end): "+
andrewonlababb11c32014-11-04 15:03:24 -05001096 str(link_down_lat_graph3)+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001097
andrewonlabf9828f02014-11-10 14:50:27 -05001098 main.log.info("Link down latency ONOS1 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001099 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001100 str(link_down_lat_link1)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001101 main.log.info("Link down latency ONOS2 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001102 str(i)+" (link-event-to-system-timestamp): "+
andrewonlababb11c32014-11-04 15:03:24 -05001103 str(link_down_lat_link2)+" ms")
andrewonlabf9828f02014-11-10 14:50:27 -05001104 main.log.info("Link down latency ONOS3 iteration "+
andrewonlab4e124482014-11-04 13:37:25 -05001105 str(i)+" (link-event-to-system-timestamp): "+
1106 str(link_down_lat_link3))
1107
1108 #Calculate avg of node calculations
1109 link_down_lat_graph_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001110 (link_down_lat_graph1 +
1111 link_down_lat_graph2 +
andrewonlab65d73892014-11-10 17:36:00 -05001112 link_down_lat_graph3) / 3
andrewonlab4e124482014-11-04 13:37:25 -05001113 link_down_lat_link_avg =\
andrewonlababb11c32014-11-04 15:03:24 -05001114 (link_down_lat_link1 +
1115 link_down_lat_link2 +
andrewonlab65d73892014-11-10 17:36:00 -05001116 link_down_lat_link3) / 3
andrewonlab53b641c2014-10-31 19:44:44 -04001117
andrewonlab4e124482014-11-04 13:37:25 -05001118 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001119 if link_down_lat_graph_avg > down_threshold_min and\
1120 link_down_lat_graph_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001121 link_down_graph_to_system_list.append(
1122 link_down_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001123 else:
1124 main.log.info("Link down latency exceeded threshold")
1125 main.log.info("Results for iteration "+str(i)+
1126 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001127 if link_down_lat_link_avg > down_threshold_min and\
1128 link_down_lat_link_avg < down_threshold_max:
andrewonlab4e124482014-11-04 13:37:25 -05001129 link_down_link_to_system_list.append(
1130 link_down_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001131 else:
1132 main.log.info("Link down latency exceeded threshold")
1133 main.log.info("Results for iteration "+str(i)+
1134 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001135
1136 #NOTE: To remove loss rate and measure latency:
1137 # 'sh tc qdisc del dev s1-eth1 root'
andrewonlababb11c32014-11-04 15:03:24 -05001138 timestamp_link_up_t0 = time.time() * 1000
andrewonlab53b641c2014-10-31 19:44:44 -04001139 main.Mininet1.handle.sendline("sh tc qdisc del dev "+
1140 "s1-eth1 root")
1141 main.Mininet1.handle.expect("mininet>")
andrewonlababb11c32014-11-04 15:03:24 -05001142
1143 main.log.info("Checking ONOS for link update")
1144
1145 link_down1 = True
1146 link_down2 = True
1147 link_down3 = True
1148 loop_count = 0
1149 while( (link_down1 and link_down2 and link_down3)\
1150 and loop_count < 30 ):
1151 json_str1 = main.ONOS1cli.links()
1152 json_str2 = main.ONOS2cli.links()
1153 json_str3 = main.ONOS3cli.links()
1154 if not (json_str1 and json_str2 and json_str3):
1155 main.log.error("CLI command returned error ")
1156 break
1157 else:
1158 json_obj1 = json.loads(json_str1)
1159 json_obj2 = json.loads(json_str2)
1160 json_obj3 = json.loads(json_str3)
1161
1162 for obj1 in json_obj1:
1163 if '01' in obj1['src']['device']:
1164 link_down1 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001165 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001166 "s1 -> s2 on ONOS1 detected")
1167 for obj2 in json_obj2:
1168 if '01' in obj2['src']['device']:
1169 link_down2 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001170 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001171 "s1 -> s2 on ONOS2 detected")
1172 for obj3 in json_obj3:
1173 if '01' in obj3['src']['device']:
1174 link_down3 = False
andrewonlabf9828f02014-11-10 14:50:27 -05001175 main.log.info("Link up from "+
andrewonlababb11c32014-11-04 15:03:24 -05001176 "s1 -> s2 on ONOS3 detected")
1177
1178 loop_count += 1
1179 time.sleep(1)
1180
1181 if (link_down1 and link_down2 and link_down3):
1182 main.log.info("Link up discovery failed")
1183
1184 link_up_lat_graph1 = 0
1185 link_up_lat_graph2 = 0
1186 link_up_lat_graph3 = 0
1187 link_up_lat_device1 = 0
1188 link_up_lat_device2 = 0
1189 link_up_lat_device3 = 0
1190
1191 assertion = main.FALSE
1192 else:
1193 json_topo_metrics_1 =\
1194 main.ONOS1cli.topology_events_metrics()
1195 json_topo_metrics_2 =\
1196 main.ONOS2cli.topology_events_metrics()
1197 json_topo_metrics_3 =\
1198 main.ONOS3cli.topology_events_metrics()
1199 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
1200 json_topo_metrics_2 = json.loads(json_topo_metrics_2)
1201 json_topo_metrics_3 = json.loads(json_topo_metrics_3)
1202
1203 main.log.info("Obtaining graph and device timestamp")
1204 graph_timestamp_1 = \
1205 json_topo_metrics_1[graphTimestamp]['value']
1206 graph_timestamp_2 = \
1207 json_topo_metrics_2[graphTimestamp]['value']
1208 graph_timestamp_3 = \
1209 json_topo_metrics_3[graphTimestamp]['value']
1210
1211 link_timestamp_1 = \
1212 json_topo_metrics_1[linkTimestamp]['value']
1213 link_timestamp_2 = \
1214 json_topo_metrics_2[linkTimestamp]['value']
1215 link_timestamp_3 = \
1216 json_topo_metrics_3[linkTimestamp]['value']
1217
1218 if graph_timestamp_1 and graph_timestamp_2 and\
1219 graph_timestamp_3 and link_timestamp_1 and\
1220 link_timestamp_2 and link_timestamp_3:
1221 link_up_lat_graph1 = int(graph_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001222 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001223 link_up_lat_graph2 = int(graph_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001224 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001225 link_up_lat_graph3 = int(graph_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001226 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001227
1228 link_up_lat_link1 = int(link_timestamp_1) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001229 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001230 link_up_lat_link2 = int(link_timestamp_2) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001231 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001232 link_up_lat_link3 = int(link_timestamp_3) -\
andrewonlab4f50ec92014-11-11 14:24:45 -05001233 int(timestamp_link_up_t0)
andrewonlababb11c32014-11-04 15:03:24 -05001234 else:
1235 main.log.error("There was an error calculating"+
1236 " the delta for link down event")
1237 link_up_lat_graph1 = 0
1238 link_up_lat_graph2 = 0
1239 link_up_lat_graph3 = 0
1240
1241 link_up_lat_device1 = 0
1242 link_up_lat_device2 = 0
1243 link_up_lat_device3 = 0
andrewonlab58f7d702014-11-07 13:21:19 -05001244
1245 if debug_mode == 'on':
1246 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001247 str(i)+" (end-to-end): "+
1248 str(link_up_lat_graph1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001249 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001250 str(i)+" (end-to-end): "+
1251 str(link_up_lat_graph2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001252 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001253 str(i)+" (end-to-end): "+
1254 str(link_up_lat_graph3)+" ms")
1255
andrewonlab58f7d702014-11-07 13:21:19 -05001256 main.log.info("Link up latency ONOS1 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001257 str(i)+" (link-event-to-system-timestamp): "+
1258 str(link_up_lat_link1)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001259 main.log.info("Link up latency ONOS2 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001260 str(i)+" (link-event-to-system-timestamp): "+
1261 str(link_up_lat_link2)+" ms")
andrewonlab58f7d702014-11-07 13:21:19 -05001262 main.log.info("Link up latency ONOS3 iteration "+
andrewonlababb11c32014-11-04 15:03:24 -05001263 str(i)+" (link-event-to-system-timestamp): "+
1264 str(link_up_lat_link3))
1265
1266 #Calculate avg of node calculations
1267 link_up_lat_graph_avg =\
1268 (link_up_lat_graph1 +
1269 link_up_lat_graph2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001270 link_up_lat_graph3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001271 link_up_lat_link_avg =\
1272 (link_up_lat_link1 +
1273 link_up_lat_link2 +
andrewonlabf9828f02014-11-10 14:50:27 -05001274 link_up_lat_link3) / 3
andrewonlababb11c32014-11-04 15:03:24 -05001275
1276 #Set threshold and append latency to list
andrewonlabe5bcef92014-11-06 17:53:20 -05001277 if link_up_lat_graph_avg > up_threshold_min and\
1278 link_up_lat_graph_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001279 link_up_graph_to_system_list.append(
1280 link_up_lat_graph_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001281 else:
1282 main.log.info("Link up latency exceeded threshold")
1283 main.log.info("Results for iteration "+str(i)+
1284 "have been omitted")
andrewonlabe5bcef92014-11-06 17:53:20 -05001285 if link_up_lat_link_avg > up_threshold_min and\
1286 link_up_lat_link_avg < up_threshold_max:
andrewonlababb11c32014-11-04 15:03:24 -05001287 link_up_link_to_system_list.append(
1288 link_up_lat_link_avg)
andrewonlab8790abb2014-11-06 13:51:54 -05001289 else:
1290 main.log.info("Link up latency exceeded threshold")
1291 main.log.info("Results for iteration "+str(i)+
1292 "have been omitted")
andrewonlab53b641c2014-10-31 19:44:44 -04001293
andrewonlab4e124482014-11-04 13:37:25 -05001294 #Calculate min, max, avg of list and report
1295 link_down_min = min(link_down_graph_to_system_list)
1296 link_down_max = max(link_down_graph_to_system_list)
1297 link_down_avg = sum(link_down_graph_to_system_list) / \
1298 len(link_down_graph_to_system_list)
andrewonlababb11c32014-11-04 15:03:24 -05001299 link_up_min = min(link_up_graph_to_system_list)
1300 link_up_max = max(link_up_graph_to_system_list)
1301 link_up_avg = sum(link_up_graph_to_system_list) / \
1302 len(link_up_graph_to_system_list)
andrewonlab69864162014-11-11 16:28:48 -05001303 link_down_std_dev = \
1304 str(round(numpy.std(link_down_graph_to_system_list),1))
1305 link_up_std_dev = \
1306 str(round(numpy.std(link_up_graph_to_system_list),1))
andrewonlababb11c32014-11-04 15:03:24 -05001307
andrewonlab4f50ec92014-11-11 14:24:45 -05001308 main.log.report("Link down latency " +
1309 "Avg: "+str(link_down_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -05001310 "Std Deviation: "+link_down_std_dev+" ms")
andrewonlab4f50ec92014-11-11 14:24:45 -05001311 main.log.report("Link up latency "+
1312 "Avg: "+str(link_up_avg)+" ms "+
andrewonlab69864162014-11-11 16:28:48 -05001313 "Std Deviation: "+link_up_std_dev+" ms")
andrewonlab4e124482014-11-04 13:37:25 -05001314
andrewonlab8790abb2014-11-06 13:51:54 -05001315 utilities.assert_equals(expect=main.TRUE, actual=assertion,
1316 onpass="Link discovery latency calculation successful",
1317 onfail="Link discovery latency case failed")
1318
andrewonlabb54b85b2014-10-28 18:43:57 -04001319 def CASE5(self, main):
1320 '''
1321 100 Switch discovery latency
1322
1323 Important:
andrewonlab16ce4852014-10-30 13:41:09 -04001324 This test case can be potentially dangerous if
1325 your machine has previously set iptables rules.
1326 One of the steps of the test case will flush
1327 all existing iptables rules.
andrewonlab8790abb2014-11-06 13:51:54 -05001328 Note:
1329 You can specify the number of switches in the
1330 params file to adjust the switch discovery size
1331 (and specify the corresponding topology in Mininet1
1332 .topo file)
andrewonlabb54b85b2014-10-28 18:43:57 -04001333 '''
1334 import time
1335 import subprocess
1336 import os
1337 import requests
1338 import json
1339
1340 ONOS1_ip = main.params['CTRL']['ip1']
1341 ONOS2_ip = main.params['CTRL']['ip2']
1342 ONOS3_ip = main.params['CTRL']['ip3']
1343 MN1_ip = main.params['MN']['ip1']
1344 ONOS_user = main.params['CTRL']['user']
1345
1346 default_sw_port = main.params['CTRL']['port1']
1347
1348 #Number of iterations of case
1349 num_iter = main.params['TEST']['numIter']
andrewonlab16ce4852014-10-30 13:41:09 -04001350 num_sw = main.params['TEST']['numSwitch']
1351
andrewonlabb54b85b2014-10-28 18:43:57 -04001352 #Timestamp 'keys' for json metrics output.
1353 #These are subject to change, hence moved into params
1354 deviceTimestamp = main.params['JSON']['deviceTimestamp']
andrewonlab16ce4852014-10-30 13:41:09 -04001355 graphTimestamp = main.params['JSON']['graphTimestamp']
andrewonlab58f7d702014-11-07 13:21:19 -05001356
1357 debug_mode = main.params['TEST']['debugMode']
1358
andrewonlabb1998c52014-11-10 13:31:43 -05001359 local_time = time.strftime('%X')
1360 local_time = local_time.replace("/","")
1361 local_time = local_time.replace(" ","_")
1362 local_time = local_time.replace(":","")
andrewonlab58f7d702014-11-07 13:21:19 -05001363 if debug_mode == 'on':
1364 main.ONOS1.tshark_pcap("eth0",
andrewonlabb1998c52014-11-10 13:31:43 -05001365 "/tmp/100_sw_lat_pcap_"+local_time)
andrewonlabe5bcef92014-11-06 17:53:20 -05001366
1367 #Threshold for this test case
1368 sw_disc_threshold_str = main.params['TEST']['swDisc100Threshold']
1369 sw_disc_threshold_obj = sw_disc_threshold_str.split(",")
1370 sw_disc_threshold_min = int(sw_disc_threshold_obj[0])
1371 sw_disc_threshold_max = int(sw_disc_threshold_obj[1])
1372
andrewonlab53b641c2014-10-31 19:44:44 -04001373 tshark_ofp_output = "/tmp/tshark_ofp_"+num_sw+"sw.txt"
1374 tshark_tcp_output = "/tmp/tshark_tcp_"+num_sw+"sw.txt"
1375
1376 tshark_ofp_result_list = []
1377 tshark_tcp_result_list = []
andrewonlabb54b85b2014-10-28 18:43:57 -04001378
andrewonlabe5bcef92014-11-06 17:53:20 -05001379 sw_discovery_lat_list = []
1380
andrewonlab16ce4852014-10-30 13:41:09 -04001381 main.case(num_sw+" Switch discovery latency")
andrewonlabb54b85b2014-10-28 18:43:57 -04001382 main.step("Assigning all switches to ONOS1")
andrewonlab16ce4852014-10-30 13:41:09 -04001383 for i in range(1, int(num_sw)+1):
andrewonlabb54b85b2014-10-28 18:43:57 -04001384 main.Mininet1.assign_sw_controller(
1385 sw=str(i),
1386 ip1=ONOS1_ip,
1387 port1=default_sw_port)
andrewonlab16ce4852014-10-30 13:41:09 -04001388
andrewonlabb54b85b2014-10-28 18:43:57 -04001389 #Ensure that nodes are configured with ptpd
andrewonlab16ce4852014-10-30 13:41:09 -04001390 #Just a warning message
1391 main.log.info("Please check ptpd configuration to ensure"+\
1392 " All nodes' system times are in sync")
1393 time.sleep(5)
andrewonlabb54b85b2014-10-28 18:43:57 -04001394
1395 for i in range(0, int(num_iter)):
andrewonlab8d29f122014-10-22 17:15:04 -04001396
andrewonlabb54b85b2014-10-28 18:43:57 -04001397 main.step("Set iptables rule to block incoming sw connections")
1398 #Set iptables rule to block incoming switch connections
andrewonlab53b641c2014-10-31 19:44:44 -04001399 #The rule description is as follows:
1400 # Append to INPUT rule,
1401 # behavior DROP that matches following:
1402 # * packet type: tcp
1403 # * source IP: MN1_ip
1404 # * destination PORT: 6633
andrewonlabb54b85b2014-10-28 18:43:57 -04001405 main.ONOS1.handle.sendline(
andrewonlab16ce4852014-10-30 13:41:09 -04001406 "sudo iptables -A INPUT -p tcp -s "+MN1_ip+
andrewonlabb54b85b2014-10-28 18:43:57 -04001407 " --dport "+default_sw_port+" -j DROP")
1408 main.ONOS1.handle.expect("\$")
andrewonlab53b641c2014-10-31 19:44:44 -04001409 # Append to OUTPUT rule,
1410 # behavior DROP that matches following:
1411 # * packet type: tcp
1412 # * source IP: MN1_ip
1413 # * destination PORT: 6633
1414 main.ONOS1.handle.sendline(
1415 "sudo iptables -A OUTPUT -p tcp -s "+MN1_ip+
1416 " --dport "+default_sw_port+" -j DROP")
1417 main.ONOS1.handle.expect("\$")
andrewonlabb54b85b2014-10-28 18:43:57 -04001418 #Give time to allow rule to take effect
andrewonlab8790abb2014-11-06 13:51:54 -05001419 #NOTE: Sleep period may need to be configured
1420 # based on the number of switches in the topology
andrewonlab16ce4852014-10-30 13:41:09 -04001421 main.log.info("Please wait for switch connection to "+
1422 "time out")
1423 time.sleep(60)
1424
1425 #Gather vendor OFP with tshark
1426 main.ONOS1.tshark_grep("OFP 86 Vendor",
1427 tshark_ofp_output)
andrewonlab53b641c2014-10-31 19:44:44 -04001428 main.ONOS1.tshark_grep("TCP 74 ",
1429 tshark_tcp_output)
andrewonlabb54b85b2014-10-28 18:43:57 -04001430
andrewonlab16ce4852014-10-30 13:41:09 -04001431 #NOTE: Remove all iptables rule quickly (flush)
andrewonlabb54b85b2014-10-28 18:43:57 -04001432 # Before removal, obtain TestON timestamp at which
andrewonlab16ce4852014-10-30 13:41:09 -04001433 # removal took place
1434 # (ensuring nodes are configured via ptp)
andrewonlabb54b85b2014-10-28 18:43:57 -04001435 # sudo iptables -F
andrewonlab16ce4852014-10-30 13:41:09 -04001436
1437 t0_system = time.time() * 1000
1438 main.ONOS1.handle.sendline(
1439 "sudo iptables -F")
andrewonlabb54b85b2014-10-28 18:43:57 -04001440
andrewonlab16ce4852014-10-30 13:41:09 -04001441 #Counter to track loop count
1442 counter_loop = 0
1443 counter_avail1 = 0
1444 counter_avail2 = 0
1445 counter_avail3 = 0
1446 onos1_dev = False
1447 onos2_dev = False
1448 onos3_dev = False
1449 while counter_loop < 60:
1450 #Continue to check devices for all device
1451 #availability. When all devices in all 3
1452 #ONOS instances indicate that devices are available
1453 #obtain graph event timestamp for t1.
1454 device_str_obj1 = main.ONOS1cli.devices()
1455 device_str_obj2 = main.ONOS2cli.devices()
1456 device_str_obj3 = main.ONOS3cli.devices()
1457
1458 device_json1 = json.loads(device_str_obj1)
1459 device_json2 = json.loads(device_str_obj2)
1460 device_json3 = json.loads(device_str_obj3)
1461
1462 for device1 in device_json1:
1463 if device1['available'] == True:
1464 counter_avail1 += 1
1465 if counter_avail1 == int(num_sw):
1466 onos1_dev = True
1467 main.log.info("All devices have been "+
1468 "discovered on ONOS1")
1469 else:
1470 counter_avail1 = 0
1471 for device2 in device_json2:
1472 if device2['available'] == True:
1473 counter_avail2 += 1
1474 if counter_avail2 == int(num_sw):
1475 onos2_dev = True
1476 main.log.info("All devices have been "+
1477 "discovered on ONOS2")
1478 else:
1479 counter_avail2 = 0
1480 for device3 in device_json3:
1481 if device3['available'] == True:
1482 counter_avail3 += 1
1483 if counter_avail3 == int(num_sw):
1484 onos3_dev = True
1485 main.log.info("All devices have been "+
1486 "discovered on ONOS3")
1487 else:
1488 counter_avail3 = 0
1489
1490 if onos1_dev and onos2_dev and onos3_dev:
1491 main.log.info("All devices have been discovered "+
1492 "on all ONOS instances")
1493 json_str_topology_metrics_1 =\
1494 main.ONOS1cli.topology_events_metrics()
1495 json_str_topology_metrics_2 =\
1496 main.ONOS2cli.topology_events_metrics()
1497 json_str_topology_metrics_3 =\
1498 main.ONOS3cli.topology_events_metrics()
andrewonlab53b641c2014-10-31 19:44:44 -04001499
1500 #Exit while loop if all devices discovered
andrewonlab16ce4852014-10-30 13:41:09 -04001501 break
1502
1503 counter_loop += 1
1504 #Give some time in between CLI calls
1505 #(will not affect measurement)
1506 time.sleep(3)
1507
1508 main.ONOS1.tshark_stop()
1509
1510 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1511 tshark_ofp_output+" /tmp/")
andrewonlab53b641c2014-10-31 19:44:44 -04001512 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1513 tshark_tcp_output+" /tmp/")
andrewonlab16ce4852014-10-30 13:41:09 -04001514
andrewonlab16ce4852014-10-30 13:41:09 -04001515 #TODO: Automate OFP output analysis
andrewonlab58f7d702014-11-07 13:21:19 -05001516 #Debug mode - print out packets captured at runtime
1517 if debug_mode == 'on':
1518 ofp_file = open(tshark_ofp_output, 'r')
1519 main.log.info("Tshark OFP Vendor output: ")
1520 for line in ofp_file:
1521 tshark_ofp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001522 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001523 ofp_file.close()
andrewonlab16ce4852014-10-30 13:41:09 -04001524
andrewonlab58f7d702014-11-07 13:21:19 -05001525 tcp_file = open(tshark_tcp_output, 'r')
1526 main.log.info("Tshark TCP 74 output: ")
1527 for line in tcp_file:
1528 tshark_tcp_result_list.append(line)
andrewonlabe5bcef92014-11-06 17:53:20 -05001529 main.log.info(line)
andrewonlab58f7d702014-11-07 13:21:19 -05001530 tcp_file.close()
andrewonlab53b641c2014-10-31 19:44:44 -04001531
andrewonlab16ce4852014-10-30 13:41:09 -04001532 json_obj_1 = json.loads(json_str_topology_metrics_1)
1533 json_obj_2 = json.loads(json_str_topology_metrics_2)
1534 json_obj_3 = json.loads(json_str_topology_metrics_3)
1535
1536 graph_timestamp_1 = \
1537 json_obj_1[graphTimestamp]['value']
1538 graph_timestamp_2 = \
1539 json_obj_2[graphTimestamp]['value']
1540 graph_timestamp_3 = \
1541 json_obj_3[graphTimestamp]['value']
1542
andrewonlabe5bcef92014-11-06 17:53:20 -05001543 graph_lat_1 = int(graph_timestamp_1) - int(t0_system)
1544 graph_lat_2 = int(graph_timestamp_2) - int(t0_system)
1545 graph_lat_3 = int(graph_timestamp_3) - int(t0_system)
andrewonlab16ce4852014-10-30 13:41:09 -04001546
andrewonlabe5bcef92014-11-06 17:53:20 -05001547 avg_graph_lat = \
1548 (int(graph_lat_1) +\
1549 int(graph_lat_2) +\
1550 int(graph_lat_3)) / 3
1551
1552 if avg_graph_lat > sw_disc_threshold_min \
1553 and avg_graph_lat < sw_disc_threshold_max:
1554 sw_discovery_lat_list.append(
1555 avg_graph_lat)
1556 else:
1557 main.log.info("100 Switch discovery latency "+
1558 "exceeded the threshold.")
1559
1560 #END ITERATION FOR LOOP
andrewonlab16ce4852014-10-30 13:41:09 -04001561
andrewonlabe5bcef92014-11-06 17:53:20 -05001562 sw_lat_min = min(sw_discovery_lat_list)
1563 sw_lat_max = max(sw_discovery_lat_list)
1564 sw_lat_avg = sum(sw_discovery_lat_list) /\
1565 len(sw_discovery_lat_list)
andrewonlab16ce4852014-10-30 13:41:09 -04001566
andrewonlabf9828f02014-11-10 14:50:27 -05001567 main.log.report("100 Switch discovery lat "+\
1568 "Min: "+str(sw_lat_min)+" ms"+\
1569 "Max: "+str(sw_lat_max)+" ms"+\
1570 "Avg: "+str(sw_lat_avg)+" ms")
andrewonlab16ce4852014-10-30 13:41:09 -04001571
andrewonlabb54b85b2014-10-28 18:43:57 -04001572