blob: 78d0d3747d628806baa23485613dee87a54f726d [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 Chenge2b48e42016-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 )
198 with open( main.tsharkResultPath[ 'down' ][ 'ACK' ], "r" ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700199 ACKlines = resultFile.readlines()
200 resultFile.close()
YPZhang3943fbe2016-08-18 14:33:29 -0700201 AckPackage = ""
YPZhang38fb1192016-08-11 11:03:38 -0700202 for l in ACKlines:
chengchiyu08303a02016-09-08 17:40:26 -0700203 temp = processPackage( l )
204 finSeq = findSeqBySeqAck( FinAckOFseq, ACKlines )
205 if temp[ 'Seq' ] == finSeq:
YPZhang38fb1192016-08-11 11:03:38 -0700206 AckPackage = l
chengchiyu08303a02016-09-08 17:40:26 -0700207 if len( AckPackage ) > 0:
YPZhang3943fbe2016-08-18 14:33:29 -0700208 FinAckText = FinAckText.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700209 FinAckText = FinAckText.split( " " )
YPZhang3943fbe2016-08-18 14:33:29 -0700210 AckPackage = AckPackage.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700211 AckPackage = AckPackage.split( " " )
212 tempResultDict[ 'ACK' ] = int( float( AckPackage[ 1 ] ) * 1000 )
213 tempResultDict[ 'FA' ] = int( float( FinAckText[ 1 ] ) * 1000 )
YPZhang3943fbe2016-08-18 14:33:29 -0700214 else:
chengchiyu08303a02016-09-08 17:40:26 -0700215 main.wrong[ 'skipDown' ] += 1
216 main.wrong[ 'totalWrong' ] += 1
217 checkTotalWrongNum()
YPZhang3943fbe2016-08-18 14:33:29 -0700218 return
chengchiyu08303a02016-09-08 17:40:26 -0700219
YPZhang38fb1192016-08-11 11:03:38 -0700220 # calculate latency
221 if switchStatus == "up":
222 # up Latency
chengchiyu08303a02016-09-08 17:40:26 -0700223 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700224 T_Ftemp = 0
225 F_Rtemp = 0
226 RQ_RRtemp = 0
227 try:
chengchiyu08303a02016-09-08 17:40:26 -0700228 T_Ftemp = tempResultDict[ 'Feature' ] - tempResultDict[ 'TCP' ]
229 F_Rtemp = tempResultDict[ 'RQ' ] - tempResultDict[ 'Feature' ]
230 RQ_RRtemp = tempResultDict[ 'RR' ] - tempResultDict[ 'RQ' ]
YPZhang38fb1192016-08-11 11:03:38 -0700231 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700232 main.log.warn( "Tshark Result was incorrect!" )
233 main.log.warn( tempResultDict )
234 main.wrong[ 'TsharkValueIncorrect' ] += 1
235 main.wrong[ 'totalWrong' ] += 1
236 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700237 return
238 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700239 resultDict[ switchStatus ][ d ][ 'T_F' ].append( T_Ftemp )
240 resultDict[ switchStatus ][ d ][ 'F_R' ].append( F_Rtemp )
241 resultDict[ switchStatus ][ d ][ 'RQ_RR' ].append( RQ_RRtemp )
YPZhang38fb1192016-08-11 11:03:38 -0700242
chengchiyu08303a02016-09-08 17:40:26 -0700243 main.log.info( "{} TCP to Feature: {}".format( d, str( T_Ftemp ) ) )
244 main.log.info( "{} Feature to Role Request: {}".format( d, str( F_Rtemp ) ) )
245 main.log.info( "{} Role Request to Role Reply: {}".format( d, str( RQ_RRtemp ) ) )
YPZhang38fb1192016-08-11 11:03:38 -0700246
chengchiyu08303a02016-09-08 17:40:26 -0700247 for i in range( 1, main.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700248 RR_Dtemp = 0
249 D_Gtemp = 0
250 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700251 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700252 # get onos metrics timestamps
253 try:
chengchiyu08303a02016-09-08 17:40:26 -0700254 response = json.loads( main.CLIs[i - 1].topologyEventsMetrics() )
255 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[switchStatus] )
256 main.log.info( "ONOS{} device Event timestamp: {}".format( i, "%.2f" % DeviceTime ) )
257 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
258 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700259 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700260 main.log.warn( "TypeError" )
261 main.wrong[ 'TypeError' ] += 1
262 main.wrong[ 'totalWrong' ] += 1
263 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700264 break
265 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700266 main.log.warn( "Error to decode Json object!" )
267 main.wrong[ 'decodeJasonError' ] += 1
268 main.wrong[ 'totalWrong' ] += 1
269 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700270 break
chengchiyu08303a02016-09-08 17:40:26 -0700271 if DeviceTime != 0:
272 try:
273 RR_Dtemp = DeviceTime - tempResultDict[ 'RR' ]
274 D_Gtemp = GraphTime - DeviceTime
275 E_Etemp = GraphTime - tempResultDict[ 'TCP' ]
276 check = checkResult( RR_Dtemp, D_Gtemp, E_Etemp )
277 if check == 1:
278 main.log.info( "Role reply to Device:{}".format( RR_Dtemp ) )
279 main.log.info( "Device to Graph:{}".format( D_Gtemp ) )
280 main.log.info( "End to End:{}".format( E_Etemp ) )
281 main.log.info( "================================================" )
282 except KeyError:
283 main.log.warn( "Tshark Result was incorrect!" )
284 main.log.warn( tempResultDict )
285 main.wrong[ 'TsharkValueIncorrect' ] += 1
286 main.wrong[ 'totalWrong' ] += 1
287 checkTotalWrongNum()
288 return
289 except TypeError:
290 main.log.warn( "TypeError" )
291 main.wrong[ 'TypeError' ] += 1
292 main.wrong[ 'totalWrong' ] += 1
293 checkTotalWrongNum()
294 break
295 except ValueError:
296 main.log.warn( "Error to decode Json object!" )
297 main.wrong[ 'decodeJasonError' ] += 1
298 main.wrong[ 'totalWrong' ] += 1
299 checkTotalWrongNum()
300 break
301 if not warmup and check == 1:
302 resultDict[ switchStatus ][ 'node' + str( i )][ 'RR_D' ].append( RR_Dtemp )
303 resultDict[ switchStatus ][ 'node' + str( i )][ 'D_G' ].append( D_Gtemp )
304 resultDict[ switchStatus ][ 'node' + str( i )][ 'E_E' ].append( E_Etemp )
305 else:
306 main.wrong['checkResultIncorrect'] += 1
307 main.wrong[ 'totalWrong' ] += 1
308 checkTotalWrongNum()
309 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700310
311 if switchStatus == "down":
312 # down Latency
chengchiyu08303a02016-09-08 17:40:26 -0700313 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700314 FA_Atemp = 0
315 try:
chengchiyu08303a02016-09-08 17:40:26 -0700316 FA_Atemp = tempResultDict[ 'ACK' ] - tempResultDict[ 'FA' ]
YPZhang38fb1192016-08-11 11:03:38 -0700317 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700318 main.log.warn( "Tshark Result was incorrect!" )
319 main.log.warn( tempResultDict )
320 main.wrong[ 'TsharkValueIncorrect' ] += 1
321 main.wrong[ 'totalWrong' ] += 1
322 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700323 return
324 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700325 resultDict[ switchStatus ][ d ][ 'FA_A' ].append( FA_Atemp )
326 main.log.info( "{} FIN/ACK TO ACK {}:".format( d, FA_Atemp ) )
327 for i in range( 1, main.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700328 A_Dtemp = 0
329 D_Gtemp = 0
330 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700331 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700332 # get onos metrics timestamps
333 try:
chengchiyu08303a02016-09-08 17:40:26 -0700334 response = json.loads( main.CLIs[ i - 1 ].topologyEventsMetrics() )
335 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[switchStatus] )
336 main.log.info( "ONOS{} device Event timestamp: {}".format( i, DeviceTime ) )
337 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
338 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700339 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700340 main.log.warn( "TypeError" )
341 main.wrong[ 'TypeError' ] += 1
342 main.wrong[ 'totalWrong' ] += 1
343 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700344 break
345 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700346 main.log.warn( "Error to decode Json object!" )
347 main.wrong[ 'decodeJasonError' ] += 1
348 main.wrong[ 'totalWrong' ] += 1
349 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700350 break
chengchiyu08303a02016-09-08 17:40:26 -0700351 if DeviceTime != 0:
352 main.log.info( "================================================" )
353 try:
354 A_Dtemp = DeviceTime - tempResultDict[ 'ACK' ]
355 D_Gtemp = GraphTime - DeviceTime
356 E_Etemp = GraphTime - tempResultDict[ 'FA' ]
357 check = checkResult( A_Dtemp, D_Gtemp, E_Etemp )
358 if check == 1:
359 main.log.info( "ACK to device: {}".format( A_Dtemp ) )
360 main.log.info( "Device ot Graph: {}".format( D_Gtemp ) )
361 main.log.info( "End to End: {}".format( E_Etemp ) )
362 main.log.info( "================================================" )
363 except KeyError:
364 main.log.warn( "Tshark Result was incorrect!" )
365 main.log.warn( tempResultDict )
366 main.wrong[ 'TsharkValueIncorrect' ] += 1
367 main.wrong[ 'totalWrong' ] += 1
368 checkTotalWrongNum()
369 return
370 except TypeError:
371 main.log.warn( "TypeError" )
372 main.wrong[ 'TypeError' ] += 1
373 main.wrong[ 'totalWrong' ] += 1
374 checkTotalWrongNum()
375 break
376 except ValueError:
377 main.log.warn( "Error to decode Json object!" )
378 main.wrong[ 'decodeJasonError' ] += 1
379 main.wrong[ 'totalWrong' ] += 1
380 checkTotalWrongNum()
381 break
382 if not warmup and check == 1:
383 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'A_D' ].append( A_Dtemp )
384 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'D_G' ].append( D_Gtemp )
385 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'E_E' ].append( E_Etemp )
386
387 else:
388 main.wrong['checkResultIncorrect'] += 1
389 main.wrong['totalWrong'] += 1
390 checkTotalWrongNum()
391 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700392