blob: 7bc654a76fedf8cda78e2c9a4cca64631c9d45df [file] [log] [blame]
jenkins7ead5a82015-03-13 10:28:21 -07001# 2015.03.12 10:22:05 PDT
2#Embedded file name: ../tests/TopoPerfNextBM/TopoPerfNextBM.py
3import time
4import sys
5import os
6import re
7
8class TopoPerfNextBM:
9
10 def __init__(self):
11 self.default = ''
12
13 def CASE1(self, main):
14 """
15 ONOS startup sequence
16 """
17 global clusterCount
18 global timeToPost
19 global runNum
andrew@onlab.us09a4a0c2015-04-09 13:38:13 -040020 global jenkinsBuildNumber
andrew@onlab.us0f468c42015-04-02 17:05:47 -040021
jenkins7ead5a82015-03-13 10:28:21 -070022 import time
andrew@onlab.us09a4a0c2015-04-09 13:38:13 -040023 import os
24
jenkins7ead5a82015-03-13 10:28:21 -070025 clusterCount = 1
26 timeToPost = time.strftime('%Y-%m-%d %H:%M:%S')
27 runNum = time.strftime('%d%H%M%S')
28 cellName = main.params['ENV']['cellName']
29 gitPull = main.params['GIT']['autoPull']
30 checkoutBranch = main.params['GIT']['checkout']
andrew@onlab.us09a4a0c2015-04-09 13:38:13 -040031
32 # Get jenkins build number from environment.
33 # This environment variable will only exist when
34 # triggered by a jenkins job
35 try:
36 jenkinsBuildNumber = str(os.environ['BUILD_NUMBER'])
37 main.log.report( 'Jenkins build number: ' +
38 jenkinsBuildNumber )
39 except KeyError:
40 # Jenkins build number is also used in posting to DB
41 # If this test is not triggered by jenkins, give
42 # it the runNum variable instead, ensuring that
43 # the DB post will recognize it as a non-jenkins run
44 jenkinsBuildNumber = str(runNum)
45 main.log.info( 'Job is not run by jenkins. '+
46 'Build number set to: ' + jenkinsBuildNumber)
47
andrew@onlab.us0f468c42015-04-02 17:05:47 -040048 global CLIs
49 CLIs = []
50 global nodes
51 nodes = []
52 global nodeIpList
53 nodeIpList = []
54 for i in range( 1, 8 ):
55 CLIs.append( getattr( main, 'ONOS' + str( i ) + 'cli' ) )
56 nodes.append( getattr( main, 'ONOS' + str( i ) ) )
57 nodeIpList.append( main.params[ 'CTRL' ][ 'ip'+str(i) ] )
58
jenkins7ead5a82015-03-13 10:28:21 -070059 MN1Ip = main.params['MN']['ip1']
60 BENCHIp = main.params['BENCH']['ip']
andrew@onlab.us0f468c42015-04-02 17:05:47 -040061 cellFeatures = main.params['ENV']['cellFeatures']
jenkins7ead5a82015-03-13 10:28:21 -070062 topoCfgFile = main.params['TEST']['topoConfigFile']
63 topoCfgName = main.params['TEST']['topoConfigName']
64 portEventResultPath = main.params['DB']['portEventResultPath']
65 switchEventResultPath = main.params['DB']['switchEventResultPath']
66 mvnCleanInstall = main.params['TEST']['mci']
67
68 main.case('Setting up test environment')
andrew@onlab.us0f468c42015-04-02 17:05:47 -040069
70 # NOTE: Below is deprecated after new way to install features
71 #main.log.info('Copying topology event accumulator config' +
72 # ' to ONOS /package/etc')
73 #main.ONOSbench.handle.sendline('cp ~/' +
74 # topoCfgFile + ' ~/ONOS/tools/package/etc/' +
75 # topoCfgName)
76 #main.ONOSbench.handle.expect('\\$')
jenkins7ead5a82015-03-13 10:28:21 -070077
78 main.log.report('Setting up test environment')
79
80 main.step('Starting mininet topology ')
81 main.Mininet1.startNet()
82
83 main.step('Cleaning previously installed ONOS if any')
andrew@onlab.us0f468c42015-04-02 17:05:47 -040084 # Nodes 2 ~ 7
85 for i in range( 1, 7 ):
86 main.ONOSbench.onosUninstall(nodeIp=nodeIpList[i])
jenkins7ead5a82015-03-13 10:28:21 -070087
88 main.step('Clearing previous DB log file')
89
90 fPortLog = open(portEventResultPath, 'w')
91 fPortLog.write('')
92 fPortLog.close()
93 fSwitchLog = open(switchEventResultPath, 'w')
94 fSwitchLog.write('')
95 fSwitchLog.close()
96
jenkins7ead5a82015-03-13 10:28:21 -070097 main.step('Creating cell file')
98 cellFileResult = main.ONOSbench.createCellFile(
andrew@onlab.us0f468c42015-04-02 17:05:47 -040099 BENCHIp, cellName, MN1Ip, cellFeatures, nodeIpList[0])
jenkins7ead5a82015-03-13 10:28:21 -0700100
101 main.step('Applying cell file to environment')
102 cellApplyResult = main.ONOSbench.setCell(cellName)
103 verifyCellResult = main.ONOSbench.verifyCell()
104
105 main.step('Git checkout and pull ' + checkoutBranch)
106 if gitPull == 'on':
107 checkoutResult = main.TRUE
108 pullResult = main.ONOSbench.gitPull()
109 else:
110 checkoutResult = main.TRUE
111 pullResult = main.TRUE
112 main.log.info('Skipped git checkout and pull')
113
114 main.log.report('Commit information - ')
115 main.ONOSbench.getVersion(report=True)
116 main.step('Using mvn clean & install')
117 if mvnCleanInstall == 'on':
118 mvnResult = main.ONOSbench.cleanInstall()
119 elif mvnCleanInstall == 'off':
120 main.log.info('mci turned off by settings')
121 mvnResult = main.TRUE
122 main.step('Set cell for ONOS cli env')
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400123 CLIs[0].setCell(cellName)
jenkins7ead5a82015-03-13 10:28:21 -0700124
125 main.step('Creating ONOS package')
126 packageResult = main.ONOSbench.onosPackage()
127
128 main.step('Installing ONOS package')
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400129 install1Result = main.ONOSbench.onosInstall(node=nodeIpList[0])
jenkins7ead5a82015-03-13 10:28:21 -0700130
131 time.sleep(10)
132
133 main.step('Start onos cli')
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400134 cli1 = CLIs[0].startOnosCli(nodeIpList[0])
135
136 main.step( 'activating essential applications' )
137 CLIs[0].activateApp( 'org.onosproject.metrics' )
138 CLIs[0].activateApp( 'org.onosproject.openflow' )
139
140 main.step( 'Configuring application parameters' )
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400141
142 configName = 'org.onosproject.net.topology.impl.DefaultTopologyProvider'
143 configParam = 'maxEvents 1'
144 main.ONOSbench.onosCfgSet( nodeIpList[0], configName, configParam )
145 configParam = 'maxBatchMs 0'
146 main.ONOSbench.onosCfgSet( nodeIpList[0], configName, configParam )
147 configParam = 'maxIdleMs 0'
148 main.ONOSbench.onosCfgSet( nodeIpList[0], configName, configParam )
149
jenkins7ead5a82015-03-13 10:28:21 -0700150 utilities.assert_equals(expect=main.TRUE,
151 actual=cellFileResult and cellApplyResult and\
152 verifyCellResult and checkoutResult and\
153 pullResult and mvnResult and\
154 install1Result,
155 onpass='Test Environment setup successful',
156 onfail='Failed to setup test environment')
157
158 def CASE2(self, main):
159 """
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400160 Assign s3 to ONOS1 and measure latency
jenkins7ead5a82015-03-13 10:28:21 -0700161
162 There are 4 levels of latency measurements to this test:
163 1 ) End-to-end measurement: Complete end-to-end measurement
164 from TCP ( SYN/ACK ) handshake to Graph change
165 2 ) OFP-to-graph measurement: 'ONOS processing' snippet of
166 measurement from OFP Vendor message to Graph change
167 3 ) OFP-to-device measurement: 'ONOS processing without
168 graph change' snippet of measurement from OFP vendor
169 message to Device change timestamp
170 4 ) T0-to-device measurement: Measurement that includes
171 the switch handshake to devices timestamp without
172 the graph view change. ( TCP handshake -> Device
173 change )
174 """
175 import time
176 import subprocess
177 import json
178 import requests
179 import os
180 import numpy
andrew@onlab.us09a4a0c2015-04-09 13:38:13 -0400181
jenkins7ead5a82015-03-13 10:28:21 -0700182 ONOSUser = main.params['CTRL']['user']
183 defaultSwPort = main.params['CTRL']['port1']
184 numIter = main.params['TEST']['numIter']
185 iterIgnore = int(main.params['TEST']['iterIgnore'])
jenkins8ba10ab2015-03-24 10:31:31 -0700186
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400187 deviceTimestampKey = main.params['JSON']['deviceTimestamp']
188 graphTimestampKey = main.params['JSON']['graphTimestamp']
jenkins8ba10ab2015-03-24 10:31:31 -0700189
jenkins7ead5a82015-03-13 10:28:21 -0700190 debugMode = main.params['TEST']['debugMode']
191 onosLog = main.params['TEST']['onosLogFile']
192 resultPath = main.params['DB']['switchEventResultPath']
193 thresholdStr = main.params['TEST']['singleSwThreshold']
194 thresholdObj = thresholdStr.split(',')
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400195 thresholdMin = float(thresholdObj[0])
196 thresholdMax = float(thresholdObj[1])
jenkins7ead5a82015-03-13 10:28:21 -0700197
jenkins8ba10ab2015-03-24 10:31:31 -0700198 # Look for 'role-request' messages,
199 # which replaces the 'vendor' messages previously seen
200 # on OVS 2.0.1
jenkins7ead5a82015-03-13 10:28:21 -0700201 tsharkTcpString = main.params[ 'TSHARK' ][ 'tcpSynAck' ]
jenkins8ba10ab2015-03-24 10:31:31 -0700202 tsharkFeatureReply = main.params[ 'TSHARK' ][ 'featureReply' ]
203 tsharkRoleRequest = main.params[ 'TSHARK' ][ 'roleRequest' ]
204 tsharkOfString = main.params[ 'TSHARK' ][ 'ofpRoleReply' ]
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400205 tsharkFinAckSequence = main.params[ 'TSHARK' ][ 'finAckSequence' ]
jenkins8ba10ab2015-03-24 10:31:31 -0700206
jenkins7ead5a82015-03-13 10:28:21 -0700207 tsharkOfOutput = '/tmp/tshark_of_topo.txt'
208 tsharkTcpOutput = '/tmp/tshark_tcp_topo.txt'
jenkins8ba10ab2015-03-24 10:31:31 -0700209 tsharkRoleOutput = '/tmp/tshark_role_request.txt'
210 tsharkFeatureOutput = '/tmp/tshark_feature_reply.txt'
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400211 tsharkFinAckOutput = '/tmp/tshark_fin_ack.txt'
212
213 # Switch connect measurement list
214 # TCP Syn/Ack -> Feature Reply latency collection for each node
215 tcpToFeatureLatNodeIter = numpy.zeros((clusterCount, int(numIter)))
216 # Feature Reply -> Role Request latency collection for each node
217 featureToRoleRequestLatNodeIter = numpy.zeros((clusterCount,
218 int(numIter)))
219 # Role Request -> Role Reply latency collection for each node
220 roleRequestToRoleReplyLatNodeIter = numpy.zeros((clusterCount,
221 int(numIter)))
222 # Role Reply -> Device Update latency collection for each node
223 roleReplyToDeviceLatNodeIter = numpy.zeros((clusterCount,
224 int(numIter)))
225 # Device Update -> Graph Update latency collection for each node
226 deviceToGraphLatNodeIter = numpy.zeros((clusterCount,
227 int(numIter)))
andrew@onlab.us9210ba12015-04-09 14:11:27 -0400228 endToEndLatNodeIter = numpy.zeros((clusterCount, int(numIter)))
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400229
230 # Switch disconnect measurement lists
231 # Mininet Fin / Ack -> Mininet Ack
232 finAckTransactionLatNodeIter = numpy.zeros((clusterCount,
233 int(numIter)))
234 # Mininet Ack -> Device Event
235 ackToDeviceLatNodeIter = numpy.zeros((clusterCount,
236 int(numIter)))
237 # Device event -> Graph event
238 deviceToGraphDiscLatNodeIter = numpy.zeros((clusterCount,
239 int(numIter)))
andrew@onlab.us9210ba12015-04-09 14:11:27 -0400240 endToEndDiscLatNodeIter = numpy.zeros((clusterCount, int(numIter)))
jenkins7ead5a82015-03-13 10:28:21 -0700241
jenkins7ead5a82015-03-13 10:28:21 -0700242 assertion = main.TRUE
243 localTime = time.strftime('%x %X')
244 localTime = localTime.replace('/', '')
245 localTime = localTime.replace(' ', '_')
246 localTime = localTime.replace(':', '')
247
248 if debugMode == 'on':
249 main.ONOS1.tsharkPcap('eth0',
250 '/tmp/single_sw_lat_pcap_' + localTime)
251 main.log.info('Debug mode is on')
252 main.log.report('Latency of adding one switch to controller')
253 main.log.report('First ' + str(iterIgnore) +
254 ' iterations ignored' + ' for jvm warmup time')
255 main.log.report('Total iterations of test: ' + str(numIter))
256
257 for i in range(0, int(numIter)):
258 main.log.info('Starting tshark capture')
259 main.ONOS1.tsharkGrep(tsharkTcpString, tsharkTcpOutput)
260 main.ONOS1.tsharkGrep(tsharkOfString, tsharkOfOutput)
jenkins8ba10ab2015-03-24 10:31:31 -0700261 main.ONOS1.tsharkGrep(tsharkRoleRequest, tsharkRoleOutput)
262 main.ONOS1.tsharkGrep(tsharkFeatureReply, tsharkFeatureOutput)
263
jenkins7ead5a82015-03-13 10:28:21 -0700264 time.sleep(10)
265
266 main.log.info('Assigning s3 to controller')
267 main.Mininet1.assignSwController(sw='3',
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400268 ip1=nodeIpList[0], port1=defaultSwPort)
jenkins7ead5a82015-03-13 10:28:21 -0700269
270 time.sleep(10)
271
272 main.log.info('Stopping all Tshark processes')
273 main.ONOS1.tsharkStop()
274
275 main.log.info('Copying over tshark files')
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400276 os.system('scp ' + ONOSUser + '@' + nodeIpList[0] +
jenkins7ead5a82015-03-13 10:28:21 -0700277 ':' + tsharkTcpOutput + ' /tmp/')
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400278 os.system('scp ' + ONOSUser + '@' + nodeIpList[0] +
jenkins8ba10ab2015-03-24 10:31:31 -0700279 ':' + tsharkRoleOutput + ' /tmp/')
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400280 os.system('scp ' + ONOSUser + '@' + nodeIpList[0] +
jenkins8ba10ab2015-03-24 10:31:31 -0700281 ':' + tsharkFeatureOutput + ' /tmp/')
282 os.system('scp ' + ONOSUser + '@' +
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400283 nodeIpList[0] + ':' + tsharkOfOutput + ' /tmp/')
jenkins8ba10ab2015-03-24 10:31:31 -0700284
285 # Get tcp syn / ack output
jenkins7ead5a82015-03-13 10:28:21 -0700286 time.sleep(5)
287 tcpFile = open(tsharkTcpOutput, 'r')
288 tempText = tcpFile.readline()
289 tempText = tempText.split(' ')
290 main.log.info('Object read in from TCP capture: ' +
291 str(tempText))
292
293 if len(tempText) > 1:
294 t0Tcp = float(tempText[1]) * 1000.0
295 else:
296 main.log.error('Tshark output file for TCP' +
297 ' returned unexpected results')
298 t0Tcp = 0
299 assertion = main.FALSE
300 tcpFile.close()
jenkins8ba10ab2015-03-24 10:31:31 -0700301
302 # Get Role reply output
jenkins7ead5a82015-03-13 10:28:21 -0700303 time.sleep(5)
304 ofFile = open(tsharkOfOutput, 'r')
305 lineOfp = ''
306 while True:
307 tempText = ofFile.readline()
308 if tempText != '':
309 lineOfp = tempText
310 else:
311 break
jenkins7ead5a82015-03-13 10:28:21 -0700312 obj = lineOfp.split(' ')
313 main.log.info('Object read in from OFP capture: ' +
314 str(lineOfp))
315 if len(obj) > 1:
316 t0Ofp = float(obj[1]) * 1000.0
317 else:
318 main.log.error('Tshark output file for OFP' +
319 ' returned unexpected results')
320 t0Ofp = 0
321 assertion = main.FALSE
322 ofFile.close()
jenkins8ba10ab2015-03-24 10:31:31 -0700323
324 # Get role request output
325 roleFile = open(tsharkRoleOutput, 'r')
326 tempText = roleFile.readline()
327 tempText = tempText.split(' ')
328 if len(tempText) > 1:
329 main.log.info('Object read in from role request capture:' +
330 str(tempText))
331 roleTimestamp = float(tempText[1]) * 1000.0
332 else:
333 main.log.error('Tshark output file for role request' +
334 ' returned unexpected results')
335 timeRoleRequest = 0
336 assertion = main.FALSE
337 roleFile.close()
338
339 # Get feature reply output
340 featureFile = open(tsharkFeatureOutput, 'r')
341 tempText = featureFile.readline()
342 tempText = tempText.split(' ')
343 if len(tempText) > 1:
344 main.log.info('Object read in from feature reply capture: '+
345 str(tempText))
346 featureTimestamp = float(tempText[1]) * 1000.0
347 else:
348 main.log.error('Tshark output file for feature reply' +
349 ' returned unexpected results')
350 timeFeatureReply = 0
351 assertion = main.FALSE
352 featureFile.close()
353
354 # TODO: calculate feature reply, role request times
355 # stack measurements correctly and report
356
jenkins8ba10ab2015-03-24 10:31:31 -0700357 #TODO: Refactor in progress
358
359 for node in range(0, clusterCount):
360 nodeNum = node+1
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400361 metricsSwUp = CLIs[node].topologyEventsMetrics
jenkins8ba10ab2015-03-24 10:31:31 -0700362 jsonStr = metricsSwUp()
363 jsonObj = json.loads(jsonStr)
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400364 if jsonObj:
365 graphTimestamp = jsonObj[graphTimestampKey]['value']
366 deviceTimestamp = jsonObj[deviceTimestampKey]['value']
jenkins8ba10ab2015-03-24 10:31:31 -0700367 else:
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400368 main.log.error( "Unexpected JSON object" )
369 # If we could not obtain the JSON object,
370 # set the timestamps to 0, which will be
371 # excluded from the measurement later on
372 # (realized as invalid)
373 graphTimestamp = 0
374 deviceTimestamp = 0
375
376 endToEnd = int(graphTimestamp) - int(t0Tcp)
377
378 # Below are measurement breakdowns of the end-to-end
379 # measurement.
380 tcpToFeature = int(featureTimestamp) - int(t0Tcp)
381 featureToRole = int(roleTimestamp) - int(featureTimestamp)
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400382 roleToOfp = float(t0Ofp) - float(roleTimestamp)
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400383 ofpToDevice = float(deviceTimestamp) - float(t0Ofp)
384 # Timestamps gathered from ONOS are millisecond
385 # precision. They are returned as integers, thus no
386 # need to be more precise than 'int'. However,
387 # the processing seems to be mostly under 1 ms,
388 # thus this may be a problem point to handle any
389 # submillisecond output that we are unsure of.
390 # For now, this will be treated as 0 ms if less than 1 ms
391 deviceToGraph = int(graphTimestamp) - int(deviceTimestamp)
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400392
393 if endToEnd > thresholdMin and\
394 endToEnd < thresholdMax and i >= iterIgnore:
395 endToEndLatNodeIter[node][i] = endToEnd
396 main.log.info("ONOS "+str(nodeNum)+ " end-to-end: "+
397 str(endToEnd) + " ms")
398 else:
399 main.log.info("ONOS "+str(nodeNum)+ " end-to-end "+
jenkins8ba10ab2015-03-24 10:31:31 -0700400 "measurement ignored due to excess in "+
401 "threshold or premature iteration")
402
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400403 if tcpToFeature > thresholdMin and\
404 tcpToFeature < thresholdMax and i >= iterIgnore:
405 tcpToFeatureLatNodeIter[node][i] = tcpToFeature
406 main.log.info("ONOS "+str(nodeNum)+ " tcp-to-feature: "+
407 str(tcpToFeature) + " ms")
jenkins8ba10ab2015-03-24 10:31:31 -0700408 else:
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400409 main.log.info("ONOS "+str(nodeNum)+ " tcp-to-feature "+
jenkins8ba10ab2015-03-24 10:31:31 -0700410 "measurement ignored due to excess in "+
411 "threshold or premature iteration")
412
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400413 if featureToRole > thresholdMin and\
414 featureToRole < thresholdMax and i >= iterIgnore:
415 featureToRoleRequestLatNodeIter[node][i] = featureToRole
416 main.log.info("ONOS "+str(nodeNum)+ " feature-to-role: "+
417 str(featureToRole) + " ms")
jenkins8ba10ab2015-03-24 10:31:31 -0700418 else:
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400419 main.log.info("ONOS "+str(nodeNum)+ " feature-to-role "+
jenkins8ba10ab2015-03-24 10:31:31 -0700420 "measurement ignored due to excess in "+
421 "threshold or premature iteration")
422
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400423 if roleToOfp > thresholdMin and\
424 roleToOfp < thresholdMax and i >= iterIgnore:
425 roleRequestToRoleReplyLatNodeIter[node][i] = roleToOfp
426 main.log.info("ONOS "+str(nodeNum)+ " role-to-reply: "+
427 str(roleToOfp) + " ms")
428 else:
429 main.log.info("ONOS "+str(nodeNum)+ " role-to-reply "+
430 "measurement ignored due to excess in "+
431 "threshold or premature iteration")
432
433 if ofpToDevice > thresholdMin and\
434 ofpToDevice < thresholdMax and i >= iterIgnore:
435 roleReplyToDeviceLatNodeIter[node][i] = ofpToDevice
436 main.log.info("ONOS "+str(nodeNum)+ " reply-to-device: "+
437 str(ofpToDevice) + " ms")
438 else:
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400439 main.log.info("ONOS "+str(nodeNum)+ " reply-to-device "+
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400440 "measurement ignored due to excess in "+
441 "threshold or premature iteration")
jenkins8ba10ab2015-03-24 10:31:31 -0700442
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400443 if deviceToGraph > thresholdMin and\
444 deviceToGraph < thresholdMax and i >= iterIgnore:
445 deviceToGraphLatNodeIter[node][i] = deviceToGraph
446 main.log.info("ONOS "+str(nodeNum)+ " device-to-graph: "+
447 str(deviceToGraph) + " ms")
448 else:
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400449 if deviceToGraph == 0:
450 deviceToGraphLatNodeIter[node][i] = 0
451 main.log.info("ONOS "+str(nodeNum) +
452 " device-to-graph measurement "+
453 "was set to 0 ms because of precision "+
454 "uncertainty")
455 else:
456 main.log.info("ONOS "+str(nodeNum)+
457 " device-to-graph "+
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400458 "measurement ignored due to excess in "+
459 "threshold or premature iteration")
460
jenkins8ba10ab2015-03-24 10:31:31 -0700461 # ********************
jenkins7ead5a82015-03-13 10:28:21 -0700462 time.sleep(5)
463
464 # Get device id to remove
465 deviceIdJsonStr = main.ONOS1cli.devices()
466
467 main.log.info( "Device obj obtained: " + str(deviceIdJsonStr) )
468 deviceId = json.loads(deviceIdJsonStr)
469
470 deviceList = []
471 for device in deviceId:
472 deviceList.append(device['id'])
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400473
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400474 # Measure switch down metrics
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400475 # TCP FIN/ACK -> TCP FIN
476 # TCP FIN -> Device Event
477 # Device Event -> Graph Event
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400478 # Capture switch down FIN / ACK packets
479
andrew@onlab.us09a4a0c2015-04-09 13:38:13 -0400480 # The -A 1 grep option allows us to grab 1 extra line after the
481 # last tshark output grepped originally
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400482 main.ONOS1.tsharkGrep( tsharkFinAckSequence, tsharkFinAckOutput,
483 grepOptions = '-A 1' )
484
485 time.sleep( 5 )
486
487 removeJsonList = []
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400488
jenkins7ead5a82015-03-13 10:28:21 -0700489 main.step('Remove switch from controller')
490 main.Mininet1.deleteSwController('s3')
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400491 firstDevice = deviceList[0]
jenkins7ead5a82015-03-13 10:28:21 -0700492 main.log.info( "Removing device " +str(firstDevice)+
493 " from ONOS" )
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400494
495 time.sleep( 5 )
496
497 # We need to get metrics before removing
498 # device from the store below.
499 for node in range(0, clusterCount):
500 metricsSwDown = CLIs[node].topologyEventsMetrics
501 jsonStr = metricsSwDown()
502 removeJsonList.append( json.loads(jsonStr) )
503
jenkins7ead5a82015-03-13 10:28:21 -0700504 #if deviceId:
505 main.ONOS1cli.deviceRemove(firstDevice)
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400506
507 main.ONOS1.tsharkStop()
508
509 main.log.info('Copying over tshark files')
510 os.system('scp ' + ONOSUser + '@' + nodeIpList[0] +
511 ':' + tsharkFinAckOutput + ' /tmp/')
512
513 time.sleep( 10 )
514 finAckOutputList = []
515 with open(tsharkFinAckOutput, 'r') as f:
516 tempLine = f.readlines()
517 main.log.info('Object read in from FinAck capture: ' +
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400518 "\n".join(tempLine))
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400519
520 index = 1
521 for line in tempLine:
522 obj = line.split(' ')
jenkins7ead5a82015-03-13 10:28:21 -0700523
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400524 if len(obj) > 1:
525 if index == 1:
526 tFinAck = float(obj[1]) * 1000.0
527 elif index == 3:
528 tAck = float(obj[1]) * 1000.0
529 else:
530 main.log.error('Tshark output file for OFP' +
531 ' returned unexpected results')
532 tFinAck = 0
533 tAck = 0
534 assertion = main.FALSE
535
536 index = index+1
537
538 # with open() as f takes care of closing file
539
jenkins7ead5a82015-03-13 10:28:21 -0700540 time.sleep(5)
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400541
542 for node in range(0, clusterCount):
543 nodeNum = node+1
544 jsonObj = removeJsonList[node]
545 if jsonObj:
546 graphTimestamp = jsonObj[graphTimestampKey]['value']
547 deviceTimestamp = jsonObj[deviceTimestampKey]['value']
548 main.log.info("Graph timestamp: "+str(graphTimestamp))
549 main.log.info("Device timestamp: "+str(deviceTimestamp))
550 else:
551 main.log.error( "Unexpected JSON object" )
552 # If we could not obtain the JSON object,
553 # set the timestamps to 0, which will be
554 # excluded from the measurement later on
555 # (realized as invalid)
556 graphTimestamp = 0
557 deviceTimestamp = 0
558
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400559 finAckTransaction = float(tAck) - float(tFinAck)
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400560 ackToDevice = int(deviceTimestamp) - int(tAck)
561 deviceToGraph = int(graphTimestamp) - int(deviceTimestamp)
andrew@onlab.us9210ba12015-04-09 14:11:27 -0400562 endToEndDisc = int(graphTimestamp) - int(tFinAck)
563
564 if endToEndDisc > thresholdMin and\
565 endToEndDisc < thresholdMax and i >= iterIgnore:
566 endToEndDiscLatNodeIter[node][i] = endToEndDisc
567 main.log.info("ONOS "+str(nodeNum) +
568 "end-to-end disconnection: "+
569 str(endToEndDisc) + " ms" )
570 else:
571 main.log.info("ONOS " + str(nodeNum) +
572 " end-to-end disconnection "+
573 "measurement ignored due to excess in "+
574 "threshold or premature iteration")
575
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400576 if finAckTransaction > thresholdMin and\
577 finAckTransaction < thresholdMax and i >= iterIgnore:
578 finAckTransactionLatNodeIter[node][i] = finAckTransaction
579 main.log.info("ONOS "+str(nodeNum)+
580 " fin/ack transaction: "+
581 str(finAckTransaction) + " ms")
582 else:
583 main.log.info("ONOS "+str(nodeNum)+
584 " fin/ack transaction "+
585 "measurement ignored due to excess in "+
586 "threshold or premature iteration")
587
588 if ackToDevice > thresholdMin and\
589 ackToDevice < thresholdMax and i >= iterIgnore:
590 ackToDeviceLatNodeIter[node][i] = ackToDevice
591 main.log.info("ONOS "+str(nodeNum)+
592 " ack-to-device: "+
593 str(ackToDevice) + " ms")
594 else:
595 main.log.info("ONOS "+str(nodeNum)+
596 " ack-to-device "+
597 "measurement ignored due to excess in "+
598 "threshold or premature iteration")
599
600 if deviceToGraph > thresholdMin and\
601 deviceToGraph < thresholdMax and i >= iterIgnore:
602 deviceToGraphDiscLatNodeIter[node][i] = deviceToGraph
603 main.log.info("ONOS "+str(nodeNum)+
604 " device-to-graph disconnect: "+
605 str(deviceToGraph) + " ms")
606 else:
607 main.log.info("ONOS "+str(nodeNum)+
608 " device-to-graph disconnect "+
609 "measurement ignored due to excess in "+
610 "threshold or premature iteration")
jenkins7ead5a82015-03-13 10:28:21 -0700611
612 endToEndAvg = 0
613 ofpToGraphAvg = 0
jenkins7ead5a82015-03-13 10:28:21 -0700614 dbCmdList = []
615 for node in range(0, clusterCount):
jenkins8ba10ab2015-03-24 10:31:31 -0700616 # List of latency for each node
617 endToEndList = []
jenkins8ba10ab2015-03-24 10:31:31 -0700618 tcpToFeatureList = []
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400619 featureToRoleList = []
620 roleToOfpList = []
621 ofpToDeviceList = []
622 deviceToGraphList = []
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400623
624 finAckTransactionList = []
625 ackToDeviceList = []
626 deviceToGraphDiscList = []
andrew@onlab.us9210ba12015-04-09 14:11:27 -0400627 endToEndDiscList = []
628
jenkins8ba10ab2015-03-24 10:31:31 -0700629 # LatNodeIter 2d arrays contain all iteration latency
630 # for each node of the current scale cluster size
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400631 # Switch connection measurements
632 # Set further acceptance criteria for measurements
633 # here if you would like to filter reporting results
jenkins7ead5a82015-03-13 10:28:21 -0700634 for item in endToEndLatNodeIter[node]:
635 if item > 0.0:
636 endToEndList.append(item)
637
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400638 for item in tcpToFeatureLatNodeIter[node]:
jenkins8ba10ab2015-03-24 10:31:31 -0700639 if item > 0.0:
640 tcpToFeatureList.append(item)
641
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400642 for item in featureToRoleRequestLatNodeIter[node]:
jenkins8ba10ab2015-03-24 10:31:31 -0700643 if item > 0.0:
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400644 featureToRoleList.append(item)
645
646 for item in roleRequestToRoleReplyLatNodeIter[node]:
647 if item > 0.0:
648 roleToOfpList.append(item)
649
650 for item in roleReplyToDeviceLatNodeIter[node]:
651 if item > 0.0:
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400652 tcpToFeatureList.append(item)
653
654 for item in featureToRoleRequestLatNodeIter[node]:
655 if item > 0.0:
656 featureToRoleList.append(item)
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400657
658 for item in deviceToGraphLatNodeIter[node]:
659 if item > 0.0:
660 deviceToGraphList.append(item)
jenkins8ba10ab2015-03-24 10:31:31 -0700661
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400662 # Switch disconnect measurements
andrew@onlab.us9210ba12015-04-09 14:11:27 -0400663 for item in endToEndDiscLatNodeIter[node]:
664 if item > 0.0:
665 endToEndDiscList.append(item)
666
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400667 for item in finAckTransactionLatNodeIter[node]:
668 if item > 0.0:
669 finAckTransactionList.append(item)
670
671 for item in ackToDeviceLatNodeIter[node]:
672 if item > 0.0:
673 ackToDeviceList.append(item)
674
675 for item in deviceToGraphDiscLatNodeIter[node]:
676 if item > 0.0:
677 deviceToGraphDiscList.append(item)
678
jenkins7ead5a82015-03-13 10:28:21 -0700679 endToEndAvg = round(numpy.mean(endToEndList), 2)
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400680 endToEndStdDev = round(numpy.std(endToEndList), 2)
681
jenkins8ba10ab2015-03-24 10:31:31 -0700682 tcpToFeatureAvg = round(numpy.mean(tcpToFeatureList), 2)
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400683 tcpToFeatureStdDev = round(numpy.std(tcpToFeatureList), 2)
684
685 featureToRoleAvg = round(numpy.mean(featureToRoleList), 2)
686 featureToRoleStdDev = round(numpy.std(featureToRoleList), 2)
687
688 roleToOfpAvg = round(numpy.mean(roleToOfpList), 2)
689 roleToOfpStdDev = round(numpy.std(roleToOfpList), 2)
690
jenkins7ead5a82015-03-13 10:28:21 -0700691 ofpToDeviceAvg = round(numpy.mean(ofpToDeviceList), 2)
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400692 ofpToDeviceStdDev = round(numpy.std(ofpToDeviceList), 2)
693
694 deviceToGraphAvg = round(numpy.mean(deviceToGraphList), 2)
695 deviceToGraphStdDev = round(numpy.std(deviceToGraphList), 2)
696
andrew@onlab.us9210ba12015-04-09 14:11:27 -0400697 endToEndDiscAvg = round(numpy.mean(endToEndDiscList), 2)
698 endToEndDiscStdDev = round(numpy.std(endToEndDiscList), 2)
699
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400700 finAckAvg = round(numpy.mean(finAckTransactionList), 2)
701 finAckStdDev = round(numpy.std(finAckTransactionList), 2)
702
703 ackToDeviceAvg = round(numpy.mean(ackToDeviceList), 2)
704 ackToDeviceStdDev = round(numpy.std(ackToDeviceList), 2)
705
706 deviceToGraphDiscAvg = round(numpy.mean(deviceToGraphDiscList), 2)
707 deviceToGraphDiscStdDev = round(numpy.std(deviceToGraphDiscList), 2)
708
jenkins7ead5a82015-03-13 10:28:21 -0700709 main.log.report(' - Node ' + str(node + 1) + ' Summary - ')
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400710 main.log.report(' - Switch Connection Statistics - ')
711
jenkins7ead5a82015-03-13 10:28:21 -0700712 main.log.report(' End-to-end Avg: ' + str(endToEndAvg) +
713 ' ms' + ' End-to-end Std dev: ' +
andrew@onlab.us0f468c42015-04-02 17:05:47 -0400714 str(endToEndStdDev) + ' ms')
715
716 main.log.report(' Tcp-to-feature-reply Avg: ' +
717 str(tcpToFeatureAvg) + ' ms')
718 main.log.report(' Tcp-to-feature-reply Std dev: '+
719 str(tcpToFeatureStdDev) + ' ms')
720
721 main.log.report(' Feature-reply-to-role-request Avg: ' +
722 str(featureToRoleAvg) + ' ms')
723 main.log.report(' Feature-reply-to-role-request Std Dev: ' +
724 str(featureToRoleStdDev) + ' ms')
725
726 main.log.report(' Role-request-to-role-reply Avg: ' +
727 str(roleToOfpAvg) +' ms')
728 main.log.report(' Role-request-to-role-reply Std dev: ' +
729 str(roleToOfpStdDev) + ' ms')
730
731 main.log.report(' Role-reply-to-device Avg: ' +
732 str(ofpToDeviceAvg) +' ms')
733 main.log.report(' Role-reply-to-device Std dev: ' +
734 str(ofpToDeviceStdDev) + ' ms')
735
736 main.log.report(' Device-to-graph Avg: ' +
737 str(deviceToGraphAvg) + ' ms')
738 main.log.report( 'Device-to-graph Std dev: ' +
739 str(deviceToGraphStdDev) + ' ms')
740
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400741 main.log.report(' - Switch Disconnection Statistics - ')
andrew@onlab.us9210ba12015-04-09 14:11:27 -0400742 main.log.report(' End-to-end switch disconnect Avg: ' +
743 str(endToEndDiscAvg) + ' ms')
744 main.log.report(' End-to-end switch disconnect Std dev: ' +
745 str(endToEndDiscStdDev) + ' ms')
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400746 main.log.report(' Fin/Ack-to-Ack Avg: ' + str(finAckAvg) + ' ms')
747 main.log.report(' Fin/Ack-to-Ack Std dev: ' +
748 str(finAckStdDev) + ' ms')
749
750 main.log.report(' Ack-to-device Avg: ' + str(ackToDeviceAvg) +
751 ' ms')
752 main.log.report(' Ack-to-device Std dev: ' + str(ackToDeviceStdDev) +
753 ' ms')
754
755 main.log.report(' Device-to-graph (disconnect) Avg: ' +
756 str(deviceToGraphDiscAvg) + ' ms')
757 main.log.report(' Device-to-graph (disconnect) Std dev: ' +
758 str(deviceToGraphDiscStdDev) + ' ms')
759
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400760 # For database schema, refer to Amazon web services
jenkins7ead5a82015-03-13 10:28:21 -0700761 dbCmdList.append(
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400762 "INSERT INTO switch_latency_details VALUES('" +
jenkins7ead5a82015-03-13 10:28:21 -0700763 timeToPost + "','switch_latency_results'," +
andrew@onlab.us09a4a0c2015-04-09 13:38:13 -0400764 jenkinsBuildNumber + ',' + str(clusterCount) + ",'baremetal" +
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400765 str(node + 1) + "'," +
766 str(endToEndAvg) + ',' +
767 str(tcpToFeatureAvg) + ',' +
768 str(featureToRoleAvg) + ',' +
769 str(roleToOfpAvg) + ',' +
770 str(ofpToDeviceAvg) + ',' +
771 str(deviceToGraphAvg) + ',' +
772 str(endToEndDiscAvg) + ',' +
773 str(finAckAvg) + ',' +
774 str(ackToDeviceAvg) + ',' +
775 str(deviceToGraphDiscAvg) +
776 ');')
jenkins7ead5a82015-03-13 10:28:21 -0700777
778 if debugMode == 'on':
779 main.ONOS1.cpLogsToDir('/opt/onos/log/karaf.log',
780 '/tmp/', copyFileName='sw_lat_karaf')
781 fResult = open(resultPath, 'a')
782 for line in dbCmdList:
783 if line:
784 fResult.write(line + '\n')
jenkins7ead5a82015-03-13 10:28:21 -0700785 fResult.close()
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400786
jenkins7ead5a82015-03-13 10:28:21 -0700787 assertion = main.TRUE
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -0400788
jenkins7ead5a82015-03-13 10:28:21 -0700789 utilities.assert_equals(expect=main.TRUE, actual=assertion,
790 onpass='Switch latency test successful',
791 onfail='Switch latency test failed')
792
793 def CASE3(self, main):
794 """
795 Bring port up / down and measure latency.
796 Port enable / disable is simulated by ifconfig up / down
797
798 In ONOS-next, we must ensure that the port we are
799 manipulating is connected to another switch with a valid
800 connection. Otherwise, graph view will not be updated.
801 """
802 global timeToPost
803 import time
804 import subprocess
805 import os
806 import requests
807 import json
808 import numpy
809 ONOS1Ip = main.params['CTRL']['ip1']
810 ONOS2Ip = main.params['CTRL']['ip2']
811 ONOS3Ip = main.params['CTRL']['ip3']
812 ONOSUser = main.params['CTRL']['user']
813 defaultSwPort = main.params['CTRL']['port1']
814 assertion = main.TRUE
815 numIter = main.params['TEST']['numIter']
816 iterIgnore = int(main.params['TEST']['iterIgnore'])
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400817
818 deviceTimestampKey = main.params['JSON']['deviceTimestamp']
819 graphTimestampKey = main.params['JSON']['graphTimestamp']
820 linkTimestampKey = main.params['JSON']['linkTimestamp']
jenkins7ead5a82015-03-13 10:28:21 -0700821
822 tsharkPortUp = '/tmp/tshark_port_up.txt'
823 tsharkPortDown = '/tmp/tshark_port_down.txt'
824 tsharkPortStatus = main.params[ 'TSHARK' ][ 'ofpPortStatus' ]
825
826 debugMode = main.params['TEST']['debugMode']
827 postToDB = main.params['DB']['postToDB']
828 resultPath = main.params['DB']['portEventResultPath']
829 timeToPost = time.strftime('%Y-%m-%d %H:%M:%S')
830 localTime = time.strftime('%x %X')
831 localTime = localTime.replace('/', '')
832 localTime = localTime.replace(' ', '_')
833 localTime = localTime.replace(':', '')
834
835 if debugMode == 'on':
836 main.ONOS1.tsharkPcap('eth0', '/tmp/port_lat_pcap_' + localTime)
837
838 upThresholdStr = main.params['TEST']['portUpThreshold']
839 downThresholdStr = main.params['TEST']['portDownThreshold']
840 upThresholdObj = upThresholdStr.split(',')
841 downThresholdObj = downThresholdStr.split(',')
842 upThresholdMin = int(upThresholdObj[0])
843 upThresholdMax = int(upThresholdObj[1])
844 downThresholdMin = int(downThresholdObj[0])
845 downThresholdMax = int(downThresholdObj[1])
846
847 interfaceConfig = 's1-eth1'
848 main.log.report('Port enable / disable latency')
849 main.log.report('Simulated by ifconfig up / down')
850 main.log.report('Total iterations of test: ' + str(numIter))
851 main.step('Assign switches s1 and s2 to controller 1')
852
853 main.Mininet1.assignSwController(sw='1',
854 ip1=ONOS1Ip, port1=defaultSwPort)
855 main.Mininet1.assignSwController(sw='2',
856 ip1=ONOS1Ip, port1=defaultSwPort)
857
858 time.sleep(15)
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400859
860 portUpEndToEndNodeIter = numpy.zeros((clusterCount, int(numIter)))
861 portUpOfpToDevNodeIter = numpy.zeros((clusterCount, int(numIter)))
862 portUpDevToLinkNodeIter = numpy.zeros((clusterCount, int(numIter)))
863 portUpLinkToGraphNodeIter = numpy.zeros((clusterCount, int(numIter)))
864
865 portDownEndToEndNodeIter = numpy.zeros((clusterCount, int(numIter)))
866 portDownOfpToDevNodeIter = numpy.zeros((clusterCount, int(numIter)))
867 portDownDevToLinkNodeIter = numpy.zeros((clusterCount, int(numIter)))
868 portDownLinkToGraphNodeIter = numpy.zeros((clusterCount, int(numIter)))
jenkins7ead5a82015-03-13 10:28:21 -0700869
870 for i in range(0, int(numIter)):
871 main.step('Starting wireshark capture for port status down')
872 main.ONOS1.tsharkGrep(tsharkPortStatus, tsharkPortDown)
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400873
jenkins7ead5a82015-03-13 10:28:21 -0700874 time.sleep(5)
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400875
jenkins7ead5a82015-03-13 10:28:21 -0700876 main.step('Disable port: ' + interfaceConfig)
877 main.Mininet1.handle.sendline('sh ifconfig ' +
878 interfaceConfig + ' down')
879 main.Mininet1.handle.expect('mininet>')
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400880
jenkins7ead5a82015-03-13 10:28:21 -0700881 time.sleep(3)
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400882
jenkins7ead5a82015-03-13 10:28:21 -0700883 main.ONOS1.tsharkStop()
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400884
jenkins7ead5a82015-03-13 10:28:21 -0700885 os.system('scp ' + ONOSUser + '@' + ONOS1Ip + ':' +
886 tsharkPortDown + ' /tmp/')
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400887
jenkins7ead5a82015-03-13 10:28:21 -0700888 fPortDown = open(tsharkPortDown, 'r')
889 fLine = fPortDown.readline()
890 objDown = fLine.split(' ')
891 if len(fLine) > 0:
892 timestampBeginPtDown = int(float(objDown[1]) * 1000)
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400893 # At times, tshark reports timestamp at the 3rd
894 # index of the array. If initial readings were
895 # unlike the epoch timestamp, then check the 3rd
896 # index and set that as a timestamp
jenkins7ead5a82015-03-13 10:28:21 -0700897 if timestampBeginPtDown < 1400000000000:
898 timestampBeginPtDown = int(float(objDown[2]) * 1000)
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400899 # If there are any suspicion of invalid results
900 # check this reported value
jenkins7ead5a82015-03-13 10:28:21 -0700901 main.log.info('Port down begin timestamp: ' +
902 str(timestampBeginPtDown))
903 else:
904 main.log.info('Tshark output file returned unexpected' +
905 ' results: ' + str(objDown))
906 timestampBeginPtDown = 0
907 fPortDown.close()
jenkins8ba10ab2015-03-24 10:31:31 -0700908
jenkins8ba10ab2015-03-24 10:31:31 -0700909 for node in range(0, clusterCount):
910 nodeNum = node+1
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400911 metricsDown = CLIs[node].topologyEventsMetrics
jenkins8ba10ab2015-03-24 10:31:31 -0700912 jsonStrDown = metricsDown()
913 jsonObj = json.loads(jsonStrDown)
914
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -0400915 if jsonObj:
916 graphTimestamp = jsonObj[graphTimestampKey]['value']
917 deviceTimestamp = jsonObj[deviceTimestampKey]['value']
918 linkTimestamp = jsonObj[linkTimestampKey]['value']
919 else:
920 main.log.error( "Unexpected json object" )
921 graphTimestamp = 0
922 deviceTimestamp = 0
923 linkTimestamp = 0
924
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400925 ptDownEndToEnd = int(graphTimestamp) - int(timestampBeginPtDown)
926 ptDownOfpToDevice = int(deviceTimestamp) - int(timestampBeginPtDown)
927 ptDownDeviceToLink = int(linkTimestamp) - int(deviceTimestamp)
928 ptDownLinkToGraph = int(graphTimestamp) - int(linkTimestamp)
jenkins8ba10ab2015-03-24 10:31:31 -0700929
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400930 if ptDownEndToEnd > downThresholdMin and\
931 ptDownEndToEnd < downThresholdMax and i >= iterIgnore:
932 portDownEndToEndNodeIter[node][i] = ptDownEndToEnd
jenkins8ba10ab2015-03-24 10:31:31 -0700933 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400934 " port down End-to-end: "+
935 str(ptDownEndToEnd) + " ms")
jenkins8ba10ab2015-03-24 10:31:31 -0700936 else:
937 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400938 " port down End-to-end ignored"+
jenkins8ba10ab2015-03-24 10:31:31 -0700939 " due to excess in threshold or premature iteration")
940
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400941 if ptDownOfpToDevice > downThresholdMin and\
942 ptDownOfpToDevice < downThresholdMax and i >= iterIgnore:
943 portDownOfpToDevNodeIter[node][i] = ptDownOfpToDevice
jenkins8ba10ab2015-03-24 10:31:31 -0700944 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400945 " port down Ofp-to-device: "+
946 str(ptDownOfpToDevice) + " ms")
jenkins8ba10ab2015-03-24 10:31:31 -0700947 else:
948 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400949 " port down Ofp-to-device ignored"+
jenkins8ba10ab2015-03-24 10:31:31 -0700950 " due to excess in threshold or premature iteration")
951
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400952 if ptDownDeviceToLink > downThresholdMin and\
953 ptDownDeviceToLink < downThresholdMax and i >= iterIgnore:
954 portDownDevToLinkNodeIter[node][i] = ptDownDeviceToLink
jenkins8ba10ab2015-03-24 10:31:31 -0700955 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400956 " port down Device-to-link "+
957 str(ptDownDeviceToLink) + " ms")
jenkins8ba10ab2015-03-24 10:31:31 -0700958 else:
959 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -0400960 " port down Device-to-link ignored"+
961 " due to excess in threshold or premature iteration")
962
963 if ptDownLinkToGraph > downThresholdMin and\
964 ptDownLinkToGraph < downThresholdMax and i >= iterIgnore:
965 portDownLinkToGraphNodeIter[node][i] = ptDownLinkToGraph
966 main.log.info("ONOS "+str(nodeNum)+
967 " port down Link-to-graph "+
968 str(ptDownLinkToGraph) + " ms")
969 else:
970 main.log.info("ONOS "+str(nodeNum)+
971 " port down Link-to-graph ignored"+
jenkins8ba10ab2015-03-24 10:31:31 -0700972 " due to excess in threshold or premature iteration")
jenkins8ba10ab2015-03-24 10:31:31 -0700973
jenkins7ead5a82015-03-13 10:28:21 -0700974 time.sleep(3)
975
976 main.step('Starting wireshark capture for port status up')
977 main.ONOS1.tsharkGrep(tsharkPortStatus, tsharkPortUp)
978
979 time.sleep(5)
980 main.step('Enable port and obtain timestamp')
981 main.Mininet1.handle.sendline('sh ifconfig ' + interfaceConfig + ' up')
982 main.Mininet1.handle.expect('mininet>')
983
984 time.sleep(5)
985 main.ONOS1.tsharkStop()
986
987 time.sleep(3)
988 os.system('scp ' + ONOSUser + '@' +
989 ONOS1Ip + ':' + tsharkPortUp + ' /tmp/')
990
991 fPortUp = open(tsharkPortUp, 'r')
992 fLine = fPortUp.readline()
993 objUp = fLine.split(' ')
994 if len(fLine) > 0:
995 timestampBeginPtUp = int(float(objUp[1]) * 1000)
996 if timestampBeginPtUp < 1400000000000:
997 timestampBeginPtUp = int(float(objUp[2]) * 1000)
998 main.log.info('Port up begin timestamp: ' + str(timestampBeginPtUp))
999 else:
1000 main.log.info('Tshark output file returned unexpected' + ' results.')
1001 timestampBeginPtUp = 0
1002 fPortUp.close()
jenkins8ba10ab2015-03-24 10:31:31 -07001003
1004 for node in range(0, clusterCount):
1005 nodeNum = node+1
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -04001006 metricsUp = CLIs[node].topologyEventsMetrics
jenkins8ba10ab2015-03-24 10:31:31 -07001007 jsonStrUp = metricsUp()
1008 jsonObj = json.loads(jsonStrUp)
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -04001009
1010 if jsonObj:
1011 graphTimestamp = jsonObj[graphTimestampKey]['value']
1012 deviceTimestamp = jsonObj[deviceTimestampKey]['value']
1013 linkTimestamp = jsonObj[linkTimestampKey]['value']
1014 else:
1015 main.log.error( "Unexpected json object" )
1016 graphTimestamp = 0
1017 deviceTimestamp = 0
1018 linkTimestamp = 0
jenkins8ba10ab2015-03-24 10:31:31 -07001019
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001020 ptUpEndToEnd = int(graphTimestamp) - int(timestampBeginPtUp)
1021 ptUpOfpToDevice = int(deviceTimestamp) - int(timestampBeginPtUp)
1022 ptUpDeviceToLink = int(linkTimestamp) - int(deviceTimestamp)
1023 ptUpLinkToGraph = int(graphTimestamp) - int(linkTimestamp)
jenkins8ba10ab2015-03-24 10:31:31 -07001024
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001025 if ptUpEndToEnd > upThresholdMin and\
1026 ptUpEndToEnd < upThresholdMax and i > iterIgnore:
1027 portUpEndToEndNodeIter[node][i] = ptUpEndToEnd
jenkins8ba10ab2015-03-24 10:31:31 -07001028 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001029 " port up End-to-end: "+
1030 str(ptUpEndToEnd) + " ms")
jenkins8ba10ab2015-03-24 10:31:31 -07001031 else:
1032 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001033 " port up End-to-end ignored"+
jenkins8ba10ab2015-03-24 10:31:31 -07001034 " due to excess in threshold or premature iteration")
1035
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001036 if ptUpOfpToDevice > upThresholdMin and\
1037 ptUpOfpToDevice < upThresholdMax and i > iterIgnore:
1038 portUpOfpToDevNodeIter[node][i] = ptUpOfpToDevice
jenkins8ba10ab2015-03-24 10:31:31 -07001039 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001040 " port up Ofp-to-device: "+
1041 str(ptUpOfpToDevice) + " ms")
jenkins8ba10ab2015-03-24 10:31:31 -07001042 else:
1043 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001044 " port up Ofp-to-device ignored"+
jenkins8ba10ab2015-03-24 10:31:31 -07001045 " due to excess in threshold or premature iteration")
1046
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001047 if ptUpDeviceToLink > upThresholdMin and\
1048 ptUpDeviceToLink < upThresholdMax and i > iterIgnore:
1049 portUpDevToLinkNodeIter[node][i] = ptUpDeviceToLink
jenkins8ba10ab2015-03-24 10:31:31 -07001050 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001051 " port up Device-to-link: "+
1052 str(ptUpDeviceToLink) + " ms")
jenkins8ba10ab2015-03-24 10:31:31 -07001053 else:
1054 main.log.info("ONOS "+str(nodeNum)+
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001055 " port up Device-to-link ignored"+
1056 " due to excess in threshold or premature iteration")
1057
1058 if ptUpLinkToGraph > upThresholdMin and\
1059 ptUpLinkToGraph < upThresholdMax and i > iterIgnore:
1060 portUpLinkToGraphNodeIter[node][i] = ptUpLinkToGraph
1061 main.log.info("ONOS "+str(nodeNum)+
1062 " port up Link-to-graph: "+
1063 str(ptUpLinkToGraph) + " ms")
1064 else:
1065 main.log.info("ONOS "+str(nodeNum)+
1066 " port up Link-to-graph ignored"+
jenkins8ba10ab2015-03-24 10:31:31 -07001067 " due to excess in threshold or premature iteration")
1068
jenkins7ead5a82015-03-13 10:28:21 -07001069 dbCmdList = []
1070 for node in range(0, clusterCount):
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001071 portUpEndToEndList = []
1072 portUpOfpToDevList = []
1073 portUpDevToLinkList = []
1074 portUpLinkToGraphList = []
jenkins8ba10ab2015-03-24 10:31:31 -07001075
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001076 portDownEndToEndList = []
1077 portDownOfpToDevList = []
1078 portDownDevToLinkList = []
1079 portDownLinkToGraphList = []
1080
1081 portUpEndToEndAvg = 0
1082 portUpOfpToDevAvg = 0
1083 portUpDevToLinkAvg = 0
1084 portUpLinkToGraphAvg = 0
1085
1086 portDownEndToEndAvg = 0
1087 portDownOfpToDevAvg = 0
1088 portDownDevToLinkAvg = 0
1089 portDownLinkToGraphAvg = 0
jenkins8ba10ab2015-03-24 10:31:31 -07001090
andrew@onlab.usaa1f0dc2015-04-10 12:18:01 -04001091 # TODO: Update for more pythonic way to get list
1092 # portUpDevList = [item for item in portUpDevNodeIter[node]
1093 # if item > 0.0]
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001094 for item in portUpEndToEndNodeIter[node]:
jenkins7ead5a82015-03-13 10:28:21 -07001095 if item > 0.0:
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001096 portUpEndToEndList.append(item)
jenkins7ead5a82015-03-13 10:28:21 -07001097
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001098 for item in portUpOfpToDevNodeIter[node]:
jenkins7ead5a82015-03-13 10:28:21 -07001099 if item > 0.0:
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001100 portUpOfpToDevList.append(item)
1101
1102 for item in portUpDevToLinkNodeIter[node]:
jenkins8ba10ab2015-03-24 10:31:31 -07001103 if item > 0.0:
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001104 portUpDevToLinkList.append(item)
jenkins8ba10ab2015-03-24 10:31:31 -07001105
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001106 for item in portUpLinkToGraphNodeIter[node]:
jenkins7ead5a82015-03-13 10:28:21 -07001107 if item > 0.0:
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001108 portUpLinkToGraphList.append(item)
jenkins7ead5a82015-03-13 10:28:21 -07001109
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001110
1111 for item in portDownEndToEndNodeIter[node]:
jenkins7ead5a82015-03-13 10:28:21 -07001112 if item > 0.0:
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001113 portDownEndToEndList.append(item)
jenkins7ead5a82015-03-13 10:28:21 -07001114
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001115 for item in portDownOfpToDevNodeIter[node]:
jenkins8ba10ab2015-03-24 10:31:31 -07001116 if item > 0.0:
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001117 portDownOfpToDevList.append(item)
jenkins8ba10ab2015-03-24 10:31:31 -07001118
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001119 for item in portDownDevToLinkNodeIter[node]:
1120 if item > 0.0:
1121 portDownDevToLinkList.append(item)
jenkins8ba10ab2015-03-24 10:31:31 -07001122
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001123 for item in portDownLinkToGraphNodeIter[node]:
1124 if item > 0.0:
1125 portDownLinkToGraphList.append(item)
1126
1127 portUpEndToEndAvg = round(numpy.mean(portUpEndToEndList), 2)
1128 portUpOfpToDevAvg = round(numpy.mean(portUpOfpToDevList), 2)
1129 portUpDevToLinkAvg = round(numpy.mean(portUpDevToLinkList), 2)
1130 portUpLinkToGraphAvg = round(numpy.mean(portUpLinkToGraphList), 2)
1131
1132 portDownEndToEndAvg = round(numpy.mean(portDownEndToEndList), 2)
1133 portDownOfpToDevAvg = round(numpy.mean(portDownOfpToDevList), 2)
1134 portDownDevToLinkAvg = round(numpy.mean(portDownDevToLinkList), 2)
1135 portDownLinkToGraphAvg = round(numpy.mean(portDownLinkToGraphList), 2)
jenkins8ba10ab2015-03-24 10:31:31 -07001136
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001137 portUpStdDev = round(numpy.std(portUpEndToEndList), 2)
1138 portDownStdDev = round(numpy.std(portDownEndToEndList), 2)
jenkins8ba10ab2015-03-24 10:31:31 -07001139
jenkins7ead5a82015-03-13 10:28:21 -07001140 main.log.report(' - Node ' + str(node + 1) + ' Summary - ')
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001141 main.log.report(' Port up End-to-end ' +
1142 str(portUpEndToEndAvg) + ' ms')
1143 main.log.report(' Port up Ofp-to-device ' +
1144 str(portUpOfpToDevAvg) + ' ms')
1145 main.log.report(' Port up Device-to-link ' +
1146 str(portUpDevToLinkAvg) + ' ms')
1147 main.log.report(' Port up Link-to-graph ' +
1148 str(portUpLinkToGraphAvg) + ' ms')
jenkins8ba10ab2015-03-24 10:31:31 -07001149
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001150 main.log.report(' Port down End-to-end ' +
1151 str(round(portDownEndToEndAvg, 2)) + ' ms')
1152 main.log.report(' Port down Ofp-to-device ' +
1153 str(portDownOfpToDevAvg) + ' ms')
1154 main.log.report(' Port down Device-to-link' +
1155 str(portDownDevToLinkAvg) + ' ms')
1156 main.log.report(' Port down Link-to-graph' +
1157 str(portDownLinkToGraphAvg) + ' ms')
jenkins8ba10ab2015-03-24 10:31:31 -07001158
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001159 dbCmdList.append("INSERT INTO port_latency_details VALUES('" +
andrew@onlab.us09a4a0c2015-04-09 13:38:13 -04001160 timeToPost + "','port_latency_results'," + jenkinsBuildNumber +
jenkins7ead5a82015-03-13 10:28:21 -07001161 ',' + str(clusterCount) + ",'baremetal" + str(node + 1) +
andrew@onlab.usede8aaf2015-04-10 14:32:26 -04001162 "'," +
1163 str(portUpEndToEndAvg) +',' +
1164 str(portUpOfpToDevAvg) + ',' +
1165 str(portUpDevToLinkAvg) + ',' +
1166 str(portUpLinkToGraphAvg) + ',' +
1167 str(portDownEndToEndAvg) + ',' +
1168 str(portDownOfpToDevAvg) + ',' +
1169 str(portDownDevToLinkAvg) + ',' +
1170 str(portDownLinkToGraphAvg) +
1171 ');')
jenkins7ead5a82015-03-13 10:28:21 -07001172
1173 fResult = open(resultPath, 'a')
1174 for line in dbCmdList:
1175 if line:
1176 fResult.write(line + '\n')
1177
1178 fResult.close()
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -04001179
1180 # Delete switches from controller to prepare for next
1181 # set of tests
jenkins7ead5a82015-03-13 10:28:21 -07001182 main.Mininet1.deleteSwController('s1')
1183 main.Mininet1.deleteSwController('s2')
1184 utilities.assert_equals(expect=main.TRUE,
1185 actual=assertion,
1186 onpass='Port discovery latency calculation successful',
1187 onfail='Port discovery test failed')
1188
1189 def CASE4(self, main):
1190 """
1191 Increase number of nodes and initiate CLI
1192
1193 With the most recent implementation, we need a method to
1194 ensure all ONOS nodes are killed, as well as redefine
1195 the cell files to ensure all nodes that will be used
1196 is in the cell file. Otherwise, exceptions will
1197 prohibit test from running successfully.
1198
1199 3/12/15
1200
1201 """
1202 global clusterCount
1203 import time
1204 import os
1205
1206 clusterCount += 2
1207
1208 benchIp = main.params[ 'BENCH' ][ 'ip' ]
1209 features = main.params[ 'ENV' ][ 'cellFeatures' ]
1210 cellName = main.params[ 'ENV' ][ 'cellName' ]
1211 mininetIp = main.params[ 'MN' ][ 'ip1' ]
1212
1213 main.log.report('Increasing cluster size to ' + str(clusterCount))
1214
1215 main.log.step( "Killing all ONOS processes before scale-out" )
1216
1217 for i in range( 1, 8 ):
1218 main.ONOSbench.onosDie(
1219 main.params[ 'CTRL' ][ 'ip'+str(i) ] )
1220 main.ONOSbench.onosUninstall(
1221 main.params[ 'CTRL' ][ 'ip'+str(i) ] )
1222
1223 main.step( "Creating scale-out cell file" )
1224 cellIp = []
1225 for node in range( 1, clusterCount + 1 ):
1226 cellIp.append( main.params[ 'CTRL' ][ 'ip'+str(node) ] )
1227
1228 main.log.info( "Cell Ip list: " + str(cellIp) )
1229 main.ONOSbench.createCellFile( benchIp, cellName, mininetIp,
1230 str(features), *cellIp )
1231
1232 main.step( "Setting cell definition" )
1233 main.ONOSbench.setCell(cellName)
1234
1235 main.step( "Packaging cell definition" )
1236 main.ONOSbench.onosPackage()
1237
jenkins7ead5a82015-03-13 10:28:21 -07001238 for node in range( 1, clusterCount + 1 ):
jenkinsac38ab72015-03-13 11:24:10 -07001239 main.ONOSbench.onosInstall(
1240 node = main.params[ 'CTRL' ][ 'ip'+str(node) ])
1241
1242 time.sleep( 20 )
1243
jenkins7ead5a82015-03-13 10:28:21 -07001244 for node in range( 1, clusterCount + 1):
1245 for i in range( 2 ):
1246 isup = main.ONOSbench.isup(
1247 main.params[ 'CTRL' ][ 'ip'+str(node) ] )
1248 if isup:
1249 main.log.info( "ONOS "+str(node) + " is up\n")
1250 break
1251 if not isup:
1252 main.log.error( "ONOS "+str(node) + " did not start" )
jenkinsac38ab72015-03-13 11:24:10 -07001253
andrew@onlab.usb4cb2b82015-04-03 14:06:09 -04001254 for node in range( 0, clusterCount ):
1255 CLIs[node].startOnosCli( cellIp[node] )
1256
1257 main.step( 'Setting configurations for metrics' )
1258 configParam = 'maxEvents 1'
1259 main.ONOSbench.onosCfgSet( nodeIpList[0], configName, configParam )
1260 configParam = 'maxBatchMs 0'
1261 main.ONOSbench.onosCfgSet( nodeIpList[0], configName, configParam )
1262 configParam = 'maxIdleMs 0'
1263 main.ONOSbench.onosCfgSet( nodeIpList[0], configName, configParam )
1264
1265 main.step( 'Activating essential applications' )
1266 CLIs[0].activateApp( 'org.onosproject.metrics' )
1267 CLIs[0].activateApp( 'org.onosproject.openflow' )
jenkinsac38ab72015-03-13 11:24:10 -07001268