SCPFswitchLat initial commit
Change-Id: Ibe001bbd0f41c56a7a16600ffa48d5d52666570e
diff --git a/TestON/tests/SCPFswitchLat/SCPFswitchLat.py b/TestON/tests/SCPFswitchLat/SCPFswitchLat.py
new file mode 100644
index 0000000..81cbf16
--- /dev/null
+++ b/TestON/tests/SCPFswitchLat/SCPFswitchLat.py
@@ -0,0 +1,848 @@
+# CASE1 starts number of nodes specified in param file
+#
+# cameron@onlab.us
+
+class SCPFswitchLat:
+
+ def __init__( self ):
+ self.default = ''
+
+ def CASE1( self, main ):
+ import sys
+ import os.path
+ import os
+ import time
+
+ global init
+ try:
+ if type(init) is not bool:
+ init = Fals
+ except NameError:
+ init = False
+
+ #Load values from params file
+ checkoutBranch = main.params[ 'GIT' ][ 'checkout' ]
+ gitPull = main.params[ 'GIT' ][ 'autopull' ]
+ cellName = main.params[ 'ENV' ][ 'cellName' ]
+ Apps = main.params[ 'ENV' ][ 'cellApps' ]
+ BENCHIp = main.params[ 'BENCH' ][ 'ip' ]
+ MN1Ip = main.params[ 'MN' ][ 'ip1' ]
+ main.maxNodes = int(main.params[ 'max' ])
+ cellName = main.params[ 'ENV' ][ 'cellName' ]
+ homeDir = os.path.expanduser('~')
+ topoCfgFile = main.params['TEST']['topoConfigFile']
+ topoCfgName = main.params['TEST']['topoConfigName']
+ switchEventResultPath = main.params['DB']['switchEventResultPath']
+ skipMvn = main.params ['TEST']['mci']
+ testONpath = os.getcwd() #testON/bin
+ user = main.params[ 'CTRL' ][ 'user' ]
+
+ # -- INIT SECTION, ONLY RUNS ONCE -- #
+ if init == False:
+ init = True
+ global clusterCount #number of nodes running
+ global scale
+ global commit
+ global timeToPost
+ global runNum
+ global jenkinsBuildNumber
+ global CLIs
+ CLIs = []
+ main.ONOSIp = []
+
+ for i in range( 1, 8 ):
+ CLIs.append( getattr( main, 'ONOS' + str( i ) + 'cli' ) )
+
+ timeToPost = time.strftime('%Y-%m-%d %H:%M:%S')
+ runNum = time.strftime('%d%H%M%S')
+
+ try:
+ jenkinsBuildNumber = str(os.environ['BUILD_NUMBER'])
+ main.log.report( 'Jenkins build number: ' + jenkinsBuildNumber )
+ except KeyError:
+ jenkinsBuildNumber = str(0)
+ main.log.info( 'Job is not run by jenkins. ' + 'Build number set to: ' + jenkinsBuildNumber)
+
+ clusterCount = 0
+ main.ONOSIp = main.ONOSbench.getOnosIps()
+
+ scale = (main.params[ 'SCALE' ]).split(",")
+ clusterCount = int(scale[0])
+
+ #mvn clean install, for debugging set param 'skipCleanInstall' to yes to speed up test
+ if skipMvn != "off":
+ mvnResult = main.ONOSbench.cleanInstall()
+
+ #git
+ main.step( "Git checkout and pull " + checkoutBranch )
+ if gitPull == 'on':
+ checkoutResult = main.ONOSbench.gitCheckout( checkoutBranch )
+ pullResult = main.ONOSbench.gitPull()
+
+ else:
+ checkoutResult = main.TRUE
+ pullResult = main.TRUE
+ main.log.info( "Skipped git checkout and pull" )
+
+ main.log.step("Grabbing commit number")
+ commit = main.ONOSbench.getVersion() ####
+ commit = (commit.split(" "))[1]
+
+ temp = testONpath.replace("bin","") + "tests/SCPFswitchLat/Dependency/"
+ main.ONOSbench.copyMininetFile("topo-perf-1sw.py", temp, user, "localhost" )
+ #main.ONOSbench.handle.expect(":~")
+
+ main.step('Clearing previous DB log file')
+ print switchEventResultPath
+ fSwitchLog = open(switchEventResultPath, "w+")
+ fSwitchLog.write("")
+ fSwitchLog.close()
+
+ # -- END OF INIT SECTION --#
+
+ main.log.step("Adjusting scale")
+ clusterCount = int(scale[0])
+ scale.remove(scale[0])
+
+ #kill off all onos processes
+ main.log.step("Safety check, killing all ONOS processes before initiating enviornment setup")
+ for node in range(main.maxNodes):
+ main.ONOSbench.onosDie(main.ONOSIp[node])
+
+ #Uninstall everywhere
+ main.log.step( "Cleaning Enviornment..." )
+ for i in range(main.maxNodes):
+ main.log.info(" Uninstalling ONOS " + str(i) )
+ main.ONOSbench.onosUninstall( main.ONOSIp[i] )
+ main.log.info("Sleep 10 second for uninstall to settle...")
+ time.sleep(10)
+ main.ONOSbench.handle.sendline(" ")
+ main.ONOSbench.handle.expect(":~")
+
+ #construct the cell file
+ main.log.info("Creating cell file")
+ cellIp = []
+ for node in range (clusterCount):
+ cellIp.append(main.ONOSIp[node])
+
+ main.ONOSbench.createCellFile(main.ONOSbench.ip_address, cellName, MN1Ip, str(Apps), cellIp)
+
+ main.step( "Set Cell" )
+ main.ONOSbench.setCell(cellName)
+
+ main.step( "Creating ONOS package" )
+ packageResult = main.ONOSbench.onosPackage()
+
+ main.step( "verify cells" )
+ verifyCellResult = main.ONOSbench.verifyCell()
+
+ main.step('Starting mininet topology ')
+ main.Mininet1.startNet()
+
+ main.log.report( "Initializeing " + str( clusterCount ) + " node cluster." )
+ for node in range(clusterCount):
+ main.log.info("Starting ONOS " + str(node) + " at IP: " + main.ONOSIp[node])
+ main.ONOSbench.onosInstall( node=main.ONOSIp[node])
+
+ for i in range(50):
+ time.sleep(15)
+ print "attempt " + str(i)
+ main.ONOSbench.handle.sendline("onos $OC1 summary")
+ main.ONOSbench.handle.expect(":~")
+ print main.ONOSbench.handle.before
+ if "nodes=" in main.ONOSbench.handle.before:
+ break
+
+ for node in range(clusterCount):
+ for i in range( 2 ):
+ isup = main.ONOSbench.isup( main.ONOSIp[node] )
+ if isup:
+ main.log.info("ONOS " + str(node) + " is up\n")
+ break
+ if not isup:
+ main.log.report( "ONOS " + str(node) + " didn't start!" )
+ main.log.info("Startup sequence complete")
+
+ #time.sleep(20)
+
+ main.step('Start onos cli')
+ for i in range(0,clusterCount):
+ cli1 = CLIs[i].startOnosCli(main.ONOSIp[i])
+
+ main.step( 'Configuring application parameters' )
+
+ configName = 'org.onosproject.net.topology.impl.DefaultTopologyProvider'
+ configParam = 'maxEvents 1'
+ main.ONOSbench.onosCfgSet( main.ONOSIp[0], configName, configParam )
+ configParam = 'maxBatchMs 0'
+ main.ONOSbench.onosCfgSet( main.ONOSIp[0], configName, configParam )
+ configParam = 'maxIdleMs 0'
+ main.ONOSbench.onosCfgSet( main.ONOSIp[0], configName, configParam )
+
+ def CASE2(self, main):
+ print "Cluster size: " + str(clusterCount)
+ """
+ Assign s3 to ONOSbench and measure latency
+
+ There are 4 levels of latency measurements to this test:
+ 1 ) End-to-end measurement: Complete end-to-end measurement
+ from TCP ( SYN/ACK ) handshake to Graph change
+ 2 ) OFP-to-graph measurement: 'ONOS processing' snippet of
+ measurement from OFP Vendor message to Graph change
+ 3 ) OFP-to-device measurement: 'ONOS processing without
+ graph change' snippet of measurement from OFP vendor
+ message to Device change timestamp
+ 4 ) T0-to-device measurement: Measurement that includes
+ the switch handshake to devices timestamp without
+ the graph view change. ( TCP handshake -> Device
+ change )
+ """
+ import time
+ import subprocess
+ import json
+ import requests
+ import os
+ import numpy
+
+ ONOSUser = main.params['CTRL']['user']
+ numIter = main.params['TEST']['numIter']
+ iterIgnore = int(main.params['TEST']['iterIgnore'])
+
+ deviceTimestampKey = main.params['JSON']['deviceTimestamp']
+ graphTimestampKey = main.params['JSON']['graphTimestamp']
+
+ debugMode = main.params['TEST']['debugMode']
+ onosLog = main.params['TEST']['onosLogFile']
+ resultPath = main.params['DB']['switchEventResultPath']
+ thresholdStr = main.params['TEST']['singleSwThreshold']
+ thresholdObj = thresholdStr.split(',')
+ thresholdMin = int(thresholdObj[0])
+ thresholdMax = int(thresholdObj[1])
+
+ # Look for 'role-request' messages,
+ # which replaces the 'vendor' messages previously seen
+ # on OVS 2.0.1
+ tsharkTcpString = main.params[ 'TSHARK' ][ 'tcpSynAck' ]
+ tsharkFeatureReply = main.params[ 'TSHARK' ][ 'featureReply' ]
+ tsharkRoleRequest = main.params[ 'TSHARK' ][ 'roleRequest' ]
+ tsharkOfString = main.params[ 'TSHARK' ][ 'ofpRoleReply' ]
+ tsharkFinAckSequence = main.params[ 'TSHARK' ][ 'finAckSequence' ]
+
+ tsharkOfOutput = '/tmp/tshark_of_topo.txt'
+ tsharkTcpOutput = '/tmp/tshark_tcp_topo.txt'
+ tsharkRoleOutput = '/tmp/tshark_role_request.txt'
+ tsharkFeatureOutput = '/tmp/tshark_feature_reply.txt'
+ tsharkFinAckOutput = '/tmp/tshark_fin_ack.txt'
+
+ # Switch connect measurement list
+ # TCP Syn/Ack -> Feature Reply latency collection for each node
+ tcpToFeatureLatNodeIter = numpy.zeros((clusterCount, int(numIter)))
+ # Feature Reply -> Role Request latency collection for each node
+ featureToRoleRequestLatNodeIter = numpy.zeros((clusterCount,
+ int(numIter)))
+ # Role Request -> Role Reply latency collection for each node
+ roleRequestToRoleReplyLatNodeIter = numpy.zeros((clusterCount,
+ int(numIter)))
+ # Role Reply -> Device Update latency collection for each node
+ roleReplyToDeviceLatNodeIter = numpy.zeros((clusterCount,
+ int(numIter)))
+ # Device Update -> Graph Update latency collection for each node
+ deviceToGraphLatNodeIter = numpy.zeros((clusterCount,
+ int(numIter)))
+ endToEndLatNodeIter = numpy.zeros((clusterCount, int(numIter)))
+
+ # Switch disconnect measurement lists
+ # Mininet Fin / Ack -> Mininet Ack
+ finAckTransactionLatNodeIter = numpy.zeros((clusterCount,
+ int(numIter)))
+ # Mininet Ack -> Device Event
+ ackToDeviceLatNodeIter = numpy.zeros((clusterCount,
+ int(numIter)))
+ # Device event -> Graph event
+ deviceToGraphDiscLatNodeIter = numpy.zeros((clusterCount,
+ int(numIter)))
+ endToEndDiscLatNodeIter = numpy.zeros((clusterCount, int(numIter)))
+
+ assertion = main.TRUE
+ localTime = time.strftime('%x %X')
+ localTime = localTime.replace('/', '')
+ localTime = localTime.replace(' ', '_')
+ localTime = localTime.replace(':', '')
+
+ if debugMode == 'on':
+ main.ONOSbench.tsharkPcap('eth0', '/tmp/single_sw_lat_pcap_' + localTime)
+ main.log.info('Debug mode is on')
+
+ main.log.report('Latency of adding one switch to controller')
+ main.log.report('First ' + str(iterIgnore) + ' iterations ignored' + ' for jvm warmup time')
+ main.log.report('Total iterations of test: ' + str(numIter))
+
+ for i in range(0, int(numIter)):
+ main.log.info('Starting tshark capture')
+ main.ONOSbench.tsharkGrep(tsharkTcpString, tsharkTcpOutput)
+ main.ONOSbench.tsharkGrep(tsharkOfString, tsharkOfOutput)
+ main.ONOSbench.tsharkGrep(tsharkRoleRequest, tsharkRoleOutput)
+ main.ONOSbench.tsharkGrep(tsharkFeatureReply, tsharkFeatureOutput)
+
+ time.sleep(10)
+
+ main.log.info('Assigning s3 to controller')
+ main.Mininet1.assignSwController(sw='s3',
+ ip=main.ONOSIp[0])
+
+ jsonStr = []
+ for node in range (0, clusterCount):
+ metricsSwUp = CLIs[node].topologyEventsMetrics()
+ jsonStr.append(metricsSwUp)
+
+ time.sleep(10)
+
+ main.log.info('Stopping all Tshark processes')
+ main.ONOSbench.tsharkStop()
+
+ time.sleep(5)
+
+ '''
+ main.log.info('Copying over tshark files')
+ os.system('scp ' + ONOSUser + '@' + main.ONOSIp[0] +
+ ':' + tsharkTcpOutput + ' /tmp/')
+ os.system('scp ' + ONOSUser + '@' + main.ONOSIp[0] +
+ ':' + tsharkRoleOutput + ' /tmp/')
+ os.system('scp ' + ONOSUser + '@' + main.ONOSIp[0] +
+ ':' + tsharkFeatureOutput + ' /tmp/')
+ os.system('scp ' + ONOSUser + '@' +
+ main.ONOSIp[0] + ':' + tsharkOfOutput + ' /tmp/')
+ '''
+
+ # Get tcp syn / ack output
+ time.sleep(1)
+
+ tcpFile = open(tsharkTcpOutput, 'r')
+ tempText = tcpFile.readline()
+ tempText = tempText.split(' ')
+ main.log.info('Object read in from TCP capture: ' + str(tempText))
+
+ if len(tempText) > 1:
+ t0Tcp = float(tempText[1]) * 1000.0
+ else:
+ main.log.error('Tshark output file for TCP' + ' returned unexpected results')
+ t0Tcp = 0
+ assertion = main.FALSE
+ tcpFile.close()
+
+ # Get Role reply output
+ ofFile = open(tsharkOfOutput, 'r')
+ lineOfp = ''
+ while True:
+ tempText = ofFile.readline()
+ if tempText != '':
+ lineOfp = tempText
+ else:
+ break
+ obj = lineOfp.split(' ')
+ main.log.info('Object read in from OFP capture: ' +
+ str(lineOfp))
+ if len(obj) > 1:
+ t0Ofp = float(obj[1]) * 1000.0
+ else:
+ main.log.error('Tshark output file for OFP' +
+ ' returned unexpected results')
+ t0Ofp = 0
+ assertion = main.FALSE
+ ofFile.close()
+
+ # Get role request output
+ roleFile = open(tsharkRoleOutput, 'r')
+ tempText = roleFile.readline()
+ tempText = tempText.split(' ')
+ if len(tempText) > 1:
+ main.log.info('Object read in from role request capture:' +
+ str(tempText))
+ roleTimestamp = float(tempText[1]) * 1000.0
+ else:
+ main.log.error('Tshark output file for role request' +
+ ' returned unexpected results')
+ timeRoleRequest = 0
+ assertion = main.FALSE
+ roleFile.close()
+
+ # Get feature reply output
+ featureFile = open(tsharkFeatureOutput, 'r')
+ tempText = featureFile.readline()
+ tempText = tempText.split(' ')
+ if len(tempText) > 1:
+ main.log.info('Object read in from feature reply capture: '+
+ str(tempText))
+ if tempText[1] != ' ' and float(tempText[1]) > 1400000000.0:
+ temp = tempText[1]
+ elif tempText[2] != ' ' and float(tempText[2]) > 1400000000.0:
+ temp = tempText[2]
+ else:
+ temp = 0
+ featureTimestamp = float(temp) * 1000.0
+ else:
+ main.log.error('Tshark output file for feature reply' +
+ ' returned unexpected results')
+ timeFeatureReply = 0
+ assertion = main.FALSE
+ featureFile.close()
+
+ for node in range(0, clusterCount):
+ nodeNum = node+1
+ #metricsSwUp = CLIs[node].topologyEventsMetrics
+ #jsonStr = metricsSwUp()
+ jsonObj = json.loads(jsonStr[node])
+ if jsonObj:
+ graphTimestamp = jsonObj[graphTimestampKey]['value']
+ deviceTimestamp = jsonObj[deviceTimestampKey]['value']
+ else:
+ main.log.error( "Unexpected JSON object" )
+ # If we could not obtain the JSON object,
+ # set the timestamps to 0, which will be
+ # excluded from the measurement later on
+ # (realized as invalid)
+ graphTimestamp = 0
+ deviceTimestamp = 0
+
+ endToEnd = int(graphTimestamp) - int(t0Tcp)
+
+ # Below are measurement breakdowns of the end-to-end
+ # measurement.
+ tcpToFeature = int(featureTimestamp) - int(t0Tcp)
+ featureToRole = int(roleTimestamp) - int(featureTimestamp)
+ roleToOfp = float(t0Ofp) - float(roleTimestamp)
+ ofpToDevice = float(deviceTimestamp) - float(t0Ofp)
+ # Timestamps gathered from ONOS are millisecond
+ # precision. They are returned as integers, thus no
+ # need to be more precise than 'int'. However,
+ # the processing seems to be mostly under 1 ms,
+ # thus this may be a problem point to handle any
+ # submillisecond output that we are unsure of.
+ # For now, this will be treated as 0 ms if less than 1 ms
+ deviceToGraph = int(graphTimestamp) - int(deviceTimestamp)
+
+ if endToEnd >= thresholdMin and\
+ endToEnd < thresholdMax and i >= iterIgnore:
+ endToEndLatNodeIter[node][i] = endToEnd
+ main.log.info("ONOS "+str(nodeNum)+ " end-to-end: "+
+ str(endToEnd) + " ms")
+ else:
+ main.log.info("ONOS "+str(nodeNum)+ " end-to-end "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(endToEnd))
+
+ if tcpToFeature >= thresholdMin and\
+ tcpToFeature < thresholdMax and i >= iterIgnore:
+ tcpToFeatureLatNodeIter[node][i] = tcpToFeature
+ main.log.info("ONOS "+str(nodeNum)+ " tcp-to-feature: "+
+ str(tcpToFeature) + " ms")
+ else:
+ main.log.info("ONOS "+str(nodeNum)+ " tcp-to-feature "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(tcpToFeature))
+
+ if featureToRole >= thresholdMin and\
+ featureToRole < thresholdMax and i >= iterIgnore:
+ featureToRoleRequestLatNodeIter[node][i] = featureToRole
+ main.log.info("ONOS "+str(nodeNum)+ " feature-to-role: "+
+ str(featureToRole) + " ms")
+ else:
+ main.log.info("ONOS "+str(nodeNum)+ " feature-to-role "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(featureToRole))
+
+ if roleToOfp >= thresholdMin and\
+ roleToOfp < thresholdMax and i >= iterIgnore:
+ roleRequestToRoleReplyLatNodeIter[node][i] = roleToOfp
+ main.log.info("ONOS "+str(nodeNum)+ " role-to-reply: "+
+ str(roleToOfp) + " ms")
+ else:
+ main.log.info("ONOS "+str(nodeNum)+ " role-to-reply "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(roleToOfp))
+
+ if ofpToDevice >= thresholdMin and\
+ ofpToDevice < thresholdMax and i >= iterIgnore:
+ roleReplyToDeviceLatNodeIter[node][i] = ofpToDevice
+ main.log.info("ONOS "+str(nodeNum)+ " reply-to-device: "+
+ str(ofpToDevice) + " ms")
+ else:
+ main.log.info("ONOS "+str(nodeNum)+ " reply-to-device "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(ofpToDevice))
+
+ if deviceToGraph >= thresholdMin and\
+ deviceToGraph < thresholdMax and i >= iterIgnore:
+ deviceToGraphLatNodeIter[node][i] = deviceToGraph
+ main.log.info("ONOS "+str(nodeNum)+ " device-to-graph: "+
+ str(deviceToGraph) + " ms")
+ else:
+ if deviceToGraph == 0:
+ deviceToGraphLatNodeIter[node][i] = 0
+ main.log.info("ONOS "+str(nodeNum) +
+ " device-to-graph measurement "+
+ "was set to 0 ms because of precision "+
+ "uncertainty. ")
+ else:
+ main.log.info("ONOS "+str(nodeNum)+
+ " device-to-graph "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(deviceToGraph))
+
+ # ********************
+ time.sleep(5)
+
+ # Get device id to remove
+ deviceIdJsonStr = main.ONOS1cli.devices()
+
+ main.log.info( "Device obj obtained: " + str(deviceIdJsonStr) )
+ deviceId = json.loads(deviceIdJsonStr)
+
+ deviceList = []
+ for device in deviceId:
+ deviceList.append(device['id'])
+
+ # Measure switch down metrics
+ # TCP FIN/ACK -> TCP FIN
+ # TCP FIN -> Device Event
+ # Device Event -> Graph Event
+ # Capture switch down FIN / ACK packets
+
+ # The -A 1 grep option allows us to grab 1 extra line after the
+ # last tshark output grepped originally
+ main.ONOSbench.tsharkGrep( tsharkFinAckSequence, tsharkFinAckOutput,
+ grepOptions = '-A 1' )
+
+ time.sleep( 5 )
+
+ removeJsonList = []
+ main.step('Remove switch from controller')
+ main.Mininet1.deleteSwController('s3')
+ firstDevice = deviceList[0]
+
+ time.sleep( 5 )
+
+ # We need to get metrics before removing
+ # device from the store below.
+ for node in range(0, clusterCount):
+ metricsSwDown = CLIs[node].topologyEventsMetrics
+ jsonStr = metricsSwDown()
+ removeJsonList.append( json.loads(jsonStr) )
+
+ main.ONOSbench.tsharkStop()
+
+ main.log.info( "Removing device " +str(firstDevice)+
+ " from ONOS" )
+
+ #if deviceId:
+ main.ONOS1cli.deviceRemove(firstDevice)
+
+ #main.log.info('Copying over tshark files')
+ #os.system('scp ' + ONOSUser + '@' + main.ONOSIp[0] + ':' + tsharkFinAckOutput + ' /tmp/')
+
+ time.sleep( 10 )
+ finAckOutputList = []
+ with open(tsharkFinAckOutput, 'r') as f:
+ tempLine = f.readlines()
+ main.log.info('Object read in from FinAck capture: ' +
+ "\n".join(tempLine))
+
+ index = 1
+ for line in tempLine:
+ obj = line.split(' ')
+
+ # There are at least 3 objects in field (valid
+ # tshark output is lengthy)
+ if len(obj) > 2:
+ # If first index of object is like an epoch time
+ if obj[1] != ' ' and float(obj[1]) > 1400000000.0:
+ temp = obj[1]
+ elif obj[2] != ' 'and float(obj[2]) > 1400000000.0:
+ temp = obj[2]
+ elif obj[3] != ' 'and float(obj[3]) > 1400000000.0:
+ temp = obj[3]
+ else:
+ temp = 0
+ if index == 1:
+ tFinAck = float(temp) * 1000.0
+ elif index == 3:
+ tAck = float(temp) * 1000.0
+ else:
+ tFinAck = 0
+ tAck = 0
+ else:
+ main.log.error('Tshark output file for OFP' +
+ ' returned unexpected results')
+ tFinAck = 0
+ tAck = 0
+ assertion = main.FALSE
+
+ index += 1
+
+ # with open() as f takes care of closing file
+
+ time.sleep(5)
+
+ for node in range(0, clusterCount):
+ nodeNum = node+1
+ jsonObj = removeJsonList[node]
+ if jsonObj:
+ graphTimestamp = jsonObj[graphTimestampKey]['value']
+ deviceTimestamp = jsonObj[deviceTimestampKey]['value']
+ main.log.info("Graph timestamp: "+str(graphTimestamp))
+ main.log.info("Device timestamp: "+str(deviceTimestamp))
+ else:
+ main.log.error( "Unexpected JSON object" )
+ # If we could not obtain the JSON object,
+ # set the timestamps to 0, which will be
+ # excluded from the measurement later on
+ # (realized as invalid)
+ graphTimestamp = 0
+ deviceTimestamp = 0
+
+ finAckTransaction = float(tAck) - float(tFinAck)
+ ackToDevice = float(deviceTimestamp) - float(tAck)
+ deviceToGraph = float(graphTimestamp) - float(deviceTimestamp)
+ endToEndDisc = int(graphTimestamp) - int(tFinAck)
+
+ if endToEndDisc >= thresholdMin and\
+ endToEndDisc < thresholdMax and i >= iterIgnore:
+ endToEndDiscLatNodeIter[node][i] = endToEndDisc
+ main.log.info("ONOS "+str(nodeNum) +
+ "end-to-end disconnection: "+
+ str(endToEndDisc) + " ms" )
+ else:
+ main.log.info("ONOS " + str(nodeNum) +
+ " end-to-end disconnection "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(endToEndDisc))
+
+ if finAckTransaction >= thresholdMin and\
+ finAckTransaction < thresholdMax and i >= iterIgnore:
+ finAckTransactionLatNodeIter[node][i] = finAckTransaction
+ main.log.info("ONOS "+str(nodeNum)+
+ " fin/ack transaction: "+
+ str(finAckTransaction) + " ms")
+ else:
+ main.log.info("ONOS "+str(nodeNum)+
+ " fin/ack transaction "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(finAckTransaction))
+
+ if ackToDevice >= thresholdMin and\
+ ackToDevice < thresholdMax and i >= iterIgnore:
+ ackToDeviceLatNodeIter[node][i] = ackToDevice
+ main.log.info("ONOS "+str(nodeNum)+
+ " ack-to-device: "+
+ str(ackToDevice) + " ms")
+ else:
+ main.log.info("ONOS "+str(nodeNum)+
+ " ack-to-device "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(ackToDevice))
+
+ if deviceToGraph >= thresholdMin and\
+ deviceToGraph < thresholdMax and i >= iterIgnore:
+ deviceToGraphDiscLatNodeIter[node][i] = deviceToGraph
+ main.log.info("ONOS "+str(nodeNum)+
+ " device-to-graph disconnect: "+
+ str(deviceToGraph) + " ms")
+ else:
+ main.log.info("ONOS "+str(nodeNum)+
+ " device-to-graph disconnect "+
+ "measurement ignored due to excess in "+
+ "threshold or premature iteration: ")
+ main.log.info(str(deviceToGraph))
+
+ endToEndAvg = 0
+ ofpToGraphAvg = 0
+ dbCmdList = []
+ for node in range(0, clusterCount):
+ # List of latency for each node
+ endToEndList = []
+ tcpToFeatureList = []
+ featureToRoleList = []
+ roleToOfpList = []
+ ofpToDeviceList = []
+ deviceToGraphList = []
+
+ finAckTransactionList = []
+ ackToDeviceList = []
+ deviceToGraphDiscList = []
+ endToEndDiscList = []
+
+ # LatNodeIter 2d arrays contain all iteration latency
+ # for each node of the current scale cluster size
+ # Switch connection measurements
+ # Set further acceptance criteria for measurements
+ # here if you would like to filter reporting results
+ for item in endToEndLatNodeIter[node]:
+ if item > 0.0:
+ endToEndList.append(item)
+
+ for item in tcpToFeatureLatNodeIter[node]:
+ if item > 0.0:
+ tcpToFeatureList.append(item)
+
+ for item in featureToRoleRequestLatNodeIter[node]:
+ if item > 0.0:
+ featureToRoleList.append(item)
+
+ for item in roleRequestToRoleReplyLatNodeIter[node]:
+ if item > 0.0:
+ roleToOfpList.append(item)
+
+ for item in roleReplyToDeviceLatNodeIter[node]:
+ if item >= 0.0:
+ ofpToDeviceList.append(item)
+
+ for item in featureToRoleRequestLatNodeIter[node]:
+ if item > 0.0:
+ featureToRoleList.append(item)
+
+ for item in deviceToGraphLatNodeIter[node]:
+ if item >= 0.0:
+ deviceToGraphList.append(item)
+
+ # Switch disconnect measurements
+ for item in endToEndDiscLatNodeIter[node]:
+ if item > 0.0:
+ endToEndDiscList.append(item)
+
+ for item in finAckTransactionLatNodeIter[node]:
+ if item > 0.0:
+ finAckTransactionList.append(item)
+
+ for item in ackToDeviceLatNodeIter[node]:
+ if item > 0.0:
+ ackToDeviceList.append(item)
+
+ for item in deviceToGraphDiscLatNodeIter[node]:
+ if item >= 0.0:
+ deviceToGraphDiscList.append(item)
+
+ endToEndAvg = round(numpy.mean(endToEndList), 2)
+ endToEndStdDev = round(numpy.std(endToEndList), 2)
+
+ tcpToFeatureAvg = round(numpy.mean(tcpToFeatureList), 2)
+ tcpToFeatureStdDev = round(numpy.std(tcpToFeatureList), 2)
+
+ featureToRoleAvg = round(numpy.mean(featureToRoleList), 2)
+ featureToRoleStdDev = round(numpy.std(featureToRoleList), 2)
+
+ roleToOfpAvg = round(numpy.mean(roleToOfpList), 2)
+ roleToOfpStdDev = round(numpy.std(roleToOfpList), 2)
+
+ ofpToDeviceAvg = round(numpy.mean(ofpToDeviceList), 2)
+ ofpToDeviceStdDev = round(numpy.std(ofpToDeviceList), 2)
+
+ deviceToGraphAvg = round(numpy.mean(deviceToGraphList), 2)
+ deviceToGraphStdDev = round(numpy.std(deviceToGraphList), 2)
+
+ endToEndDiscAvg = round(numpy.mean(endToEndDiscList), 2)
+ endToEndDiscStdDev = round(numpy.std(endToEndDiscList), 2)
+
+ finAckAvg = round(numpy.mean(finAckTransactionList), 2)
+ finAckStdDev = round(numpy.std(finAckTransactionList), 2)
+
+ ackToDeviceAvg = round(numpy.mean(ackToDeviceList), 2)
+ ackToDeviceStdDev = round(numpy.std(ackToDeviceList), 2)
+
+ deviceToGraphDiscAvg = round(numpy.mean(deviceToGraphDiscList), 2)
+ deviceToGraphDiscStdDev = round(numpy.std(deviceToGraphDiscList), 2)
+
+ main.log.report(' - Node ' + str(node + 1) + ' Summary - ')
+ main.log.report(' - Switch Connection Statistics - ')
+
+ main.log.report(' End-to-end Avg: ' + str(endToEndAvg) +
+ ' ms' + ' End-to-end Std dev: ' +
+ str(endToEndStdDev) + ' ms')
+
+ main.log.report(' Tcp-to-feature-reply Avg: ' +
+ str(tcpToFeatureAvg) + ' ms')
+ main.log.report(' Tcp-to-feature-reply Std dev: '+
+ str(tcpToFeatureStdDev) + ' ms')
+
+ main.log.report(' Feature-reply-to-role-request Avg: ' +
+ str(featureToRoleAvg) + ' ms')
+ main.log.report(' Feature-reply-to-role-request Std Dev: ' +
+ str(featureToRoleStdDev) + ' ms')
+
+ main.log.report(' Role-request-to-role-reply Avg: ' +
+ str(roleToOfpAvg) +' ms')
+ main.log.report(' Role-request-to-role-reply Std dev: ' +
+ str(roleToOfpStdDev) + ' ms')
+
+ main.log.report(' Role-reply-to-device Avg: ' +
+ str(ofpToDeviceAvg) +' ms')
+ main.log.report(' Role-reply-to-device Std dev: ' +
+ str(ofpToDeviceStdDev) + ' ms')
+
+ main.log.report(' Device-to-graph Avg: ' +
+ str(deviceToGraphAvg) + ' ms')
+ main.log.report( 'Device-to-graph Std dev: ' +
+ str(deviceToGraphStdDev) + ' ms')
+
+ main.log.report(' - Switch Disconnection Statistics - ')
+ main.log.report(' End-to-end switch disconnect Avg: ' +
+ str(endToEndDiscAvg) + ' ms')
+ main.log.report(' End-to-end switch disconnect Std dev: ' +
+ str(endToEndDiscStdDev) + ' ms')
+ main.log.report(' Fin/Ack-to-Ack Avg: ' + str(finAckAvg) + ' ms')
+ main.log.report(' Fin/Ack-to-Ack Std dev: ' +
+ str(finAckStdDev) + ' ms')
+
+ main.log.report(' Ack-to-device Avg: ' + str(ackToDeviceAvg) +
+ ' ms')
+ main.log.report(' Ack-to-device Std dev: ' + str(ackToDeviceStdDev) +
+ ' ms')
+
+ main.log.report(' Device-to-graph (disconnect) Avg: ' +
+ str(deviceToGraphDiscAvg) + ' ms')
+ main.log.report(' Device-to-graph (disconnect) Std dev: ' +
+ str(deviceToGraphDiscStdDev) + ' ms')
+
+ # For database schema, refer to Amazon web services
+ dbCmdList.append(
+ "INSERT INTO switch_latency_details VALUES('" +
+ timeToPost + "','switch_latency_results'," +
+ jenkinsBuildNumber + ',' + str(clusterCount) + ",'baremetal" +
+ str(node + 1) + "'," +
+ str(endToEndAvg) + ',' +
+ str(tcpToFeatureAvg) + ',' +
+ str(featureToRoleAvg) + ',' +
+ str(roleToOfpAvg) + ',' +
+ str(ofpToDeviceAvg) + ',' +
+ str(deviceToGraphAvg) + ',' +
+ str(endToEndDiscAvg) + ',' +
+ str(finAckAvg) + ',' +
+ str(ackToDeviceAvg) + ',' +
+ str(deviceToGraphDiscAvg) +
+ ');')
+
+ if debugMode == 'on':
+ main.ONOSbench.cpLogsToDir('/opt/onos/log/karaf.log',
+ '/tmp/', copyFileName='sw_lat_karaf')
+ fResult = open(resultPath, 'a')
+ for line in dbCmdList:
+ if line:
+ fResult.write(line + '\n')
+ main.log.report(line)
+ fResult.close()
+
+ assertion = main.TRUE
+
+ utilities.assert_equals(expect=main.TRUE, actual=assertion,
+ onpass='Switch latency test successful',
+ onfail='Switch latency test failed')
+
+ main.Mininet1.stopNet()