Gitiles
Code Review Sign In
gerrit.onosproject.org / OnosSystemTest / eae03dc1df3362d7ed6027935f39e84c02ee7258 / . / TestON / tests / SCPFswitchLat / SCPFswitchLat.py
blob: 81cbf16eb44bbd73d4060cea372b1cc5bef71a26 [file] [log] [blame]
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700[diff] [blame]1# CASE1 starts number of nodes specified in param file
2#
3# cameron@onlab.us
4
5class SCPFswitchLat:
6
7 def __init__( self ):
8 self.default = ''
9
10 def CASE1( self, main ):
11 import sys
12 import os.path
13 import os
14 import time
15
16 global init
17 try:
18 if type(init) is not bool:
19 init = Fals
20 except NameError:
21 init = False
22
23 #Load values from params file
24 checkoutBranch = main.params[ 'GIT' ][ 'checkout' ]
25 gitPull = main.params[ 'GIT' ][ 'autopull' ]
26 cellName = main.params[ 'ENV' ][ 'cellName' ]
27 Apps = main.params[ 'ENV' ][ 'cellApps' ]
28 BENCHIp = main.params[ 'BENCH' ][ 'ip' ]
29 MN1Ip = main.params[ 'MN' ][ 'ip1' ]
30 main.maxNodes = int(main.params[ 'max' ])
31 cellName = main.params[ 'ENV' ][ 'cellName' ]
32 homeDir = os.path.expanduser('~')
33 topoCfgFile = main.params['TEST']['topoConfigFile']
34 topoCfgName = main.params['TEST']['topoConfigName']
35 switchEventResultPath = main.params['DB']['switchEventResultPath']
36 skipMvn = main.params ['TEST']['mci']
37 testONpath = os.getcwd() #testON/bin
38 user = main.params[ 'CTRL' ][ 'user' ]
39
40 # -- INIT SECTION, ONLY RUNS ONCE -- #
41 if init == False:
42 init = True
43 global clusterCount #number of nodes running
44 global scale
45 global commit
46 global timeToPost
47 global runNum
48 global jenkinsBuildNumber
49 global CLIs
50 CLIs = []
51 main.ONOSIp = []
52
53 for i in range( 1, 8 ):
54 CLIs.append( getattr( main, 'ONOS' + str( i ) + 'cli' ) )
55
56 timeToPost = time.strftime('%Y-%m-%d %H:%M:%S')
57 runNum = time.strftime('%d%H%M%S')
58
59 try:
60 jenkinsBuildNumber = str(os.environ['BUILD_NUMBER'])
61 main.log.report( 'Jenkins build number: ' + jenkinsBuildNumber )
62 except KeyError:
63 jenkinsBuildNumber = str(0)
64 main.log.info( 'Job is not run by jenkins. ' + 'Build number set to: ' + jenkinsBuildNumber)
65
66 clusterCount = 0
67 main.ONOSIp = main.ONOSbench.getOnosIps()
68
69 scale = (main.params[ 'SCALE' ]).split(",")
70 clusterCount = int(scale[0])
71
72 #mvn clean install, for debugging set param 'skipCleanInstall' to yes to speed up test
73 if skipMvn != "off":
74 mvnResult = main.ONOSbench.cleanInstall()
75
76 #git
77 main.step( "Git checkout and pull " + checkoutBranch )
78 if gitPull == 'on':
79 checkoutResult = main.ONOSbench.gitCheckout( checkoutBranch )
80 pullResult = main.ONOSbench.gitPull()
81
82 else:
83 checkoutResult = main.TRUE
84 pullResult = main.TRUE
85 main.log.info( "Skipped git checkout and pull" )
86
87 main.log.step("Grabbing commit number")
88 commit = main.ONOSbench.getVersion() ####
89 commit = (commit.split(" "))[1]
90
91 temp = testONpath.replace("bin","") + "tests/SCPFswitchLat/Dependency/"
92 main.ONOSbench.copyMininetFile("topo-perf-1sw.py", temp, user, "localhost" )
93 #main.ONOSbench.handle.expect(":~")
94
95 main.step('Clearing previous DB log file')
96 print switchEventResultPath
97 fSwitchLog = open(switchEventResultPath, "w+")
98 fSwitchLog.write("")
99 fSwitchLog.close()
100
101 # -- END OF INIT SECTION --#
102
103 main.log.step("Adjusting scale")
104 clusterCount = int(scale[0])
105 scale.remove(scale[0])
106
107 #kill off all onos processes
108 main.log.step("Safety check, killing all ONOS processes before initiating enviornment setup")
109 for node in range(main.maxNodes):
110 main.ONOSbench.onosDie(main.ONOSIp[node])
111
112 #Uninstall everywhere
113 main.log.step( "Cleaning Enviornment..." )
114 for i in range(main.maxNodes):
115 main.log.info(" Uninstalling ONOS " + str(i) )
116 main.ONOSbench.onosUninstall( main.ONOSIp[i] )
117 main.log.info("Sleep 10 second for uninstall to settle...")
118 time.sleep(10)
119 main.ONOSbench.handle.sendline(" ")
120 main.ONOSbench.handle.expect(":~")
121
122 #construct the cell file
123 main.log.info("Creating cell file")
124 cellIp = []
125 for node in range (clusterCount):
126 cellIp.append(main.ONOSIp[node])
127
128 main.ONOSbench.createCellFile(main.ONOSbench.ip_address, cellName, MN1Ip, str(Apps), cellIp)
129
130 main.step( "Set Cell" )
131 main.ONOSbench.setCell(cellName)
132
133 main.step( "Creating ONOS package" )
134 packageResult = main.ONOSbench.onosPackage()
135
136 main.step( "verify cells" )
137 verifyCellResult = main.ONOSbench.verifyCell()
138
139 main.step('Starting mininet topology ')
140 main.Mininet1.startNet()
141
142 main.log.report( "Initializeing " + str( clusterCount ) + " node cluster." )
143 for node in range(clusterCount):
144 main.log.info("Starting ONOS " + str(node) + " at IP: " + main.ONOSIp[node])
145 main.ONOSbench.onosInstall( node=main.ONOSIp[node])
146
147 for i in range(50):
148 time.sleep(15)
149 print "attempt " + str(i)
150 main.ONOSbench.handle.sendline("onos $OC1 summary")
151 main.ONOSbench.handle.expect(":~")
152 print main.ONOSbench.handle.before
153 if "nodes=" in main.ONOSbench.handle.before:
154 break
155
156 for node in range(clusterCount):
157 for i in range( 2 ):
158 isup = main.ONOSbench.isup( main.ONOSIp[node] )
159 if isup:
160 main.log.info("ONOS " + str(node) + " is up\n")
161 break
162 if not isup:
163 main.log.report( "ONOS " + str(node) + " didn't start!" )
164 main.log.info("Startup sequence complete")
165
166 #time.sleep(20)
167
168 main.step('Start onos cli')
169 for i in range(0,clusterCount):
170 cli1 = CLIs[i].startOnosCli(main.ONOSIp[i])
171
172 main.step( 'Configuring application parameters' )
173
174 configName = 'org.onosproject.net.topology.impl.DefaultTopologyProvider'
175 configParam = 'maxEvents 1'
176 main.ONOSbench.onosCfgSet( main.ONOSIp[0], configName, configParam )
177 configParam = 'maxBatchMs 0'
178 main.ONOSbench.onosCfgSet( main.ONOSIp[0], configName, configParam )
179 configParam = 'maxIdleMs 0'
180 main.ONOSbench.onosCfgSet( main.ONOSIp[0], configName, configParam )
181
182 def CASE2(self, main):
183 print "Cluster size: " + str(clusterCount)
184 """
185 Assign s3 to ONOSbench and measure latency
186
187 There are 4 levels of latency measurements to this test:
188 1 ) End-to-end measurement: Complete end-to-end measurement
189 from TCP ( SYN/ACK ) handshake to Graph change
190 2 ) OFP-to-graph measurement: 'ONOS processing' snippet of
191 measurement from OFP Vendor message to Graph change
192 3 ) OFP-to-device measurement: 'ONOS processing without
193 graph change' snippet of measurement from OFP vendor
194 message to Device change timestamp
195 4 ) T0-to-device measurement: Measurement that includes
196 the switch handshake to devices timestamp without
197 the graph view change. ( TCP handshake -> Device
198 change )
199 """
200 import time
201 import subprocess
202 import json
203 import requests
204 import os
205 import numpy
206
207 ONOSUser = main.params['CTRL']['user']
208 numIter = main.params['TEST']['numIter']
209 iterIgnore = int(main.params['TEST']['iterIgnore'])
210
211 deviceTimestampKey = main.params['JSON']['deviceTimestamp']
212 graphTimestampKey = main.params['JSON']['graphTimestamp']
213
214 debugMode = main.params['TEST']['debugMode']
215 onosLog = main.params['TEST']['onosLogFile']
216 resultPath = main.params['DB']['switchEventResultPath']
217 thresholdStr = main.params['TEST']['singleSwThreshold']
218 thresholdObj = thresholdStr.split(',')
219 thresholdMin = int(thresholdObj[0])
220 thresholdMax = int(thresholdObj[1])
221
222 # Look for 'role-request' messages,
223 # which replaces the 'vendor' messages previously seen
224 # on OVS 2.0.1
225 tsharkTcpString = main.params[ 'TSHARK' ][ 'tcpSynAck' ]
226 tsharkFeatureReply = main.params[ 'TSHARK' ][ 'featureReply' ]
227 tsharkRoleRequest = main.params[ 'TSHARK' ][ 'roleRequest' ]
228 tsharkOfString = main.params[ 'TSHARK' ][ 'ofpRoleReply' ]
229 tsharkFinAckSequence = main.params[ 'TSHARK' ][ 'finAckSequence' ]
230
231 tsharkOfOutput = '/tmp/tshark_of_topo.txt'
232 tsharkTcpOutput = '/tmp/tshark_tcp_topo.txt'
233 tsharkRoleOutput = '/tmp/tshark_role_request.txt'
234 tsharkFeatureOutput = '/tmp/tshark_feature_reply.txt'
235 tsharkFinAckOutput = '/tmp/tshark_fin_ack.txt'
236
237 # Switch connect measurement list
238 # TCP Syn/Ack -> Feature Reply latency collection for each node
239 tcpToFeatureLatNodeIter = numpy.zeros((clusterCount, int(numIter)))
240 # Feature Reply -> Role Request latency collection for each node
241 featureToRoleRequestLatNodeIter = numpy.zeros((clusterCount,
242 int(numIter)))
243 # Role Request -> Role Reply latency collection for each node
244 roleRequestToRoleReplyLatNodeIter = numpy.zeros((clusterCount,
245 int(numIter)))
246 # Role Reply -> Device Update latency collection for each node
247 roleReplyToDeviceLatNodeIter = numpy.zeros((clusterCount,
248 int(numIter)))
249 # Device Update -> Graph Update latency collection for each node
250 deviceToGraphLatNodeIter = numpy.zeros((clusterCount,
251 int(numIter)))
252 endToEndLatNodeIter = numpy.zeros((clusterCount, int(numIter)))
253
254 # Switch disconnect measurement lists
255 # Mininet Fin / Ack -> Mininet Ack
256 finAckTransactionLatNodeIter = numpy.zeros((clusterCount,
257 int(numIter)))
258 # Mininet Ack -> Device Event
259 ackToDeviceLatNodeIter = numpy.zeros((clusterCount,
260 int(numIter)))
261 # Device event -> Graph event
262 deviceToGraphDiscLatNodeIter = numpy.zeros((clusterCount,
263 int(numIter)))
264 endToEndDiscLatNodeIter = numpy.zeros((clusterCount, int(numIter)))
265
266 assertion = main.TRUE
267 localTime = time.strftime('%x %X')
268 localTime = localTime.replace('/', '')
269 localTime = localTime.replace(' ', '_')
270 localTime = localTime.replace(':', '')
271
272 if debugMode == 'on':
273 main.ONOSbench.tsharkPcap('eth0', '/tmp/single_sw_lat_pcap_' + localTime)
274 main.log.info('Debug mode is on')
275
276 main.log.report('Latency of adding one switch to controller')
277 main.log.report('First ' + str(iterIgnore) + ' iterations ignored' + ' for jvm warmup time')
278 main.log.report('Total iterations of test: ' + str(numIter))
279
280 for i in range(0, int(numIter)):
281 main.log.info('Starting tshark capture')
282 main.ONOSbench.tsharkGrep(tsharkTcpString, tsharkTcpOutput)
283 main.ONOSbench.tsharkGrep(tsharkOfString, tsharkOfOutput)
284 main.ONOSbench.tsharkGrep(tsharkRoleRequest, tsharkRoleOutput)
285 main.ONOSbench.tsharkGrep(tsharkFeatureReply, tsharkFeatureOutput)
286
287 time.sleep(10)
288
289 main.log.info('Assigning s3 to controller')
290 main.Mininet1.assignSwController(sw='s3',
291 ip=main.ONOSIp[0])
292
293 jsonStr = []
294 for node in range (0, clusterCount):
295 metricsSwUp = CLIs[node].topologyEventsMetrics()
296 jsonStr.append(metricsSwUp)
297
298 time.sleep(10)
299
300 main.log.info('Stopping all Tshark processes')
301 main.ONOSbench.tsharkStop()
302
303 time.sleep(5)
304
305 '''
306 main.log.info('Copying over tshark files')
307 os.system('scp ' + ONOSUser + '@' + main.ONOSIp[0] +
308 ':' + tsharkTcpOutput + ' /tmp/')
309 os.system('scp ' + ONOSUser + '@' + main.ONOSIp[0] +
310 ':' + tsharkRoleOutput + ' /tmp/')
311 os.system('scp ' + ONOSUser + '@' + main.ONOSIp[0] +
312 ':' + tsharkFeatureOutput + ' /tmp/')
313 os.system('scp ' + ONOSUser + '@' +
314 main.ONOSIp[0] + ':' + tsharkOfOutput + ' /tmp/')
315 '''
316
317 # Get tcp syn / ack output
318 time.sleep(1)
319
320 tcpFile = open(tsharkTcpOutput, 'r')
321 tempText = tcpFile.readline()
322 tempText = tempText.split(' ')
323 main.log.info('Object read in from TCP capture: ' + str(tempText))
324
325 if len(tempText) > 1:
326 t0Tcp = float(tempText[1]) * 1000.0
327 else:
328 main.log.error('Tshark output file for TCP' + ' returned unexpected results')
329 t0Tcp = 0
330 assertion = main.FALSE
331 tcpFile.close()
332
333 # Get Role reply output
334 ofFile = open(tsharkOfOutput, 'r')
335 lineOfp = ''
336 while True:
337 tempText = ofFile.readline()
338 if tempText != '':
339 lineOfp = tempText
340 else:
341 break
342 obj = lineOfp.split(' ')
343 main.log.info('Object read in from OFP capture: ' +
344 str(lineOfp))
345 if len(obj) > 1:
346 t0Ofp = float(obj[1]) * 1000.0
347 else:
348 main.log.error('Tshark output file for OFP' +
349 ' returned unexpected results')
350 t0Ofp = 0
351 assertion = main.FALSE
352 ofFile.close()
353
354 # Get role request output
355 roleFile = open(tsharkRoleOutput, 'r')
356 tempText = roleFile.readline()
357 tempText = tempText.split(' ')
358 if len(tempText) > 1:
359 main.log.info('Object read in from role request capture:' +
360 str(tempText))
361 roleTimestamp = float(tempText[1]) * 1000.0
362 else:
363 main.log.error('Tshark output file for role request' +
364 ' returned unexpected results')
365 timeRoleRequest = 0
366 assertion = main.FALSE
367 roleFile.close()
368
369 # Get feature reply output
370 featureFile = open(tsharkFeatureOutput, 'r')
371 tempText = featureFile.readline()
372 tempText = tempText.split(' ')
373 if len(tempText) > 1:
374 main.log.info('Object read in from feature reply capture: '+
375 str(tempText))
376 if tempText[1] != ' ' and float(tempText[1]) > 1400000000.0:
377 temp = tempText[1]
378 elif tempText[2] != ' ' and float(tempText[2]) > 1400000000.0:
379 temp = tempText[2]
380 else:
381 temp = 0
382 featureTimestamp = float(temp) * 1000.0
383 else:
384 main.log.error('Tshark output file for feature reply' +
385 ' returned unexpected results')
386 timeFeatureReply = 0
387 assertion = main.FALSE
388 featureFile.close()
389
390 for node in range(0, clusterCount):
391 nodeNum = node+1
392 #metricsSwUp = CLIs[node].topologyEventsMetrics
393 #jsonStr = metricsSwUp()
394 jsonObj = json.loads(jsonStr[node])
395 if jsonObj:
396 graphTimestamp = jsonObj[graphTimestampKey]['value']
397 deviceTimestamp = jsonObj[deviceTimestampKey]['value']
398 else:
399 main.log.error( "Unexpected JSON object" )
400 # If we could not obtain the JSON object,
401 # set the timestamps to 0, which will be
402 # excluded from the measurement later on
403 # (realized as invalid)
404 graphTimestamp = 0
405 deviceTimestamp = 0
406
407 endToEnd = int(graphTimestamp) - int(t0Tcp)
408
409 # Below are measurement breakdowns of the end-to-end
410 # measurement.
411 tcpToFeature = int(featureTimestamp) - int(t0Tcp)
412 featureToRole = int(roleTimestamp) - int(featureTimestamp)
413 roleToOfp = float(t0Ofp) - float(roleTimestamp)
414 ofpToDevice = float(deviceTimestamp) - float(t0Ofp)
415 # Timestamps gathered from ONOS are millisecond
416 # precision. They are returned as integers, thus no
417 # need to be more precise than 'int'. However,
418 # the processing seems to be mostly under 1 ms,
419 # thus this may be a problem point to handle any
420 # submillisecond output that we are unsure of.
421 # For now, this will be treated as 0 ms if less than 1 ms
422 deviceToGraph = int(graphTimestamp) - int(deviceTimestamp)
423
424 if endToEnd >= thresholdMin and\
425 endToEnd < thresholdMax and i >= iterIgnore:
426 endToEndLatNodeIter[node][i] = endToEnd
427 main.log.info("ONOS "+str(nodeNum)+ " end-to-end: "+
428 str(endToEnd) + " ms")
429 else:
430 main.log.info("ONOS "+str(nodeNum)+ " end-to-end "+
431 "measurement ignored due to excess in "+
432 "threshold or premature iteration: ")
433 main.log.info(str(endToEnd))
434
435 if tcpToFeature >= thresholdMin and\
436 tcpToFeature < thresholdMax and i >= iterIgnore:
437 tcpToFeatureLatNodeIter[node][i] = tcpToFeature
438 main.log.info("ONOS "+str(nodeNum)+ " tcp-to-feature: "+
439 str(tcpToFeature) + " ms")
440 else:
441 main.log.info("ONOS "+str(nodeNum)+ " tcp-to-feature "+
442 "measurement ignored due to excess in "+
443 "threshold or premature iteration: ")
444 main.log.info(str(tcpToFeature))
445
446 if featureToRole >= thresholdMin and\
447 featureToRole < thresholdMax and i >= iterIgnore:
448 featureToRoleRequestLatNodeIter[node][i] = featureToRole
449 main.log.info("ONOS "+str(nodeNum)+ " feature-to-role: "+
450 str(featureToRole) + " ms")
451 else:
452 main.log.info("ONOS "+str(nodeNum)+ " feature-to-role "+
453 "measurement ignored due to excess in "+
454 "threshold or premature iteration: ")
455 main.log.info(str(featureToRole))
456
457 if roleToOfp >= thresholdMin and\
458 roleToOfp < thresholdMax and i >= iterIgnore:
459 roleRequestToRoleReplyLatNodeIter[node][i] = roleToOfp
460 main.log.info("ONOS "+str(nodeNum)+ " role-to-reply: "+
461 str(roleToOfp) + " ms")
462 else:
463 main.log.info("ONOS "+str(nodeNum)+ " role-to-reply "+
464 "measurement ignored due to excess in "+
465 "threshold or premature iteration: ")
466 main.log.info(str(roleToOfp))
467
468 if ofpToDevice >= thresholdMin and\
469 ofpToDevice < thresholdMax and i >= iterIgnore:
470 roleReplyToDeviceLatNodeIter[node][i] = ofpToDevice
471 main.log.info("ONOS "+str(nodeNum)+ " reply-to-device: "+
472 str(ofpToDevice) + " ms")
473 else:
474 main.log.info("ONOS "+str(nodeNum)+ " reply-to-device "+
475 "measurement ignored due to excess in "+
476 "threshold or premature iteration: ")
477 main.log.info(str(ofpToDevice))
478
479 if deviceToGraph >= thresholdMin and\
480 deviceToGraph < thresholdMax and i >= iterIgnore:
481 deviceToGraphLatNodeIter[node][i] = deviceToGraph
482 main.log.info("ONOS "+str(nodeNum)+ " device-to-graph: "+
483 str(deviceToGraph) + " ms")
484 else:
485 if deviceToGraph == 0:
486 deviceToGraphLatNodeIter[node][i] = 0
487 main.log.info("ONOS "+str(nodeNum) +
488 " device-to-graph measurement "+
489 "was set to 0 ms because of precision "+
490 "uncertainty. ")
491 else:
492 main.log.info("ONOS "+str(nodeNum)+
493 " device-to-graph "+
494 "measurement ignored due to excess in "+
495 "threshold or premature iteration: ")
496 main.log.info(str(deviceToGraph))
497
498 # ********************
499 time.sleep(5)
500
501 # Get device id to remove
502 deviceIdJsonStr = main.ONOS1cli.devices()
503
504 main.log.info( "Device obj obtained: " + str(deviceIdJsonStr) )
505 deviceId = json.loads(deviceIdJsonStr)
506
507 deviceList = []
508 for device in deviceId:
509 deviceList.append(device['id'])
510
511 # Measure switch down metrics
512 # TCP FIN/ACK -> TCP FIN
513 # TCP FIN -> Device Event
514 # Device Event -> Graph Event
515 # Capture switch down FIN / ACK packets
516
517 # The -A 1 grep option allows us to grab 1 extra line after the
518 # last tshark output grepped originally
519 main.ONOSbench.tsharkGrep( tsharkFinAckSequence, tsharkFinAckOutput,
520 grepOptions = '-A 1' )
521
522 time.sleep( 5 )
523
524 removeJsonList = []
525 main.step('Remove switch from controller')
526 main.Mininet1.deleteSwController('s3')
527 firstDevice = deviceList[0]
528
529 time.sleep( 5 )
530
531 # We need to get metrics before removing
532 # device from the store below.
533 for node in range(0, clusterCount):
534 metricsSwDown = CLIs[node].topologyEventsMetrics
535 jsonStr = metricsSwDown()
536 removeJsonList.append( json.loads(jsonStr) )
537
538 main.ONOSbench.tsharkStop()
539
540 main.log.info( "Removing device " +str(firstDevice)+
541 " from ONOS" )
542
543 #if deviceId:
544 main.ONOS1cli.deviceRemove(firstDevice)
545
546 #main.log.info('Copying over tshark files')
547 #os.system('scp ' + ONOSUser + '@' + main.ONOSIp[0] + ':' + tsharkFinAckOutput + ' /tmp/')
548
549 time.sleep( 10 )
550 finAckOutputList = []
551 with open(tsharkFinAckOutput, 'r') as f:
552 tempLine = f.readlines()
553 main.log.info('Object read in from FinAck capture: ' +
554 "\n".join(tempLine))
555
556 index = 1
557 for line in tempLine:
558 obj = line.split(' ')
559
560 # There are at least 3 objects in field (valid
561 # tshark output is lengthy)
562 if len(obj) > 2:
563 # If first index of object is like an epoch time
564 if obj[1] != ' ' and float(obj[1]) > 1400000000.0:
565 temp = obj[1]
566 elif obj[2] != ' 'and float(obj[2]) > 1400000000.0:
567 temp = obj[2]
568 elif obj[3] != ' 'and float(obj[3]) > 1400000000.0:
569 temp = obj[3]
570 else:
571 temp = 0
572 if index == 1:
573 tFinAck = float(temp) * 1000.0
574 elif index == 3:
575 tAck = float(temp) * 1000.0
576 else:
577 tFinAck = 0
578 tAck = 0
579 else:
580 main.log.error('Tshark output file for OFP' +
581 ' returned unexpected results')
582 tFinAck = 0
583 tAck = 0
584 assertion = main.FALSE
585
586 index += 1
587
588 # with open() as f takes care of closing file
589
590 time.sleep(5)
591
592 for node in range(0, clusterCount):
593 nodeNum = node+1
594 jsonObj = removeJsonList[node]
595 if jsonObj:
596 graphTimestamp = jsonObj[graphTimestampKey]['value']
597 deviceTimestamp = jsonObj[deviceTimestampKey]['value']
598 main.log.info("Graph timestamp: "+str(graphTimestamp))
599 main.log.info("Device timestamp: "+str(deviceTimestamp))
600 else:
601 main.log.error( "Unexpected JSON object" )
602 # If we could not obtain the JSON object,
603 # set the timestamps to 0, which will be
604 # excluded from the measurement later on
605 # (realized as invalid)
606 graphTimestamp = 0
607 deviceTimestamp = 0
608
609 finAckTransaction = float(tAck) - float(tFinAck)
610 ackToDevice = float(deviceTimestamp) - float(tAck)
611 deviceToGraph = float(graphTimestamp) - float(deviceTimestamp)
612 endToEndDisc = int(graphTimestamp) - int(tFinAck)
613
614 if endToEndDisc >= thresholdMin and\
615 endToEndDisc < thresholdMax and i >= iterIgnore:
616 endToEndDiscLatNodeIter[node][i] = endToEndDisc
617 main.log.info("ONOS "+str(nodeNum) +
618 "end-to-end disconnection: "+
619 str(endToEndDisc) + " ms" )
620 else:
621 main.log.info("ONOS " + str(nodeNum) +
622 " end-to-end disconnection "+
623 "measurement ignored due to excess in "+
624 "threshold or premature iteration: ")
625 main.log.info(str(endToEndDisc))
626
627 if finAckTransaction >= thresholdMin and\
628 finAckTransaction < thresholdMax and i >= iterIgnore:
629 finAckTransactionLatNodeIter[node][i] = finAckTransaction
630 main.log.info("ONOS "+str(nodeNum)+
631 " fin/ack transaction: "+
632 str(finAckTransaction) + " ms")
633 else:
634 main.log.info("ONOS "+str(nodeNum)+
635 " fin/ack transaction "+
636 "measurement ignored due to excess in "+
637 "threshold or premature iteration: ")
638 main.log.info(str(finAckTransaction))
639
640 if ackToDevice >= thresholdMin and\
641 ackToDevice < thresholdMax and i >= iterIgnore:
642 ackToDeviceLatNodeIter[node][i] = ackToDevice
643 main.log.info("ONOS "+str(nodeNum)+
644 " ack-to-device: "+
645 str(ackToDevice) + " ms")
646 else:
647 main.log.info("ONOS "+str(nodeNum)+
648 " ack-to-device "+
649 "measurement ignored due to excess in "+
650 "threshold or premature iteration: ")
651 main.log.info(str(ackToDevice))
652
653 if deviceToGraph >= thresholdMin and\
654 deviceToGraph < thresholdMax and i >= iterIgnore:
655 deviceToGraphDiscLatNodeIter[node][i] = deviceToGraph
656 main.log.info("ONOS "+str(nodeNum)+
657 " device-to-graph disconnect: "+
658 str(deviceToGraph) + " ms")
659 else:
660 main.log.info("ONOS "+str(nodeNum)+
661 " device-to-graph disconnect "+
662 "measurement ignored due to excess in "+
663 "threshold or premature iteration: ")
664 main.log.info(str(deviceToGraph))
665
666 endToEndAvg = 0
667 ofpToGraphAvg = 0
668 dbCmdList = []
669 for node in range(0, clusterCount):
670 # List of latency for each node
671 endToEndList = []
672 tcpToFeatureList = []
673 featureToRoleList = []
674 roleToOfpList = []
675 ofpToDeviceList = []
676 deviceToGraphList = []
677
678 finAckTransactionList = []
679 ackToDeviceList = []
680 deviceToGraphDiscList = []
681 endToEndDiscList = []
682
683 # LatNodeIter 2d arrays contain all iteration latency
684 # for each node of the current scale cluster size
685 # Switch connection measurements
686 # Set further acceptance criteria for measurements
687 # here if you would like to filter reporting results
688 for item in endToEndLatNodeIter[node]:
689 if item > 0.0:
690 endToEndList.append(item)
691
692 for item in tcpToFeatureLatNodeIter[node]:
693 if item > 0.0:
694 tcpToFeatureList.append(item)
695
696 for item in featureToRoleRequestLatNodeIter[node]:
697 if item > 0.0:
698 featureToRoleList.append(item)
699
700 for item in roleRequestToRoleReplyLatNodeIter[node]:
701 if item > 0.0:
702 roleToOfpList.append(item)
703
704 for item in roleReplyToDeviceLatNodeIter[node]:
705 if item >= 0.0:
706 ofpToDeviceList.append(item)
707
708 for item in featureToRoleRequestLatNodeIter[node]:
709 if item > 0.0:
710 featureToRoleList.append(item)
711
712 for item in deviceToGraphLatNodeIter[node]:
713 if item >= 0.0:
714 deviceToGraphList.append(item)
715
716 # Switch disconnect measurements
717 for item in endToEndDiscLatNodeIter[node]:
718 if item > 0.0:
719 endToEndDiscList.append(item)
720
721 for item in finAckTransactionLatNodeIter[node]:
722 if item > 0.0:
723 finAckTransactionList.append(item)
724
725 for item in ackToDeviceLatNodeIter[node]:
726 if item > 0.0:
727 ackToDeviceList.append(item)
728
729 for item in deviceToGraphDiscLatNodeIter[node]:
730 if item >= 0.0:
731 deviceToGraphDiscList.append(item)
732
733 endToEndAvg = round(numpy.mean(endToEndList), 2)
734 endToEndStdDev = round(numpy.std(endToEndList), 2)
735
736 tcpToFeatureAvg = round(numpy.mean(tcpToFeatureList), 2)
737 tcpToFeatureStdDev = round(numpy.std(tcpToFeatureList), 2)
738
739 featureToRoleAvg = round(numpy.mean(featureToRoleList), 2)
740 featureToRoleStdDev = round(numpy.std(featureToRoleList), 2)
741
742 roleToOfpAvg = round(numpy.mean(roleToOfpList), 2)
743 roleToOfpStdDev = round(numpy.std(roleToOfpList), 2)
744
745 ofpToDeviceAvg = round(numpy.mean(ofpToDeviceList), 2)
746 ofpToDeviceStdDev = round(numpy.std(ofpToDeviceList), 2)
747
748 deviceToGraphAvg = round(numpy.mean(deviceToGraphList), 2)
749 deviceToGraphStdDev = round(numpy.std(deviceToGraphList), 2)
750
751 endToEndDiscAvg = round(numpy.mean(endToEndDiscList), 2)
752 endToEndDiscStdDev = round(numpy.std(endToEndDiscList), 2)
753
754 finAckAvg = round(numpy.mean(finAckTransactionList), 2)
755 finAckStdDev = round(numpy.std(finAckTransactionList), 2)
756
757 ackToDeviceAvg = round(numpy.mean(ackToDeviceList), 2)
758 ackToDeviceStdDev = round(numpy.std(ackToDeviceList), 2)
759
760 deviceToGraphDiscAvg = round(numpy.mean(deviceToGraphDiscList), 2)
761 deviceToGraphDiscStdDev = round(numpy.std(deviceToGraphDiscList), 2)
762
763 main.log.report(' - Node ' + str(node + 1) + ' Summary - ')
764 main.log.report(' - Switch Connection Statistics - ')
765
766 main.log.report(' End-to-end Avg: ' + str(endToEndAvg) +
767 ' ms' + ' End-to-end Std dev: ' +
768 str(endToEndStdDev) + ' ms')
769
770 main.log.report(' Tcp-to-feature-reply Avg: ' +
771 str(tcpToFeatureAvg) + ' ms')
772 main.log.report(' Tcp-to-feature-reply Std dev: '+
773 str(tcpToFeatureStdDev) + ' ms')
774
775 main.log.report(' Feature-reply-to-role-request Avg: ' +
776 str(featureToRoleAvg) + ' ms')
777 main.log.report(' Feature-reply-to-role-request Std Dev: ' +
778 str(featureToRoleStdDev) + ' ms')
779
780 main.log.report(' Role-request-to-role-reply Avg: ' +
781 str(roleToOfpAvg) +' ms')
782 main.log.report(' Role-request-to-role-reply Std dev: ' +
783 str(roleToOfpStdDev) + ' ms')
784
785 main.log.report(' Role-reply-to-device Avg: ' +
786 str(ofpToDeviceAvg) +' ms')
787 main.log.report(' Role-reply-to-device Std dev: ' +
788 str(ofpToDeviceStdDev) + ' ms')
789
790 main.log.report(' Device-to-graph Avg: ' +
791 str(deviceToGraphAvg) + ' ms')
792 main.log.report( 'Device-to-graph Std dev: ' +
793 str(deviceToGraphStdDev) + ' ms')
794
795 main.log.report(' - Switch Disconnection Statistics - ')
796 main.log.report(' End-to-end switch disconnect Avg: ' +
797 str(endToEndDiscAvg) + ' ms')
798 main.log.report(' End-to-end switch disconnect Std dev: ' +
799 str(endToEndDiscStdDev) + ' ms')
800 main.log.report(' Fin/Ack-to-Ack Avg: ' + str(finAckAvg) + ' ms')
801 main.log.report(' Fin/Ack-to-Ack Std dev: ' +
802 str(finAckStdDev) + ' ms')
803
804 main.log.report(' Ack-to-device Avg: ' + str(ackToDeviceAvg) +
805 ' ms')
806 main.log.report(' Ack-to-device Std dev: ' + str(ackToDeviceStdDev) +
807 ' ms')
808
809 main.log.report(' Device-to-graph (disconnect) Avg: ' +
810 str(deviceToGraphDiscAvg) + ' ms')
811 main.log.report(' Device-to-graph (disconnect) Std dev: ' +
812 str(deviceToGraphDiscStdDev) + ' ms')
813
814 # For database schema, refer to Amazon web services
815 dbCmdList.append(
816 "INSERT INTO switch_latency_details VALUES('" +
817 timeToPost + "','switch_latency_results'," +
818 jenkinsBuildNumber + ',' + str(clusterCount) + ",'baremetal" +
819 str(node + 1) + "'," +
820 str(endToEndAvg) + ',' +
821 str(tcpToFeatureAvg) + ',' +
822 str(featureToRoleAvg) + ',' +
823 str(roleToOfpAvg) + ',' +
824 str(ofpToDeviceAvg) + ',' +
825 str(deviceToGraphAvg) + ',' +
826 str(endToEndDiscAvg) + ',' +
827 str(finAckAvg) + ',' +
828 str(ackToDeviceAvg) + ',' +
829 str(deviceToGraphDiscAvg) +
830 ');')
831
832 if debugMode == 'on':
833 main.ONOSbench.cpLogsToDir('/opt/onos/log/karaf.log',
834 '/tmp/', copyFileName='sw_lat_karaf')
835 fResult = open(resultPath, 'a')
836 for line in dbCmdList:
837 if line:
838 fResult.write(line + '\n')
839 main.log.report(line)
840 fResult.close()
841
842 assertion = main.TRUE
843
844 utilities.assert_equals(expect=main.TRUE, actual=assertion,
845 onpass='Switch latency test successful',
846 onfail='Switch latency test failed')
847
848 main.Mininet1.stopNet()