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