blob: 79f7c7fb92f5154e0a1e1158c7ccd898f05a0743 [file] [log] [blame]
adminbae64d82013-08-01 10:50:15 -07001#/usr/bin/env python
2'''
3Created on 07-Jan-2013
Jeremy Songsterae01bba2016-07-11 15:39:17 -07004Modified 2015 by ON.Lab
Jon Hall81d3d392015-04-24 14:40:35 -07005
Jeremy Songsterae01bba2016-07-11 15:39:17 -07006Please refer questions to either the onos test mailing list at <onos-test@onosproject.org>,
7the System Testing Plans and Results wiki page at <https://wiki.onosproject.org/x/voMg>,
8or the System Testing Guide page at <https://wiki.onosproject.org/x/WYQg>
adminbae64d82013-08-01 10:50:15 -07009
10 TestON is free software: you can redistribute it and/or modify
11 it under the terms of the GNU General Public License as published by
12 the Free Software Foundation, either version 2 of the License, or
13 (at your option) any later version.
14
15 TestON is distributed in the hope that it will be useful,
16 but WITHOUT ANY WARRANTY; without even the implied warranty of
17 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
18 GNU General Public License for more details.
19
20 You should have received a copy of the GNU General Public License
Jon Hall81d3d392015-04-24 14:40:35 -070021 along with TestON. If not, see <http://www.gnu.org/licenses/>.
adminbae64d82013-08-01 10:50:15 -070022
23
24'''
25
26import logging
27import datetime
28import re
29import os
30class Logger:
31 '''
32 Add continuous logs and reports of the test.
Jon Hall81d3d392015-04-24 14:40:35 -070033
adminbae64d82013-08-01 10:50:15 -070034 @author: Raghav Kashyap(raghavkashyap@paxterrasolutions.com)
35 '''
36 def _printHeader(self,main) :
37 '''
38 Log's header will be append to the Log file
39 '''
40 logmsg = "\n"+" " * 32+"+----------------+\n" +"-" * 30+" { Script And Files } "+"-" * 30+"\n" +" " * 32+"+----------------+\n";
41 logmsg = logmsg + "\n\tScript Log File : " + main.LogFileName + ""
42 logmsg = logmsg + "\n\tReport Log File : " + main.ReportFileName + ""
43 for component in main.componentDictionary.keys():
44 logmsg = logmsg + "\n\t"+component+" Session Log : " + main.logdir+"/"+component+".session" + ""
Jon Hall81d3d392015-04-24 14:40:35 -070045
adminbae64d82013-08-01 10:50:15 -070046 logmsg = logmsg + "\n\tTest Script :" + path + "Tests/" + main.TEST + ".py"+ ""
47 logmsg = logmsg + "\n\tTest Params : " + path + "Tests/" + main.TEST + ".params" + ""
Jon Hall368769f2014-11-19 15:43:35 -080048 logmsg = logmsg + "\n\tTopology : " + path + "Tests/" +main.TEST + ".topo" + ""
adminbae64d82013-08-01 10:50:15 -070049 logmsg = logmsg + "\n"+" " * 30+"+" +"-" * 18+"+" +"\n" +"-" * 27+" { Script Exec Params } "+"-" * 27 +"\n" +" " * 30 +"+"+"-" * 18 +"+\n";
50 values = "\n\t" + str(main.params)
51 values = re.sub(",", "\n\t", values)
52 values = re.sub("{", "\n\t", values)
53 values = re.sub("}", "\n\t", values)
54 logmsg = logmsg + values
adminbae64d82013-08-01 10:50:15 -070055 logmsg = logmsg + "\n\n"+" " * 31+"+---------------+\n" +"-" * 29+" { Components Used } " +"-" * 29+"\n"+" " * 31+"+---------------+\n"
56 component_list = []
57 component_list.append(None)
Jon Hall81d3d392015-04-24 14:40:35 -070058
adminbae64d82013-08-01 10:50:15 -070059 # Listing the components in the order of test_target component should be first.
60 if type(main.componentDictionary) == dict:
61 for key in main.componentDictionary.keys():
62 if main.test_target == key :
63 component_list[0] = key+"-Test Target"
64 else :
65 component_list.append(key)
Jon Hall81d3d392015-04-24 14:40:35 -070066
adminbae64d82013-08-01 10:50:15 -070067 for index in range(len(component_list)) :
68 if index==0:
69 if component_list[index]:
70 logmsg+="\t"+component_list[index]+"\n"
71 elif index > 0 :
72 logmsg+="\t"+str(component_list[index])+"\n"
Jon Hall81d3d392015-04-24 14:40:35 -070073
adminbae64d82013-08-01 10:50:15 -070074 logmsg = logmsg + "\n\n"+" " * 30+"+--------+\n" +"-" * 28+" { Topology } "+"-" * 28 +"\n" +" " * 30+"+--------+\n"
75 values = "\n\t" + str(main.topology['COMPONENT'])
76 values = re.sub(",", "\n\t", values)
77 values = re.sub("{", "\n\t", values)
78 values = re.sub("}", "\n\t", values)
79 logmsg = logmsg + values
adminbae64d82013-08-01 10:50:15 -070080 logmsg = logmsg + "\n"+"-" * 60+"\n"
Jon Hall81d3d392015-04-24 14:40:35 -070081
adminbae64d82013-08-01 10:50:15 -070082 # enter into log file all headers
83 logfile = open(main.LogFileName,"w+")
84 logfile.write (logmsg)
85 print logmsg
86 main.logHeader = logmsg
adminbae64d82013-08-01 10:50:15 -070087 logfile.close()
Jon Hall81d3d392015-04-24 14:40:35 -070088
adminbae64d82013-08-01 10:50:15 -070089 #enter into report file all headers
90 main.reportFile = open(main.ReportFileName,"w+")
91 main.reportFile.write(logmsg)
92 main.reportFile.close()
Jon Hall81d3d392015-04-24 14:40:35 -070093
Jon Hall79bec222015-04-30 16:23:30 -070094 #Sumamry file header
95 currentTime = str( main.STARTTIME.strftime("%d %b %Y %H:%M:%S") )
96 main.summaryFile = open( main.SummaryFileName, "w+" )
97 main.summaryFile.write( main.TEST + " at " + currentTime + "\n" )
98 main.summaryFile.close()
99
Jon Hall81d3d392015-04-24 14:40:35 -0700100 #wiki file header
101 currentTime = str( main.STARTTIME.strftime("%d %b %Y %H:%M:%S") )
102 main.wikiFile = open( main.WikiFileName, "w+" )
Jon Hall79bec222015-04-30 16:23:30 -0700103 main.wikiFile.write( main.TEST + " at " + currentTime + "<p></p>\n" )
Jon Hall81d3d392015-04-24 14:40:35 -0700104 main.wikiFile.close()
105
adminbae64d82013-08-01 10:50:15 -0700106 def initlog(self,main):
107 '''
108 Initialise all the log handles.
109 '''
110 main._getTest()
Jon Hall81d3d392015-04-24 14:40:35 -0700111 main.STARTTIME = datetime.datetime.now()
adminbae64d82013-08-01 10:50:15 -0700112
113 currentTime = re.sub("-|\s|:|\.", "_", str(main.STARTTIME.strftime("%d %b %Y %H:%M:%S")))
114 if main.logdir:
115 main.logdir = main.logdir+ "/"+main.TEST + "_" + currentTime
116 else:
117 main.logdir = main.logs_path + main.TEST + "_" + currentTime
Jon Hall81d3d392015-04-24 14:40:35 -0700118
adminbae64d82013-08-01 10:50:15 -0700119 os.mkdir(main.logdir)
Jon Hall81d3d392015-04-24 14:40:35 -0700120
adminbae64d82013-08-01 10:50:15 -0700121 main.LogFileName = main.logdir + "/" + main.TEST + "_" +str(currentTime) + ".log"
122 main.ReportFileName = main.logdir + "/" + main.TEST + "_" + str(currentTime) + ".rpt"
Jon Hall79bec222015-04-30 16:23:30 -0700123 main.WikiFileName = main.logdir + "/" + main.TEST + "Wiki.txt"
124 main.SummaryFileName = main.logdir + "/" + main.TEST + "Summary.txt"
Jon Hall94fd0472014-12-08 11:52:42 -0800125 main.JenkinsCSV = main.logdir + "/" + main.TEST + ".csv"
Jon Hall25079782015-10-13 13:54:39 -0700126 main.TOTAL_TC_SUCCESS = 0
Jon Hall81d3d392015-04-24 14:40:35 -0700127
adminbae64d82013-08-01 10:50:15 -0700128 #### Add log-level - Report
129 logging.addLevelName(9, "REPORT")
130 logging.addLevelName(7, "EXACT")
Jon Hall0bde9ba2015-03-19 11:32:57 -0700131 logging.addLevelName(11, "CASE")
132 logging.addLevelName(12, "STEP")
adminbae64d82013-08-01 10:50:15 -0700133 main.log = logging.getLogger(main.TEST)
Jon Hall81d3d392015-04-24 14:40:35 -0700134 def report(msg):
adminbae64d82013-08-01 10:50:15 -0700135 '''
136 Will append the report message to the logs.
137 '''
138 main.log._log(9,msg,"OpenFlowAutoMattion","OFAutoMation")
139 currentTime = datetime.datetime.now()
140 currentTime = currentTime.strftime("%d %b %Y %H:%M:%S")
141 newmsg = "\n[REPORT] " +"["+ str(currentTime)+"] "+msg
142 print newmsg
143 main.reportFile = open(main.ReportFileName,"a+")
144 main.reportFile.write(newmsg)
145 main.reportFile.close()
Jon Hall81d3d392015-04-24 14:40:35 -0700146
147 main.log.report = report
148
Jon Hall79bec222015-04-30 16:23:30 -0700149 def summary( msg ):
150 '''
151 Will append the message to the txt file for the summary.
152 '''
153 main.log._log(6,msg,"OpenFlowAutoMattion","OFAutoMation")
154 main.summaryFile = open(main.SummaryFileName,"a+")
155 main.summaryFile.write(msg+"\n")
156 main.summaryFile.close()
157
158 main.log.summary = summary
159
Jon Hall81d3d392015-04-24 14:40:35 -0700160 def wiki( msg ):
161 '''
162 Will append the message to the txt file for the wiki.
163 '''
164 main.log._log(6,msg,"OpenFlowAutoMattion","OFAutoMation")
165 main.wikiFile = open(main.WikiFileName,"a+")
166 main.wikiFile.write(msg+"\n")
167 main.wikiFile.close()
168
169 main.log.wiki = wiki
170
171 def exact(exmsg):
adminbae64d82013-08-01 10:50:15 -0700172 '''
173 Will append the raw formatted message to the logs
174 '''
175 main.log._log(7,exmsg,"OpenFlowAutoMattion","OFAutoMation")
176 main.reportFile = open(main.ReportFileName,"a+")
177 main.reportFile.write(exmsg)
178 main.reportFile.close()
179 logfile = open(main.LogFileName,"a")
180 logfile.write("\n"+ str(exmsg) +"\n")
181 logfile.close()
182 print exmsg
Jon Hall81d3d392015-04-24 14:40:35 -0700183
184 main.log.exact = exact
185
adminbae64d82013-08-01 10:50:15 -0700186 def case(msg):
187 '''
188 Format of the case type log defined here.
189 '''
190 main.log._log(9,msg,"OpenFlowAutoMattion","OFAutoMation")
191 currentTime = datetime.datetime.now()
192 newmsg = "["+str(currentTime)+"] " + "["+main.TEST+"] " + "[CASE] " +msg
193 logfile = open(main.LogFileName,"a")
194 logfile.write("\n"+ str(newmsg) +"\n")
195 logfile.close()
196 print newmsg
Jon Hall81d3d392015-04-24 14:40:35 -0700197
Jon Hall4ba53f02015-07-29 13:07:41 -0700198 main.log.case = case
Jon Hall81d3d392015-04-24 14:40:35 -0700199
200 def step(msg):
adminbae64d82013-08-01 10:50:15 -0700201 '''
202 Format of the step type log defined here.
203 '''
204 main.log._log(9,msg,"OpenFlowAutoMattion","OFAutoMation")
205 currentTime = datetime.datetime.now()
206 newmsg = "["+str(currentTime)+"] " + "["+main.TEST+"] " + "[STEP] " +msg
207 logfile = open(main.LogFileName,"a")
208 logfile.write("\n"+ str(newmsg) +"\n")
209 logfile.close()
210 print newmsg
Jon Hall81d3d392015-04-24 14:40:35 -0700211
212 main.log.step = step
213
adminbae64d82013-08-01 10:50:15 -0700214 main.LogFileHandler = logging.FileHandler(main.LogFileName)
215 self._printHeader(main)
216
217 ### initializing logging module and settig log level
218 main.log.setLevel(logging.INFO)
Jon Hall0bde9ba2015-03-19 11:32:57 -0700219 main.log.setLevel(logging.DEBUG) # Temporary
adminbae64d82013-08-01 10:50:15 -0700220 main.LogFileHandler.setLevel(logging.INFO)
Jon Hall81d3d392015-04-24 14:40:35 -0700221
adminbae64d82013-08-01 10:50:15 -0700222 # create console handler with a higher log level
223 main.ConsoleHandler = logging.StreamHandler()
224 main.ConsoleHandler.setLevel(logging.INFO)
Jon Hall0bde9ba2015-03-19 11:32:57 -0700225 main.ConsoleHandler.setLevel(logging.DEBUG) #Temporary
adminbae64d82013-08-01 10:50:15 -0700226 # create formatter and add it to the handlers
Jon Hall0bde9ba2015-03-19 11:32:57 -0700227 #formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
228 class MyFormatter( logging.Formatter ):
229 colors = { 'cyan': '\033[96m', 'purple': '\033[95m',
230 'blue': '\033[94m', 'green': '\033[92m',
231 'yellow': '\033[93m', 'red': '\033[91m',
232 'end': '\033[0m' }
233
234 FORMATS = {'DEFAULT': '%(asctime)s - %(name)s - %(levelname)s - %(message)s'}
235 if COLORS: # NOTE:colors will only be loaded if command is run from one line
236 # IE: './cli.py run testname'
237 # This is to prevent issues with Jenkins parsing
238 # TODO: Make colors configurable
239 levels = { logging.ERROR : colors['red'] +
240 FORMATS['DEFAULT'] +
241 colors['end'],
242 logging.WARN : colors['yellow'] +
243 FORMATS['DEFAULT'] +
244 colors['end'],
245 logging.DEBUG : colors['purple'] +
246 FORMATS['DEFAULT'] +
247 colors['end'] }
248 FORMATS.update( levels )
249
250 def format( self, record ):
251 self._fmt = self.FORMATS.get( record.levelno,
252 self.FORMATS[ 'DEFAULT' ] )
253 return logging.Formatter.format( self, record )
254 formatter = MyFormatter()
adminbae64d82013-08-01 10:50:15 -0700255 main.ConsoleHandler.setFormatter(formatter)
256 main.LogFileHandler.setFormatter(formatter)
257
258 # add the handlers to logger
259 main.log.addHandler(main.ConsoleHandler)
260 main.log.addHandler(main.LogFileHandler)
Jon Hall81d3d392015-04-24 14:40:35 -0700261
adminbae64d82013-08-01 10:50:15 -0700262 def testSummary(self,main):
263 '''
264 testSummary will take care about the Summary of test.
265 '''
266
267 main.ENDTIME = datetime.datetime.now()
268 main.EXECTIME = main.ENDTIME - main.STARTTIME
269 if (main.TOTAL_TC_PASS == 0):
270 main.TOTAL_TC_SUCCESS = 0
271 else:
272 main.TOTAL_TC_SUCCESS = str((main.TOTAL_TC_PASS*100)/main.TOTAL_TC_RUN)
adminbae64d82013-08-01 10:50:15 -0700273 if (main.TOTAL_TC_RUN == 0) :
274 main.TOTAL_TC_EXECPERCENT = 0
275 else :
276 main.TOTAL_TC_EXECPERCENT = str((main.TOTAL_TC_RUN*100)/main.TOTAL_TC_PLANNED)
adminbae64d82013-08-01 10:50:15 -0700277 testResult = "\n\n"+"*" * 37+"\n" + "\tTest Execution Summary\n" + "\n"+"*" * 37+" \n"
278 testResult = testResult + "\n Test Start : " + str(main.STARTTIME.strftime("%d %b %Y %H:%M:%S"))
279 testResult = testResult + "\n Test End : " + str(main.ENDTIME.strftime("%d %b %Y %H:%M:%S"))
280 testResult = testResult + "\n Execution Time : " + str(main.EXECTIME)
281 testResult = testResult + "\n Total tests planned : " + str(main.TOTAL_TC_PLANNED)
282 testResult = testResult + "\n Total tests RUN : " + str(main.TOTAL_TC_RUN)
283 testResult = testResult + "\n Total Pass : " + str(main.TOTAL_TC_PASS)
284 testResult = testResult + "\n Total Fail : " + str(main.TOTAL_TC_FAIL)
285 testResult = testResult + "\n Total No Result : " + str(main.TOTAL_TC_NORESULT)
286 testResult = testResult + "\n Success Percentage : " + str(main.TOTAL_TC_SUCCESS) + "%"
287 testResult = testResult + "\n Execution Result : " + str(main.TOTAL_TC_EXECPERCENT) + "%"
Jon Hall81d3d392015-04-24 14:40:35 -0700288
adminbae64d82013-08-01 10:50:15 -0700289 #main.log.report(testResult)
290 main.testResult = testResult
291 main.log.exact(testResult)
Jon Hall94fd0472014-12-08 11:52:42 -0800292
Jon Hall368769f2014-11-19 15:43:35 -0800293 ##CSV output needed for Jenkin's plot plugin
294 #NOTE: the elements were orded based on the colors assigned to the data
295 logfile = open(main.JenkinsCSV ,"w")
296 logfile.write(",".join( ['Tests Failed', 'Tests Passed', 'Tests Planned'] ) + "\n")
Jon Hall94fd0472014-12-08 11:52:42 -0800297 logfile.write(",".join( [str(int(main.TOTAL_TC_FAIL)), str(int(main.TOTAL_TC_PASS)), str(int(main.TOTAL_TC_PLANNED))] ))
298 logfile.close()
299
adminbae64d82013-08-01 10:50:15 -0700300 def updateCaseResults(self,main):
301 '''
302 Update the case result based on the steps execution and asserting each step in the test-case
303 '''
304 case = str(main.CurrentTestCaseNumber)
Jon Hall79bec222015-04-30 16:23:30 -0700305 currentResult = main.testCaseResult.get(case, 2)
Jon Hall81d3d392015-04-24 14:40:35 -0700306
Jon Hall79bec222015-04-30 16:23:30 -0700307 if currentResult == 2:
adminbae64d82013-08-01 10:50:15 -0700308 main.TOTAL_TC_RUN = main.TOTAL_TC_RUN + 1
309 main.TOTAL_TC_NORESULT = main.TOTAL_TC_NORESULT + 1
310 main.log.exact("\n "+"*" * 29+"\n" + "\n Result: No Assertion Called \n"+"*" * 29+"\n")
Jon Hall79bec222015-04-30 16:23:30 -0700311 line = "Case "+case+": "+main.CurrentTestCase+" - No Result"
312 elif currentResult == 1:
adminbae64d82013-08-01 10:50:15 -0700313 main.TOTAL_TC_RUN = main.TOTAL_TC_RUN + 1
314 main.TOTAL_TC_PASS = main.TOTAL_TC_PASS + 1
315 main.log.exact("\n"+"*" * 29+"\n Result: Pass \n"+"*" * 29+"\n")
Jon Hall79bec222015-04-30 16:23:30 -0700316 line = "Case "+case+": "+main.CurrentTestCase+" - PASS"
317 elif currentResult == 0:
adminbae64d82013-08-01 10:50:15 -0700318 main.TOTAL_TC_RUN = main.TOTAL_TC_RUN + 1
319 main.TOTAL_TC_FAIL = main.TOTAL_TC_FAIL + 1
320 main.log.exact("\n"+"*" * 29+"\n Result: Failed \n"+"*" * 29+"\n")
Jon Hall79bec222015-04-30 16:23:30 -0700321 line = "Case "+case+": "+main.CurrentTestCase+" - FAIL"
322 else:
323 main.log.error( " Unknown result of case " + case +
324 ". Result was: " + currentResult )
325 line = "Case "+case+": "+main.CurrentTestCase+" - ERROR"
326 main.log.wiki( "<h3>" + line + "</h3>" )
327 main.log.summary( line )
Jon Hall81d3d392015-04-24 14:40:35 -0700328