blob: cde275ecaa95d5e64d4fed13cd74208c8e30e615 [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 )
Devin Lim44075962017-08-11 10:56:37 -0700142 main.cleanAndExit()
chengchiyu08303a02016-09-08 17:40:26 -0700143
YPZhang38fb1192016-08-11 11:03:38 -0700144def captureOfPack( main, deviceName, ofPack, switchStatus, resultDict, warmup ):
145 '''
146
147 Args:
148 main: TestON class
149 deviceName: device name
150 ofPack: openflow package key word
151 switchStatus: Up -- assign, down -- remove
152 resultDict: dictionary to contain result
153 warmup: warm up boolean
154
YPZhang38fb1192016-08-11 11:03:38 -0700155 '''
chengchiyu08303a02016-09-08 17:40:26 -0700156 main.log.debug( "TOTAL WRONG: " + str( main.wrong ) )
157 for d in ofPack[ switchStatus ]:
158 main.log.info( "Clean up Tshark" )
159 with open( main.tsharkResultPath[ switchStatus ][ d ], "w" ) as tshark:
160 tshark.write( "" )
161 # use one tshark to grep everything
162 # Get the grep string
163 grepString = ''
164 keyTerm = {}
165 for d in ofPack[ switchStatus ]:
166 grepString = grepString + ofPack[ switchStatus ][ d ] + '|'
167 # get rid of regular experssion format
168 cleanTerm = ofPack[ switchStatus ][ d ].replace( '\\', '' )
169 keyTerm[ cleanTerm ] = d
170 # Delete the last '|'
171 grepString = grepString[:-1]
172 # open tshark
173 main.log.info( "starting tshark capture" )
174 main.ONOSbench.tsharkGrep( grepString, main.tsharkResultPath[ switchStatus ][ 'ALL' ], grepOptions='-E' )
YPZhang38fb1192016-08-11 11:03:38 -0700175 if switchStatus == 'up':
176 # if up, assign switch to controller
chengchiyu08303a02016-09-08 17:40:26 -0700177 time.sleep( main.measurementSleep )
178 main.log.info( 'Assigning {} to controller'.format( deviceName ))
Devin Lim142b5342017-07-20 15:22:39 -0700179 main.Mininet1.assignSwController( sw=deviceName, ip=main.Cluster.active( 0 ).ipAddress )
chengchiyu08303a02016-09-08 17:40:26 -0700180 time.sleep( main.measurementSleep )
YPZhang38fb1192016-08-11 11:03:38 -0700181 if switchStatus == 'down':
182 # if down, remove switch from topology
chengchiyu08303a02016-09-08 17:40:26 -0700183 time.sleep( main.measurementSleep )
184 main.step( 'Remove switch from controler' )
185 main.Mininet1.deleteSwController( deviceName )
186 time.sleep( main.deleteSwSleep )
YPZhang38fb1192016-08-11 11:03:38 -0700187 main.log.info( "Stopping all Tshark processes" )
188 main.ONOSbench.tsharkStop()
YPZhang38fb1192016-08-11 11:03:38 -0700189 tempResultDict = {}
chengchiyu08303a02016-09-08 17:40:26 -0700190 arrangeTsharkFile( switchStatus, keyTerm )
191
YPZhang38fb1192016-08-11 11:03:38 -0700192 if switchStatus == 'up':
chengchiyu08303a02016-09-08 17:40:26 -0700193 for d in main.tsharkResultPath[ 'up' ]:
194 with open( main.tsharkResultPath[ switchStatus ][ d ], "r" ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700195 # grep tshark result timestamp
196 resultText = resultFile.readlines()
You Wang5b811272017-08-04 17:22:18 -0700197 if not resultText:
198 main.log.warn( "Empty tshark result!" )
199 main.wrong[ 'TsharkValueIncorrect' ] += 1
200 main.wrong[ 'totalWrong' ] += 1
201 checkTotalWrongNum()
202 return
YPZhang21adb602016-08-18 16:00:11 -0700203 if d == "TCP":
204 # if TCP package, we should use the latest one package
chengchiyu08303a02016-09-08 17:40:26 -0700205 resultText = resultText[ len( resultText ) - 1 ]
YPZhang21adb602016-08-18 16:00:11 -0700206 else:
chengchiyu08303a02016-09-08 17:40:26 -0700207 resultText = resultText[ 0 ]
208 main.log.info( "Capture result:" + resultText )
YPZhang38fb1192016-08-11 11:03:38 -0700209 resultText = resultText.strip()
210 resultText = resultText.split( " " )
211 if len(resultText) > 1:
chengchiyu08303a02016-09-08 17:40:26 -0700212 tempResultDict[d]= int( ( float( resultText[ 1 ] ) * 1000 ) )
YPZhang38fb1192016-08-11 11:03:38 -0700213 resultFile.close()
214 elif switchStatus == 'down':
215 # if state is down, we should capture Fin/Ack and ACK package
216 # Use seq number in FIN/ACK package to located ACK package
chengchiyu08303a02016-09-08 17:40:26 -0700217 with open( main.tsharkResultPath[ 'down' ][ 'FA' ], 'r' ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700218 resultText = resultFile.readlines()
chengchiyu08303a02016-09-08 17:40:26 -0700219 FinAckText = resultText.pop( 0 )
YPZhang38fb1192016-08-11 11:03:38 -0700220 resultFile.close()
chengchiyu08303a02016-09-08 17:40:26 -0700221 FinAckSeq = processPackage( FinAckText )[ 'Seq' ]
222 FinAckOFseq = findSeqBySeqAck( FinAckSeq, resultText )
You Wang18477602017-02-24 15:48:01 -0800223 if FinAckOFseq == None:
224 main.log.warn( "Tshark Result was incorrect!" )
225 main.log.warn( resultText )
226 main.wrong[ 'TsharkValueIncorrect' ] += 1
227 main.wrong[ 'totalWrong' ] += 1
228 checkTotalWrongNum()
229 return
chengchiyu08303a02016-09-08 17:40:26 -0700230 with open( main.tsharkResultPath[ 'down' ][ 'ACK' ], "r" ) as resultFile:
YPZhang38fb1192016-08-11 11:03:38 -0700231 ACKlines = resultFile.readlines()
232 resultFile.close()
YPZhang3943fbe2016-08-18 14:33:29 -0700233 AckPackage = ""
YPZhang38fb1192016-08-11 11:03:38 -0700234 for l in ACKlines:
chengchiyu08303a02016-09-08 17:40:26 -0700235 temp = processPackage( l )
236 finSeq = findSeqBySeqAck( FinAckOFseq, ACKlines )
237 if temp[ 'Seq' ] == finSeq:
YPZhang38fb1192016-08-11 11:03:38 -0700238 AckPackage = l
chengchiyu08303a02016-09-08 17:40:26 -0700239 if len( AckPackage ) > 0:
YPZhang3943fbe2016-08-18 14:33:29 -0700240 FinAckText = FinAckText.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700241 FinAckText = FinAckText.split( " " )
YPZhang3943fbe2016-08-18 14:33:29 -0700242 AckPackage = AckPackage.strip()
chengchiyu08303a02016-09-08 17:40:26 -0700243 AckPackage = AckPackage.split( " " )
244 tempResultDict[ 'ACK' ] = int( float( AckPackage[ 1 ] ) * 1000 )
245 tempResultDict[ 'FA' ] = int( float( FinAckText[ 1 ] ) * 1000 )
YPZhang3943fbe2016-08-18 14:33:29 -0700246 else:
chengchiyu08303a02016-09-08 17:40:26 -0700247 main.wrong[ 'skipDown' ] += 1
248 main.wrong[ 'totalWrong' ] += 1
249 checkTotalWrongNum()
YPZhang3943fbe2016-08-18 14:33:29 -0700250 return
chengchiyu08303a02016-09-08 17:40:26 -0700251
YPZhang38fb1192016-08-11 11:03:38 -0700252 # calculate latency
253 if switchStatus == "up":
254 # up Latency
chengchiyu08303a02016-09-08 17:40:26 -0700255 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700256 T_Ftemp = 0
257 F_Rtemp = 0
258 RQ_RRtemp = 0
259 try:
chengchiyu08303a02016-09-08 17:40:26 -0700260 T_Ftemp = tempResultDict[ 'Feature' ] - tempResultDict[ 'TCP' ]
261 F_Rtemp = tempResultDict[ 'RQ' ] - tempResultDict[ 'Feature' ]
262 RQ_RRtemp = tempResultDict[ 'RR' ] - tempResultDict[ 'RQ' ]
YPZhang38fb1192016-08-11 11:03:38 -0700263 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700264 main.log.warn( "Tshark Result was incorrect!" )
265 main.log.warn( tempResultDict )
266 main.wrong[ 'TsharkValueIncorrect' ] += 1
267 main.wrong[ 'totalWrong' ] += 1
268 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700269 return
270 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700271 resultDict[ switchStatus ][ d ][ 'T_F' ].append( T_Ftemp )
272 resultDict[ switchStatus ][ d ][ 'F_R' ].append( F_Rtemp )
273 resultDict[ switchStatus ][ d ][ 'RQ_RR' ].append( RQ_RRtemp )
YPZhang38fb1192016-08-11 11:03:38 -0700274
chengchiyu08303a02016-09-08 17:40:26 -0700275 main.log.info( "{} TCP to Feature: {}".format( d, str( T_Ftemp ) ) )
276 main.log.info( "{} Feature to Role Request: {}".format( d, str( F_Rtemp ) ) )
277 main.log.info( "{} Role Request to Role Reply: {}".format( d, str( RQ_RRtemp ) ) )
YPZhang38fb1192016-08-11 11:03:38 -0700278
Devin Lim142b5342017-07-20 15:22:39 -0700279 for i in range( 1, main.Cluster.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700280 RR_Dtemp = 0
281 D_Gtemp = 0
282 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700283 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700284 # get onos metrics timestamps
285 try:
Devin Lim142b5342017-07-20 15:22:39 -0700286 response = json.loads( main.Cluster.active( i - 1 ).CLI.topologyEventsMetrics() )
chengchiyu08303a02016-09-08 17:40:26 -0700287 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[switchStatus] )
288 main.log.info( "ONOS{} device Event timestamp: {}".format( i, "%.2f" % DeviceTime ) )
289 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
290 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700291 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700292 main.log.warn( "TypeError" )
293 main.wrong[ 'TypeError' ] += 1
294 main.wrong[ 'totalWrong' ] += 1
295 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700296 break
297 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700298 main.log.warn( "Error to decode Json object!" )
299 main.wrong[ 'decodeJasonError' ] += 1
300 main.wrong[ 'totalWrong' ] += 1
301 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700302 break
chengchiyu08303a02016-09-08 17:40:26 -0700303 if DeviceTime != 0:
304 try:
305 RR_Dtemp = DeviceTime - tempResultDict[ 'RR' ]
306 D_Gtemp = GraphTime - DeviceTime
307 E_Etemp = GraphTime - tempResultDict[ 'TCP' ]
308 check = checkResult( RR_Dtemp, D_Gtemp, E_Etemp )
309 if check == 1:
310 main.log.info( "Role reply to Device:{}".format( RR_Dtemp ) )
311 main.log.info( "Device to Graph:{}".format( D_Gtemp ) )
312 main.log.info( "End to End:{}".format( E_Etemp ) )
313 main.log.info( "================================================" )
314 except KeyError:
315 main.log.warn( "Tshark Result was incorrect!" )
316 main.log.warn( tempResultDict )
317 main.wrong[ 'TsharkValueIncorrect' ] += 1
318 main.wrong[ 'totalWrong' ] += 1
319 checkTotalWrongNum()
320 return
321 except TypeError:
322 main.log.warn( "TypeError" )
323 main.wrong[ 'TypeError' ] += 1
324 main.wrong[ 'totalWrong' ] += 1
325 checkTotalWrongNum()
326 break
327 except ValueError:
328 main.log.warn( "Error to decode Json object!" )
329 main.wrong[ 'decodeJasonError' ] += 1
330 main.wrong[ 'totalWrong' ] += 1
331 checkTotalWrongNum()
332 break
333 if not warmup and check == 1:
334 resultDict[ switchStatus ][ 'node' + str( i )][ 'RR_D' ].append( RR_Dtemp )
335 resultDict[ switchStatus ][ 'node' + str( i )][ 'D_G' ].append( D_Gtemp )
336 resultDict[ switchStatus ][ 'node' + str( i )][ 'E_E' ].append( E_Etemp )
337 else:
338 main.wrong['checkResultIncorrect'] += 1
339 main.wrong[ 'totalWrong' ] += 1
340 checkTotalWrongNum()
341 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700342
343 if switchStatus == "down":
344 # down Latency
chengchiyu08303a02016-09-08 17:40:26 -0700345 for d in resultDict[ switchStatus ]:
YPZhang38fb1192016-08-11 11:03:38 -0700346 FA_Atemp = 0
347 try:
chengchiyu08303a02016-09-08 17:40:26 -0700348 FA_Atemp = tempResultDict[ 'ACK' ] - tempResultDict[ 'FA' ]
YPZhang38fb1192016-08-11 11:03:38 -0700349 except KeyError:
chengchiyu08303a02016-09-08 17:40:26 -0700350 main.log.warn( "Tshark Result was incorrect!" )
351 main.log.warn( tempResultDict )
352 main.wrong[ 'TsharkValueIncorrect' ] += 1
353 main.wrong[ 'totalWrong' ] += 1
354 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700355 return
356 if not warmup:
chengchiyu08303a02016-09-08 17:40:26 -0700357 resultDict[ switchStatus ][ d ][ 'FA_A' ].append( FA_Atemp )
358 main.log.info( "{} FIN/ACK TO ACK {}:".format( d, FA_Atemp ) )
Devin Lim142b5342017-07-20 15:22:39 -0700359 for i in range( 1, main.Cluster.numCtrls + 1 ):
YPZhang38fb1192016-08-11 11:03:38 -0700360 A_Dtemp = 0
361 D_Gtemp = 0
362 E_Etemp = 0
chengchiyu08303a02016-09-08 17:40:26 -0700363 main.log.info( "================================================" )
YPZhang38fb1192016-08-11 11:03:38 -0700364 # get onos metrics timestamps
365 try:
Devin Lim142b5342017-07-20 15:22:39 -0700366 response = json.loads( main.Cluster.active( i - 1 ).CLI.topologyEventsMetrics() )
367 DeviceTime = getTimestampFromLog( i - 1, searchTerm=main.searchTerm[ switchStatus ] )
chengchiyu08303a02016-09-08 17:40:26 -0700368 main.log.info( "ONOS{} device Event timestamp: {}".format( i, DeviceTime ) )
369 GraphTime = int( response.get( "topologyGraphEventTimestamp" ).get( "value" ) )
370 main.log.info( "ONOS{} Graph Event timestamp: {}".format( i, GraphTime ) )
YPZhang38fb1192016-08-11 11:03:38 -0700371 except TypeError:
chengchiyu08303a02016-09-08 17:40:26 -0700372 main.log.warn( "TypeError" )
373 main.wrong[ 'TypeError' ] += 1
374 main.wrong[ 'totalWrong' ] += 1
375 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700376 break
377 except ValueError:
chengchiyu08303a02016-09-08 17:40:26 -0700378 main.log.warn( "Error to decode Json object!" )
379 main.wrong[ 'decodeJasonError' ] += 1
380 main.wrong[ 'totalWrong' ] += 1
381 checkTotalWrongNum()
YPZhang38fb1192016-08-11 11:03:38 -0700382 break
chengchiyu08303a02016-09-08 17:40:26 -0700383 if DeviceTime != 0:
384 main.log.info( "================================================" )
385 try:
386 A_Dtemp = DeviceTime - tempResultDict[ 'ACK' ]
387 D_Gtemp = GraphTime - DeviceTime
388 E_Etemp = GraphTime - tempResultDict[ 'FA' ]
389 check = checkResult( A_Dtemp, D_Gtemp, E_Etemp )
390 if check == 1:
391 main.log.info( "ACK to device: {}".format( A_Dtemp ) )
You Wang0e4ca9e2017-08-04 16:40:33 -0700392 main.log.info( "Device to Graph: {}".format( D_Gtemp ) )
chengchiyu08303a02016-09-08 17:40:26 -0700393 main.log.info( "End to End: {}".format( E_Etemp ) )
394 main.log.info( "================================================" )
395 except KeyError:
396 main.log.warn( "Tshark Result was incorrect!" )
397 main.log.warn( tempResultDict )
398 main.wrong[ 'TsharkValueIncorrect' ] += 1
399 main.wrong[ 'totalWrong' ] += 1
400 checkTotalWrongNum()
401 return
402 except TypeError:
403 main.log.warn( "TypeError" )
404 main.wrong[ 'TypeError' ] += 1
405 main.wrong[ 'totalWrong' ] += 1
406 checkTotalWrongNum()
407 break
408 except ValueError:
409 main.log.warn( "Error to decode Json object!" )
410 main.wrong[ 'decodeJasonError' ] += 1
411 main.wrong[ 'totalWrong' ] += 1
412 checkTotalWrongNum()
413 break
414 if not warmup and check == 1:
415 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'A_D' ].append( A_Dtemp )
416 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'D_G' ].append( D_Gtemp )
417 resultDict[ switchStatus ][ 'node' + str( i ) ][ 'E_E' ].append( E_Etemp )
418
419 else:
420 main.wrong['checkResultIncorrect'] += 1
421 main.wrong['totalWrong'] += 1
422 checkTotalWrongNum()
423 main.log.debug("Skip this iteration due to the None Devicetime")
YPZhang38fb1192016-08-11 11:03:38 -0700424