YPZhang | 38fb119 | 2016-08-11 11:03:38 -0700 | [diff] [blame] | 1 | ''' |
| 2 | Wrapper function for SCPFswitchLat test |
| 3 | Assign switch and capture openflow package |
| 4 | remove switch and caputer openflow package |
| 5 | calculate latency |
| 6 | ''' |
| 7 | |
| 8 | |
| 9 | import time |
| 10 | import json |
| 11 | def processPackage( package ): |
| 12 | ''' |
| 13 | split package information to dictionary |
| 14 | Args: |
| 15 | package: Package String |
| 16 | |
| 17 | Returns: |
| 18 | |
| 19 | ''' |
| 20 | pacakge = package.split(" ") |
| 21 | dic = {} |
| 22 | for s in pacakge: |
| 23 | try: |
| 24 | [key, value] = s.split("=") |
| 25 | dic[key] = value |
| 26 | except: |
| 27 | continue |
| 28 | return dic |
| 29 | |
| 30 | def findSeqBySeqAck( seq, packageList): |
| 31 | ''' |
| 32 | Find specific Seq of package in packageList |
| 33 | Args: |
| 34 | seq: seq from last TCP package |
| 35 | packageList: find package in packageList |
| 36 | |
| 37 | Returns: |
| 38 | |
| 39 | ''' |
| 40 | for l in packageList: |
| 41 | temp = processPackage(l) |
| 42 | tA = temp['Ack'] |
| 43 | if int(seq) + 1 == int(tA): |
| 44 | return temp['Seq'] |
| 45 | |
| 46 | def captureOfPack( main, deviceName, ofPack, switchStatus, resultDict, warmup ): |
| 47 | ''' |
| 48 | |
| 49 | Args: |
| 50 | main: TestON class |
| 51 | deviceName: device name |
| 52 | ofPack: openflow package key word |
| 53 | switchStatus: Up -- assign, down -- remove |
| 54 | resultDict: dictionary to contain result |
| 55 | warmup: warm up boolean |
| 56 | |
| 57 | Returns: |
| 58 | |
| 59 | ''' |
| 60 | for d in ofPack[switchStatus]: |
| 61 | main.log.info("Clean up Tshark") |
| 62 | with open(main.tsharkResultPath[switchStatus][d], "w") as tshark: |
| 63 | tshark.write("") |
| 64 | main.log.info( "Starting tshark capture" ) |
| 65 | main.ONOSbench.tsharkGrep(ofPack[switchStatus][d], main.tsharkResultPath[switchStatus][d]) |
| 66 | if switchStatus == 'up': |
| 67 | # if up, assign switch to controller |
| 68 | time.sleep(main.measurementSleep) |
| 69 | main.log.info('Assigning {} to controller'.format(deviceName)) |
| 70 | main.Mininet1.assignSwController(sw=deviceName, ip=main.ONOSip[0]) |
| 71 | time.sleep(main.measurementSleep) |
| 72 | if switchStatus == 'down': |
| 73 | # if down, remove switch from topology |
| 74 | time.sleep(main.measurementSleep) |
| 75 | main.step('Remove switch from controller') |
| 76 | main.Mininet1.deleteSwController(deviceName) |
| 77 | time.sleep(10) |
| 78 | main.log.info( "Stopping all Tshark processes" ) |
| 79 | main.ONOSbench.tsharkStop() |
YPZhang | 38fb119 | 2016-08-11 11:03:38 -0700 | [diff] [blame] | 80 | tempResultDict = {} |
| 81 | if switchStatus == 'up': |
| 82 | for d in main.tsharkResultPath['up']: |
| 83 | with open(main.tsharkResultPath[switchStatus][d], "r") as resultFile: |
| 84 | # grep tshark result timestamp |
| 85 | resultText = resultFile.readlines() |
YPZhang | 21adb60 | 2016-08-18 16:00:11 -0700 | [diff] [blame] | 86 | if d == "TCP": |
| 87 | # if TCP package, we should use the latest one package |
YPZhang | 347b8ae | 2016-08-19 09:43:24 -0700 | [diff] [blame] | 88 | resultText = resultText[len(resultText) - 1] |
YPZhang | 21adb60 | 2016-08-18 16:00:11 -0700 | [diff] [blame] | 89 | else: |
| 90 | resultText = resultText[0] |
YPZhang | 38fb119 | 2016-08-11 11:03:38 -0700 | [diff] [blame] | 91 | main.log.info("Capture result:" + resultText) |
| 92 | resultText = resultText.strip() |
| 93 | resultText = resultText.split( " " ) |
| 94 | if len(resultText) > 1: |
| 95 | tempResultDict[d]= int( ( float(resultText[1]) * 1000 ) ) |
| 96 | resultFile.close() |
| 97 | elif switchStatus == 'down': |
| 98 | # if state is down, we should capture Fin/Ack and ACK package |
| 99 | # Use seq number in FIN/ACK package to located ACK package |
| 100 | with open(main.tsharkResultPath['down']['FA']) as resultFile: |
| 101 | resultText = resultFile.readlines() |
| 102 | FinAckText = resultText.pop(0) |
| 103 | resultFile.close() |
| 104 | FinAckSeq = processPackage(FinAckText)['Seq'] |
| 105 | FinAckOFseq = findSeqBySeqAck(FinAckSeq, resultText) |
| 106 | |
| 107 | with open(main.tsharkResultPath['down']['ACK']) as resultFile: |
| 108 | ACKlines = resultFile.readlines() |
| 109 | resultFile.close() |
| 110 | |
YPZhang | 3943fbe | 2016-08-18 14:33:29 -0700 | [diff] [blame] | 111 | AckPackage = "" |
YPZhang | 38fb119 | 2016-08-11 11:03:38 -0700 | [diff] [blame] | 112 | for l in ACKlines: |
| 113 | temp = processPackage(l) |
| 114 | if temp['Seq'] == findSeqBySeqAck(FinAckOFseq, ACKlines): |
| 115 | AckPackage = l |
YPZhang | 3943fbe | 2016-08-18 14:33:29 -0700 | [diff] [blame] | 116 | if len(AckPackage) > 0: |
| 117 | FinAckText = FinAckText.strip() |
| 118 | FinAckText = FinAckText.split(" ") |
| 119 | AckPackage = AckPackage.strip() |
| 120 | AckPackage = AckPackage.split(" ") |
| 121 | tempResultDict['ACK'] = float("%.2f" % (float(AckPackage[1]) * 1000) ) |
| 122 | tempResultDict['FA'] = float("%.2f" % (float(FinAckText[1]) * 1000) ) |
| 123 | else: |
| 124 | return |
YPZhang | 38fb119 | 2016-08-11 11:03:38 -0700 | [diff] [blame] | 125 | # calculate latency |
| 126 | if switchStatus == "up": |
| 127 | # up Latency |
| 128 | for d in resultDict[switchStatus]: |
| 129 | T_Ftemp = 0 |
| 130 | F_Rtemp = 0 |
| 131 | RQ_RRtemp = 0 |
| 132 | try: |
| 133 | T_Ftemp = tempResultDict['Feature'] - tempResultDict['TCP'] |
| 134 | F_Rtemp = tempResultDict['RQ'] - tempResultDict['Feature'] |
| 135 | RQ_RRtemp = tempResultDict['RR'] - tempResultDict['RQ'] |
| 136 | except KeyError: |
| 137 | main.log.warn("Tshark Result was incorrect!") |
| 138 | main.log.warn(tempResultDict) |
| 139 | return |
| 140 | if not warmup: |
| 141 | resultDict[switchStatus][d][ 'T_F' ].append( T_Ftemp ) |
| 142 | resultDict[switchStatus][d][ 'F_R' ].append( F_Rtemp ) |
| 143 | resultDict[switchStatus][d][ 'RQ_RR' ].append( RQ_RRtemp ) |
| 144 | |
| 145 | main.log.info("{} TCP to Feature: {}".format(d, str( T_Ftemp ) ) ) |
| 146 | main.log.info("{} Feature to Role Request: {}".format(d, str(F_Rtemp))) |
| 147 | main.log.info("{} Role Request to Role Reply: {}".format(d, str(RQ_RRtemp))) |
| 148 | |
| 149 | for i in range(1, main.numCtrls + 1): |
| 150 | RR_Dtemp = 0 |
| 151 | D_Gtemp = 0 |
| 152 | E_Etemp = 0 |
| 153 | main.log.info("================================================") |
| 154 | # get onos metrics timestamps |
| 155 | try: |
| 156 | response = json.loads(main.CLIs[i - 1].topologyEventsMetrics()) |
| 157 | DeviceTime = int( response.get("topologyDeviceEventTimestamp").get("value") ) |
| 158 | main.log.info("ONOS{} device Event timestamp: {}".format(i, "%.2f" % DeviceTime)) |
| 159 | GraphTime = int( response.get("topologyGraphEventTimestamp").get("value") ) |
| 160 | main.log.info("ONOS{} Graph Event timestamp: {}".format(i, GraphTime)) |
| 161 | except TypeError: |
| 162 | main.log.warn("TypeError") |
| 163 | break |
| 164 | except ValueError: |
| 165 | main.log.warn("Error to decode Json object!") |
| 166 | break |
| 167 | try: |
You Wang | 21722ec | 2016-08-31 15:33:40 -0700 | [diff] [blame] | 168 | #FIXME: the Device Event (PORT_ADD) we got from metrics app is not the one generated Graph Event |
| 169 | if DeviceTime > GraphTime: |
| 170 | # This fixes the negative latency values. However we are not using the right Device Event |
| 171 | # timestamp. This should be fixed later. |
| 172 | DeviceTime = GraphTime |
YPZhang | 38fb119 | 2016-08-11 11:03:38 -0700 | [diff] [blame] | 173 | RR_Dtemp = DeviceTime - tempResultDict['RR'] |
| 174 | D_Gtemp = GraphTime - DeviceTime |
| 175 | E_Etemp = GraphTime - tempResultDict['TCP'] |
| 176 | main.log.info("Role reply to Device:{}".format(RR_Dtemp)) |
| 177 | main.log.info("Device to Graph:{}".format(D_Gtemp)) |
| 178 | main.log.info("End to End:{}".format(E_Etemp)) |
| 179 | main.log.info("================================================") |
| 180 | except KeyError: |
| 181 | main.log.warn("Tshark Result was incorrect!") |
| 182 | main.log.warn(tempResultDict) |
| 183 | return |
| 184 | except TypeError: |
| 185 | main.log.warn("TypeError") |
| 186 | break |
| 187 | except ValueError: |
| 188 | main.log.warn("Error to decode Json object!") |
| 189 | break |
| 190 | if not warmup: |
| 191 | resultDict[switchStatus]['node' + str(i)][ 'RR_D' ].append( RR_Dtemp ) |
| 192 | resultDict[switchStatus]['node' + str(i)][ 'D_G' ].append( D_Gtemp ) |
| 193 | resultDict[switchStatus]['node' + str(i)][ 'E_E' ].append( E_Etemp ) |
| 194 | |
YPZhang | 841262e | 2016-08-23 17:20:39 -0700 | [diff] [blame] | 195 | main.log.info( "Node {} Role Reply to Device: {}".format(str(i), str(RR_Dtemp) ) ) |
| 196 | main.log.info( "Node {} Device to Graph: {}".format(str(i), str(D_Gtemp) ) ) |
| 197 | main.log.info( "Node {} End to End: {}".format(str(i), str(E_Etemp) ) ) |
YPZhang | 38fb119 | 2016-08-11 11:03:38 -0700 | [diff] [blame] | 198 | |
| 199 | if switchStatus == "down": |
| 200 | # down Latency |
| 201 | for d in resultDict[switchStatus]: |
| 202 | FA_Atemp = 0 |
| 203 | try: |
| 204 | FA_Atemp = float("%.2f" % (tempResultDict['ACK'] - tempResultDict['FA']) ) |
| 205 | except KeyError: |
| 206 | main.log.warn("Tshark Result was incorrect!") |
| 207 | main.log.warn(tempResultDict) |
| 208 | return |
YPZhang | 841262e | 2016-08-23 17:20:39 -0700 | [diff] [blame] | 209 | |
YPZhang | 38fb119 | 2016-08-11 11:03:38 -0700 | [diff] [blame] | 210 | if not warmup: |
| 211 | resultDict[switchStatus][d][ 'FA_A' ].append( FA_Atemp ) |
| 212 | main.log.info( "{} FIN/ACK TO ACK {}:".format(d , FA_Atemp) ) |
| 213 | for i in range(1, main.numCtrls + 1): |
| 214 | A_Dtemp = 0 |
| 215 | D_Gtemp = 0 |
| 216 | E_Etemp = 0 |
| 217 | |
| 218 | main.log.info("================================================") |
| 219 | # get onos metrics timestamps |
| 220 | try: |
| 221 | response = json.loads(main.CLIs[i - 1].topologyEventsMetrics()) |
| 222 | DeviceTime = int( response.get("topologyDeviceEventTimestamp").get("value") ) |
| 223 | main.log.info("ONOS{} device Event timestamp: {}".format(i, DeviceTime)) |
| 224 | GraphTime = int( response.get("topologyGraphEventTimestamp").get("value") ) |
| 225 | main.log.info("ONOS{} Graph Event timestamp: {}".format(i, GraphTime)) |
| 226 | except TypeError: |
| 227 | main.log.warn("TypeError") |
| 228 | break |
| 229 | except ValueError: |
| 230 | main.log.warn("Error to decode Json object!") |
| 231 | break |
| 232 | main.log.info("================================================") |
| 233 | try: |
| 234 | A_Dtemp = float("%.2f" % (DeviceTime - tempResultDict['ACK']) ) |
| 235 | D_Gtemp = GraphTime - DeviceTime |
| 236 | E_Etemp = float("%.2f" % (GraphTime - tempResultDict['FA']) ) |
| 237 | main.log.info("ACK to device: {}".format(A_Dtemp)) |
| 238 | main.log.info("Device ot Graph: {}".format(D_Gtemp)) |
| 239 | main.log.info("End to End: {}".format(E_Etemp)) |
| 240 | main.log.info("================================================") |
| 241 | except KeyError: |
| 242 | main.log.warn("Tshark Result was incorrect!") |
| 243 | main.log.warn(tempResultDict) |
| 244 | return |
| 245 | except TypeError: |
| 246 | main.log.warn("TypeError") |
| 247 | break |
| 248 | except ValueError: |
| 249 | main.log.warn("Error to decode Json object!") |
| 250 | break |
| 251 | if not warmup: |
| 252 | resultDict[switchStatus]['node' + str(i)][ 'A_D' ].append( A_Dtemp ) |
| 253 | resultDict[switchStatus]['node' + str(i)][ 'D_G' ].append( D_Gtemp ) |
| 254 | resultDict[switchStatus]['node' + str(i)][ 'E_E' ].append( E_Etemp ) |
YPZhang | 347b8ae | 2016-08-19 09:43:24 -0700 | [diff] [blame] | 255 | main.CLIs[0].removeDevice( "of:0000000000000001" ) |
YPZhang | 38fb119 | 2016-08-11 11:03:38 -0700 | [diff] [blame] | 256 | |