test
CMS 3D CMS Logo

 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Properties Friends Macros Pages
cmsPerfRegress.py
Go to the documentation of this file.
1 #!/usr/bin/env python
2 
3 import time, os, sys, math, re, gzip
4 import tempfile as tmp
5 import optparse as opt
6 from cmsPerfCommons import CandFname
7 #from ROOT import gROOT, TCanvas, TF1
8 import ROOT
9 from array import array
10 #Substitute popen with subprocess.Popen! popen obsolete...
11 import subprocess
12 
13 _cmsver = os.environ['CMSSW_VERSION']
14 values_set=('vsize','delta_vsize','rss','delta_rss')
15 
17  """Base class for exceptions in this module."""
18  pass
19 
21  """Exception raised when Could not parse TimingReport Log.
22 
23  Attributes:
24  expression -- input expression in which the error occurred
25  message -- explanation of the error
26  """
27 
28  def __init__(self, message):
29  self.message = message
30 
32  """Exception raised when Could not parse TimingReport Log.
33 
34  Attributes:
35  expression -- input expression in which the error occurred
36  message -- explanation of the error
37  """
38 
39  def __init__(self, message):
40  self.message = message
41 
43  """Exception raised when Could not parse TimingReport Log.
44 
45  Attributes:
46  expression -- input expression in which the error occurred
47  message -- explanation of the error
48  """
49 
50  def __init__(self, message):
51  self.message = message
52 
54  """Exception raised when Could not parse TimingReport Log.
55 
56  Attributes:
57  expression -- input expression in which the error occurred
58  message -- explanation of the error
59  """
60 
61  def __init__(self, message):
62  self.message = message
63 
64 #############
65 # Option parser
66 #
68  parser = opt.OptionParser()
69  #
70  # Options
71  #
72  parser.add_option('-n',
73  type="int",
74  help='Number of secs per bin. Default is 1.' ,
75  default=1,
76  dest='startevt')
77  parser.add_option('-t',
78  '--report-type',
79  type="choice",
80  choices= ("timing", "simplememory","edmsize","igprof","callgrind",""),
81  help='Type of report to perform regrssion on. Default is TimingReport.' ,
82  default="timing",
83  dest='reporttype')
84  parser.add_option('-i',
85  '--IgProfMemOption',
86  type="choice",
87  choices= ("-y MEM_TOTAL", "-y MEM_LIVE",""),
88  help='Eventual IgProfMem counter to use for the regression. Default is no argument (IgProfPerf).' ,
89  default="",
90  dest='igprofmem')
91  (options,args) = parser.parse_args()
92  if len(args) < 2:
93  parser.error("ERROR: Not enough arguments")
94  sys.exit()
95 
96 
97  path1 = os.path.abspath(args[0])
98  path2 = os.path.abspath(args[1])
99  if os.path.exists(path1) and os.path.exists(path2):
100  return (path1, path2, options.startevt, options.reporttype, options.igprofmem)
101  else:
102  print "Error: one of the paths does not exist"
103  sys.exit()
104 
105 ###########
106 # Get max value in data set
107 #
108 def get_max(data,index=1):
109  max_time=-1
110  for el in data:
111  sec=el[index]
112  if max_time<sec:
113  max_time=sec
114  return max_time
115 
116 ###########
117 # Get min value in data set
118 #
119 def get_min(data,index=1):
120  min_time=1e20
121  for el in data:
122  sec=el[index]
123  if min_time>sec:
124  min_time=sec
125  return min_time
126 
127 ###########
128 # Setup PyRoot as a batch run
129 #
130 def setBatch():
131  __argv=sys.argv # trick for a strange behaviour of the TApp..
132  sys.argv=sys.argv[:1]
133  ROOT.gROOT.SetStyle("Plain") # style paranoia
134  sys.argv=__argv
135  #Cannot use this option when the logfile includes
136  #a large number of events... PyRoot seg-faults.
137  #Set ROOT in batch mode to avoid canvases popping up!
138  ROOT.gROOT.SetBatch(1)
139 
140 ##########
141 # Create the root file to save the graphs in
142 #
143 def createROOT(outdir,filename):
144 
145  # Save in file
146  rootfilename = os.path.join(outdir,filename)
147  myfile = None
148  exists = os.path.exists(rootfilename)
149  if exists:
150  myfile=ROOT.TFile(rootfilename,'UPDATE')
151  else:
152  myfile=ROOT.TFile(rootfilename,'RECREATE')
153  return myfile
154 
155 ##########
156 # Parse timing data from log file
157 #
158 def getTimingLogData(logfile_name):
159  data=[]
160 
161  # open file and read it and fill the structure!
162  logfile=open(logfile_name,'r')
163  logfile_lines=logfile.readlines()
164  logfile.close()
165 
166  # we get the info we need!
167  i=0
168  while i < len(logfile_lines):
169  line=logfile_lines[i]
170  if 'TimeEvent>' in line:
171  line=line.strip()
172  line_content_list = line.split(' ')[0:]
173  event_number = int(line_content_list[1])
174  seconds = float(line_content_list[3])
175  data.append((event_number,seconds))
176  i+=1
177 
178  return data
179 
180 ###########
181 # Parse memory check data from log file
182 #
183 def getSimpleMemLogData(logfile_name,startevt, candle):
184  data=[]
185  values_set=('vsize','delta_vsize','rss','delta_rss')
186 
187  # open file and read it and fill the structure!
188  logfile=open(logfile_name,'r')
189  logfile_lines=logfile.readlines()
190  logfile.close()
191 
192  step = ""
193  steps = []
194  #print candle
195  #print CandFname[candle]
196  #Get the step from log filename:
197 
198  #Catching the case of command line use in which the candle is unknown (and the log name does not match the perfsuite naming convention
199  if candle:
200  stepreg = re.compile("%s_([^_]*(_PILEUP)?)_%s((.log)|(.gz))?" % (CandFname[candle],"TimingReport"))
201  else:
202  stepreg = re.compile("([^_]*(_PILEUP)?)_%s((.log)|(.gz))?"%"TimingReport")
203 
204  #print logfile_name
205  found=stepreg.search(logfile_name)
206  if found:
207  step=found.groups()[0]
208  print "Determined step from log filename to be %s"%step
209  else:
210  print "Could not determine step from log filename"
211 
212  #steps.append((step,data))
213 
214  #Rewriting the following code... what a mess!
215  # we get the info we need!
216  #i=0
217  #while i < len(logfile_lines):
218  #line=logfile_lines[i]
219  #Format has changed... we use the output of individual steps, so no need to read into the logfile to find which step we are
220  #referring too (by the way it would not work now!)... the step info comes from the logfilename done above...
221  #if "RelValreport" in line and "cmsDriver" in line and "step" in line:
222  # stepreg = re.compile("--step=([^ ]*)")
223  # found = stepreg.search(line)
224  # if found:
225  # if step == "":
226  # step = found.groups()[0]
227  # else:
228  # steps.append((step,data))
229  # step = found.groups()[0]
230  # data = []
231  #if '%MSG-w MemoryCheck:' in line:
232  # line=line[:-1] #no \n!
233  # line_content_list=line.split(' ')
234  # event_number=int(line_content_list[-1])
235  # if event_number<startevt:
236  # i+=1
237  # continue
238  # i+=1 # we inspect the following line
239  # try:
240  # line=logfile_lines[i]
241  # except IndexError:
242  # continue
243  # line=line[:-1] #no \n!
244  # line_content_list=line.split(' ')
245  # vsize=float(line_content_list[4])
246  # delta_vsize=float(line_content_list[5])
247  # rss=float(line_content_list[7])
248  # delta_rss=float(line_content_list[8])
249  #
250  # data.append((event_number,{'vsize':vsize,
251  # 'delta_vsize':delta_vsize,
252  # 'rss':rss,
253  # 'delta_rss':delta_rss}))
254  #i += 1
255  event_number= startevt
256  for line in logfile_lines:
257  #Match SimpleMemoryCheck output to get the event number
258  if '%MSG-w MemoryCheck:' in line: #Harcoded based on format: %MSG-w MemoryCheck: PostModule 12-Jan-2009 16:00:29 CET Run: 1 Event: 1
259  tokens=line.split()
260  if int(tokens[-1])>= startevt:
261  event_number=int(tokens[-1])
262  if 'VSIZE' in line: #Harcoded based on format: MemoryCheck: event : VSIZE 648.426 0 RSS 426.332 0
263  tokens=line.split()
264  vsize=float(tokens[4])
265  delta_vsize=float(tokens[5])
266  rss=float(tokens[7])
267  delta_rss=float(tokens[8])
268  data.append((event_number,{'vsize':vsize,
269  'delta_vsize':delta_vsize,
270  'rss':rss,
271  'delta_rss':delta_rss
272  }
273  )
274  )
275 
276  if not len(data) == 0:
277  #print "!!!!!!!!!!!!!Adding step %s and data!"%step
278  steps.append((step,data))
279 
280  #print "PRINTOUT@@@@@@"
281  #print steps
282  return steps
283 
284 ###############
285 #
286 # Create a new timing graph and histogram
287 #
288 def newGraphAndHisto(histoleg,leg,npoints,nbins,min_val,max_val,data,graph_num,prevrev=""):
289 
290  colors = [2,4]
291  prevRevName = "???"
292  if not prevrev == "":
293  (head, tail) = os.path.split(prevrev)
294  prevRevName = os.path.basename(tail)
295  releaseNames = ["Previous (%s)" % prevRevName,_cmsver]
296 
297  histo=ROOT.TH1F("Seconds per event (histo: %s)" % graph_num,'Seconds per event',nbins,min_val,max_val)
298 
299  graph=ROOT.TGraph(npoints)
300 
301  evt_counter=0
302  peak = data[0][1]
303  for evt_num,secs in data:
304  if secs > peak:
305  peak = secs
306  graph.SetPoint(evt_counter,evt_num,secs)
307  histo.Fill(secs)
308  evt_counter+=1
309 
310  allsecs = []
311  map(lambda x: allsecs.append(x[1]),data)
312  total = reduce(lambda x,y: x + y,allsecs)
313  mean = total / evt_counter
314  rms = math.sqrt(reduce(lambda x,y: x + y,map(lambda x: x * x,allsecs)) / evt_counter)
315 
316 
317  graph.SetMarkerStyle(8)
318  graph.SetMarkerSize(.7)
319  graph.SetMarkerColor(1)
320  graph.SetLineWidth(3)
321  graph.SetLineColor(colors[graph_num]) # for each iterate through colors
322  histo.SetLineColor(colors[graph_num])
323  histo.SetStats(1)
324  histoleg.AddEntry(histo, "%s release" % releaseNames[graph_num], "l")
325  leg.AddEntry(graph , "%s release" % releaseNames[graph_num], "l")
326  leg.AddEntry(graph , "Mean: %s" % str(mean) , "l")
327  leg.AddEntry(graph , "RMS : %s" % str(rms) , "l")
328  leg.AddEntry(graph , "Peak: %s" % str(peak) , "l")
329  leg.AddEntry(graph , "Total time: %s" % str(total) , "l")
330  if graph_num == 0 :
331  histo.SetFillColor(colors[graph_num])
332 
333  return (graph,histo,mean)
334 
335 ###########
336 # Get limits to plot the graph
337 #
338 def getLimits(data,secsperbin):
339  min_val=get_min(data,1)
340  max_val=get_max(data,1)
341  interval=int(max_val-min_val)
342 
343  min_val=min_val-interval*0.2
344  max_val=max_val+interval*0.2
345  interval=int(max_val-min_val)
346 
347  nbins=int(interval/secsperbin)
348 
349  npoints=len(data)
350 
351  last_event=data[-1][0]
352 
353  return (min_val,max_val,interval,npoints,last_event)
354 
355 ##############
356 # Setup graph information for one graph (no need to it on both if they are superimposed)
357 #
358 def setupSuperimpose(graph1,graph2,last_event,max_val,reporttype=0, title = ""):
359  name = ""
360  xtitle = ""
361  ytitle = ""
362  if reporttype == 0:
363  title = 'Seconds per event'
364  name = 'SecondsPerEvent'
365  xtitle = "Event"
366  ytitle = "Processing time for each event (s)"
367  graph1.GetYaxis().SetRangeUser(0,max_val)
368  graph2.GetYaxis().SetRangeUser(0,max_val)
369  elif reporttype == 1:
370  name = "%s_graph" % title
371  xtitle = "Event"
372  ytitle = "MB"
373 
374  graph1.SetTitle(title)
375  graph1.SetName(name)
376  graph1.GetXaxis().SetTitle(xtitle)
377  graph1.GetYaxis().SetTitleOffset(1.3)
378  graph1.GetYaxis().SetTitle(ytitle)
379  graph1.GetXaxis().SetLimits(0,last_event)
380  # Do I need to set limits on graph 2? I don't know
381  # I'm doing it anyway, can't hurt.
382  graph2.GetXaxis().SetLimits(0,last_event)
383 
384 #############
385 # Plot the mean line on a graph
386 #
387 def getMeanLines(avg,last_event,graph_num):
388  colors = [2,4]
389  avg_line=ROOT.TLine(1,avg,last_event,avg)
390  avg_line.SetLineColor(colors[graph_num])
391  avg_line.SetLineWidth(2)
392 
393  return avg_line
394 
395 ############
396 # Get the difference in timing data (for comparison of two releases)
397 #
398 def getTimingDiff(data1,data2,npoints,last_event,orig_max_val):
399  data3 = []
400  for x in range(len(data2)):
401  try:
402  if data2[x][0] == data1[x][0]:
403  avgEventNum = data2[x][0]
404  diffSecs = data2[x][1] - data1[x][1]
405  data3.append((avgEventNum,diffSecs))
406  except IndexError:
407  pass
408  except ValueError:
409  pass
410 
411  graph=ROOT.TGraph(npoints)
412 
413  evt_counter=0
414  peak = data3[0][1]
415  for evt_num,secs in data3:
416  if secs > peak:
417  peak = secs
418  graph.SetPoint(evt_counter,evt_num,secs)
419  evt_counter+=1
420 
421  allsecs = []
422  map(lambda x: allsecs.append(x[1]),data3)
423  total = reduce(lambda x,y: x + y,allsecs)
424  mean = total / evt_counter
425  rms = math.sqrt(reduce(lambda x,y: x + y,map(lambda x: x * x,allsecs)) / evt_counter)
426 
427  min_val=get_min(data3,1)
428  max_val=get_max(data3,1)
429  interval=int(max_val-min_val)
430 
431  min_val=min_val-interval*0.2
432  max_val=max_val+interval*0.2
433  interval=int(max_val-min_val)
434 
435  # Determine the max value to be something that makes the scale similar to what
436  # the original graph had. Unless we can't seem the maximum value.
437 
438  new_max = min_val + orig_max_val
439  if new_max < max_val:
440  pass
441  else :
442  max_val = new_max
443 
444  graph.SetTitle('Change in processing time for each event between revs')
445  graph.SetName('SecondsPerEvent')
446  graph.GetXaxis().SetTitle("Event Number")
447  graph.GetYaxis().SetTitle("Change in processing time between revs (s)")
448  graph.GetYaxis().SetTitleOffset(1.3)
449  graph.SetLineColor(2)
450  graph.SetMarkerStyle(8)
451  graph.SetMarkerSize(.7)
452  graph.SetMarkerColor(1)
453  graph.SetLineWidth(3)
454  graph.GetXaxis().SetLimits(0,last_event)
455  graph.GetYaxis().SetRangeUser(min_val,max_val)
456  leg = ROOT.TLegend(0.5,0.7,0.89,0.89)
457  leg.AddEntry(graph, "Mean: %s" % str(mean), "l")
458  leg.AddEntry(graph, "RMS : %s" % str(rms) , "l")
459  leg.AddEntry(graph, "Peak: %s" % str(peak), "l")
460  leg.AddEntry(graph, "Total time change: %s" % str(total) , "l")
461 
462  return (graph,leg)
463 
464 ##########
465 # Draw superimposed graphs on a separate canvas
466 #
467 def drawGraphs(graph1,graph2,avg1,avg2,leg):
468  graph_canvas = ROOT.TCanvas("graph_canvas")
469  graph_canvas.cd()
470  graph1.Draw("ALP")
471  graph2.Draw("LP")
472  avg1.Draw("Same")
473  avg2.Draw("Same")
474  leg.Draw()
475  return graph_canvas
476 
477 ##########
478 # Draw superimposed histograms on a separate canvas
479 #
480 def drawHistos(histo_stack,hstleg):
481  histo_canvas = ROOT.TCanvas("histo_canvas")
482  histo_canvas.cd()
483  histo_stack.Draw("nostack")
484  hstleg.Draw()
485  return histo_canvas
486 
487 ##########
488 # Draw data differences (comparison between two data sets or releases) on a separate canvas
489 #
490 def drawChanges(graph,chgleg):
491  graph_canvas = ROOT.TCanvas("change_canvas")
492  graph_canvas.cd()
493  graph.Draw("ALP")
494  chgleg.Draw()
495  return graph_canvas
496 
497 ###########
498 # Get limits for two graphs that will be superimposed upon one another
499 #
500 def getTwoGraphLimits(last_event1,max_val1,last_event2,max_val2,min_val1=-1,min_val2=-1):
501  biggestLastEvt = last_event1
502  biggestMaxval = max_val1
503  lowest_val = min_val1
504 
505  if min_val2 < lowest_val:
506  lowest_val = min_val2
507  if last_event2 > biggestLastEvt:
508  biggestLastEvt = last_event2
509  if max_val2 > biggestMaxval:
510  biggestMaxval = max_val2
511  return (biggestLastEvt,biggestMaxval,lowest_val)
512 
513 def getNpoints(data):
514  new_data=[]
515  try:
516  #This was necessary due to a bug in the getSimpleMemLogData parsing!!! no more necessary!
517  if data[0][0]==data[1][0]:
518  print 'Two modules seem to have some output.\nCollapsing ...'
519  i=0
520  while True:
521  dataline1=data[i]
522  i+=1
523  dataline2=data[i]
524  new_eventnumber=dataline1[0]
525  new_vsize=dataline2[1]['vsize']
526  new_delta_vsize=dataline1[1]['delta_vsize']+dataline2[1]['delta_vsize']
527  new_rss=dataline2[1]['rss']
528  new_delta_rss=dataline1[1]['delta_rss']+dataline2[1]['delta_rss']
529 
530  new_data.append((new_eventnumber,{'vsize':new_vsize,
531  'delta_vsize':new_delta_vsize,
532  'rss':new_rss,
533  'delta_rss':new_delta_rss}))
534  i+=1
535  if i==len(data): break
536 
537  data=new_data
538  print 'Collapsing: Done!'
539  except IndexError:
540  pass
541 
542  return (data,len(data))
543 
544 ###########
545 # Create simple memory check graphs
546 #
547 def createSimplMemGraphs(data,npoints,graph_num,legs,prevrev=""):
548  colors = [2,4]
549  values = ["vsize", "rss"]
550 
551  prevRevName = "???"
552  if not prevrev == "":
553  (head, tail) = os.path.split(prevrev)
554  prevRevName = os.path.basename(tail)
555 
556  releaseNames = ["Previous (%s)" % prevRevName,_cmsver]
557 
558  #fill the graphs
559  graphs = []
560  minim = -1
561  peak = -1
562  peaks = []
563  minims = []
564  idx = 0
565  for value in values:
566  leg = legs[idx]
567 
568  graph = ROOT.TGraph(npoints)
569  graph.SetTitle(value)
570  graph.SetLineColor(colors[graph_num])
571  graph.SetMarkerStyle(8)
572  graph.SetMarkerSize(.7)
573  graph.SetMarkerColor(1)
574  graph.SetLineWidth(3)
575  graph.GetXaxis().SetTitle("Event")
576  graph.GetYaxis().SetTitleOffset(1.3)
577  graph.GetYaxis().SetTitle("MB")
578 
579  total = 0
580  point_counter=0
581  rms = 0
582  first = True
583  for event_number,vals_dict in data:
584  if first:
585  minim = vals_dict[value]
586  peak = vals_dict[value]
587  first = False
588  if vals_dict[value] > peak:
589  peak = vals_dict[value]
590  if vals_dict[value] < minim:
591  minim = vals_dict[value]
592  graph.SetPoint(point_counter, event_number, vals_dict[value])
593  total += vals_dict[value]
594  rms += vals_dict[value] * vals_dict[value]
595  point_counter+=1
596 
597  rms = math.sqrt(rms / float(point_counter))
598  mean = total / float(point_counter)
599  last_event=data[-1][0]
600  peaks.append(peak)
601  minims.append(minim)
602  graph.GetXaxis().SetRangeUser(0,last_event+1)
603  leg.AddEntry(graph , "%s release" % releaseNames[graph_num], "l")
604  leg.AddEntry(graph , "Mean: %s" % str(mean) , "l")
605  leg.AddEntry(graph , "RMS : %s" % str(rms) , "l")
606  leg.AddEntry(graph , "Peak: %s" % str(peak) , "l")
607  graphs.append(graph)
608  idx += 1
609 
610  return (graphs[0] , last_event, peaks[0], minims[0], graphs[1], last_event, peaks[1], minims[1])
611 
612 #############
613 # Produce the difference of two memory data sets
614 #
615 def getMemDiff(data1,data2,npoints,last_event,orig_max_val,stepname,rss=False):
616  data3 = []
617  memtype = "vsize"
618  if rss:
619  memtype = "rss"
620 
621  graph=ROOT.TGraph(npoints)
622  total = 0
623  rms = 0
624  evt_counter=0
625  peak = -1
626  minum = -1
627  first = True
628  for x in range(len(data2)):
629  try:
630  (evtnum2,valdict2) = data2[x]
631  (evtnum1,valdict1) = data1[x]
632  if evtnum2 == evtnum1:
633  diffMBytes = valdict2[memtype] - valdict1[memtype]
634 
635  if first:
636  peak = diffMBytes
637  minum = diffMBytes
638  first = False
639  if diffMBytes > peak:
640  peak = diffMBytes
641  if diffMBytes < minum:
642  minum = diffMBytes
643  graph.SetPoint(evt_counter,evtnum2,diffMBytes)
644  evt_counter+=1
645  total += diffMBytes
646  rms += (diffMBytes * diffMBytes)
647  except IndexError:
648  pass
649  except ValueError:
650  pass
651 
652  mean = total / evt_counter
653  rms = math.sqrt(rms / float(evt_counter))
654 
655  min_val = minum
656  max_val = peak
657  interval = int(max_val-min_val)
658 
659  min_val=min_val-interval*0.2
660  max_val=max_val+interval*0.2
661  interval=int(max_val-min_val)
662  # Determine the max value to be something that makes the scale similar to what
663  # the original graph had. Unless we can't seem the maximum value.
664 
665  new_max = min_val + orig_max_val
666  if new_max < max_val:
667  pass
668  else :
669  max_val = new_max
670 
671  graph.SetTitle("Change in %s memory usage for each event between revs for step %s" % (memtype,stepname))
672  graph.SetName('MemoryUsagePerEvent')
673  graph.GetXaxis().SetTitle("Event Number")
674  graph.GetYaxis().SetTitle("Change in memory usage between revs (MBs)")
675  graph.GetYaxis().SetTitleOffset(1.3)
676  graph.SetLineColor(2)
677  graph.SetMarkerStyle(8)
678  graph.SetMarkerSize(.7)
679  graph.SetMarkerColor(1)
680  graph.SetLineWidth(3)
681  graph.GetXaxis().SetLimits(0,last_event)
682  graph.GetYaxis().SetRangeUser(min_val,max_val)
683  leg = ROOT.TLegend(0.5,0.7,0.89,0.89)
684  leg.AddEntry(graph, "Mean: %s" % str(mean), "l")
685  leg.AddEntry(graph, "RMS : %s" % str(rms) , "l")
686  leg.AddEntry(graph, "Peak: %s" % str(peak), "l")
687  leg.AddEntry(graph, "Trough: %s" % str(minum) , "l")
688 
689  return (graph,leg)
690 
691 ############
692 # Draw two memory graphs superimposed on one another
693 #
694 def drawMemGraphs(graph1,graph2,min_val,max_val,last_event,leg,memtype,stepname):
695  graph_canvas=ROOT.TCanvas("%s_%s_canvas" % (memtype,stepname))
696  graph_canvas.cd()
697  graph1.GetYaxis().SetRangeUser(min_val,max_val)
698  graph1.GetXaxis().SetRangeUser(0,last_event)
699  graph1.Draw("ALP")
700  graph2.Draw("LP" )
701  leg.Draw()
702  graph_canvas.ForceUpdate()
703  graph_canvas.Flush()
704  return graph_canvas
705 
706 ###########
707 # Draw the comparison graphs of two memory graphs
708 #
709 def drawMemChangeGraphs(graph,leg,memtype,stepname):
710  graph_canvas=ROOT.TCanvas("%s_%s_change_canvas" % (memtype,stepname))
711  graph_canvas.cd()
712  graph.Draw("ALP" )
713  leg.Draw()
714  graph_canvas.ForceUpdate()
715  graph_canvas.Flush()
716  return graph_canvas
717 
718 def getMemOrigScale(fst_min,snd_min,fst_max,snd_max):
719  minim = fst_min
720  if snd_min < minim:
721  minim = snd_min
722  maxim = fst_max
723  if snd_max > maxim:
724  maxim = snd_max
725  return (minim,maxim)
726 
727 def cmpSimpMemReport(rootfilename,outdir,oldLogfile,newLogfile,startevt,batch=True,candle="",prevrev=""):
728  if batch:
729  setBatch()
730  # the fundamental structure: the key is the evt number the value is a list containing
731  # VSIZE deltaVSIZE RSS deltaRSS
732  print "#####LOGFILES in cmsPErfRegress:"
733  print oldLogfile
734  print newLogfile
735  try:
736  info1 = getSimpleMemLogData(oldLogfile,startevt, candle)
737  if len(info1) == 0:
738  raise IndexError
739  except IndexError:
740  raise SimpMemParseErr(oldLogfile)
741  except IOError:
742  raise SimpMemParseErr(oldLogfile)
743 
744  try:
745  info2 = getSimpleMemLogData(newLogfile,startevt, candle)
746  if len(info2) == 0:
747  raise IndexError
748  except IndexError:
749  raise SimpMemParseErr(newLogfile)
750  except IOError:
751  raise SimpMemParseErr(newLogfile)
752  #print "DDDDD info1 %s"%info1 #Format is of the type:[('GEN,SIM', [(1, {'delta_vsize': 0.0, 'delta_rss': 0.0, 'vsize': 648.42600000000004, 'rss': 426.33199999999999}), (2,{...
753  #print "DDDDD info2 %s"%info2
754  canvases = []
755  # skim the second entry when the event number is the same BUG!!!!!!!
756  # i take elements in couples!
757 
758  candreg = re.compile("(.*)(?:\.log)")
759  vsize_canvas = None
760  rss_canvas = None
761  i = 0
762  firstRoot = True
763  newrootfile = None
764  #The following whileis confusing and not necessary info1 and info2 are supposed to only contain one set of simplememorycheck numbers
765  #in a tuple as seen above ('GEN,SIM',[(event_number,{'delta_vsize': 0.0, etc
766  #The data structure is questionable... but it is a remnant of past format of the log files I guess.
767  #while ( i < len(info1) and i < len(info2)):
768  #curinfo1 = info1[i]
769  #curinfo2 = info2[i]
770  (stepname1, data1) = info1[0]
771  (stepname2, data2) = info2[0]
772 
773  #Again this is not necessary anymore...
774  #if not stepname1 == stepname2:
775  #print "WARNING: Could not compare %s step and %s step because they are not the same step" % (stepname1, stepname2)
776  # print " Searching for next occurence"
777  # x = 1
778  # if not (i + 1) > len(info1):
779  # found = False
780  # for info in info1[i + 1:]:
781  # (stepname,trash) = info
782  # if stepname == stepname2:
783  # i += x
784  #print " Next occurence found, skipping in-between steps"
785  # assert i < len(info1)
786  # found = True
787  # break
788  # x += 1
789  # if found:
790  # continue
791  # print " No more occurences of this step, continuing"
792  # i += 1
793  # continue
794 
795  #Not sure what this is for!
796  #OK it was due to the bug of duplicated info in getSimpleMemLogData parsing!
797  #No need!
798  #(data1,npoints1) = getNpoints(data1)
799  #(data2,npoints2) = getNpoints(data2)
800  npoints1=len(data1)
801  npoints2=len(data2)
802 
803  legs = []
804  leg = ROOT.TLegend(0.6,0.99,0.89,0.8)
805  legs.append(leg)
806  leg = ROOT.TLegend(0.6,0.99,0.89,0.8)
807  legs.append(leg)
808 
809  try:
810  if len(data1) == 0:
811  raise IndexError
812  (vsize_graph1,
813  vsize_lstevt1,
814  vsize_peak1,
815  vsize_minim1,
816  rss_graph1,
817  rss_lstevt1,
818  rss_peak1,
819  rss_minim1) = createSimplMemGraphs(data1,npoints1,0,legs,prevrev=prevrev)
820  #candFilename = CandFname[candle]
821  #outputdir = "%s_%s_SimpleMemReport" % (candFilename,stepname1)
822  #outputdir = os.path.join(outdir,outputdir)
823  #print "Graph1"
824  #vsize_graph1.Print()
825  except IndexError:
826  raise SimpMemParseErr(oldLogfile)
827 
828  try:
829  if len(data2) == 0:
830  raise IndexError
831  (vsize_graph2,
832  vsize_lstevt2,
833  vsize_peak2,
834  vsize_minim2,
835  rss_graph2,
836  rss_lstevt2,
837  rss_peak2,
838  rss_minim2) = createSimplMemGraphs(data2,npoints2,1,legs,prevrev=prevrev)
839  #candFilename = CandFname[candle]
840  #outputdir = "%s_%s_SimpleMemReport" % (candFilename,stepname1)
841  #outputdir = os.path.join(outdir,outputdir)
842  #print "Graph2"
843  #vsize_graph2.Print()# os.path.join(outputdir,"vsize_graph2.png"))
844  except IndexError:
845  raise SimpMemParseErr(newLogfile)
846 
847 
848  (vsize_lstevt, vsize_max_val, vsize_min_val) = getTwoGraphLimits(vsize_lstevt1, vsize_peak1, vsize_lstevt2, vsize_peak2, vsize_minim1, vsize_minim2)
849  (rss_lstevt , rss_max_val , rss_min_val) = getTwoGraphLimits(rss_lstevt1 , rss_peak1, rss_lstevt2 , rss_peak2, rss_minim1, rss_minim2)
850 
851  (vsize_min,vsize_max) = getMemOrigScale(vsize_minim1,vsize_minim2,vsize_peak1,vsize_peak2)
852  (rss_min ,rss_max ) = getMemOrigScale(rss_minim1,rss_minim2,rss_peak1,rss_peak2)
853 
854  setupSuperimpose(vsize_graph1,
855  vsize_graph2,
856  vsize_lstevt,
857  0,
858  reporttype = 1,
859  title = "%s_vsize" % stepname1)
860  setupSuperimpose(rss_graph1 ,
861  rss_graph2 ,
862  rss_lstevt ,
863  0,
864  reporttype = 1,
865  title = "%s_rss" % stepname2)
866 
867  (vsizePerfDiffgraph, vsizeleg) = getMemDiff(data1,data2,npoints2,vsize_lstevt, (vsize_max - vsize_min), stepname1, rss=False)
868  (rssPerfDiffgraph, rssleg) = getMemDiff(data1,data2,npoints2,rss_lstevt , (rss_max - rss_min) , stepname1, rss=True )
869 
870  vsize_canvas = drawMemGraphs(vsize_graph1, vsize_graph2, vsize_min_val, vsize_max_val, vsize_lstevt, legs[0], "vsize", stepname1)
871  rss_canvas = drawMemGraphs(rss_graph1 , rss_graph2 , rss_min_val, rss_max_val, rss_lstevt, legs[1], "rss" , stepname1)
872  vsize_change_canvas = drawMemChangeGraphs(vsizePerfDiffgraph, vsizeleg, "vsize", stepname1)
873  rss_change_canvas = drawMemChangeGraphs(rssPerfDiffgraph , rssleg , "rss" , stepname1)
874 
875  if batch:
876 
877 
878  logcandle = ""
879  candname = ""
880  found = candreg.search(os.path.basename(newLogfile))
881 
882  if found:
883  logcandle = found.groups()[0]
884 
885  if CandFname.has_key(candle):
886  candFilename = CandFname[candle]
887  elif CandFname.has_key(logcandle):
888  candFilename = CandFname[logcandle]
889  else:
890  print "%s is an unknown candle!"%candle
891  candFilename = "Unknown-candle"
892 
893  outputdir = "%s_%s_SimpleMemReport" % (candFilename,stepname1)
894  outputdir = os.path.join(outdir,outputdir)
895 
896  if not os.path.exists(outputdir):
897  os.mkdir(outputdir)
898 
899  #print the graphs as files :)
900 
901  newrootfile = createROOT(outputdir,rootfilename)
902 
903  vsize_canvas.Print( os.path.join(outputdir,"vsize_graphs.png"), "png")
904  rss_canvas.Print( os.path.join(outputdir,"rss_graphs.png" ), "png")
905  vsize_change_canvas.Print(os.path.join(outputdir,"vsize_change.png"), "png")
906  rss_change_canvas.Print( os.path.join(outputdir,"rss_change.png" ), "png")
907  # write it on file
908  map(lambda x: x.Write(), [vsize_graph1,vsize_graph2, rss_graph1, rss_graph2, vsizePerfDiffgraph, rssPerfDiffgraph])
909  map(lambda x: x.Write(), [vsize_canvas,rss_canvas,vsize_change_canvas,rss_change_canvas])
910  newrootfile.Close()
911  else:
912  # we have to do this if we are running the application standalone
913  # For some reason it will not draw some graphs at all if there is more than
914  # one step.
915  # If we wait between iterations of this loop the graphs will be drawn correctly.
916  # Perhaps a graphics buffer problem with ROOT?
917  # Perhaps a garbage collection problem in python? (Doubt it)
918  canvases.append(rss_canvas)
919  canvases.append(vsize_canvas)
920  canvases.append(vsize_change_canvas)
921  canvases.append(rss_change_canvas)
922  time.sleep(5.0)
923 
924  #Eliminated the while loop!
925  #i += 1
926 
927  #
928  # Create a one dimensional function and draw it
929  #
930 
931  if batch:
932  pass
933  else:
934  if len(canvases) > 0:
935  while reduce(lambda x,y: x or y ,canvases):
936  time.sleep(2.5)
937  return 0
938 
939 
940 def cmpTimingReport(rootfilename,outdir,oldLogfile,newLogfile,secsperbin,batch=True,prevrev=""):
941  if batch:
942  setBatch()
943 
944  data1 = getTimingLogData(oldLogfile)
945  data2 = getTimingLogData(newLogfile)
946 
947  try:
948  (min_val1,max_val1,nbins1,npoints1,last_event1) = getLimits(data1,secsperbin)
949  except IndexError, detail:
950  raise TimingParseErr(oldLogfile)
951 
952  try:
953  (min_val2,max_val2,nbins2,npoints2,last_event2) = getLimits(data2,secsperbin)
954  except IndexError, detail:
955  raise TimingParseErr(newLogfile)
956 
957  hsStack = ROOT.THStack("hsStack","Histogram Comparison")
958  leg = ROOT.TLegend(0.6,0.99,0.89,0.8)
959  histoleg = ROOT.TLegend(0.5,0.8,0.89,0.89)
960 
961  #
962 
963  (graph1,histo1,mean1) = newGraphAndHisto(histoleg,leg,npoints1,nbins1,min_val1,max_val1,data1,0,prevrev)
964  hsStack.Add(histo1)
965  (graph2,histo2,mean2) = newGraphAndHisto(histoleg,leg,npoints2,nbins2,min_val2,max_val2,data2,1,prevrev)
966  hsStack.Add(histo2)
967 
968  (biggestLastEvt,biggestMaxval, trashthis) = getTwoGraphLimits(last_event1,max_val1,last_event2,max_val2,min_val1,min_val2)
969 
970  (changegraph,chgleg) = getTimingDiff(data1,data2,npoints2,biggestLastEvt,biggestMaxval)
971  setupSuperimpose(graph1,graph2,biggestLastEvt,biggestMaxval)
972  avg_line1 = getMeanLines(mean1,last_event1,0)
973  avg_line2 = getMeanLines(mean2,last_event2,1)
974 
975  #
976  # Create a one dimensional function and draw it
977  #
978  histo1.GetXaxis().SetTitle("s")
979  graph_canvas = drawGraphs(graph1,graph2,avg_line1,avg_line2,leg)
980  changes_canvas = drawChanges(changegraph,chgleg)
981  histo_canvas = drawHistos(hsStack,histoleg)
982 
983  newrootfile = None
984  if batch:
985 
986  newrootfile = createROOT(outdir,rootfilename)
987 
988  cput = ROOT.TTree()
989  # array(typecode, initializer)
990  # typecode is i for int, f for float etc.
991  tot_a1 = array( "f", [ 0 ] )
992  tot_a2 = array( "f", [ 0 ] )
993 
994  tot_a1[0] = mean1
995  tot_a2[0] = mean2
996 
997  cput.Branch("total1",tot_a1,"total1/F")
998  cput.Branch("total2",tot_a2,"total2/F")
999  cput.Fill()
1000  cput.Write("cpu_time_tuple",ROOT.TObject.kOverwrite)
1001 
1002  names = ["graphs.png","changes.png","histos.png"]
1003 
1004  graph_canvas.Print( os.path.join(outdir,names[0]),"png")
1005  changes_canvas.Print(os.path.join(outdir,names[1]),"png")
1006  histo_canvas.Print( os.path.join(outdir,names[2]),"png")
1007 
1008  map(lambda x:x.Write(),[graph1,graph2,changegraph,hsStack,histo1,histo2])
1009 
1010  graph_canvas.Write() # to file
1011  changes_canvas.Write()
1012  histo_canvas.Write()
1013  newrootfile.Close()
1014 
1015  return names
1016  else:
1017 
1018  while graph_canvas or histo_canvas or changes_canvas:
1019  time.sleep(2.5)
1020  return 0
1021 
1022 def rmtree(path):
1023  try:
1024  #os.remove(path)
1025  #Brute force solution:
1026  RemoveCmd="rm -Rf %s"%path
1027  os.system(RemoveCmd)
1028  except OSError, detail:
1029  if detail.errno == 39:
1030  try:
1031  gen = os.walk(path)
1032  nodes = gen.next()
1033  nodes[0] = par
1034  nodes[1] = dirs
1035  nodes[2] = files
1036  for f in files:
1037  os.remove(os.path.join(path,f))
1038  for d in dirs:
1039  rmtree(os.path.join(path,d))
1040  except OSError, detail:
1041  print detail
1042  except IOError, detail:
1043  print detail
1044  os.remove(path)
1045 
1046 def perfreport(perftype,file1,file2,outdir,IgProfMemopt=""):
1047  src = ""
1048  try:
1049  src = os.environ["CMSSW_SEARCH_PATH"]
1050  except KeyError , detail:
1051  print "ERROR: scramv1 environment could not be located", detail
1052 
1053  vars = src.split(":")
1054  loc = vars[0]
1055 
1056  proftype = ""
1057  if perftype == 0: # EdmSize
1058  proftype = "-fe"
1059  elif perftype == 1: # IgProf
1060  proftype = "-fi"
1061  else: # Callgrind
1062  proftype = "-ff"
1063 
1064  cmssw_release_base = ""
1065  cmssw_data = ""
1066  try:
1067  cmssw_release_base = os.environ['CMSSW_RELEASE_BASE']
1068  cmssw_data = os.environ['CMSSW_DATA_PATH']
1069  except KeyError, detail:
1070  raise PerfReportErr
1071 
1072  xmlfile = os.path.join(cmssw_release_base,"src","Validation","Performance","doc","regress.xml")
1073 
1074  prRoot = "/afs/cern.ch/user/g/gbenelli/public/PerfReport2/2.0.1"
1075 
1076  # this might be useful at some point
1077  #cd %s ; eval `scramv1 runtime -csh` ; source $CMSSW_DATA_PATH/perfreport/2.0.0/etc/profile.d/init.csh; cd - ; %s\"" % (loc,perfcmd)
1078 
1079  # Before adding Danilo's 2.1 we did this
1080  #perfcmd = "perfreport -tmp %s -i %s -r %s -o %s" % (proftype,file2,file1,outdir)
1081  #cmd = "tcsh -c \"source %s/perfreport/2.0.0/etc/profile.d/init.csh; cd - ; %s\"" % (cmssw_data,perfcmd)
1082 
1083  # now we do
1084 
1085  tmpdir = tmp.mkdtemp(prefix=os.path.join(outdir,"tmp"))
1086 
1087  perfcmd = "%s %s %s -c %s -t%s -i %s -r %s -o %s" % (os.path.join(prRoot,"bin","perfreport"),proftype,IgProfMemopt,xmlfile,tmpdir,file2,file1,outdir)
1088  cmd = "tcsh -c \"cd %s ; eval `scramv1 runtime -csh` ; cd - ;source %s/etc/profile.d/init.csh ; %s\"" % (loc,prRoot,perfcmd)
1089  #Obsolete popen4-> subprocess.Popen
1090  #process = os.popen(cmd)
1091  process = subprocess.Popen(cmd,shell=True,stdout=subprocess.PIPE,stderr=subprocess.STDOUT)
1092  exitstat = process.wait()
1093  cmdout = process.stdout.read()
1094  exitstat = process.returncode
1095 
1096  try:
1097  rmtree(tmpdir) #Brute force solution rm -RF tmpdir done in rmtree()
1098  #os.rmdir(tmpdir)
1099  except IOError, detail:
1100  print "WARNING: Could not remove dir because IO%s" % detail
1101  except OSError, detail:
1102  print "WARNING: Could not remove dir because %s" % detail
1103 
1104  if True:
1105  print cmd
1106  print cmdout
1107 
1108  if not exitstat == None:
1109  sig = exitstat >> 16 # Get the top 16 bits
1110  xstatus = exitstat & 0xffff # Mask out all bits except the bottom 16
1111  raise PerfReportErr("ERROR: PerfReport returned a non-zero exit status (%s, SIG_INT = %s) run %s. Dump follows: \n%s" % (perfcmd,xstatus,sig,cmdout))
1112 
1113 
1114 def cmpEdmSizeReport(outdir,file1,file2):
1115  perfreport(0,file1,file2,outdir)
1116 
1117 def ungzip(inf,outh):
1118  gzf = gzip.open(inf,"r")
1119  print "ungzipping"
1120  for char in gzf:
1121  os.write(outh,char)
1122  os.close(outh)
1123  print "finish ungzipping"
1124  gzf.close()
1125 
1126 def ungzip2(inf,out):
1127  os.system("gzip -c -d %s > %s" % (inf,out))
1128 
1129 def cmpIgProfReport(outdir,file1,file2,IgProfMemOpt=""):
1130  (tfile1, tfile2) = ("", "")
1131  try:
1132  # don't make temp files in /tmp because it's never bloody big enough
1133  (th1, tfile1) = tmp.mkstemp(prefix=os.path.join(outdir,"igprofRegressRep."))
1134  (th2, tfile2) = tmp.mkstemp(prefix=os.path.join(outdir,"igprofRegressRep."))
1135  os.close(th1)
1136  os.close(th2)
1137  os.remove(tfile1)
1138  os.remove(tfile2)
1139  ungzip2(file1,tfile1)
1140  ungzip2(file2,tfile2)
1141 
1142  perfreport(1,tfile1,tfile2,outdir,IgProfMemOpt)
1143 
1144  os.remove(tfile1)
1145  os.remove(tfile2)
1146  except OSError, detail:
1147  raise PerfReportErr("WARNING: The OS returned the following error when comparing %s and %s\n%s" % (file1,file2,str(detail)))
1148  if os.path.exists(tfile1):
1149  os.remove(tfile1)
1150  if os.path.exists(tfile2):
1151  os.remove(tfile2)
1152  except IOError, detail:
1153  raise PerfReportErr("IOError: When comparing %s and %s using temporary files %s and %s. Error message:\n%s" % (file1,file2,tfile1,tfile2,str(detail)))
1154  if os.path.exists(tfile1):
1155  os.remove(tfile1)
1156  if os.path.exists(tfile2):
1157  os.remove(tfile2)
1158 
1159 
1160 def cmpCallgrindReport(outdir,file1,file2):
1161  perfreport(2,file1,file2,outdir)
1162 
1163 def _main():
1164  outdir = os.getcwd()
1165 
1166  (file1,file2,secsperbin,reporttype,IgProfMemOptions) = getParameters()
1167 
1168  try:
1169  if reporttype == "timing":
1170  rootfilename = "timingrep-regression.root"
1171  cmpTimingReport(rootfilename ,outdir,file1,file2,secsperbin,True)
1172  elif reporttype == "simplememory":
1173  rootfilename = "simpmem-regression.root"
1174  cmpSimpMemReport(rootfilename,outdir,file1,file2,secsperbin,True)
1175  elif reporttype == "edmsize":
1176  cmpEdmSizeReport(outdir,file1,file2)
1177  elif reporttype == "callgrind":
1178  cmpCallgrindReport(outdir,file1,file2)
1179  elif reporttype == "igprof":
1180  cmpIgProfReport(outdir,file1,file2,IgProfMemOptions)
1181  except TimingParseErr, detail:
1182  print "WARNING: Could not parse data from Timing report file %s; not performing regression" % detail.message
1183  except SimpMemParseErr, detail:
1184  print "WARNING: Could not parse data from Memory report file %s; not performing regression" % detail.message
1185  except PerfReportErr , detail:
1186  print "WARNING: Could not parse data from Edm file %s; not performing regression" % detail.message
1187  except IOError, detail:
1188  print detail
1189  except OSError, detail:
1190  print detail
1191 
1192 if __name__ == "__main__":
1193  _main()
1194 
def getMeanLines
Plot the mean line on a graph.
def getTwoGraphLimits
Get limits for two graphs that will be superimposed upon one another.
def getMemDiff
Produce the difference of two memory data sets.
def setBatch
Setup PyRoot as a batch run.
def getLimits
Get limits to plot the graph.
def createSimplMemGraphs
Create simple memory check graphs.
def newGraphAndHisto
Create a new timing graph and histogram.
def drawMemGraphs
Draw two memory graphs superimposed on one another.
def drawMemChangeGraphs
Draw the comparison graphs of two memory graphs.
def get_max
Get max value in data set.
def setupSuperimpose
Setup graph information for one graph (no need to it on both if they are superimposed) ...
def drawChanges
Draw data differences (comparison between two data sets or releases) on a separate canvas...
def drawGraphs
Draw superimposed graphs on a separate canvas.
def getTimingDiff
Get the difference in timing data (for comparison of two releases)
def getSimpleMemLogData
Parse memory check data from log file.
def getTimingLogData
Parse timing data from log file.
def get_min
Get min value in data set.
def drawHistos
Draw superimposed histograms on a separate canvas.
def createROOT
Create the root file to save the graphs in.