blob: d10c0ee4778075647d77feafda67e6daa07d9d17 [file] [log] [blame]
andrewonlab47eddf22014-11-06 17:10:54 -05001#TopoPerfNext
2#
3#Topology Performance test for ONOS-next
4#*** Revised for single node operation ***
5#
6#andrew@onlab.us
7
8import time
9import sys
10import os
11import re
12
13class TopoPerfNextSingleNode:
14 def __init__(self):
15 self.default = ''
16
17 def CASE1(self, main):
18 '''
19 ONOS startup sequence
20 '''
21 import time
22
23 cell_name = main.params['ENV']['cellName']
24
25 git_pull = main.params['GIT']['autoPull']
26 checkout_branch = main.params['GIT']['checkout']
27
28 ONOS1_ip = main.params['CTRL']['ip1']
29 MN1_ip = main.params['MN']['ip1']
30 BENCH_ip = main.params['BENCH']['ip']
31
32 main.case("Setting up test environment")
33
34 main.step("Creating cell file")
35 cell_file_result = main.ONOSbench.create_cell_file(
36 BENCH_ip, cell_name, MN1_ip, "onos-core",
37 ONOS1_ip)
38
39 main.step("Applying cell file to environment")
40 cell_apply_result = main.ONOSbench.set_cell(cell_name)
41 verify_cell_result = main.ONOSbench.verify_cell()
42
43 main.step("Git checkout and pull "+checkout_branch)
44 if git_pull == 'on':
45 checkout_result = \
46 main.ONOSbench.git_checkout(checkout_branch)
47 pull_result = main.ONOSbench.git_pull()
48 else:
49 checkout_result = main.TRUE
50 pull_result = main.TRUE
51 main.log.info("Skipped git checkout and pull")
52
53 main.step("Using mvn clean & install")
54 #mvn_result = main.ONOSbench.clean_install()
55 mvn_result = main.TRUE
56
57 main.step("Creating ONOS package")
58 package_result = main.ONOSbench.onos_package()
59
60 main.step("Installing ONOS package")
61 install1_result = main.ONOSbench.onos_install(node=ONOS1_ip)
62
63 #NOTE: This step may be unnecessary
64 #main.step("Starting ONOS service")
65 #start_result = main.ONOSbench.onos_start(ONOS1_ip)
66
67 main.step("Set cell for ONOS cli env")
68 main.ONOS1cli.set_cell(cell_name)
69
70 time.sleep(10)
71
72 main.step("Start onos cli")
73 cli1 = main.ONOS1cli.start_onos_cli(ONOS1_ip)
74
75 main.step("Enable metrics feature")
76 main.ONOS1cli.feature_install("onos-app-metrics")
77
78 utilities.assert_equals(expect=main.TRUE,
79 actual= cell_file_result and cell_apply_result and\
80 verify_cell_result and checkout_result and\
81 pull_result and mvn_result and\
82 install1_result,
83 onpass="ONOS started successfully",
84 onfail="Failed to start ONOS")
85
86 def CASE2(self, main):
87 '''
88 Assign s1 to ONOS1 and measure latency
89
90 There are 4 levels of latency measurements to this test:
91 1) End-to-end measurement: Complete end-to-end measurement
92 from TCP (SYN/ACK) handshake to Graph change
93 2) OFP-to-graph measurement: 'ONOS processing' snippet of
94 measurement from OFP Vendor message to Graph change
95 3) OFP-to-device measurement: 'ONOS processing without
96 graph change' snippet of measurement from OFP vendor
97 message to Device change timestamp
98 4) T0-to-device measurement: Measurement that includes
99 the switch handshake to devices timestamp without
100 the graph view change. (TCP handshake -> Device
101 change)
102 '''
103 import time
104 import subprocess
105 import json
106 import requests
107 import os
108
109 ONOS1_ip = main.params['CTRL']['ip1']
110 ONOS_user = main.params['CTRL']['user']
111
112 default_sw_port = main.params['CTRL']['port1']
113
114 #Number of iterations of case
115 num_iter = main.params['TEST']['numIter']
116
117 #Timestamp 'keys' for json metrics output.
118 #These are subject to change, hence moved into params
119 deviceTimestamp = main.params['JSON']['deviceTimestamp']
120 graphTimestamp = main.params['JSON']['graphTimestamp']
121
122 #List of switch add latency collected from
123 #all iterations
124 latency_end_to_end_list = []
125 latency_ofp_to_graph_list = []
126 latency_ofp_to_device_list = []
127 latency_t0_to_device_list = []
128
129 #Directory/file to store tshark results
130 tshark_of_output = "/tmp/tshark_of_topo.txt"
131 tshark_tcp_output = "/tmp/tshark_tcp_topo.txt"
132
133 #String to grep in tshark output
134 tshark_tcp_string = "TCP 74 "+default_sw_port
135 tshark_of_string = "OFP 86 Vendor"
136
137 #Initialize assertion to TRUE
138 assertion = main.TRUE
139
140 main.log.report("Latency of adding one switch")
141
142 for i in range(0, int(num_iter)):
143 main.log.info("Starting tshark capture")
144
145 #* TCP [ACK, SYN] is used as t0_a, the
146 # very first "exchange" between ONOS and
147 # the switch for end-to-end measurement
148 #* OFP [Stats Reply] is used for t0_b
149 # the very last OFP message between ONOS
150 # and the switch for ONOS measurement
151 main.ONOS1.tshark_grep(tshark_tcp_string,
152 tshark_tcp_output)
153 main.ONOS1.tshark_grep(tshark_of_string,
154 tshark_of_output)
155
156 #Wait and ensure tshark is started and
157 #capturing
158 time.sleep(10)
159
160 main.log.info("Assigning s1 to controller")
161
162 main.Mininet1.assign_sw_controller(sw="1",
163 ip1=ONOS1_ip, port1=default_sw_port)
164
165 #Wait and ensure switch is assigned
166 #before stopping tshark
167 time.sleep(30)
168
169 main.log.info("Stopping all Tshark processes")
170 main.ONOS1.stop_tshark()
171
172 #tshark output is saved in ONOS. Use subprocess
173 #to copy over files to TestON for parsing
174 main.log.info("Copying over tshark files")
175
176 #TCP CAPTURE ****
177 #Copy the tshark output from ONOS machine to
178 #TestON machine in tshark_tcp_output directory>file
179 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
180 tshark_tcp_output+" /tmp/")
181 tcp_file = open(tshark_tcp_output, 'r')
182 temp_text = tcp_file.readline()
183 temp_text = temp_text.split(" ")
184
185 main.log.info("Object read in from TCP capture: "+
186 str(temp_text))
187 if len(temp_text) > 1:
188 t0_tcp = float(temp_text[1])*1000.0
189 else:
190 main.log.error("Tshark output file for TCP"+
191 " returned unexpected results")
192 t0_tcp = 0
193 assertion = main.FALSE
194
195 tcp_file.close()
196 #****************
197
198 #OF CAPTURE ****
199 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
200 tshark_of_output+" /tmp/")
201 of_file = open(tshark_of_output, 'r')
202
203 line_ofp = ""
204 #Read until last line of file
205 while True:
206 temp_text = of_file.readline()
207 if temp_text !='':
208 line_ofp = temp_text
209 else:
210 break
211 obj = line_ofp.split(" ")
212
213 main.log.info("Object read in from OFP capture: "+
214 str(line_ofp))
215
216 if len(line_ofp) > 1:
217 t0_ofp = float(obj[1])*1000.0
218 else:
219 main.log.error("Tshark output file for OFP"+
220 " returned unexpected results")
221 t0_ofp = 0
222 assertion = main.FALSE
223
224 of_file.close()
225 #****************
226
227 json_str_1 = main.ONOS1cli.topology_events_metrics()
228
229 json_obj_1 = json.loads(json_str_1)
230
231 #Obtain graph timestamp. This timestsamp captures
232 #the epoch time at which the topology graph was updated.
233 graph_timestamp_1 = \
234 json_obj_1[graphTimestamp]['value']
235
236 #Obtain device timestamp. This timestamp captures
237 #the epoch time at which the device event happened
238 device_timestamp_1 = \
239 json_obj_1[deviceTimestamp]['value']
240
241 #t0 to device processing latency
242 delta_device_1 = int(device_timestamp_1) - int(t0_tcp)
243
244 #Get average of delta from all instances
245 avg_delta_device = (int(delta_device_1))
246
247 #Ensure avg delta meets the threshold before appending
248 if avg_delta_device > 0.0 and avg_delta_device < 10000:
249 latency_t0_to_device_list.append(avg_delta_device)
250 else:
251 main.log.info("Results for t0-to-device ignored"+\
252 "due to excess in threshold")
253
254 #t0 to graph processing latency (end-to-end)
255 delta_graph_1 = int(graph_timestamp_1) - int(t0_tcp)
256
257 #Get average of delta from all instances
258 avg_delta_graph = int(delta_graph_1)
259
260 #Ensure avg delta meets the threshold before appending
261 if avg_delta_graph > 0.0 and avg_delta_graph < 10000:
262 latency_end_to_end_list.append(avg_delta_graph)
263 else:
264 main.log.info("Results for end-to-end ignored"+\
265 "due to excess in threshold")
266
267 #ofp to graph processing latency (ONOS processing)
268 delta_ofp_graph_1 = int(graph_timestamp_1) - int(t0_ofp)
269
270 avg_delta_ofp_graph = int(delta_ofp_graph_1)
271
272 if avg_delta_ofp_graph > 0.0 and avg_delta_ofp_graph < 10000:
273 latency_ofp_to_graph_list.append(avg_delta_ofp_graph)
274 else:
275 main.log.info("Results for ofp-to-graph "+\
276 "ignored due to excess in threshold")
277
278 #ofp to device processing latency (ONOS processing)
279 delta_ofp_device_1 = float(device_timestamp_1) - float(t0_ofp)
280
281 avg_delta_ofp_device = float(delta_ofp_device_1)
282
283 #NOTE: ofp - delta measurements are occasionally negative
284 # due to system time misalignment.
285 latency_ofp_to_device_list.append(avg_delta_ofp_device)
286
287 #TODO:
288 #Fetch logs upon threshold excess
289
290 main.log.info("ONOS1 delta end-to-end: "+
291 str(delta_graph_1) + " ms")
292
293 main.log.info("ONOS1 delta OFP - graph: "+
294 str(delta_ofp_graph_1) + " ms")
295
296 main.log.info("ONOS1 delta device - t0: "+
297 str(delta_device_1) + " ms")
298
299 main.step("Remove switch from controller")
300 main.Mininet1.delete_sw_controller("s1")
301
302 time.sleep(5)
303
304 #END of for loop iteration
305
306 #If there is at least 1 element in each list,
307 #pass the test case
308 if len(latency_end_to_end_list) > 0 and\
309 len(latency_ofp_to_graph_list) > 0 and\
310 len(latency_ofp_to_device_list) > 0 and\
311 len(latency_t0_to_device_list) > 0:
312 assertion = main.TRUE
313 elif len(latency_end_to_end_list) == 0:
314 #The appending of 0 here is to prevent
315 #the min,max,sum functions from failing
316 #below
317 latency_end_to_end_list.append(0)
318 assertion = main.FALSE
319 elif len(latency_ofp_to_graph_list) == 0:
320 latency_ofp_to_graph_list.append(0)
321 assertion = main.FALSE
322 elif len(latency_ofp_to_device_list) == 0:
323 latency_ofp_to_device_list.append(0)
324 assertion = main.FALSE
325 elif len(latency_t0_to_device_list) == 0:
326 latency_t0_to_device_list.append(0)
327 assertion = main.FALSE
328
329 #Calculate min, max, avg of latency lists
330 latency_end_to_end_max = \
331 int(max(latency_end_to_end_list))
332 latency_end_to_end_min = \
333 int(min(latency_end_to_end_list))
334 latency_end_to_end_avg = \
335 (int(sum(latency_end_to_end_list)) / \
336 len(latency_end_to_end_list))
337
338 latency_ofp_to_graph_max = \
339 int(max(latency_ofp_to_graph_list))
340 latency_ofp_to_graph_min = \
341 int(min(latency_ofp_to_graph_list))
342 latency_ofp_to_graph_avg = \
343 (int(sum(latency_ofp_to_graph_list)) / \
344 len(latency_ofp_to_graph_list))
345
346 latency_ofp_to_device_max = \
347 int(max(latency_ofp_to_device_list))
348 latency_ofp_to_device_min = \
349 int(min(latency_ofp_to_device_list))
350 latency_ofp_to_device_avg = \
351 (int(sum(latency_ofp_to_device_list)) / \
352 len(latency_ofp_to_device_list))
353
354 latency_t0_to_device_max = \
355 float(max(latency_t0_to_device_list))
356 latency_t0_to_device_min = \
357 float(min(latency_t0_to_device_list))
358 latency_t0_to_device_avg = \
359 (float(sum(latency_t0_to_device_list)) / \
360 len(latency_ofp_to_device_list))
361
362 main.log.report("Switch add - End-to-end latency: \n"+\
363 "Min: "+str(latency_end_to_end_min)+"\n"+\
364 "Max: "+str(latency_end_to_end_max)+"\n"+\
365 "Avg: "+str(latency_end_to_end_avg))
366 main.log.report("Switch add - OFP-to-Graph latency: \n"+\
367 "Min: "+str(latency_ofp_to_graph_min)+"\n"+\
368 "Max: "+str(latency_ofp_to_graph_max)+"\n"+\
369 "Avg: "+str(latency_ofp_to_graph_avg))
370 main.log.report("Switch add - t0-to-Device latency: \n"+\
371 "Min: "+str(latency_t0_to_device_min)+"\n"+\
372 "Max: "+str(latency_t0_to_device_max)+"\n"+\
373 "Avg: "+str(latency_t0_to_device_avg))
374
375 utilities.assert_equals(expect=main.TRUE, actual=assertion,
376 onpass="Switch latency test successful",
377 onfail="Switch latency test failed")
378
379 def CASE3(self, main):
380 '''
381 Bring port up / down and measure latency.
382 Port enable / disable is simulated by ifconfig up / down
383
384 In ONOS-next, we must ensure that the port we are
385 manipulating is connected to another switch with a valid
386 connection. Otherwise, graph view will not be updated.
387 '''
388 import time
389 import subprocess
390 import os
391 import requests
392 import json
393
394 ONOS1_ip = main.params['CTRL']['ip1']
395 ONOS_user = main.params['CTRL']['user']
396
397 default_sw_port = main.params['CTRL']['port1']
398
399 assertion = main.TRUE
400 #Number of iterations of case
401 num_iter = main.params['TEST']['numIter']
402
403 #Timestamp 'keys' for json metrics output.
404 #These are subject to change, hence moved into params
405 deviceTimestamp = main.params['JSON']['deviceTimestamp']
406 graphTimestamp = main.params['JSON']['graphTimestamp']
407
408 #NOTE: Some hardcoded variables you may need to configure
409 # besides the params
410
411 tshark_port_status = "OFP 130 Port Status"
412
413 tshark_port_up = "/tmp/tshark_port_up.txt"
414 tshark_port_down = "/tmp/tshark_port_down.txt"
415 interface_config = "s1-eth1"
416
417 main.log.report("Port enable / disable latency")
418
419 main.step("Assign switches s1 and s2 to controller 1")
420 main.Mininet1.assign_sw_controller(sw="1",ip1=ONOS1_ip,
421 port1=default_sw_port)
422 main.Mininet1.assign_sw_controller(sw="2",ip1=ONOS1_ip,
423 port1=default_sw_port)
424
425 #Give enough time for metrics to propagate the
426 #assign controller event. Otherwise, these events may
427 #carry over to our measurements
428 time.sleep(10)
429
430 main.step("Verify switch is assigned correctly")
431 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
432 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
433 if result_s1 == main.FALSE or result_s2 == main.FALSE:
434 main.log.info("Switch s1 was not assigned correctly")
435 assertion = main.FALSE
436 else:
437 main.log.info("Switch s1 was assigned correctly")
438
439 port_up_device_to_ofp_list = []
440 port_up_graph_to_ofp_list = []
441 port_down_device_to_ofp_list = []
442 port_down_graph_to_ofp_list = []
443
444 for i in range(0, int(num_iter)):
445 main.step("Starting wireshark capture for port status down")
446 main.ONOS1.tshark_grep(tshark_port_status,
447 tshark_port_down)
448
449 time.sleep(10)
450
451 #Disable interface that is connected to switch 2
452 main.step("Disable port: "+interface_config)
453 main.Mininet2.handle.sendline("sudo ifconfig "+
454 interface_config+" down")
455 main.Mininet2.handle.expect("\$")
456 time.sleep(10)
457
458 main.ONOS1.tshark_stop()
459 time.sleep(5)
460
461 #Copy tshark output file from ONOS to TestON instance
462 #/tmp directory
463 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
464 tshark_port_down+" /tmp/")
465
466 f_port_down = open(tshark_port_down, 'r')
467 #Get first line of port down event from tshark
468 f_line = f_port_down.readline()
469 obj_down = f_line.split(" ")
470 if len(f_line) > 0:
471 timestamp_begin_pt_down = int(float(obj_down[1]))*1000
472 main.log.info("Port down begin timestamp: "+
473 str(timestamp_begin_pt_down))
474 else:
475 main.log.info("Tshark output file returned unexpected"+
476 " results: "+str(obj_down))
477 timestamp_begin_pt_down = 0
478
479 f_port_down.close()
480
481 main.log.info("TEST tshark obj: "+str(obj_down))
482
483 main.step("Obtain t1 by REST call")
484 json_str_1 = main.ONOS1cli.topology_events_metrics()
485
486 main.log.info("TEST json_str 1: "+str(json_str_1))
487
488 json_obj_1 = json.loads(json_str_1)
489
490 time.sleep(5)
491
492 #Obtain graph timestamp. This timestsamp captures
493 #the epoch time at which the topology graph was updated.
494 graph_timestamp_1 = \
495 json_obj_1[graphTimestamp]['value']
496
497 #Obtain device timestamp. This timestamp captures
498 #the epoch time at which the device event happened
499 device_timestamp_1 = \
500 json_obj_1[deviceTimestamp]['value']
501
502 #Get delta between graph event and OFP
503 pt_down_graph_to_ofp_1 = int(graph_timestamp_1) -\
504 int(timestamp_begin_pt_down)
505
506 #Get delta between device event and OFP
507 pt_down_device_to_ofp_1 = int(device_timestamp_1) -\
508 int(timestamp_begin_pt_down)
509
510 #Caluclate average across clusters
511 pt_down_graph_to_ofp_avg = int(pt_down_graph_to_ofp_1)
512 pt_down_device_to_ofp_avg = int(pt_down_device_to_ofp_1)
513
514 if pt_down_graph_to_ofp_avg > 0.0 and \
515 pt_down_graph_to_ofp_avg < 1000:
516 port_down_graph_to_ofp_list.append(
517 pt_down_graph_to_ofp_avg)
518 main.log.info("Port down: graph to ofp avg: "+
519 str(pt_down_graph_to_ofp_avg) + " ms")
520 else:
521 main.log.info("Average port down graph-to-ofp result" +
522 " exceeded the threshold: "+
523 str(pt_down_graph_to_ofp_avg))
524
525 if pt_down_device_to_ofp_avg > 0 and \
526 pt_down_device_to_ofp_avg < 1000:
527 port_down_device_to_ofp_list.append(
528 pt_down_device_to_ofp_avg)
529 main.log.info("Port down: device to ofp avg: "+
530 str(pt_down_device_to_ofp_avg) + " ms")
531 else:
532 main.log.info("Average port down device-to-ofp result" +
533 " exceeded the threshold: "+
534 str(pt_down_device_to_ofp_avg))
535
536 #Port up events
537 main.step("Enable port and obtain timestamp")
538 main.step("Starting wireshark capture for port status up")
539 main.ONOS1.tshark_grep("OFP 130 Port Status", tshark_port_up)
540 time.sleep(5)
541
542 main.Mininet2.handle.sendline("sudo ifconfig "+
543 interface_config+" up")
544 main.Mininet2.handle.expect("\$")
545 time.sleep(10)
546
547 main.ONOS1.tshark_stop()
548
549 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
550 tshark_port_up+" /tmp/")
551
552 f_port_up = open(tshark_port_up, 'r')
553 f_line = f_port_up.readline()
554 obj_up = f_line.split(" ")
555 if len(f_line) > 0:
556 timestamp_begin_pt_up = int(float(obj_up[1]))*1000
557 main.log.info("Port up begin timestamp: "+
558 str(timestamp_begin_pt_up))
559 else:
560 main.log.info("Tshark output file returned unexpected"+
561 " results.")
562 timestamp_begin_pt_up = 0
563
564 f_port_up.close()
565
566 main.step("Obtain t1 by REST call")
567 json_str_1 = main.ONOS1cli.topology_events_metrics()
568
569 json_obj_1 = json.loads(json_str_1)
570
571 #Obtain graph timestamp. This timestsamp captures
572 #the epoch time at which the topology graph was updated.
573 graph_timestamp_1 = \
574 json_obj_1[graphTimestamp]['value']
575
576 #Obtain device timestamp. This timestamp captures
577 #the epoch time at which the device event happened
578 device_timestamp_1 = \
579 json_obj_1[deviceTimestamp]['value']
580
581 #Get delta between graph event and OFP
582 pt_up_graph_to_ofp_1 = int(graph_timestamp_1) -\
583 int(timestamp_begin_pt_up)
584
585 #Get delta between device event and OFP
586 pt_up_device_to_ofp_1 = int(device_timestamp_1) -\
587 int(timestamp_begin_pt_up)
588
589 pt_up_graph_to_ofp_avg = float(pt_up_graph_to_ofp_1)
590
591 pt_up_device_to_ofp_avg = float(pt_up_device_to_ofp_1)
592
593 if pt_up_graph_to_ofp_avg > 0 and \
594 pt_up_graph_to_ofp_avg < 1000:
595 port_up_graph_to_ofp_list.append(
596 pt_up_graph_to_ofp_avg)
597 main.log.info("Port down: graph to ofp avg: "+
598 str(pt_up_graph_to_ofp_avg) + " ms")
599 else:
600 main.log.info("Average port up graph-to-ofp result"+
601 " exceeded the threshold: "+
602 str(pt_up_graph_to_ofp_avg))
603
604 if pt_up_device_to_ofp_avg > 0 and \
605 pt_up_device_to_ofp_avg < 1000:
606 port_up_device_to_ofp_list.append(
607 pt_up_device_to_ofp_avg)
608 main.log.info("Port up: device to ofp avg: "+
609 str(pt_up_device_to_ofp_avg) + " ms")
610 else:
611 main.log.info("Average port up device-to-ofp result"+
612 " exceeded the threshold: "+
613 str(pt_up_device_to_ofp_avg))
614
615 #END ITERATION FOR LOOP
616
617 #Check all list for latency existence and set assertion
618 if (port_down_graph_to_ofp_list and port_down_device_to_ofp_list\
619 and port_up_graph_to_ofp_list and port_up_device_to_ofp_list):
620 assertion = main.TRUE
621
622 #Calculate and report latency measurements
623 port_down_graph_to_ofp_min = min(port_down_graph_to_ofp_list)
624 port_down_graph_to_ofp_max = max(port_down_graph_to_ofp_list)
625 port_down_graph_to_ofp_avg = \
626 (sum(port_down_graph_to_ofp_list) /
627 len(port_down_graph_to_ofp_list))
628
629 main.log.report("Port down graph-to-ofp Min: "+
630 str(port_down_graph_to_ofp_min)+" ms Max: "+
631 str(port_down_graph_to_ofp_max)+" ms Avg: "+
632 str(port_down_graph_to_ofp_avg))
633
634 port_down_device_to_ofp_min = min(port_down_device_to_ofp_list)
635 port_down_device_to_ofp_max = max(port_down_device_to_ofp_list)
636 port_down_device_to_ofp_avg = \
637 (sum(port_down_device_to_ofp_list) /\
638 len(port_down_device_to_ofp_list))
639
640 main.log.report("Port down device-to-ofp Min: "+
641 str(port_down_device_to_ofp_min)+" ms Max: "+
642 str(port_down_device_to_ofp_max)+" ms Avg: "+
643 str(port_down_device_to_ofp_avg))
644
645 port_up_graph_to_ofp_min = min(port_up_graph_to_ofp_list)
646 port_up_graph_to_ofp_max = max(port_up_graph_to_ofp_list)
647 port_up_graph_to_ofp_avg = \
648 (sum(port_up_graph_to_ofp_list) /\
649 len(port_up_graph_to_ofp_list))
650
651 main.log.report("Port up graph-to-ofp Min: "+
652 str(port_up_graph_to_ofp_min)+" ms Max: "+
653 str(port_up_graph_to_ofp_max)+" ms Avg: "+
654 str(port_up_graph_to_ofp_avg))
655
656 port_up_device_to_ofp_min = min(port_up_device_to_ofp_list)
657 port_up_device_to_ofp_max = max(port_up_device_to_ofp_list)
658 port_up_device_to_ofp_avg = \
659 (sum(port_up_device_to_ofp_list) /\
660 len(port_up_device_to_ofp_list))
661
662 main.log.report("Port up device-to-ofp Min: "+
663 str(port_up_device_to_ofp_min)+" ms Max: "+
664 str(port_up_device_to_ofp_max)+" ms Avg: "+
665 str(port_up_device_to_ofp_avg))
666
667 utilities.assert_equals(expect=main.TRUE, actual=assertion,
668 onpass="Port discovery latency calculation successful",
669 onfail="Port discovery test failed")
670
671 def CASE4(self, main):
672 '''
673 Link down event using loss rate 100%
674
675 Important:
676 Use a simple 2 switch topology with 1 link between
677 the two switches. Ensure that mac addresses of the
678 switches are 1 / 2 respectively
679 '''
680 import time
681 import subprocess
682 import os
683 import requests
684 import json
685
686 ONOS1_ip = main.params['CTRL']['ip1']
687 ONOS_user = main.params['CTRL']['user']
688
689 default_sw_port = main.params['CTRL']['port1']
690
691 #Number of iterations of case
692 num_iter = main.params['TEST']['numIter']
693
694 #Timestamp 'keys' for json metrics output.
695 #These are subject to change, hence moved into params
696 deviceTimestamp = main.params['JSON']['deviceTimestamp']
697 linkTimestamp = main.params['JSON']['linkTimestamp']
698 graphTimestamp = main.params['JSON']['graphTimestamp']
699
700 assertion = main.TRUE
701 #Link event timestamp to system time list
702 link_down_link_to_system_list = []
703 link_up_link_to_system_list = []
704 #Graph event timestamp to system time list
705 link_down_graph_to_system_list = []
706 link_up_graph_to_system_list = []
707
708 main.log.report("Add / remove link latency between "+
709 "two switches")
710
711 main.step("Assign all switches")
712 main.Mininet1.assign_sw_controller(sw="1",
713 ip1=ONOS1_ip, port1=default_sw_port)
714 main.Mininet1.assign_sw_controller(sw="2",
715 ip1=ONOS1_ip, port1=default_sw_port)
716
717 main.step("Verifying switch assignment")
718 result_s1 = main.Mininet1.get_sw_controller(sw="s1")
719 result_s2 = main.Mininet1.get_sw_controller(sw="s2")
720
721 #Allow time for events to finish before taking measurements
722 time.sleep(10)
723
724 link_down = False
725 #Start iteration of link event test
726 for i in range(0, int(num_iter)):
727 main.step("Getting initial system time as t0")
728
729 timestamp_link_down_t0 = time.time() * 1000
730 #Link down is simulated by 100% loss rate using traffic
731 #control command
732 main.Mininet1.handle.sendline(
733 "sh tc qdisc add dev s1-eth1 root netem loss 100%")
734
735 #TODO: Iterate through 'links' command to verify that
736 # link s1 -> s2 went down (loop timeout 30 seconds)
737 # on all 3 ONOS instances
738 main.log.info("Checking ONOS for link update")
739 loop_count = 0
740 while( not link_down and loop_count < 30 ):
741 json_str = main.ONOS1cli.links()
742
743 if not json_str:
744 main.log.error("CLI command returned error ")
745 break
746 else:
747 json_obj = json.loads(json_str)
748 for obj in json_obj:
749 if '01' not in obj['src']['device']:
750 link_down = True
751 main.log.report("Link down from "+
752 "s1 -> s2 on ONOS1 detected")
753 loop_count += 1
754 #If CLI doesn't like the continuous requests
755 #and exits in this loop, increase the sleep here.
756 #Consequently, while loop timeout will increase
757 time.sleep(1)
758
759 #Give time for metrics measurement to catch up
760 #NOTE: May need to be configured more accurately
761 time.sleep(10)
762 #If we exited the while loop and link down 1,2,3 are still
763 #false, then ONOS has failed to discover link down event
764 if not link_down:
765 main.log.info("Link down discovery failed")
766
767 link_down_lat_graph1 = 0
768 link_down_lat_device1 = 0
769 assertion = main.FALSE
770 else:
771 json_topo_metrics_1 =\
772 main.ONOS1cli.topology_events_metrics()
773 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
774
775 main.log.info("Obtaining graph and device timestamp")
776 graph_timestamp_1 = \
777 json_topo_metrics_1[graphTimestamp]['value']
778
779 link_timestamp_1 = \
780 json_topo_metrics_1[linkTimestamp]['value']
781
782 if graph_timestamp_1 and link_timestamp_1:
783 link_down_lat_graph1 = int(graph_timestamp_1) -\
784 timestamp_link_down_t0
785
786 link_down_lat_link1 = int(link_timestamp_1) -\
787 timestamp_link_down_t0
788 else:
789 main.log.error("There was an error calculating"+
790 " the delta for link down event")
791 link_down_lat_graph1 = 0
792
793 link_down_lat_device1 = 0
794
795 main.log.report("Link down latency ONOS1 iteration "+
796 str(i)+" (end-to-end): "+
797 str(link_down_lat_graph1)+" ms")
798
799 main.log.report("Link down latency ONOS1 iteration "+
800 str(i)+" (link-event-to-system-timestamp): "+
801 str(link_down_lat_link1)+" ms")
802
803 #Calculate avg of node calculations
804 link_down_lat_graph_avg = link_down_lat_graph1
805 link_down_lat_link_avg = link_down_lat_link1
806
807 #Set threshold and append latency to list
808 if link_down_lat_graph_avg > 0.0 and\
809 link_down_lat_graph_avg < 30000:
810 link_down_graph_to_system_list.append(
811 link_down_lat_graph_avg)
812 else:
813 main.log.info("Link down latency exceeded threshold")
814 main.log.info("Results for iteration "+str(i)+
815 "have been omitted")
816 if link_down_lat_link_avg > 0.0 and\
817 link_down_lat_link_avg < 30000:
818 link_down_link_to_system_list.append(
819 link_down_lat_link_avg)
820 else:
821 main.log.info("Link down latency exceeded threshold")
822 main.log.info("Results for iteration "+str(i)+
823 "have been omitted")
824
825 #NOTE: To remove loss rate and measure latency:
826 # 'sh tc qdisc del dev s1-eth1 root'
827 timestamp_link_up_t0 = time.time() * 1000
828 main.Mininet1.handle.sendline("sh tc qdisc del dev "+
829 "s1-eth1 root")
830 main.Mininet1.handle.expect("mininet>")
831
832 main.log.info("Checking ONOS for link update")
833
834 link_down1 = True
835 loop_count = 0
836 while( link_down1 and loop_count < 30 ):
837 json_str1 = main.ONOS1cli.links()
838 if not json_str1:
839 main.log.error("CLI command returned error ")
840 break
841 else:
842 json_obj1 = json.loads(json_str1)
843
844 for obj1 in json_obj1:
845 if '01' in obj1['src']['device']:
846 link_down1 = False
847 main.log.report("Link up from "+
848 "s1 -> s2 on ONOS1 detected")
849 loop_count += 1
850 time.sleep(1)
851
852 if link_down1:
853 main.log.info("Link up discovery failed")
854 link_up_lat_graph1 = 0
855 link_up_lat_device1 = 0
856 assertion = main.FALSE
857 else:
858 json_topo_metrics_1 =\
859 main.ONOS1cli.topology_events_metrics()
860 json_topo_metrics_1 = json.loads(json_topo_metrics_1)
861
862 main.log.info("Obtaining graph and device timestamp")
863 graph_timestamp_1 = \
864 json_topo_metrics_1[graphTimestamp]['value']
865
866 link_timestamp_1 = \
867 json_topo_metrics_1[linkTimestamp]['value']
868
869 if graph_timestamp_1 and link_timestamp_1:
870 link_up_lat_graph1 = int(graph_timestamp_1) -\
871 timestamp_link_up_t0
872 link_up_lat_link1 = int(link_timestamp_1) -\
873 timestamp_link_up_t0
874 else:
875 main.log.error("There was an error calculating"+
876 " the delta for link down event")
877 link_up_lat_graph1 = 0
878 link_up_lat_device1 = 0
879
880 main.log.info("Link up latency ONOS1 iteration "+
881 str(i)+" (end-to-end): "+
882 str(link_up_lat_graph1)+" ms")
883
884 main.log.info("Link up latency ONOS1 iteration "+
885 str(i)+" (link-event-to-system-timestamp): "+
886 str(link_up_lat_link1)+" ms")
887
888 #Calculate avg of node calculations
889 link_up_lat_graph_avg = link_up_lat_graph1
890 link_up_lat_link_avg = link_up_lat_link1
891
892 #Set threshold and append latency to list
893 if link_up_lat_graph_avg > 0.0 and\
894 link_up_lat_graph_avg < 30000:
895 link_up_graph_to_system_list.append(
896 link_up_lat_graph_avg)
897 else:
898 main.log.info("Link up latency exceeded threshold")
899 main.log.info("Results for iteration "+str(i)+
900 "have been omitted")
901 if link_up_lat_link_avg > 0.0 and\
902 link_up_lat_link_avg < 30000:
903 link_up_link_to_system_list.append(
904 link_up_lat_link_avg)
905 else:
906 main.log.info("Link up latency exceeded threshold")
907 main.log.info("Results for iteration "+str(i)+
908 "have been omitted")
909
910 #Calculate min, max, avg of list and report
911 link_down_min = min(link_down_graph_to_system_list)
912 link_down_max = max(link_down_graph_to_system_list)
913 link_down_avg = sum(link_down_graph_to_system_list) / \
914 len(link_down_graph_to_system_list)
915 link_up_min = min(link_up_graph_to_system_list)
916 link_up_max = max(link_up_graph_to_system_list)
917 link_up_avg = sum(link_up_graph_to_system_list) / \
918 len(link_up_graph_to_system_list)
919
920 main.log.report("Link down latency - Min: "+
921 str(link_down_min)+"ms Max: "+
922 str(link_down_max)+"ms Avg: "+
923 str(link_down_avg)+"ms")
924 main.log.report("Link up latency - Min: "+
925 str(link_up_min)+"ms Max: "+
926 str(link_up_max)+"ms Avg: "+
927 str(link_up_avg)+"ms")
928
929 utilities.assert_equals(expect=main.TRUE, actual=assertion,
930 onpass="Link discovery latency calculation successful",
931 onfail="Link discovery latency case failed")
932
933 def CASE5(self, main):
934 '''
935 100 Switch discovery latency
936
937 Important:
938 This test case can be potentially dangerous if
939 your machine has previously set iptables rules.
940 One of the steps of the test case will flush
941 all existing iptables rules.
942 Note:
943 You can specify the number of switches in the
944 params file to adjust the switch discovery size
945 (and specify the corresponding topology in Mininet1
946 .topo file)
947 '''
948 import time
949 import subprocess
950 import os
951 import requests
952 import json
953
954 ONOS1_ip = main.params['CTRL']['ip1']
955 MN1_ip = main.params['MN']['ip1']
956 ONOS_user = main.params['CTRL']['user']
957
958 default_sw_port = main.params['CTRL']['port1']
959
960 #Number of iterations of case
961 num_iter = main.params['TEST']['numIter']
962 num_sw = main.params['TEST']['numSwitch']
963
964 #Timestamp 'keys' for json metrics output.
965 #These are subject to change, hence moved into params
966 deviceTimestamp = main.params['JSON']['deviceTimestamp']
967 graphTimestamp = main.params['JSON']['graphTimestamp']
968
969 tshark_ofp_output = "/tmp/tshark_ofp_"+num_sw+"sw.txt"
970 tshark_tcp_output = "/tmp/tshark_tcp_"+num_sw+"sw.txt"
971
972 tshark_ofp_result_list = []
973 tshark_tcp_result_list = []
974
975 main.case(num_sw+" Switch discovery latency")
976 main.step("Assigning all switches to ONOS1")
977 for i in range(1, int(num_sw)+1):
978 main.Mininet1.assign_sw_controller(
979 sw=str(i),
980 ip1=ONOS1_ip,
981 port1=default_sw_port)
982
983 #Ensure that nodes are configured with ptpd
984 #Just a warning message
985 main.log.info("Please check ptpd configuration to ensure"+\
986 " All nodes' system times are in sync")
987 time.sleep(5)
988
989 for i in range(0, int(num_iter)):
990
991 main.step("Set iptables rule to block incoming sw connections")
992 #Set iptables rule to block incoming switch connections
993 #The rule description is as follows:
994 # Append to INPUT rule,
995 # behavior DROP that matches following:
996 # * packet type: tcp
997 # * source IP: MN1_ip
998 # * destination PORT: 6633
999 main.ONOS1.handle.sendline(
1000 "sudo iptables -A INPUT -p tcp -s "+MN1_ip+
1001 " --dport "+default_sw_port+" -j DROP")
1002 main.ONOS1.handle.expect("\$")
1003 # Append to OUTPUT rule,
1004 # behavior DROP that matches following:
1005 # * packet type: tcp
1006 # * source IP: MN1_ip
1007 # * destination PORT: 6633
1008 main.ONOS1.handle.sendline(
1009 "sudo iptables -A OUTPUT -p tcp -s "+MN1_ip+
1010 " --dport "+default_sw_port+" -j DROP")
1011 main.ONOS1.handle.expect("\$")
1012 #Give time to allow rule to take effect
1013 #NOTE: Sleep period may need to be configured
1014 # based on the number of switches in the topology
1015 main.log.info("Please wait for switch connection to "+
1016 "time out")
1017 time.sleep(60)
1018
1019 #Gather vendor OFP with tshark
1020 main.ONOS1.tshark_grep("OFP 86 Vendor",
1021 tshark_ofp_output)
1022 main.ONOS1.tshark_grep("TCP 74 ",
1023 tshark_tcp_output)
1024
1025 #NOTE: Remove all iptables rule quickly (flush)
1026 # Before removal, obtain TestON timestamp at which
1027 # removal took place
1028 # (ensuring nodes are configured via ptp)
1029 # sudo iptables -F
1030
1031 t0_system = time.time() * 1000
1032 main.ONOS1.handle.sendline(
1033 "sudo iptables -F")
1034
1035 #Counter to track loop count
1036 counter_loop = 0
1037 counter_avail1 = 0
1038 onos1_dev = False
1039 while counter_loop < 60:
1040 #Continue to check devices for all device
1041 #availability. When all devices in all 3
1042 #ONOS instances indicate that devices are available
1043 #obtain graph event timestamp for t1.
1044 device_str_obj1 = main.ONOS1cli.devices()
1045 device_json1 = json.loads(device_str_obj1)
1046
1047 for device1 in device_json1:
1048 if device1['available'] == True:
1049 counter_avail1 += 1
1050 if counter_avail1 == int(num_sw):
1051 onos1_dev = True
1052 main.log.info("All devices have been "+
1053 "discovered on ONOS1")
1054 else:
1055 counter_avail1 = 0
1056
1057 if onos1_dev:
1058 main.log.info("All devices have been discovered "+
1059 "on all ONOS instances")
1060 json_str_topology_metrics_1 =\
1061 main.ONOS1cli.topology_events_metrics()
1062 #Exit while loop if all devices discovered
1063 break
1064
1065 counter_loop += 1
1066 #Give some time in between CLI calls
1067 #(will not affect measurement)
1068 time.sleep(3)
1069
1070 main.ONOS1.tshark_stop()
1071
1072 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1073 tshark_ofp_output+" /tmp/")
1074 os.system("scp "+ONOS_user+"@"+ONOS1_ip+":"+
1075 tshark_tcp_output+" /tmp/")
1076 ofp_file = open(tshark_ofp_output, 'r')
1077
1078 #The following is for information purpose only.
1079 #TODO: Automate OFP output analysis
1080 main.log.info("Tshark OFP Vendor output: ")
1081 for line in ofp_file:
1082 tshark_ofp_result_list.append(line)
1083 main.log.info(line)
1084
1085 ofp_file.close()
1086
1087 tcp_file = open(tshark_tcp_output, 'r')
1088 main.log.info("Tshark TCP 74 output: ")
1089 for line in tcp_file:
1090 tshark_tcp_result_list.append(line)
1091 main.log.info(line)
1092
1093 tcp_file.close()
1094
1095 json_obj_1 = json.loads(json_str_topology_metrics_1)
1096
1097 graph_timestamp_1 = \
1098 json_obj_1[graphTimestamp]['value']
1099
1100 main.log.info(
1101 int(graph_timestamp_1) - int(t0_system))
1102
1103
1104
1105
1106
1107
1108