blob: 11fbc310dee092e7953702a48d55acff413106ae [file] [log] [blame]
Jeremy Ronquillob27ce4c2017-07-17 12:41:28 -07001"""
2Copyright 2016 Open Networking Foundation (ONF)
3
4Please refer questions to either the onos test mailing list at <onos-test@onosproject.org>,
5the System Testing Plans and Results wiki page at <https://wiki.onosproject.org/x/voMg>,
6or the System Testing Guide page at <https://wiki.onosproject.org/x/WYQg>
7
8 TestON is free software: you can redistribute it and/or modify
9 it under the terms of the GNU General Public License as published by
10 the Free Software Foundation, either version 2 of the License, or
11 (at your option) any later version.
12
13 TestON is distributed in the hope that it will be useful,
14 but WITHOUT ANY WARRANTY; without even the implied warranty of
15 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
16 GNU General Public License for more details.
17
18 You should have received a copy of the GNU General Public License
19 along with TestON. If not, see <http://www.gnu.org/licenses/>.
20"""
21
YPZhang38fb1192016-08-11 11:03:38 -070022'''
23 Wrapper function for SCPFswitchLat test
24 Assign switch and capture openflow package
25 remove switch and caputer openflow package
26 calculate latency
27'''
YPZhang38fb1192016-08-11 11:03:38 -070028import time
29import json
chengchiyu08303a02016-09-08 17:40:26 -070030
31def getTimestampFromLog( index, searchTerm ):
32 '''
33 Get timestamp value of the search term from log.
34 Args:
35 index: the index of cli
36 searchTerm: the key term of timestamp
37
38 '''
Devin Lim142b5342017-07-20 15:22:39 -070039 lines = main.Cluster.active( index ).CLI.logSearch( mode='last', searchTerm=searchTerm )
chengchiyu08303a02016-09-08 17:40:26 -070040 try:
41 assert lines != None
42 logString = lines[ len ( lines ) - 1 ]
43 #get the target value
44 line = logString.split( "time = " )
45 key = line[ 1 ].split( " " )
46 return int( key[ 0 ] )
47 except IndexError:
48 main.log.warn( "Index Error!" )
49 return 0
50 except AssertionError:
51 main.log.warn( "Search Term Not Found" )
52 return 0
53
YPZhang38fb1192016-08-11 11:03:38 -070054def processPackage( package ):
55 '''
56 split package information to dictionary
57 Args:
58 package: Package String
59
YPZhang38fb1192016-08-11 11:03:38 -070060 '''
chengchiyu08303a02016-09-08 17:40:26 -070061 pacakge = package.split( " " )
YPZhang38fb1192016-08-11 11:03:38 -070062 dic = {}
63 for s in pacakge:
64 try:
chengchiyu08303a02016-09-08 17:40:26 -070065 [ key, value ] = s.split( "=" )
66 dic[ key ] = value
YPZhang38fb1192016-08-11 11:03:38 -070067 except:
68 continue
69 return dic
70
chengchiyu08303a02016-09-08 17:40:26 -070071def findSeqBySeqAck( seq, packageList ):
YPZhang38fb1192016-08-11 11:03:38 -070072 '''
73 Find specific Seq of package in packageList
74 Args:
75 seq: seq from last TCP package
76 packageList: find package in packageList
77
YPZhang38fb1192016-08-11 11:03:38 -070078 '''
79 for l in packageList:
chengchiyu08303a02016-09-08 17:40:26 -070080 temp = processPackage( l )
81 tA = temp[ 'Ack' ]
82 if int( seq ) + 1 == int( tA ):
83 return temp[ 'Seq' ]
84
85def arrangeTsharkFile( switchStatus, keyTerm ):
86 '''
87 Arrange different tshark messeage from overall file to different specific files
88 Args:
89 switchStatus: switch up or down
90 keyTerm: A dictionary that store the path name as value and the searchTerm as key
91
92 '''
93 with open( main.tsharkResultPath[ switchStatus ][ 'ALL' ], 'r' ) as resultFile:
94 resultText = resultFile.readlines()
95 resultFile.close()
96
97 for line in resultText:
98 for term in keyTerm:
99 if term in line:
100 path = '/tmp/Tshark_' + str( keyTerm[ term ] )
101 with open( path, 'a' ) as outputfile:
102 outputfile.write( line )
103 outputfile.close()
104
105def checkResult( result1, result2, result3 ):
106 '''
107 Check if the inputs meet the requirement
108 Returns:
109 1 means the results are right, 0 means the results are wrong
110
111 '''
112 result = check( result1 ) + check( result2 ) + check( result3 )
113 if result < 3:
114 # if any result is wrong, increase the main wrong number
115 main.wrong[ 'checkResultIncorrect' ] += 1
116 main.wrong[ 'totalWrong' ] += 1
117 checkTotalWrongNum()
118 return 0
119 return 1
120
121def check( result ):
122 '''
123 Check the single input.
124 Returns:
125 1 means the input is good, 0 means the input is wrong
126
127 '''
128 if result < int( main.resultRange[ 'Min' ] ) or result > int( main.resultRange[ 'Max' ] ):
129 main.log.debug( str( result ) + " is not meet the requirement" )
130 return 0
131 return 1
132
133def checkTotalWrongNum():
134 '''
135 Check if the total wrong number is bigger than the max wrong number. If it is, then exit the
136 test.
137
138 '''
139 # if there are too many wrongs in this test, then exit
140 if main.wrong['totalWrong'] > main.maxWrong:
141 main.log.error( "The total wrong number exceeds %d, test terminated" % main.maxWrong )
142 main.cleanup()
143 main.exit()
144
YPZhang38fb1192016-08-11 11:03:38 -0700145
146def captureOfPack( main, deviceName, ofPack, switchStatus, resultDict, warmup ):
147 '''
148
149 Args:
150 main: TestON class
151 deviceName: device name
152 ofPack: openflow package key word
153 switchStatus: Up -- assign, down -- remove
154 resultDict: dictionary to contain result
155 warmup: warm up boolean
156
YPZhang38fb1192016-08-11 11:03:38 -0700157 '''
chengchiyu08303a02016-09-08 17:40:26 -0700158 main.log.debug( "TOTAL WRONG: " + str( main.wrong ) )
159 for d in ofPack[ switchStatus ]:
160 main.log.info( "Clean up Tshark" )
161 with open( main.tsharkResultPath[ switchStatus ][ d ], "w" ) as tshark:
162 tshark.write( "" )
163 # use one tshark to grep everything
164 # Get the grep string
165 grepString = ''
166 keyTerm = {}
167 for d in ofPack[ switchStatus ]:
168 grepString = grepString + ofPack[ switchStatus ][ d ] + '|'
169 # get rid of regular experssion format
170 cleanTerm = ofPack[ switchStatus ][ d ].replace( '\\', '' )
171 keyTerm[ cleanTerm ] = d
172 # Delete the last '|'
173 grepString = grepString[:-1]
174 # open tshark
175 main.log.info( "starting tshark capture" )
176 main.ONOSbench.tsharkGrep( grepString, main.tsharkResultPath[ switchStatus ][ 'ALL' ], grepOptions='-E' )
YPZhang38fb1192016-08-11 11:03:38 -0700177 if switchStatus == 'up':
178 # if up, assign switch to controller
chengchiyu08303a02016-09-08 17:40:26 -0700179 time.sleep( main.measurementSleep )
180 main.log.info( 'Assigning {} to controller'.format( deviceName ))
Devin Lim142b5342017-07-20 15:22:39 -0700181 main.Mininet1.assignSwController( sw=deviceName, ip=main.Cluster.active( 0 ).ipAddress )
chengchiyu08303a02016-09-08 17:40:26 -0700182 time.sleep( main.measurementSleep )
YPZhang38fb1192016-08-11 11:03:38 -0700183 if switchStatus == 'down':
184 # if down, remove switch from topology
chengchiyu08303a02016-09-08 17:40:26 -0700185 time.sleep( main.measurementSleep )
186 main.step( 'Remove switch from controler' )
187 main.Mininet1.deleteSwController( deviceName )
188 time.sleep( main.deleteSwSleep )
YPZhang38fb1192016-08-11 11:03:38 -0700189 main.log.info( "Stopping all Tshark processes" )
190 main.ONOSbench.tsharkStop()
YPZhang38fb1192016-08-11 11:03:38 -0700191 tempResultDict = {}
chengchiyu08303a02016-09-08 17:40:26 -0700192 arrangeTsharkFile( switchStatus, keyTerm )
193
YPZhang38fb1192016-08-11 11:03:38 -0700194 if switchStatus == 'up':
chengchiyu08303a02016-09-08 17:40:26 -0700195 for d in main.tsharkResultPath[ 'up' ]:
196 with open( main.tsharkResultPath[ switchStatus ][ d ], "r" ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700197 # grep tshark result timestamp
198 resultText = resultFile.readlines()
You Wang5b811272017-08-04 17:22:18 -0700199 if not resultText:
200 main.log.warn( "Empty tshark result!" )
201 main.wrong[ 'TsharkValueIncorrect' ] += 1
202 main.wrong[ 'totalWrong' ] += 1
203 checkTotalWrongNum()
204 return
YPZhang21adb602016-08-18 16:00:11 -0700205 if d == "TCP":
206 # if TCP package, we should use the latest one package
chengchiyu08303a02016-09-08 17:40:26 -0700207 resultText = resultText[ len( resultText ) - 1 ]
YPZhang21adb602016-08-18 16:00:11 -0700208 else:
chengchiyu08303a02016-09-08 17:40:26 -0700209 resultText = resultText[ 0 ]
210 main.log.info( "Capture result:" + resultText )
YPZhang38fb1192016-08-11 11:03:38 -0700211 resultText = resultText.strip()
212 resultText = resultText.split( " " )
213 if len(resultText) > 1:
chengchiyu08303a02016-09-08 17:40:26 -0700214 tempResultDict[d]= int( ( float( resultText[ 1 ] ) * 1000 ) )
YPZhang38fb1192016-08-11 11:03:38 -0700215 resultFile.close()
216 elif switchStatus == 'down':
217 # if state is down, we should capture Fin/Ack and ACK package
218 # Use seq number in FIN/ACK package to located ACK package
chengchiyu08303a02016-09-08 17:40:26 -0700219 with open( main.tsharkResultPath[ 'down' ][ 'FA' ], 'r' ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700220 resultText = resultFile.readlines()
chengchiyu08303a02016-09-08 17:40:26 -0700221 FinAckText = resultText.pop( 0 )
YPZhang38fb1192016-08-11 11:03:38 -0700222 resultFile.close()
chengchiyu08303a02016-09-08 17:40:26 -0700223 FinAckSeq = processPackage( FinAckText )[ 'Seq' ]
224 FinAckOFseq = findSeqBySeqAck( FinAckSeq, resultText )
You Wang18477602017-02-24 15:48:01 -0800225 if FinAckOFseq == None:
226 main.log.warn( "Tshark Result was incorrect!" )
227 main.log.warn( resultText )
228 main.wrong[ 'TsharkValueIncorrect' ] += 1
229 main.wrong[ 'totalWrong' ] += 1
230 checkTotalWrongNum()
231 return
chengchiyu08303a02016-09-08 17:40:26 -0700232 with open( main.tsharkResultPath[ 'down' ][ 'ACK' ], "r" ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700233 ACKlines = resultFile.readlines()
234 resultFile.close()
YPZhang3943fbe2016-08-18 14:33:29 -0700235 AckPackage = ""
YPZhang38fb1192016-08-11 11:03:38 -0700236 for l in ACKlines:
chengchiyu08303a02016-09-08 17:40:26 -0700237 temp = processPackage( l )
238 finSeq = findSeqBySeqAck( FinAckOFseq, ACKlines )
239 if temp[ 'Seq' ] == finSeq:
YPZhang38fb1192016-08-11 11:03:38 -0700240 AckPackage = l
chengchiyu08303a02016-09-08 17:40:26 -0700241 if len( AckPackage ) > 0:
YPZhang3943fbe2016-08-18 14:33:29 -0700242 FinAckText = FinAckText.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700243 FinAckText = FinAckText.split( " " )
YPZhang3943fbe2016-08-18 14:33:29 -0700244 AckPackage = AckPackage.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700245 AckPackage = AckPackage.split( " " )
246 tempResultDict[ 'ACK' ] = int( float( AckPackage[ 1 ] ) * 1000 )
247 tempResultDict[ 'FA' ] = int( float( FinAckText[ 1 ] ) * 1000 )
YPZhang3943fbe2016-08-18 14:33:29 -0700248 else:
chengchiyu08303a02016-09-08 17:40:26 -0700249 main.wrong[ 'skipDown' ] += 1
250 main.wrong[ 'totalWrong' ] += 1
251 checkTotalWrongNum()
YPZhang3943fbe2016-08-18 14:33:29 -0700252 return
chengchiyu08303a02016-09-08 17:40:26 -0700253
YPZhang38fb1192016-08-11 11:03:38 -0700254 # calculate latency
255 if switchStatus == "up":
256 # up Latency
chengchiyu08303a02016-09-08 17:40:26 -0700257 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700258 T_Ftemp = 0
259 F_Rtemp = 0
260 RQ_RRtemp = 0
261 try:
chengchiyu08303a02016-09-08 17:40:26 -0700262 T_Ftemp = tempResultDict[ 'Feature' ] - tempResultDict[ 'TCP' ]
263 F_Rtemp = tempResultDict[ 'RQ' ] - tempResultDict[ 'Feature' ]
264 RQ_RRtemp = tempResultDict[ 'RR' ] - tempResultDict[ 'RQ' ]
YPZhang38fb1192016-08-11 11:03:38 -0700265 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700266 main.log.warn( "Tshark Result was incorrect!" )
267 main.log.warn( tempResultDict )
268 main.wrong[ 'TsharkValueIncorrect' ] += 1
269 main.wrong[ 'totalWrong' ] += 1
270 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700271 return
272 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700273 resultDict[ switchStatus ][ d ][ 'T_F' ].append( T_Ftemp )
274 resultDict[ switchStatus ][ d ][ 'F_R' ].append( F_Rtemp )
275 resultDict[ switchStatus ][ d ][ 'RQ_RR' ].append( RQ_RRtemp )
YPZhang38fb1192016-08-11 11:03:38 -0700276
chengchiyu08303a02016-09-08 17:40:26 -0700277 main.log.info( "{} TCP to Feature: {}".format( d, str( T_Ftemp ) ) )
278 main.log.info( "{} Feature to Role Request: {}".format( d, str( F_Rtemp ) ) )
279 main.log.info( "{} Role Request to Role Reply: {}".format( d, str( RQ_RRtemp ) ) )
YPZhang38fb1192016-08-11 11:03:38 -0700280
Devin Lim142b5342017-07-20 15:22:39 -0700281 for i in range( 1, main.Cluster.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700282 RR_Dtemp = 0
283 D_Gtemp = 0
284 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700285 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700286 # get onos metrics timestamps
287 try:
Devin Lim142b5342017-07-20 15:22:39 -0700288 response = json.loads( main.Cluster.active( i - 1 ).CLI.topologyEventsMetrics() )
chengchiyu08303a02016-09-08 17:40:26 -0700289 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[switchStatus] )
290 main.log.info( "ONOS{} device Event timestamp: {}".format( i, "%.2f" % DeviceTime ) )
291 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
292 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700293 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700294 main.log.warn( "TypeError" )
295 main.wrong[ 'TypeError' ] += 1
296 main.wrong[ 'totalWrong' ] += 1
297 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700298 break
299 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700300 main.log.warn( "Error to decode Json object!" )
301 main.wrong[ 'decodeJasonError' ] += 1
302 main.wrong[ 'totalWrong' ] += 1
303 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700304 break
chengchiyu08303a02016-09-08 17:40:26 -0700305 if DeviceTime != 0:
306 try:
307 RR_Dtemp = DeviceTime - tempResultDict[ 'RR' ]
308 D_Gtemp = GraphTime - DeviceTime
309 E_Etemp = GraphTime - tempResultDict[ 'TCP' ]
310 check = checkResult( RR_Dtemp, D_Gtemp, E_Etemp )
311 if check == 1:
312 main.log.info( "Role reply to Device:{}".format( RR_Dtemp ) )
313 main.log.info( "Device to Graph:{}".format( D_Gtemp ) )
314 main.log.info( "End to End:{}".format( E_Etemp ) )
315 main.log.info( "================================================" )
316 except KeyError:
317 main.log.warn( "Tshark Result was incorrect!" )
318 main.log.warn( tempResultDict )
319 main.wrong[ 'TsharkValueIncorrect' ] += 1
320 main.wrong[ 'totalWrong' ] += 1
321 checkTotalWrongNum()
322 return
323 except TypeError:
324 main.log.warn( "TypeError" )
325 main.wrong[ 'TypeError' ] += 1
326 main.wrong[ 'totalWrong' ] += 1
327 checkTotalWrongNum()
328 break
329 except ValueError:
330 main.log.warn( "Error to decode Json object!" )
331 main.wrong[ 'decodeJasonError' ] += 1
332 main.wrong[ 'totalWrong' ] += 1
333 checkTotalWrongNum()
334 break
335 if not warmup and check == 1:
336 resultDict[ switchStatus ][ 'node' + str( i )][ 'RR_D' ].append( RR_Dtemp )
337 resultDict[ switchStatus ][ 'node' + str( i )][ 'D_G' ].append( D_Gtemp )
338 resultDict[ switchStatus ][ 'node' + str( i )][ 'E_E' ].append( E_Etemp )
339 else:
340 main.wrong['checkResultIncorrect'] += 1
341 main.wrong[ 'totalWrong' ] += 1
342 checkTotalWrongNum()
343 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700344
345 if switchStatus == "down":
346 # down Latency
chengchiyu08303a02016-09-08 17:40:26 -0700347 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700348 FA_Atemp = 0
349 try:
chengchiyu08303a02016-09-08 17:40:26 -0700350 FA_Atemp = tempResultDict[ 'ACK' ] - tempResultDict[ 'FA' ]
YPZhang38fb1192016-08-11 11:03:38 -0700351 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700352 main.log.warn( "Tshark Result was incorrect!" )
353 main.log.warn( tempResultDict )
354 main.wrong[ 'TsharkValueIncorrect' ] += 1
355 main.wrong[ 'totalWrong' ] += 1
356 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700357 return
358 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700359 resultDict[ switchStatus ][ d ][ 'FA_A' ].append( FA_Atemp )
360 main.log.info( "{} FIN/ACK TO ACK {}:".format( d, FA_Atemp ) )
Devin Lim142b5342017-07-20 15:22:39 -0700361 for i in range( 1, main.Cluster.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700362 A_Dtemp = 0
363 D_Gtemp = 0
364 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700365 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700366 # get onos metrics timestamps
367 try:
Devin Lim142b5342017-07-20 15:22:39 -0700368 response = json.loads( main.Cluster.active( i - 1 ).CLI.topologyEventsMetrics() )
369 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[ switchStatus ] )
chengchiyu08303a02016-09-08 17:40:26 -0700370 main.log.info( "ONOS{} device Event timestamp: {}".format( i, DeviceTime ) )
371 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
372 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700373 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700374 main.log.warn( "TypeError" )
375 main.wrong[ 'TypeError' ] += 1
376 main.wrong[ 'totalWrong' ] += 1
377 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700378 break
379 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700380 main.log.warn( "Error to decode Json object!" )
381 main.wrong[ 'decodeJasonError' ] += 1
382 main.wrong[ 'totalWrong' ] += 1
383 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700384 break
chengchiyu08303a02016-09-08 17:40:26 -0700385 if DeviceTime != 0:
386 main.log.info( "================================================" )
387 try:
388 A_Dtemp = DeviceTime - tempResultDict[ 'ACK' ]
389 D_Gtemp = GraphTime - DeviceTime
390 E_Etemp = GraphTime - tempResultDict[ 'FA' ]
391 check = checkResult( A_Dtemp, D_Gtemp, E_Etemp )
392 if check == 1:
393 main.log.info( "ACK to device: {}".format( A_Dtemp ) )
394 main.log.info( "Device ot Graph: {}".format( D_Gtemp ) )
395 main.log.info( "End to End: {}".format( E_Etemp ) )
396 main.log.info( "================================================" )
397 except KeyError:
398 main.log.warn( "Tshark Result was incorrect!" )
399 main.log.warn( tempResultDict )
400 main.wrong[ 'TsharkValueIncorrect' ] += 1
401 main.wrong[ 'totalWrong' ] += 1
402 checkTotalWrongNum()
403 return
404 except TypeError:
405 main.log.warn( "TypeError" )
406 main.wrong[ 'TypeError' ] += 1
407 main.wrong[ 'totalWrong' ] += 1
408 checkTotalWrongNum()
409 break
410 except ValueError:
411 main.log.warn( "Error to decode Json object!" )
412 main.wrong[ 'decodeJasonError' ] += 1
413 main.wrong[ 'totalWrong' ] += 1
414 checkTotalWrongNum()
415 break
416 if not warmup and check == 1:
417 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'A_D' ].append( A_Dtemp )
418 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'D_G' ].append( D_Gtemp )
419 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'E_E' ].append( E_Etemp )
420
421 else:
422 main.wrong['checkResultIncorrect'] += 1
423 main.wrong['totalWrong'] += 1
424 checkTotalWrongNum()
425 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700426