Performance/scripts/cmsTiming_parser.py

0001 #! /usr/bin/env python3
0002
0003 from __future__ import print_function
0004 from builtins import range
0005 import sys, os
0006 import time
0007 import optparse
0008 from math import sqrt, log10, floor
0009
0010 import ROOT
0011
0012 def manipulate_log(outdir, logfile_name, secsperbin):
0013     """ Parses logfile_name and create an html report
0014         with information and plots, at the outdir path.
0015         Graphs' production is also done here.
0016     """
0017     ################################
0018     #### Parse of the log file. ####
0019     ################################
0020     logfile = open(logfile_name,'r')
0021     logfile_lines = iter(logfile.readlines())
0022     logfile.close()
0023     data = {}
0024     report = ''
0025     for line in logfile_lines:
0026         # Retrieve cpu time of every event.
0027         if 'TimeEvent>' in line:
0028             line = line[:-1] #no \n!
0029             content = line.split(' ')
0030             event =  int(content[1])
0031             seconds = float(content[3])
0032             data[event] = seconds
0033         # Fill the time report.
0034         elif 'TimeReport' in line:
0035             if '[sec]' in line:
0036                 report += line.replace('TimeReport', '\n')
0037             elif 'headings' in line:
0038                 continue
0039             elif 'complete' in line:
0040                 report += line.replace('TimeReport', '\n')
0041                 for count in range(12):
0042                     line = next(logfile_lines)
0043                     report += line
0044                 break
0045             else:
0046                 report += line.replace('TimeReport', '')
0047
0048     ##############################
0049     #### Graph and Histogram  ####
0050     ##############################
0051     __argv = sys.argv # trick for a strange behaviour of the TApp..
0052     sys.argv = sys.argv[:1]
0053     ROOT.gROOT.SetStyle("Plain") # style paranoia
0054     sys.argv = __argv
0055     #Cannot use this option when the logfile includes
0056     #a large number of events... PyRoot seg-faults.
0057     #Set ROOT in batch mode to avoid canvases popping up!
0058     ROOT.gROOT.SetBatch(1)
0059
0060     # Save in file
0061     rootfilename = '%s/graphs.root' %outdir
0062     myfile = ROOT.TFile(rootfilename,'RECREATE')
0063
0064     # Set limits
0065     min_val = data[min(data, key=data.get)]
0066     max_val = data[max(data, key=data.get)]
0067     interval = max_val-min_val
0068     min_val = min_val - (interval*0.2)
0069     max_val = max_val + (interval*0.2)
0070     interval = max_val - min_val
0071     nbins = int(interval/secsperbin)
0072
0073     # Initialize Histogram
0074     histo = ROOT.TH1F('Seconds per event','Seconds per event', nbins, min_val, max_val)
0075     histo.GetXaxis().SetTitle("s")
0076     # Initialize Graph
0077     npoints = len(data)
0078     graph = ROOT.TGraph(npoints)
0079     graph.SetMarkerStyle(8)
0080     graph.SetMarkerSize(.7)
0081     graph.SetMarkerColor(1)
0082     graph.SetLineWidth(3)
0083     graph.SetLineColor(2)
0084     graph.SetTitle('Seconds per event')
0085     graph.SetName('SecondsPerEvent')
0086     graph.GetXaxis().SetTitle("Event")
0087     last_event = max(data)
0088     graph.GetXaxis().SetLimits(0, last_event)
0089     graph.GetYaxis().SetTitleOffset(1.3)
0090     graph.GetYaxis().SetTitle("s")
0091     graph.GetYaxis().SetRangeUser(0, max_val)
0092     # Fill them
0093     total_time = 0
0094     for event_num in data.keys():
0095         seconds = data[event_num]
0096         graph.SetPoint(event_num-1, event_num, seconds)
0097         histo.Fill(seconds)
0098         total_time += seconds
0099     # A line which represents the average is drawn in the TGraph
0100     avg = histo.GetMean()
0101     avg_line = ROOT.TLine(1,avg,last_event, avg)
0102     avg_line.SetLineColor(4)
0103     avg_line.SetLineWidth(2)
0104     # Draw and save!
0105     graph_canvas = ROOT.TCanvas('graph_canvas')
0106     graph_canvas.cd()
0107     graph.Draw("ALP")
0108     avg_line.Draw("Same")
0109
0110
0111     # Write graph to file
0112     graph_canvas.Print("%s/graph.png" %outdir,"png")
0113     graph.Write()
0114     graph_canvas.Write()
0115     histo_canvas = ROOT.TCanvas('histo_canvas')
0116     histo_canvas.cd()
0117     histo.Draw('')
0118
0119     # Write histogram to file
0120     histo_canvas.Print("%s/histo.png" %outdir,"png")
0121     histo.Write()
0122     histo_canvas.Write()
0123
0124     myfile.Close()
0125
0126     ########################
0127     #### The html page! ####
0128     ########################
0129     titlestring = '<b>Report executed with release %s on %s.</b>\n<br>\n<hr>\n'\
0130                                    %(os.environ['CMSSW_VERSION'], time.asctime())
0131     html_file_name = '%s/%s_TimingReport.html' %(outdir, logfile_name[:-4])
0132     html_file = open(html_file_name,'w')
0133     html_file.write('<html>\n<body>\n'+\
0134                     titlestring)
0135     html_file.write('<table>\n'+\
0136                     '<tr>\n<td><img  src=graph.png></img></td>\n'+\
0137                     '<td><img  src=histo.png></img></td>\n</tr>\n'+\
0138                     '</table>\n')
0139     html_file.write('<hr>\n<h2>Time Report</h2>\n<pre>\n' + report + '</pre>\n')
0140     html_file.write('</body>\n</html>')
0141     html_file.close()
0142
0143     ##########################
0144     #### Print statistics ####
0145     ##########################
0146     total_events = max(data)
0147     average_time = total_time / total_events
0148     sum = 0.
0149     for i in range(1, max(data)+1):
0150         sum += (data[i]-average_time)**2
0151     denominator = total_events**2 - total_events
0152     uncertainty = sqrt(sum/denominator)
0153     # Comment out next 2 line to round uncertainty to the most significant digit
0154     #rounded_uncertainty=round(uncertainty, -int(floor(log10(uncertainty))))
0155     #print 'Rounded uncertainty=' , rounded_uncertainty
0156     print('------ Statistics ------')
0157     print('last event = {}'.format(last_event))
0158     print('Minval = {} maxval = {} interval = {}'.format(min_val, max_val, interval))
0159     print('Total Time = {}'.format(total_time))
0160     print('Average Time = {}'.format(average_time))
0161     print('Uncertainty of Average Time = {} +/- {}'.format(average_time, uncertainty))
0162
0163 #################################################################################################
0164
0165 if __name__ == '__main__':
0166
0167     # Here we define an option parser to handle commandline options..
0168     usage = 'timing_parser.py <options>'
0169     parser = optparse.OptionParser(usage)
0170     parser.add_option('-i', '--in_  profile',
0171                       help='The profile to manipulate' ,
0172                       default='',
0173                       dest='profile')
0174
0175     parser.add_option('-o', '--outdir',
0176                       help='The directory of the output' ,
0177                       default='',
0178                       dest='outdir')
0179
0180     parser.add_option('-n',
0181                       help='Number of secs per bin. Default is 1.' ,
0182                       default='1',
0183                       dest='startevt')
0184     (options,args) = parser.parse_args()
0185
0186     # Now some fault control..If an error is found we raise an exception
0187     if options.profile == '' or\
0188        options.outdir == '':
0189         raise Exception('Please select a profile and an output dir!')
0190
0191     if not os.path.exists(options.profile) or\
0192        not os.path.exists(options.outdir):
0193         raise Exception('Outdir or input profile not present!')
0194
0195     try:
0196         startevt = float(options.startevt)
0197     except ValueError:
0198          print('Problems in convertng starting event value!')
0199
0200     # launch the function!
0201     manipulate_log(options.outdir,options.profile,startevt)