blob: c0c4ba49bb835b40437b382c1a761a3aed5a8ef6 [file] [log] [blame]
cameron@onlab.us21106ea2015-07-23 15:32:51 -07001# 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
Jon Hallf632d202015-07-30 15:45:11 -070012 import re
cameron@onlab.us21106ea2015-07-23 15:32:51 -070013 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']
Jon Hallf632d202015-07-30 15:45:11 -070037 testONpath = re.sub( "(tests)$", "bin", main.testDir ) # TestON/bin
cameron@onlab.us21106ea2015-07-23 15:32:51 -070038 user = main.params[ 'CTRL' ][ 'user' ]
39
Jon Hall4ba53f02015-07-29 13:07:41 -070040 # -- INIT SECTION, ONLY RUNS ONCE -- #
41 if init == False:
cameron@onlab.us21106ea2015-07-23 15:32:51 -070042 init = True
43 global clusterCount #number of nodes running
Jon Hall4ba53f02015-07-29 13:07:41 -070044 global scale
cameron@onlab.us21106ea2015-07-23 15:32:51 -070045 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
Jon Hall4ba53f02015-07-29 13:07:41 -070069 scale = (main.params[ 'SCALE' ]).split(",")
cameron@onlab.us21106ea2015-07-23 15:32:51 -070070 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
Jon Hall4ba53f02015-07-29 13:07:41 -070087 main.log.step("Grabbing commit number")
cameron@onlab.us21106ea2015-07-23 15:32:51 -070088 commit = main.ONOSbench.getVersion() ####
89 commit = (commit.split(" "))[1]
Jon Hall4ba53f02015-07-29 13:07:41 -070090
cameron@onlab.us21106ea2015-07-23 15:32:51 -070091 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("")
Jon Hall4ba53f02015-07-29 13:07:41 -070099 fSwitchLog.close()
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700100
101 # -- END OF INIT SECTION --#
102
Jon Hall4ba53f02015-07-29 13:07:41 -0700103 main.log.step("Adjusting scale")
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700104 clusterCount = int(scale[0])
Jon Hall4ba53f02015-07-29 13:07:41 -0700105 scale.remove(scale[0])
106
107 #kill off all onos processes
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700108 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])
Jon Hall4ba53f02015-07-29 13:07:41 -0700111
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700112 #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(":~")
Jon Hall4ba53f02015-07-29 13:07:41 -0700121
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700122 #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])
Jon Hall4ba53f02015-07-29 13:07:41 -0700127
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700128 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" )
Jon Hall4ba53f02015-07-29 13:07:41 -0700134 packageResult = main.ONOSbench.onosPackage()
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700135
136 main.step( "verify cells" )
137 verifyCellResult = main.ONOSbench.verifyCell()
Jon Hall4ba53f02015-07-29 13:07:41 -0700138
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700139 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:
Jon Hall4ba53f02015-07-29 13:07:41 -0700154 break
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700155
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)
Jon Hall4ba53f02015-07-29 13:07:41 -0700167
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700168 main.step('Start onos cli')
Jon Hall4ba53f02015-07-29 13:07:41 -0700169 for i in range(0,clusterCount):
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700170 cli1 = CLIs[i].startOnosCli(main.ONOSIp[i])
171
172 main.step( 'Configuring application parameters' )
Jon Hall4ba53f02015-07-29 13:07:41 -0700173
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700174 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'
Jon Hall4ba53f02015-07-29 13:07:41 -0700180 main.ONOSbench.onosCfgSet( main.ONOSIp[0], configName, configParam )
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700181
182 def CASE2(self, main):
183 print "Cluster size: " + str(clusterCount)
184 """
185 Assign s3 to ONOSbench and measure latency
Jon Hall4ba53f02015-07-29 13:07:41 -0700186
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700187 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'])
Jon Hall4ba53f02015-07-29 13:07:41 -0700210
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700211 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])
Jon Hall4ba53f02015-07-29 13:07:41 -0700221
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700222 # 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
Jon Hall4ba53f02015-07-29 13:07:41 -0700241 featureToRoleRequestLatNodeIter = numpy.zeros((clusterCount,
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700242 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)))
Jon Hall4ba53f02015-07-29 13:07:41 -0700253
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700254 # 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)))
Jon Hall4ba53f02015-07-29 13:07:41 -0700265
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700266 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))
Jon Hall4ba53f02015-07-29 13:07:41 -0700279
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700280 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)
Jon Hall4ba53f02015-07-29 13:07:41 -0700288
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700289 main.log.info('Assigning s3 to controller')
290 main.Mininet1.assignSwController(sw='s3',
291 ip=main.ONOSIp[0])
Jon Hall4ba53f02015-07-29 13:07:41 -0700292
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700293 jsonStr = []
Jon Hall4ba53f02015-07-29 13:07:41 -0700294 for node in range (0, clusterCount):
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700295 metricsSwUp = CLIs[node].topologyEventsMetrics()
296 jsonStr.append(metricsSwUp)
Jon Hall4ba53f02015-07-29 13:07:41 -0700297
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700298 time.sleep(10)
299
300 main.log.info('Stopping all Tshark processes')
301 main.ONOSbench.tsharkStop()
Jon Hall4ba53f02015-07-29 13:07:41 -0700302
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700303 time.sleep(5)
Jon Hall4ba53f02015-07-29 13:07:41 -0700304
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700305 '''
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))
Jon Hall4ba53f02015-07-29 13:07:41 -0700324
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700325 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()
Jon Hall4ba53f02015-07-29 13:07:41 -0700332
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700333 # 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()
Jon Hall4ba53f02015-07-29 13:07:41 -0700353
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700354 # 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:
Jon Hall4ba53f02015-07-29 13:07:41 -0700381 temp = 0
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700382 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" )
Jon Hall4ba53f02015-07-29 13:07:41 -0700400 # If we could not obtain the JSON object,
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700401 # 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
Jon Hall4ba53f02015-07-29 13:07:41 -0700406
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700407 endToEnd = int(graphTimestamp) - int(t0Tcp)
Jon Hall4ba53f02015-07-29 13:07:41 -0700408
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700409 # Below are measurement breakdowns of the end-to-end
Jon Hall4ba53f02015-07-29 13:07:41 -0700410 # measurement.
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700411 tcpToFeature = int(featureTimestamp) - int(t0Tcp)
412 featureToRole = int(roleTimestamp) - int(featureTimestamp)
413 roleToOfp = float(t0Ofp) - float(roleTimestamp)
414 ofpToDevice = float(deviceTimestamp) - float(t0Ofp)
Jon Hall4ba53f02015-07-29 13:07:41 -0700415 # Timestamps gathered from ONOS are millisecond
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700416 # precision. They are returned as integers, thus no
417 # need to be more precise than 'int'. However,
Jon Hall4ba53f02015-07-29 13:07:41 -0700418 # the processing seems to be mostly under 1 ms,
419 # thus this may be a problem point to handle any
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700420 # 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)
Jon Hall4ba53f02015-07-29 13:07:41 -0700423
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700424 if endToEnd >= thresholdMin and\
425 endToEnd < thresholdMax and i >= iterIgnore:
Jon Hall4ba53f02015-07-29 13:07:41 -0700426 endToEndLatNodeIter[node][i] = endToEnd
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700427 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))
Jon Hall4ba53f02015-07-29 13:07:41 -0700434
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700435 if tcpToFeature >= thresholdMin and\
436 tcpToFeature < thresholdMax and i >= iterIgnore:
Jon Hall4ba53f02015-07-29 13:07:41 -0700437 tcpToFeatureLatNodeIter[node][i] = tcpToFeature
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700438 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:
Jon Hall4ba53f02015-07-29 13:07:41 -0700448 featureToRoleRequestLatNodeIter[node][i] = featureToRole
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700449 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))
Jon Hall4ba53f02015-07-29 13:07:41 -0700467
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700468 if ofpToDevice >= thresholdMin and\
469 ofpToDevice < thresholdMax and i >= iterIgnore:
Jon Hall4ba53f02015-07-29 13:07:41 -0700470 roleReplyToDeviceLatNodeIter[node][i] = ofpToDevice
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700471 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:
Jon Hall4ba53f02015-07-29 13:07:41 -0700492 main.log.info("ONOS "+str(nodeNum)+
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700493 " device-to-graph "+
494 "measurement ignored due to excess in "+
495 "threshold or premature iteration: ")
Jon Hall4ba53f02015-07-29 13:07:41 -0700496 main.log.info(str(deviceToGraph))
497
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700498 # ********************
499 time.sleep(5)
Jon Hall4ba53f02015-07-29 13:07:41 -0700500
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700501 # Get device id to remove
502 deviceIdJsonStr = main.ONOS1cli.devices()
Jon Hall4ba53f02015-07-29 13:07:41 -0700503
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700504 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'])
Jon Hall4ba53f02015-07-29 13:07:41 -0700510
511 # Measure switch down metrics
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700512 # 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
Jon Hall4ba53f02015-07-29 13:07:41 -0700519 main.ONOSbench.tsharkGrep( tsharkFinAckSequence, tsharkFinAckOutput,
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700520 grepOptions = '-A 1' )
Jon Hall4ba53f02015-07-29 13:07:41 -0700521
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700522 time.sleep( 5 )
523
524 removeJsonList = []
525 main.step('Remove switch from controller')
526 main.Mininet1.deleteSwController('s3')
Jon Hall4ba53f02015-07-29 13:07:41 -0700527 firstDevice = deviceList[0]
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700528
529 time.sleep( 5 )
Jon Hall4ba53f02015-07-29 13:07:41 -0700530
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700531 # 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()
Jon Hall4ba53f02015-07-29 13:07:41 -0700536 removeJsonList.append( json.loads(jsonStr) )
537
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700538 main.ONOSbench.tsharkStop()
Jon Hall4ba53f02015-07-29 13:07:41 -0700539
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700540 main.log.info( "Removing device " +str(firstDevice)+
541 " from ONOS" )
Jon Hall4ba53f02015-07-29 13:07:41 -0700542
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700543 #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/')
Jon Hall4ba53f02015-07-29 13:07:41 -0700548
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700549 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))
Jon Hall4ba53f02015-07-29 13:07:41 -0700555
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700556 index = 1
557 for line in tempLine:
558 obj = line.split(' ')
Jon Hall4ba53f02015-07-29 13:07:41 -0700559
560 # There are at least 3 objects in field (valid
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700561 # 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:
Jon Hall4ba53f02015-07-29 13:07:41 -0700565 temp = obj[1]
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700566 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
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700574 main.log.info("DEBUG-- tFinAck: " + str(tFinAck))
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700575 elif index == 3:
576 tAck = float(temp) * 1000.0
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700577 main.log.info("DEBUG-- tAck: " + str(tAck))
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700578 else:
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700579 tAck = 0
580 else:
581 main.log.error('Tshark output file for OFP' +
582 ' returned unexpected results')
583 tFinAck = 0
584 tAck = 0
585 assertion = main.FALSE
Jon Hall4ba53f02015-07-29 13:07:41 -0700586
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700587 index += 1
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700588 main.log.info("DEBUG-- tFinAck: " + str(tFinAck))
589 main.log.info("DEBUG-- tAck: " + str(tAck))
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700590
591 # with open() as f takes care of closing file
592
593 time.sleep(5)
Jon Hall4ba53f02015-07-29 13:07:41 -0700594
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700595 for node in range(0, clusterCount):
596 nodeNum = node+1
597 jsonObj = removeJsonList[node]
598 if jsonObj:
599 graphTimestamp = jsonObj[graphTimestampKey]['value']
600 deviceTimestamp = jsonObj[deviceTimestampKey]['value']
601 main.log.info("Graph timestamp: "+str(graphTimestamp))
602 main.log.info("Device timestamp: "+str(deviceTimestamp))
603 else:
604 main.log.error( "Unexpected JSON object" )
Jon Hall4ba53f02015-07-29 13:07:41 -0700605 # If we could not obtain the JSON object,
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700606 # set the timestamps to 0, which will be
607 # excluded from the measurement later on
608 # (realized as invalid)
609 graphTimestamp = 0
610 deviceTimestamp = 0
Jon Hall4ba53f02015-07-29 13:07:41 -0700611
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700612 finAckTransaction = float(tAck) - float(tFinAck)
613 ackToDevice = float(deviceTimestamp) - float(tAck)
614 deviceToGraph = float(graphTimestamp) - float(deviceTimestamp)
615 endToEndDisc = int(graphTimestamp) - int(tFinAck)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700616 main.log.info("DEBUG-- endToEndDisc = graphTimestamp - tFinAck == (" + str(graphTimestamp) + "-" + str(tFinAck) + ")")
Jon Hall4ba53f02015-07-29 13:07:41 -0700617
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700618 if endToEndDisc >= thresholdMin and\
619 endToEndDisc < thresholdMax and i >= iterIgnore:
620 endToEndDiscLatNodeIter[node][i] = endToEndDisc
Jon Hall4ba53f02015-07-29 13:07:41 -0700621 main.log.info("ONOS "+str(nodeNum) +
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700622 "end-to-end disconnection: "+
623 str(endToEndDisc) + " ms" )
624 else:
Jon Hall4ba53f02015-07-29 13:07:41 -0700625 main.log.info("ONOS " + str(nodeNum) +
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700626 " end-to-end disconnection "+
627 "measurement ignored due to excess in "+
628 "threshold or premature iteration: ")
629 main.log.info(str(endToEndDisc))
630
631 if finAckTransaction >= thresholdMin and\
632 finAckTransaction < thresholdMax and i >= iterIgnore:
Jon Hall4ba53f02015-07-29 13:07:41 -0700633 finAckTransactionLatNodeIter[node][i] = finAckTransaction
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700634 main.log.info("ONOS "+str(nodeNum)+
635 " fin/ack transaction: "+
636 str(finAckTransaction) + " ms")
637 else:
638 main.log.info("ONOS "+str(nodeNum)+
639 " fin/ack transaction "+
640 "measurement ignored due to excess in "+
641 "threshold or premature iteration: ")
642 main.log.info(str(finAckTransaction))
643
644 if ackToDevice >= thresholdMin and\
645 ackToDevice < thresholdMax and i >= iterIgnore:
646 ackToDeviceLatNodeIter[node][i] = ackToDevice
647 main.log.info("ONOS "+str(nodeNum)+
648 " ack-to-device: "+
649 str(ackToDevice) + " ms")
650 else:
651 main.log.info("ONOS "+str(nodeNum)+
652 " ack-to-device "+
653 "measurement ignored due to excess in "+
654 "threshold or premature iteration: ")
655 main.log.info(str(ackToDevice))
656
657 if deviceToGraph >= thresholdMin and\
658 deviceToGraph < thresholdMax and i >= iterIgnore:
659 deviceToGraphDiscLatNodeIter[node][i] = deviceToGraph
660 main.log.info("ONOS "+str(nodeNum)+
661 " device-to-graph disconnect: "+
662 str(deviceToGraph) + " ms")
663 else:
664 main.log.info("ONOS "+str(nodeNum)+
665 " device-to-graph disconnect "+
666 "measurement ignored due to excess in "+
667 "threshold or premature iteration: ")
668 main.log.info(str(deviceToGraph))
669
670 endToEndAvg = 0
671 ofpToGraphAvg = 0
672 dbCmdList = []
673 for node in range(0, clusterCount):
674 # List of latency for each node
675 endToEndList = []
676 tcpToFeatureList = []
677 featureToRoleList = []
678 roleToOfpList = []
679 ofpToDeviceList = []
680 deviceToGraphList = []
Jon Hall4ba53f02015-07-29 13:07:41 -0700681
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700682 finAckTransactionList = []
683 ackToDeviceList = []
684 deviceToGraphDiscList = []
685 endToEndDiscList = []
Jon Hall4ba53f02015-07-29 13:07:41 -0700686
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700687 # LatNodeIter 2d arrays contain all iteration latency
688 # for each node of the current scale cluster size
689 # Switch connection measurements
690 # Set further acceptance criteria for measurements
691 # here if you would like to filter reporting results
692 for item in endToEndLatNodeIter[node]:
693 if item > 0.0:
694 endToEndList.append(item)
695
696 for item in tcpToFeatureLatNodeIter[node]:
697 if item > 0.0:
698 tcpToFeatureList.append(item)
699
700 for item in featureToRoleRequestLatNodeIter[node]:
701 if item > 0.0:
702 featureToRoleList.append(item)
703
704 for item in roleRequestToRoleReplyLatNodeIter[node]:
705 if item > 0.0:
706 roleToOfpList.append(item)
707
708 for item in roleReplyToDeviceLatNodeIter[node]:
709 if item >= 0.0:
710 ofpToDeviceList.append(item)
Jon Hall4ba53f02015-07-29 13:07:41 -0700711
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700712 for item in featureToRoleRequestLatNodeIter[node]:
713 if item > 0.0:
714 featureToRoleList.append(item)
715
716 for item in deviceToGraphLatNodeIter[node]:
717 if item >= 0.0:
718 deviceToGraphList.append(item)
719
720 # Switch disconnect measurements
721 for item in endToEndDiscLatNodeIter[node]:
722 if item > 0.0:
723 endToEndDiscList.append(item)
Jon Hall4ba53f02015-07-29 13:07:41 -0700724
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700725 for item in finAckTransactionLatNodeIter[node]:
726 if item > 0.0:
727 finAckTransactionList.append(item)
728
729 for item in ackToDeviceLatNodeIter[node]:
730 if item > 0.0:
731 ackToDeviceList.append(item)
732
733 for item in deviceToGraphDiscLatNodeIter[node]:
734 if item >= 0.0:
735 deviceToGraphDiscList.append(item)
736
737 endToEndAvg = round(numpy.mean(endToEndList), 2)
738 endToEndStdDev = round(numpy.std(endToEndList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700739 main.log.info("endToEndList: " + str(endToEndList))
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700740
741 tcpToFeatureAvg = round(numpy.mean(tcpToFeatureList), 2)
742 tcpToFeatureStdDev = round(numpy.std(tcpToFeatureList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700743 main.log.info("tcpToFeatureList: " + str(tcpToFeatureList))
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700744
745 featureToRoleAvg = round(numpy.mean(featureToRoleList), 2)
746 featureToRoleStdDev = round(numpy.std(featureToRoleList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700747 main.log.info("featureToRoleList: " + str(featureToRoleList))
Jon Hall4ba53f02015-07-29 13:07:41 -0700748
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700749 roleToOfpAvg = round(numpy.mean(roleToOfpList), 2)
750 roleToOfpStdDev = round(numpy.std(roleToOfpList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700751 main.log.info("roleToOfList: " + str(roleToOfpList))
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700752
753 ofpToDeviceAvg = round(numpy.mean(ofpToDeviceList), 2)
754 ofpToDeviceStdDev = round(numpy.std(ofpToDeviceList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700755 main.log.info("ofpToDeviceList: " + str(ofpToDeviceList))
Jon Hall4ba53f02015-07-29 13:07:41 -0700756
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700757 deviceToGraphAvg = round(numpy.mean(deviceToGraphList), 2)
758 deviceToGraphStdDev = round(numpy.std(deviceToGraphList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700759 main.log.info("deviceToGraphList: " + str(deviceToGraphList))
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700760
761 endToEndDiscAvg = round(numpy.mean(endToEndDiscList), 2)
762 endToEndDiscStdDev = round(numpy.std(endToEndDiscList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700763 main.log.info("endToEndDiscList: " + str(endToEndDiscList))
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700764
765 finAckAvg = round(numpy.mean(finAckTransactionList), 2)
766 finAckStdDev = round(numpy.std(finAckTransactionList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700767 main.log.info("finAckTransactionList: " + str(finAckTransactionList))
Jon Hall4ba53f02015-07-29 13:07:41 -0700768
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700769 ackToDeviceAvg = round(numpy.mean(ackToDeviceList), 2)
770 ackToDeviceStdDev = round(numpy.std(ackToDeviceList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700771 main.log.info("ackToDeviceList: " + str(ackToDeviceList))
Jon Hall4ba53f02015-07-29 13:07:41 -0700772
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700773 deviceToGraphDiscAvg = round(numpy.mean(deviceToGraphDiscList), 2)
774 deviceToGraphDiscStdDev = round(numpy.std(deviceToGraphDiscList), 2)
cameron@onlab.us222f2e42015-07-30 12:08:27 -0700775 main.log.info("deviceToGraphDiscList: " + str(deviceToGraphDiscList))
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700776
777 main.log.report(' - Node ' + str(node + 1) + ' Summary - ')
778 main.log.report(' - Switch Connection Statistics - ')
Jon Hall4ba53f02015-07-29 13:07:41 -0700779
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700780 main.log.report(' End-to-end Avg: ' + str(endToEndAvg) +
781 ' ms' + ' End-to-end Std dev: ' +
782 str(endToEndStdDev) + ' ms')
Jon Hall4ba53f02015-07-29 13:07:41 -0700783
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700784 main.log.report(' Tcp-to-feature-reply Avg: ' +
785 str(tcpToFeatureAvg) + ' ms')
786 main.log.report(' Tcp-to-feature-reply Std dev: '+
787 str(tcpToFeatureStdDev) + ' ms')
Jon Hall4ba53f02015-07-29 13:07:41 -0700788
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700789 main.log.report(' Feature-reply-to-role-request Avg: ' +
790 str(featureToRoleAvg) + ' ms')
791 main.log.report(' Feature-reply-to-role-request Std Dev: ' +
792 str(featureToRoleStdDev) + ' ms')
Jon Hall4ba53f02015-07-29 13:07:41 -0700793
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700794 main.log.report(' Role-request-to-role-reply Avg: ' +
795 str(roleToOfpAvg) +' ms')
796 main.log.report(' Role-request-to-role-reply Std dev: ' +
797 str(roleToOfpStdDev) + ' ms')
Jon Hall4ba53f02015-07-29 13:07:41 -0700798
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700799 main.log.report(' Role-reply-to-device Avg: ' +
800 str(ofpToDeviceAvg) +' ms')
801 main.log.report(' Role-reply-to-device Std dev: ' +
802 str(ofpToDeviceStdDev) + ' ms')
Jon Hall4ba53f02015-07-29 13:07:41 -0700803
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700804 main.log.report(' Device-to-graph Avg: ' +
805 str(deviceToGraphAvg) + ' ms')
806 main.log.report( 'Device-to-graph Std dev: ' +
807 str(deviceToGraphStdDev) + ' ms')
Jon Hall4ba53f02015-07-29 13:07:41 -0700808
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700809 main.log.report(' - Switch Disconnection Statistics - ')
Jon Hall4ba53f02015-07-29 13:07:41 -0700810 main.log.report(' End-to-end switch disconnect Avg: ' +
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700811 str(endToEndDiscAvg) + ' ms')
812 main.log.report(' End-to-end switch disconnect Std dev: ' +
813 str(endToEndDiscStdDev) + ' ms')
814 main.log.report(' Fin/Ack-to-Ack Avg: ' + str(finAckAvg) + ' ms')
815 main.log.report(' Fin/Ack-to-Ack Std dev: ' +
816 str(finAckStdDev) + ' ms')
Jon Hall4ba53f02015-07-29 13:07:41 -0700817
818 main.log.report(' Ack-to-device Avg: ' + str(ackToDeviceAvg) +
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700819 ' ms')
820 main.log.report(' Ack-to-device Std dev: ' + str(ackToDeviceStdDev) +
821 ' ms')
822
823 main.log.report(' Device-to-graph (disconnect) Avg: ' +
824 str(deviceToGraphDiscAvg) + ' ms')
825 main.log.report(' Device-to-graph (disconnect) Std dev: ' +
826 str(deviceToGraphDiscStdDev) + ' ms')
827
828 # For database schema, refer to Amazon web services
829 dbCmdList.append(
830 "INSERT INTO switch_latency_details VALUES('" +
831 timeToPost + "','switch_latency_results'," +
Jon Hall4ba53f02015-07-29 13:07:41 -0700832 jenkinsBuildNumber + ',' + str(clusterCount) + ",'baremetal" +
833 str(node + 1) + "'," +
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700834 str(endToEndAvg) + ',' +
835 str(tcpToFeatureAvg) + ',' +
836 str(featureToRoleAvg) + ',' +
837 str(roleToOfpAvg) + ',' +
838 str(ofpToDeviceAvg) + ',' +
839 str(deviceToGraphAvg) + ',' +
840 str(endToEndDiscAvg) + ',' +
841 str(finAckAvg) + ',' +
842 str(ackToDeviceAvg) + ',' +
Jon Hall4ba53f02015-07-29 13:07:41 -0700843 str(deviceToGraphDiscAvg) +
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700844 ');')
845
846 if debugMode == 'on':
847 main.ONOSbench.cpLogsToDir('/opt/onos/log/karaf.log',
848 '/tmp/', copyFileName='sw_lat_karaf')
849 fResult = open(resultPath, 'a')
850 for line in dbCmdList:
851 if line:
852 fResult.write(line + '\n')
Jon Hall4ba53f02015-07-29 13:07:41 -0700853 main.log.report(line)
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700854 fResult.close()
Jon Hall4ba53f02015-07-29 13:07:41 -0700855
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700856 assertion = main.TRUE
Jon Hall4ba53f02015-07-29 13:07:41 -0700857
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700858 utilities.assert_equals(expect=main.TRUE, actual=assertion,
Jon Hall4ba53f02015-07-29 13:07:41 -0700859 onpass='Switch latency test successful',
cameron@onlab.us21106ea2015-07-23 15:32:51 -0700860 onfail='Switch latency test failed')
861
862 main.Mininet1.stopNet()