blob: 4f46e484e8f0afc47ef5997d3bf26fd4ed982eed [file] [log] [blame]
YPZhang38fb1192016-08-11 11:03:38 -07001'''
2 Wrapper function for SCPFswitchLat test
3 Assign switch and capture openflow package
4 remove switch and caputer openflow package
5 calculate latency
6'''
YPZhang38fb1192016-08-11 11:03:38 -07007import time
8import json
chengchiyu08303a02016-09-08 17:40:26 -07009
10def getTimestampFromLog( index, searchTerm ):
11 '''
12 Get timestamp value of the search term from log.
13 Args:
14 index: the index of cli
15 searchTerm: the key term of timestamp
16
17 '''
Chiyu Chengec63bde2016-11-17 18:11:36 -080018 lines = main.CLIs[ index ].logSearch( mode='last', searchTerm=searchTerm )
chengchiyu08303a02016-09-08 17:40:26 -070019 try:
20 assert lines != None
21 logString = lines[ len ( lines ) - 1 ]
22 #get the target value
23 line = logString.split( "time = " )
24 key = line[ 1 ].split( " " )
25 return int( key[ 0 ] )
26 except IndexError:
27 main.log.warn( "Index Error!" )
28 return 0
29 except AssertionError:
30 main.log.warn( "Search Term Not Found" )
31 return 0
32
YPZhang38fb1192016-08-11 11:03:38 -070033def processPackage( package ):
34 '''
35 split package information to dictionary
36 Args:
37 package: Package String
38
YPZhang38fb1192016-08-11 11:03:38 -070039 '''
chengchiyu08303a02016-09-08 17:40:26 -070040 pacakge = package.split( " " )
YPZhang38fb1192016-08-11 11:03:38 -070041 dic = {}
42 for s in pacakge:
43 try:
chengchiyu08303a02016-09-08 17:40:26 -070044 [ key, value ] = s.split( "=" )
45 dic[ key ] = value
YPZhang38fb1192016-08-11 11:03:38 -070046 except:
47 continue
48 return dic
49
chengchiyu08303a02016-09-08 17:40:26 -070050def findSeqBySeqAck( seq, packageList ):
YPZhang38fb1192016-08-11 11:03:38 -070051 '''
52 Find specific Seq of package in packageList
53 Args:
54 seq: seq from last TCP package
55 packageList: find package in packageList
56
YPZhang38fb1192016-08-11 11:03:38 -070057 '''
58 for l in packageList:
chengchiyu08303a02016-09-08 17:40:26 -070059 temp = processPackage( l )
60 tA = temp[ 'Ack' ]
61 if int( seq ) + 1 == int( tA ):
62 return temp[ 'Seq' ]
63
64def arrangeTsharkFile( switchStatus, keyTerm ):
65 '''
66 Arrange different tshark messeage from overall file to different specific files
67 Args:
68 switchStatus: switch up or down
69 keyTerm: A dictionary that store the path name as value and the searchTerm as key
70
71 '''
72 with open( main.tsharkResultPath[ switchStatus ][ 'ALL' ], 'r' ) as resultFile:
73 resultText = resultFile.readlines()
74 resultFile.close()
75
76 for line in resultText:
77 for term in keyTerm:
78 if term in line:
79 path = '/tmp/Tshark_' + str( keyTerm[ term ] )
80 with open( path, 'a' ) as outputfile:
81 outputfile.write( line )
82 outputfile.close()
83
84def checkResult( result1, result2, result3 ):
85 '''
86 Check if the inputs meet the requirement
87 Returns:
88 1 means the results are right, 0 means the results are wrong
89
90 '''
91 result = check( result1 ) + check( result2 ) + check( result3 )
92 if result < 3:
93 # if any result is wrong, increase the main wrong number
94 main.wrong[ 'checkResultIncorrect' ] += 1
95 main.wrong[ 'totalWrong' ] += 1
96 checkTotalWrongNum()
97 return 0
98 return 1
99
100def check( result ):
101 '''
102 Check the single input.
103 Returns:
104 1 means the input is good, 0 means the input is wrong
105
106 '''
107 if result < int( main.resultRange[ 'Min' ] ) or result > int( main.resultRange[ 'Max' ] ):
108 main.log.debug( str( result ) + " is not meet the requirement" )
109 return 0
110 return 1
111
112def checkTotalWrongNum():
113 '''
114 Check if the total wrong number is bigger than the max wrong number. If it is, then exit the
115 test.
116
117 '''
118 # if there are too many wrongs in this test, then exit
119 if main.wrong['totalWrong'] > main.maxWrong:
120 main.log.error( "The total wrong number exceeds %d, test terminated" % main.maxWrong )
121 main.cleanup()
122 main.exit()
123
YPZhang38fb1192016-08-11 11:03:38 -0700124
125def captureOfPack( main, deviceName, ofPack, switchStatus, resultDict, warmup ):
126 '''
127
128 Args:
129 main: TestON class
130 deviceName: device name
131 ofPack: openflow package key word
132 switchStatus: Up -- assign, down -- remove
133 resultDict: dictionary to contain result
134 warmup: warm up boolean
135
YPZhang38fb1192016-08-11 11:03:38 -0700136 '''
chengchiyu08303a02016-09-08 17:40:26 -0700137 main.log.debug( "TOTAL WRONG: " + str( main.wrong ) )
138 for d in ofPack[ switchStatus ]:
139 main.log.info( "Clean up Tshark" )
140 with open( main.tsharkResultPath[ switchStatus ][ d ], "w" ) as tshark:
141 tshark.write( "" )
142 # use one tshark to grep everything
143 # Get the grep string
144 grepString = ''
145 keyTerm = {}
146 for d in ofPack[ switchStatus ]:
147 grepString = grepString + ofPack[ switchStatus ][ d ] + '|'
148 # get rid of regular experssion format
149 cleanTerm = ofPack[ switchStatus ][ d ].replace( '\\', '' )
150 keyTerm[ cleanTerm ] = d
151 # Delete the last '|'
152 grepString = grepString[:-1]
153 # open tshark
154 main.log.info( "starting tshark capture" )
155 main.ONOSbench.tsharkGrep( grepString, main.tsharkResultPath[ switchStatus ][ 'ALL' ], grepOptions='-E' )
YPZhang38fb1192016-08-11 11:03:38 -0700156 if switchStatus == 'up':
157 # if up, assign switch to controller
chengchiyu08303a02016-09-08 17:40:26 -0700158 time.sleep( main.measurementSleep )
159 main.log.info( 'Assigning {} to controller'.format( deviceName ))
160 main.Mininet1.assignSwController( sw=deviceName, ip=main.ONOSip[0] )
161 time.sleep( main.measurementSleep )
YPZhang38fb1192016-08-11 11:03:38 -0700162 if switchStatus == 'down':
163 # if down, remove switch from topology
chengchiyu08303a02016-09-08 17:40:26 -0700164 time.sleep( main.measurementSleep )
165 main.step( 'Remove switch from controler' )
166 main.Mininet1.deleteSwController( deviceName )
167 time.sleep( main.deleteSwSleep )
YPZhang38fb1192016-08-11 11:03:38 -0700168 main.log.info( "Stopping all Tshark processes" )
169 main.ONOSbench.tsharkStop()
YPZhang38fb1192016-08-11 11:03:38 -0700170 tempResultDict = {}
chengchiyu08303a02016-09-08 17:40:26 -0700171 arrangeTsharkFile( switchStatus, keyTerm )
172
YPZhang38fb1192016-08-11 11:03:38 -0700173 if switchStatus == 'up':
chengchiyu08303a02016-09-08 17:40:26 -0700174 for d in main.tsharkResultPath[ 'up' ]:
175 with open( main.tsharkResultPath[ switchStatus ][ d ], "r" ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700176 # grep tshark result timestamp
177 resultText = resultFile.readlines()
YPZhang21adb602016-08-18 16:00:11 -0700178 if d == "TCP":
179 # if TCP package, we should use the latest one package
chengchiyu08303a02016-09-08 17:40:26 -0700180 resultText = resultText[ len( resultText ) - 1 ]
YPZhang21adb602016-08-18 16:00:11 -0700181 else:
chengchiyu08303a02016-09-08 17:40:26 -0700182 resultText = resultText[ 0 ]
183 main.log.info( "Capture result:" + resultText )
YPZhang38fb1192016-08-11 11:03:38 -0700184 resultText = resultText.strip()
185 resultText = resultText.split( " " )
186 if len(resultText) > 1:
chengchiyu08303a02016-09-08 17:40:26 -0700187 tempResultDict[d]= int( ( float( resultText[ 1 ] ) * 1000 ) )
YPZhang38fb1192016-08-11 11:03:38 -0700188 resultFile.close()
189 elif switchStatus == 'down':
190 # if state is down, we should capture Fin/Ack and ACK package
191 # Use seq number in FIN/ACK package to located ACK package
chengchiyu08303a02016-09-08 17:40:26 -0700192 with open( main.tsharkResultPath[ 'down' ][ 'FA' ], 'r' ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700193 resultText = resultFile.readlines()
chengchiyu08303a02016-09-08 17:40:26 -0700194 FinAckText = resultText.pop( 0 )
YPZhang38fb1192016-08-11 11:03:38 -0700195 resultFile.close()
chengchiyu08303a02016-09-08 17:40:26 -0700196 FinAckSeq = processPackage( FinAckText )[ 'Seq' ]
197 FinAckOFseq = findSeqBySeqAck( FinAckSeq, resultText )
You Wang18477602017-02-24 15:48:01 -0800198 if FinAckOFseq == None:
199 main.log.warn( "Tshark Result was incorrect!" )
200 main.log.warn( resultText )
201 main.wrong[ 'TsharkValueIncorrect' ] += 1
202 main.wrong[ 'totalWrong' ] += 1
203 checkTotalWrongNum()
204 return
chengchiyu08303a02016-09-08 17:40:26 -0700205 with open( main.tsharkResultPath[ 'down' ][ 'ACK' ], "r" ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700206 ACKlines = resultFile.readlines()
207 resultFile.close()
YPZhang3943fbe2016-08-18 14:33:29 -0700208 AckPackage = ""
YPZhang38fb1192016-08-11 11:03:38 -0700209 for l in ACKlines:
chengchiyu08303a02016-09-08 17:40:26 -0700210 temp = processPackage( l )
211 finSeq = findSeqBySeqAck( FinAckOFseq, ACKlines )
212 if temp[ 'Seq' ] == finSeq:
YPZhang38fb1192016-08-11 11:03:38 -0700213 AckPackage = l
chengchiyu08303a02016-09-08 17:40:26 -0700214 if len( AckPackage ) > 0:
YPZhang3943fbe2016-08-18 14:33:29 -0700215 FinAckText = FinAckText.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700216 FinAckText = FinAckText.split( " " )
YPZhang3943fbe2016-08-18 14:33:29 -0700217 AckPackage = AckPackage.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700218 AckPackage = AckPackage.split( " " )
219 tempResultDict[ 'ACK' ] = int( float( AckPackage[ 1 ] ) * 1000 )
220 tempResultDict[ 'FA' ] = int( float( FinAckText[ 1 ] ) * 1000 )
YPZhang3943fbe2016-08-18 14:33:29 -0700221 else:
chengchiyu08303a02016-09-08 17:40:26 -0700222 main.wrong[ 'skipDown' ] += 1
223 main.wrong[ 'totalWrong' ] += 1
224 checkTotalWrongNum()
YPZhang3943fbe2016-08-18 14:33:29 -0700225 return
chengchiyu08303a02016-09-08 17:40:26 -0700226
YPZhang38fb1192016-08-11 11:03:38 -0700227 # calculate latency
228 if switchStatus == "up":
229 # up Latency
chengchiyu08303a02016-09-08 17:40:26 -0700230 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700231 T_Ftemp = 0
232 F_Rtemp = 0
233 RQ_RRtemp = 0
234 try:
chengchiyu08303a02016-09-08 17:40:26 -0700235 T_Ftemp = tempResultDict[ 'Feature' ] - tempResultDict[ 'TCP' ]
236 F_Rtemp = tempResultDict[ 'RQ' ] - tempResultDict[ 'Feature' ]
237 RQ_RRtemp = tempResultDict[ 'RR' ] - tempResultDict[ 'RQ' ]
YPZhang38fb1192016-08-11 11:03:38 -0700238 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700239 main.log.warn( "Tshark Result was incorrect!" )
240 main.log.warn( tempResultDict )
241 main.wrong[ 'TsharkValueIncorrect' ] += 1
242 main.wrong[ 'totalWrong' ] += 1
243 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700244 return
245 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700246 resultDict[ switchStatus ][ d ][ 'T_F' ].append( T_Ftemp )
247 resultDict[ switchStatus ][ d ][ 'F_R' ].append( F_Rtemp )
248 resultDict[ switchStatus ][ d ][ 'RQ_RR' ].append( RQ_RRtemp )
YPZhang38fb1192016-08-11 11:03:38 -0700249
chengchiyu08303a02016-09-08 17:40:26 -0700250 main.log.info( "{} TCP to Feature: {}".format( d, str( T_Ftemp ) ) )
251 main.log.info( "{} Feature to Role Request: {}".format( d, str( F_Rtemp ) ) )
252 main.log.info( "{} Role Request to Role Reply: {}".format( d, str( RQ_RRtemp ) ) )
YPZhang38fb1192016-08-11 11:03:38 -0700253
chengchiyu08303a02016-09-08 17:40:26 -0700254 for i in range( 1, main.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700255 RR_Dtemp = 0
256 D_Gtemp = 0
257 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700258 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700259 # get onos metrics timestamps
260 try:
chengchiyu08303a02016-09-08 17:40:26 -0700261 response = json.loads( main.CLIs[i - 1].topologyEventsMetrics() )
262 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[switchStatus] )
263 main.log.info( "ONOS{} device Event timestamp: {}".format( i, "%.2f" % DeviceTime ) )
264 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
265 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700266 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700267 main.log.warn( "TypeError" )
268 main.wrong[ 'TypeError' ] += 1
269 main.wrong[ 'totalWrong' ] += 1
270 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700271 break
272 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700273 main.log.warn( "Error to decode Json object!" )
274 main.wrong[ 'decodeJasonError' ] += 1
275 main.wrong[ 'totalWrong' ] += 1
276 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700277 break
chengchiyu08303a02016-09-08 17:40:26 -0700278 if DeviceTime != 0:
279 try:
280 RR_Dtemp = DeviceTime - tempResultDict[ 'RR' ]
281 D_Gtemp = GraphTime - DeviceTime
282 E_Etemp = GraphTime - tempResultDict[ 'TCP' ]
283 check = checkResult( RR_Dtemp, D_Gtemp, E_Etemp )
284 if check == 1:
285 main.log.info( "Role reply to Device:{}".format( RR_Dtemp ) )
286 main.log.info( "Device to Graph:{}".format( D_Gtemp ) )
287 main.log.info( "End to End:{}".format( E_Etemp ) )
288 main.log.info( "================================================" )
289 except KeyError:
290 main.log.warn( "Tshark Result was incorrect!" )
291 main.log.warn( tempResultDict )
292 main.wrong[ 'TsharkValueIncorrect' ] += 1
293 main.wrong[ 'totalWrong' ] += 1
294 checkTotalWrongNum()
295 return
296 except TypeError:
297 main.log.warn( "TypeError" )
298 main.wrong[ 'TypeError' ] += 1
299 main.wrong[ 'totalWrong' ] += 1
300 checkTotalWrongNum()
301 break
302 except ValueError:
303 main.log.warn( "Error to decode Json object!" )
304 main.wrong[ 'decodeJasonError' ] += 1
305 main.wrong[ 'totalWrong' ] += 1
306 checkTotalWrongNum()
307 break
308 if not warmup and check == 1:
309 resultDict[ switchStatus ][ 'node' + str( i )][ 'RR_D' ].append( RR_Dtemp )
310 resultDict[ switchStatus ][ 'node' + str( i )][ 'D_G' ].append( D_Gtemp )
311 resultDict[ switchStatus ][ 'node' + str( i )][ 'E_E' ].append( E_Etemp )
312 else:
313 main.wrong['checkResultIncorrect'] += 1
314 main.wrong[ 'totalWrong' ] += 1
315 checkTotalWrongNum()
316 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700317
318 if switchStatus == "down":
319 # down Latency
chengchiyu08303a02016-09-08 17:40:26 -0700320 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700321 FA_Atemp = 0
322 try:
chengchiyu08303a02016-09-08 17:40:26 -0700323 FA_Atemp = tempResultDict[ 'ACK' ] - tempResultDict[ 'FA' ]
YPZhang38fb1192016-08-11 11:03:38 -0700324 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700325 main.log.warn( "Tshark Result was incorrect!" )
326 main.log.warn( tempResultDict )
327 main.wrong[ 'TsharkValueIncorrect' ] += 1
328 main.wrong[ 'totalWrong' ] += 1
329 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700330 return
331 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700332 resultDict[ switchStatus ][ d ][ 'FA_A' ].append( FA_Atemp )
333 main.log.info( "{} FIN/ACK TO ACK {}:".format( d, FA_Atemp ) )
334 for i in range( 1, main.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700335 A_Dtemp = 0
336 D_Gtemp = 0
337 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700338 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700339 # get onos metrics timestamps
340 try:
chengchiyu08303a02016-09-08 17:40:26 -0700341 response = json.loads( main.CLIs[ i - 1 ].topologyEventsMetrics() )
342 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[switchStatus] )
343 main.log.info( "ONOS{} device Event timestamp: {}".format( i, DeviceTime ) )
344 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
345 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700346 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700347 main.log.warn( "TypeError" )
348 main.wrong[ 'TypeError' ] += 1
349 main.wrong[ 'totalWrong' ] += 1
350 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700351 break
352 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700353 main.log.warn( "Error to decode Json object!" )
354 main.wrong[ 'decodeJasonError' ] += 1
355 main.wrong[ 'totalWrong' ] += 1
356 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700357 break
chengchiyu08303a02016-09-08 17:40:26 -0700358 if DeviceTime != 0:
359 main.log.info( "================================================" )
360 try:
361 A_Dtemp = DeviceTime - tempResultDict[ 'ACK' ]
362 D_Gtemp = GraphTime - DeviceTime
363 E_Etemp = GraphTime - tempResultDict[ 'FA' ]
364 check = checkResult( A_Dtemp, D_Gtemp, E_Etemp )
365 if check == 1:
366 main.log.info( "ACK to device: {}".format( A_Dtemp ) )
367 main.log.info( "Device ot Graph: {}".format( D_Gtemp ) )
368 main.log.info( "End to End: {}".format( E_Etemp ) )
369 main.log.info( "================================================" )
370 except KeyError:
371 main.log.warn( "Tshark Result was incorrect!" )
372 main.log.warn( tempResultDict )
373 main.wrong[ 'TsharkValueIncorrect' ] += 1
374 main.wrong[ 'totalWrong' ] += 1
375 checkTotalWrongNum()
376 return
377 except TypeError:
378 main.log.warn( "TypeError" )
379 main.wrong[ 'TypeError' ] += 1
380 main.wrong[ 'totalWrong' ] += 1
381 checkTotalWrongNum()
382 break
383 except ValueError:
384 main.log.warn( "Error to decode Json object!" )
385 main.wrong[ 'decodeJasonError' ] += 1
386 main.wrong[ 'totalWrong' ] += 1
387 checkTotalWrongNum()
388 break
389 if not warmup and check == 1:
390 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'A_D' ].append( A_Dtemp )
391 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'D_G' ].append( D_Gtemp )
392 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'E_E' ].append( E_Etemp )
393
394 else:
395 main.wrong['checkResultIncorrect'] += 1
396 main.wrong['totalWrong'] += 1
397 checkTotalWrongNum()
398 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700399