blob: b81a674276746b0cbf519f9416e07dfffe872803 [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 -0700145def captureOfPack( main, deviceName, ofPack, switchStatus, resultDict, warmup ):
146 '''
147
148 Args:
149 main: TestON class
150 deviceName: device name
151 ofPack: openflow package key word
152 switchStatus: Up -- assign, down -- remove
153 resultDict: dictionary to contain result
154 warmup: warm up boolean
155
YPZhang38fb1192016-08-11 11:03:38 -0700156 '''
chengchiyu08303a02016-09-08 17:40:26 -0700157 main.log.debug( "TOTAL WRONG: " + str( main.wrong ) )
158 for d in ofPack[ switchStatus ]:
159 main.log.info( "Clean up Tshark" )
160 with open( main.tsharkResultPath[ switchStatus ][ d ], "w" ) as tshark:
161 tshark.write( "" )
162 # use one tshark to grep everything
163 # Get the grep string
164 grepString = ''
165 keyTerm = {}
166 for d in ofPack[ switchStatus ]:
167 grepString = grepString + ofPack[ switchStatus ][ d ] + '|'
168 # get rid of regular experssion format
169 cleanTerm = ofPack[ switchStatus ][ d ].replace( '\\', '' )
170 keyTerm[ cleanTerm ] = d
171 # Delete the last '|'
172 grepString = grepString[:-1]
173 # open tshark
174 main.log.info( "starting tshark capture" )
175 main.ONOSbench.tsharkGrep( grepString, main.tsharkResultPath[ switchStatus ][ 'ALL' ], grepOptions='-E' )
YPZhang38fb1192016-08-11 11:03:38 -0700176 if switchStatus == 'up':
177 # if up, assign switch to controller
chengchiyu08303a02016-09-08 17:40:26 -0700178 time.sleep( main.measurementSleep )
179 main.log.info( 'Assigning {} to controller'.format( deviceName ))
Devin Lim142b5342017-07-20 15:22:39 -0700180 main.Mininet1.assignSwController( sw=deviceName, ip=main.Cluster.active( 0 ).ipAddress )
chengchiyu08303a02016-09-08 17:40:26 -0700181 time.sleep( main.measurementSleep )
YPZhang38fb1192016-08-11 11:03:38 -0700182 if switchStatus == 'down':
183 # if down, remove switch from topology
chengchiyu08303a02016-09-08 17:40:26 -0700184 time.sleep( main.measurementSleep )
185 main.step( 'Remove switch from controler' )
186 main.Mininet1.deleteSwController( deviceName )
187 time.sleep( main.deleteSwSleep )
YPZhang38fb1192016-08-11 11:03:38 -0700188 main.log.info( "Stopping all Tshark processes" )
189 main.ONOSbench.tsharkStop()
YPZhang38fb1192016-08-11 11:03:38 -0700190 tempResultDict = {}
chengchiyu08303a02016-09-08 17:40:26 -0700191 arrangeTsharkFile( switchStatus, keyTerm )
192
YPZhang38fb1192016-08-11 11:03:38 -0700193 if switchStatus == 'up':
chengchiyu08303a02016-09-08 17:40:26 -0700194 for d in main.tsharkResultPath[ 'up' ]:
195 with open( main.tsharkResultPath[ switchStatus ][ d ], "r" ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700196 # grep tshark result timestamp
197 resultText = resultFile.readlines()
You Wang5b811272017-08-04 17:22:18 -0700198 if not resultText:
199 main.log.warn( "Empty tshark result!" )
200 main.wrong[ 'TsharkValueIncorrect' ] += 1
201 main.wrong[ 'totalWrong' ] += 1
202 checkTotalWrongNum()
203 return
YPZhang21adb602016-08-18 16:00:11 -0700204 if d == "TCP":
205 # if TCP package, we should use the latest one package
chengchiyu08303a02016-09-08 17:40:26 -0700206 resultText = resultText[ len( resultText ) - 1 ]
YPZhang21adb602016-08-18 16:00:11 -0700207 else:
chengchiyu08303a02016-09-08 17:40:26 -0700208 resultText = resultText[ 0 ]
209 main.log.info( "Capture result:" + resultText )
YPZhang38fb1192016-08-11 11:03:38 -0700210 resultText = resultText.strip()
211 resultText = resultText.split( " " )
212 if len(resultText) > 1:
chengchiyu08303a02016-09-08 17:40:26 -0700213 tempResultDict[d]= int( ( float( resultText[ 1 ] ) * 1000 ) )
YPZhang38fb1192016-08-11 11:03:38 -0700214 resultFile.close()
215 elif switchStatus == 'down':
216 # if state is down, we should capture Fin/Ack and ACK package
217 # Use seq number in FIN/ACK package to located ACK package
chengchiyu08303a02016-09-08 17:40:26 -0700218 with open( main.tsharkResultPath[ 'down' ][ 'FA' ], 'r' ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700219 resultText = resultFile.readlines()
chengchiyu08303a02016-09-08 17:40:26 -0700220 FinAckText = resultText.pop( 0 )
YPZhang38fb1192016-08-11 11:03:38 -0700221 resultFile.close()
chengchiyu08303a02016-09-08 17:40:26 -0700222 FinAckSeq = processPackage( FinAckText )[ 'Seq' ]
223 FinAckOFseq = findSeqBySeqAck( FinAckSeq, resultText )
You Wang18477602017-02-24 15:48:01 -0800224 if FinAckOFseq == None:
225 main.log.warn( "Tshark Result was incorrect!" )
226 main.log.warn( resultText )
227 main.wrong[ 'TsharkValueIncorrect' ] += 1
228 main.wrong[ 'totalWrong' ] += 1
229 checkTotalWrongNum()
230 return
chengchiyu08303a02016-09-08 17:40:26 -0700231 with open( main.tsharkResultPath[ 'down' ][ 'ACK' ], "r" ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700232 ACKlines = resultFile.readlines()
233 resultFile.close()
YPZhang3943fbe2016-08-18 14:33:29 -0700234 AckPackage = ""
YPZhang38fb1192016-08-11 11:03:38 -0700235 for l in ACKlines:
chengchiyu08303a02016-09-08 17:40:26 -0700236 temp = processPackage( l )
237 finSeq = findSeqBySeqAck( FinAckOFseq, ACKlines )
238 if temp[ 'Seq' ] == finSeq:
YPZhang38fb1192016-08-11 11:03:38 -0700239 AckPackage = l
chengchiyu08303a02016-09-08 17:40:26 -0700240 if len( AckPackage ) > 0:
YPZhang3943fbe2016-08-18 14:33:29 -0700241 FinAckText = FinAckText.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700242 FinAckText = FinAckText.split( " " )
YPZhang3943fbe2016-08-18 14:33:29 -0700243 AckPackage = AckPackage.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700244 AckPackage = AckPackage.split( " " )
245 tempResultDict[ 'ACK' ] = int( float( AckPackage[ 1 ] ) * 1000 )
246 tempResultDict[ 'FA' ] = int( float( FinAckText[ 1 ] ) * 1000 )
YPZhang3943fbe2016-08-18 14:33:29 -0700247 else:
chengchiyu08303a02016-09-08 17:40:26 -0700248 main.wrong[ 'skipDown' ] += 1
249 main.wrong[ 'totalWrong' ] += 1
250 checkTotalWrongNum()
YPZhang3943fbe2016-08-18 14:33:29 -0700251 return
chengchiyu08303a02016-09-08 17:40:26 -0700252
YPZhang38fb1192016-08-11 11:03:38 -0700253 # calculate latency
254 if switchStatus == "up":
255 # up Latency
chengchiyu08303a02016-09-08 17:40:26 -0700256 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700257 T_Ftemp = 0
258 F_Rtemp = 0
259 RQ_RRtemp = 0
260 try:
chengchiyu08303a02016-09-08 17:40:26 -0700261 T_Ftemp = tempResultDict[ 'Feature' ] - tempResultDict[ 'TCP' ]
262 F_Rtemp = tempResultDict[ 'RQ' ] - tempResultDict[ 'Feature' ]
263 RQ_RRtemp = tempResultDict[ 'RR' ] - tempResultDict[ 'RQ' ]
YPZhang38fb1192016-08-11 11:03:38 -0700264 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700265 main.log.warn( "Tshark Result was incorrect!" )
266 main.log.warn( tempResultDict )
267 main.wrong[ 'TsharkValueIncorrect' ] += 1
268 main.wrong[ 'totalWrong' ] += 1
269 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700270 return
271 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700272 resultDict[ switchStatus ][ d ][ 'T_F' ].append( T_Ftemp )
273 resultDict[ switchStatus ][ d ][ 'F_R' ].append( F_Rtemp )
274 resultDict[ switchStatus ][ d ][ 'RQ_RR' ].append( RQ_RRtemp )
YPZhang38fb1192016-08-11 11:03:38 -0700275
chengchiyu08303a02016-09-08 17:40:26 -0700276 main.log.info( "{} TCP to Feature: {}".format( d, str( T_Ftemp ) ) )
277 main.log.info( "{} Feature to Role Request: {}".format( d, str( F_Rtemp ) ) )
278 main.log.info( "{} Role Request to Role Reply: {}".format( d, str( RQ_RRtemp ) ) )
YPZhang38fb1192016-08-11 11:03:38 -0700279
Devin Lim142b5342017-07-20 15:22:39 -0700280 for i in range( 1, main.Cluster.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700281 RR_Dtemp = 0
282 D_Gtemp = 0
283 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700284 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700285 # get onos metrics timestamps
286 try:
Devin Lim142b5342017-07-20 15:22:39 -0700287 response = json.loads( main.Cluster.active( i - 1 ).CLI.topologyEventsMetrics() )
chengchiyu08303a02016-09-08 17:40:26 -0700288 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[switchStatus] )
289 main.log.info( "ONOS{} device Event timestamp: {}".format( i, "%.2f" % DeviceTime ) )
290 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
291 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700292 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700293 main.log.warn( "TypeError" )
294 main.wrong[ 'TypeError' ] += 1
295 main.wrong[ 'totalWrong' ] += 1
296 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700297 break
298 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700299 main.log.warn( "Error to decode Json object!" )
300 main.wrong[ 'decodeJasonError' ] += 1
301 main.wrong[ 'totalWrong' ] += 1
302 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700303 break
chengchiyu08303a02016-09-08 17:40:26 -0700304 if DeviceTime != 0:
305 try:
306 RR_Dtemp = DeviceTime - tempResultDict[ 'RR' ]
307 D_Gtemp = GraphTime - DeviceTime
308 E_Etemp = GraphTime - tempResultDict[ 'TCP' ]
309 check = checkResult( RR_Dtemp, D_Gtemp, E_Etemp )
310 if check == 1:
311 main.log.info( "Role reply to Device:{}".format( RR_Dtemp ) )
312 main.log.info( "Device to Graph:{}".format( D_Gtemp ) )
313 main.log.info( "End to End:{}".format( E_Etemp ) )
314 main.log.info( "================================================" )
315 except KeyError:
316 main.log.warn( "Tshark Result was incorrect!" )
317 main.log.warn( tempResultDict )
318 main.wrong[ 'TsharkValueIncorrect' ] += 1
319 main.wrong[ 'totalWrong' ] += 1
320 checkTotalWrongNum()
321 return
322 except TypeError:
323 main.log.warn( "TypeError" )
324 main.wrong[ 'TypeError' ] += 1
325 main.wrong[ 'totalWrong' ] += 1
326 checkTotalWrongNum()
327 break
328 except ValueError:
329 main.log.warn( "Error to decode Json object!" )
330 main.wrong[ 'decodeJasonError' ] += 1
331 main.wrong[ 'totalWrong' ] += 1
332 checkTotalWrongNum()
333 break
334 if not warmup and check == 1:
335 resultDict[ switchStatus ][ 'node' + str( i )][ 'RR_D' ].append( RR_Dtemp )
336 resultDict[ switchStatus ][ 'node' + str( i )][ 'D_G' ].append( D_Gtemp )
337 resultDict[ switchStatus ][ 'node' + str( i )][ 'E_E' ].append( E_Etemp )
338 else:
339 main.wrong['checkResultIncorrect'] += 1
340 main.wrong[ 'totalWrong' ] += 1
341 checkTotalWrongNum()
342 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700343
344 if switchStatus == "down":
345 # down Latency
chengchiyu08303a02016-09-08 17:40:26 -0700346 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700347 FA_Atemp = 0
348 try:
chengchiyu08303a02016-09-08 17:40:26 -0700349 FA_Atemp = tempResultDict[ 'ACK' ] - tempResultDict[ 'FA' ]
YPZhang38fb1192016-08-11 11:03:38 -0700350 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700351 main.log.warn( "Tshark Result was incorrect!" )
352 main.log.warn( tempResultDict )
353 main.wrong[ 'TsharkValueIncorrect' ] += 1
354 main.wrong[ 'totalWrong' ] += 1
355 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700356 return
357 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700358 resultDict[ switchStatus ][ d ][ 'FA_A' ].append( FA_Atemp )
359 main.log.info( "{} FIN/ACK TO ACK {}:".format( d, FA_Atemp ) )
Devin Lim142b5342017-07-20 15:22:39 -0700360 for i in range( 1, main.Cluster.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700361 A_Dtemp = 0
362 D_Gtemp = 0
363 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700364 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700365 # get onos metrics timestamps
366 try:
Devin Lim142b5342017-07-20 15:22:39 -0700367 response = json.loads( main.Cluster.active( i - 1 ).CLI.topologyEventsMetrics() )
368 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[ switchStatus ] )
chengchiyu08303a02016-09-08 17:40:26 -0700369 main.log.info( "ONOS{} device Event timestamp: {}".format( i, DeviceTime ) )
370 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
371 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700372 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700373 main.log.warn( "TypeError" )
374 main.wrong[ 'TypeError' ] += 1
375 main.wrong[ 'totalWrong' ] += 1
376 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700377 break
378 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700379 main.log.warn( "Error to decode Json object!" )
380 main.wrong[ 'decodeJasonError' ] += 1
381 main.wrong[ 'totalWrong' ] += 1
382 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700383 break
chengchiyu08303a02016-09-08 17:40:26 -0700384 if DeviceTime != 0:
385 main.log.info( "================================================" )
386 try:
387 A_Dtemp = DeviceTime - tempResultDict[ 'ACK' ]
388 D_Gtemp = GraphTime - DeviceTime
389 E_Etemp = GraphTime - tempResultDict[ 'FA' ]
390 check = checkResult( A_Dtemp, D_Gtemp, E_Etemp )
391 if check == 1:
392 main.log.info( "ACK to device: {}".format( A_Dtemp ) )
You Wang0e4ca9e2017-08-04 16:40:33 -0700393 main.log.info( "Device to Graph: {}".format( D_Gtemp ) )
chengchiyu08303a02016-09-08 17:40:26 -0700394 main.log.info( "End to End: {}".format( E_Etemp ) )
395 main.log.info( "================================================" )
396 except KeyError:
397 main.log.warn( "Tshark Result was incorrect!" )
398 main.log.warn( tempResultDict )
399 main.wrong[ 'TsharkValueIncorrect' ] += 1
400 main.wrong[ 'totalWrong' ] += 1
401 checkTotalWrongNum()
402 return
403 except TypeError:
404 main.log.warn( "TypeError" )
405 main.wrong[ 'TypeError' ] += 1
406 main.wrong[ 'totalWrong' ] += 1
407 checkTotalWrongNum()
408 break
409 except ValueError:
410 main.log.warn( "Error to decode Json object!" )
411 main.wrong[ 'decodeJasonError' ] += 1
412 main.wrong[ 'totalWrong' ] += 1
413 checkTotalWrongNum()
414 break
415 if not warmup and check == 1:
416 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'A_D' ].append( A_Dtemp )
417 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'D_G' ].append( D_Gtemp )
418 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'E_E' ].append( E_Etemp )
419
420 else:
421 main.wrong['checkResultIncorrect'] += 1
422 main.wrong['totalWrong'] += 1
423 checkTotalWrongNum()
424 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700425