CMS 3D CMS Logo
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Properties Friends Macros Pages
Functions
parserTimingReport Namespace Reference

Functions

def calc_MinMaxAvgRMS
 
def calcRMS
 
def extractRSS_VSIZE
 
def loadTimeLog
 
def manual_run
 
def perf_profile
 
def processModuleTimeLogData
 mod_data["stats"] =calc_MinMaxAvgRMS(f_time = lambda x: x["time"], f_evt_num = lambda x: x["event_number"], items = times_bymod[mod_name]) More...
 

Function Documentation

def parserTimingReport.calc_MinMaxAvgRMS (   items,
  remove_first = True,
  f_time = lambda x: x[0],
  f_evt_num = lambda x: x[1] 
) 
returns a dict of avg, min, max, rms

Definition at line 141 of file parserTimingReport.py.

References calcRMS(), python.multivaluedict.map(), max(), and min.

Referenced by processModuleTimeLogData().

141 
142 def calc_MinMaxAvgRMS(items, remove_first = True, f_time = lambda x: x[0], f_evt_num = lambda x: x[1],):
143  """ returns a dict of avg, min, max, rms """
144  # save the cpu time of first event before removing the first result!
145  cpu_time_first = f_time(items[0])
146 
147  if len(items) > 1 and remove_first == True:
148  items.remove(items[0]) #TODO: if there is only one event - we have a problem -> do we eliminate the whole module?
149  # TODO: it removes it completely from all the data because we do not save/ do not copy it
150 
151  items_time = map(f_time, items)
152  min_value = min(items_time)
153  max_value = max(items_time)
154  max_index = items_time.index(max_value)
155  avg_value = float(sum(items_time)) / float(len(items_time))
156  rms_value = calcRMS(items_time,avg_value)
157 
158  return {"min": min_value, "max": max_value, "cputime_first": cpu_time_first,
159  "rms": rms_value, "avg": avg_value,
160  "event_number_of_max": f_evt_num(items[max_index])}
161 
min
#define min(a, b)
Definition: mlp_lapack.h:161
max
const T & max(const T &a, const T &b)
Definition: MaterialBudgetTrackerHistos.cc:4
def parserTimingReport.calcRMS (   items,
  avg 
) 
returns RootMeanSquare  of items in a list

Definition at line 134 of file parserTimingReport.py.

Referenced by calc_MinMaxAvgRMS().

134 
135 def calcRMS(items,avg):
136  """ returns RootMeanSquare of items in a list """
137  # sqrt(sum(x^2))
138  # Not statistics RMS... "physics" RMS, i.e. standard deviation: sqrt(sum((x-avg)**2)/N)
139  # return math.sqrt(reduce(lambda x: (x - avg)**2, items) / len(items))
140  return math.sqrt(sum([(x-avg)**2 for x in items])/len(items))
def parserTimingReport.extractRSS_VSIZE (   line1,
  line2,
  record_number 
) 
>>> extractRSS_VSIZE("%MSG-w MemoryCheck:  PostModule 19-Jun-2009 13:06:08 CEST Run: 1 Event: 1", \
             "MemoryCheck: event : VSIZE 923.07 0 RSS 760.25 0")
(('1', '760.25'), ('1', '923.07'))

Definition at line 29 of file parserTimingReport.py.

References split, and strip().

Referenced by loadTimeLog().

29 
30 def extractRSS_VSIZE(line1, line2, record_number):
31  """
32  >>> extractRSS_VSIZE("%MSG-w MemoryCheck: PostModule 19-Jun-2009 13:06:08 CEST Run: 1 Event: 1", \
33  "MemoryCheck: event : VSIZE 923.07 0 RSS 760.25 0")
34  (('1', '760.25'), ('1', '923.07'))
35  """
36 
37  if ("Run" in line1) and ("Event" in line1): # the first line
38  event_number = line1.split('Event:')[1].strip()
39  else: return False
40 
41  """ it's first or second MemoryCheck line """
42  if ("VSIZE" in line2) and ("RSS" in line2): # the second line
43  RSS = line2.split("RSS")[1].strip().split(" ")[0].strip() #changed partition into split for backward compatability with py2.3
44  VSIZE = line2.split("RSS")[0].strip().split("VSIZE")[1].strip().split(" ")[0].strip()
45  #Hack to return the record number instea of event number for now... can always switch back of add event number on top
46  #return ((event_number, RSS), (event_number, VSIZE))
47  return ((record_number, RSS), (record_number, VSIZE))
48  else: return False
49 
strip
void strip(std::string &input, const std::string &blanks=" \n\t")
Definition: stringTools.cc:16
split
double split
Definition: MVATrainer.cc:139
def parserTimingReport.loadTimeLog (   log_filename,
  maxsize_rad = 0 
) 
gets the timing data from the logfile
 returns 4 lists:

    * ModuleTime data (event_number, module_label, module_name, seconds) and
    * EventTime data
        - with granularity of event (initial - not processed data)
    * RSS per event
    * VSIZE per event

Definition at line 50 of file parserTimingReport.py.

References extractRSS_VSIZE().

Referenced by manual_run(), perf_profile(), and cmsPerfSuiteHarvest.process_timesize_dir().

50 
51 def loadTimeLog(log_filename, maxsize_rad = 0): #TODO: remove maxsize to read, used for debugging
52  """ gets the timing data from the logfile
53  returns 4 lists:
54 
55  * ModuleTime data (event_number, module_label, module_name, seconds) and
56  * EventTime data
57  - with granularity of event (initial - not processed data)
58  * RSS per event
59  * VSIZE per event
60  """
61  # ----- format of logfile ----
62  # Report columns headings for modules: eventnum runnum modulelabel modulename timetakeni"
63  # e.g. TimeModule> 1 1 csctfDigis CSCTFUnpacker 0.0624561
64 
65  mod_data = []
66  evt_data = []
67  rss_data = []
68  vsize_data = []
69  # open file and read it and fill the structure!
70  logfile = open(log_filename, 'r')
71 
72  # get only the lines which have time report data
73  #TODO: reading and processing line by line might speed up the process!
74 
75  memcheck_line1 = False
76 
77  record_number=0
78  last_record=0
79  last_event=0
80  for line in logfile.xreadlines():
81  if 'TimeModule>' in line.strip():
82  line = line.strip()
83  line_content_list = line.split(' ')[0:]
84  #Hack to avoid issues with the non-consecutive run numbers:
85  event_number = int(line_content_list[1])
86  if event_number != last_event:
87  record_number=record_number+1
88  last_event=event_number
89  # module label and name were mixed up in the original doc
90  module_label = str(line_content_list[4])
91  module_name = str(line_content_list[3])
92  seconds = float(line_content_list[5])
93  #For now let's try to switch to the record_number... if we need to also have the event_number we can always add it back.
94  #mod_data.append((event_number, module_label, module_name, seconds))
95  mod_data.append((record_number, module_label, module_name, seconds))
96  if 'TimeEvent>' in line.strip():
97  line = line.strip()
98  line_content_list = line.split(' ')[0:]
99  #Hack to avoid issues with the non-consecutive run numbers:
100  event_number = int(line_content_list[1])
101  if event_number != last_event:
102  record_number=record_number+1
103  last_event=event_number
104  # module label and name were mixed up in the original doc
105  time_seconds = str(line_content_list[3])
106 
107  #TODO: what are the other [last two] numbers? Real time? smf else? TimeEvent> 1 1 15.3982 13.451 13.451
108  #For now let's try to switch to the record_number... if we need to also have the event_number we can always add it back.
109  #evt_data.append((event_number, time_seconds))
110  evt_data.append((record_number, time_seconds))
111  """
112  %MSG-w MemoryCheck: PostModule 19-Jun-2009 13:06:08 CEST Run: 1 Event: 1
113  MemoryCheck: event : VSIZE 923.07 0 RSS 760.25 0
114  """
115  if 'MemoryCheck:' in line.strip():
116  # this is the first line out of two
117  if (not memcheck_line1):
118  memcheck_line1 = line.strip()
119  else:
120  #FIXME (eventually)
121  #Hacking in the record_number extracted from the TimeEvent and TimeModule parsing... NOT ROBUST...
122  (rss, vsize) = extractRSS_VSIZE(memcheck_line1, line.strip(), record_number)
123  rss_data.append(rss)
124  vsize_data.append(vsize)
125  else:
126  memcheck_line1 = False
127 
128  logfile.close()
129 
130  return (mod_data, evt_data, rss_data, vsize_data)
131 
132 
133 
def parserTimingReport.manual_run ( )

Definition at line 245 of file parserTimingReport.py.

References cmssw_exportdb_xml.export_xml(), FileNamesHelper.getJobID_fromTimeReportLogName(), loadTimeLog(), and processModuleTimeLogData().

245 
246 def manual_run():
247  timelog_f = "TTBAR__RAW2DIGI,RECO_TimingReport.log"
248  timelog_f = "TTBAR__GEN,SIM,DIGI,L1,DIGI2RAW,HLT_TimingReport.log"
249  #TODO: get STEP name from filename
250  release_files = {
251 
252  "CMSSW_3_1_0_pre9":
253  (
254  "CMSSW_3_1_0_pre9/MINBIAS__RAW2DIGI,RECO_TimingReport.log",
255  "CMSSW_3_1_0_pre9/TTBAR__RAW2DIGI,RECO_TimingReport.log")
256  ## "CMSSW_3_1_0_pre10":
257  }
258  for release, files in release_files.items():
259  print "Processing release: %s" % release
260  for timelog_f in files:
261  print "Processing file: %s" % timelog_f
262 
263  # TODO: automaticaly detect type of report file!!!
264  (mod_timelog, evt_timelog, rss_data, vsize_data) =loadTimeLog(timelog_f)
265 
266  mod_timelog= processModuleTimeLogData(mod_timelog, groupBy = "module_label")
267  print "Number of modules grouped by (module_label): %s" % len(mod_timelog)
268 
269  (candle, step, pileup_type, conditions, event_content) = getJobID_fromTimeReportLogName(timelog_f)
270 
271  """ We could get release from the path but that's quite ugly! """
272  export_xml(jobID = jobID, release=release, timelog_result=(mod_timelog, evt_timelog, rss_data, vsize_data))
273 
""" use to run performance profiling """
FileNamesHelper.getJobID_fromTimeReportLogName
def getJobID_fromTimeReportLogName
Definition: FileNamesHelper.py:203
parserTimingReport.processModuleTimeLogData
def processModuleTimeLogData
mod_data["stats"] =calc_MinMaxAvgRMS(f_time = lambda x: x["time"], f_evt_num = lambda x: x["event_num...
Definition: parserTimingReport.py:162
cmssw_exportdb_xml.export_xml
def export_xml
Definition: cmssw_exportdb_xml.py:125
def parserTimingReport.perf_profile ( )

Definition at line 274 of file parserTimingReport.py.

References cmssw_exportdb_xml.export_xml(), FileNamesHelper.getJobID_fromTimeReportLogName(), loadTimeLog(), processModuleTimeLogData(), and MCScenario_CRAFT1_22X.write_xml().

274 
275 def perf_profile():
276  timelog_f = "test_data/TTBAR__RAW2DIGI,RECO_TimingReport.log"
277  (modules_timelog, evt_timelog, rss_data, vsize_data) = loadTimeLog(timelog_f)
278 
279  mod_timelog= processModuleTimeLogData(modules_timelog, groupBy = "module_label")
280 
281  (candle, step, pileup_type, conditions, event_content) = getJobID_fromTimeReportLogName(timelog_f)
282 
283  xmldoc = minidom.Document()
284  export_xml(step = step, candle = candle, release="test", timelog_result=(mod_timelog, evt_timelog, rss_data, vsize_data), xml_doc = xmldoc)
285  write_xml(xmldoc, "test_xml_output.xml")
FileNamesHelper.getJobID_fromTimeReportLogName
def getJobID_fromTimeReportLogName
Definition: FileNamesHelper.py:203
parserTimingReport.processModuleTimeLogData
def processModuleTimeLogData
mod_data["stats"] =calc_MinMaxAvgRMS(f_time = lambda x: x["time"], f_evt_num = lambda x: x["event_num...
Definition: parserTimingReport.py:162
MCScenario_CRAFT1_22X.write_xml
def write_xml
Definition: MCScenario_CRAFT1_22X.py:124
cmssw_exportdb_xml.export_xml
def export_xml
Definition: cmssw_exportdb_xml.py:125
def parserTimingReport.processModuleTimeLogData (   modules_timelog,
  groupBy = "module_name" 
)

mod_data["stats"] =calc_MinMaxAvgRMS(f_time = lambda x: x["time"], f_evt_num = lambda x: x["event_number"], items = times_bymod[mod_name]) 

Processes the timelog data grouping events by module and calculates min, max, avg, rms 
Returns data as a list of dicts like: !

 {
    <module_name>: 
        {name:, label:, 
            stats: {num_events, avg, min, max, rms} 
 }

mod_data["stats"]["num_events"] = len(times_bymod[mod_name])

times_bymod[mod_name] = mod_data Let's rewrite this using the dictionary we now have without any logical change (could do with some...):

Definition at line 162 of file parserTimingReport.py.

References python.multivaluedict.append(), calc_MinMaxAvgRMS(), relativeConstraints.keys, and update.

Referenced by manual_run(), perf_profile(), and cmsPerfSuiteHarvest.process_timesize_dir().

162 
163 def processModuleTimeLogData(modules_timelog, groupBy = "module_name"):
164  """ Processes the timelog data grouping events by module and calculates min, max, avg, rms
165  Returns data as a list of dicts like: !
166 
167  {
168  <module_name>:
169  {name:, label:,
170  stats: {num_events, avg, min, max, rms}
171  }
172 
173  """
174  # group by module_name, we save a list for each module name
175  times_bymod = {}
176 
177  # print "Num of useful TimeLog lines: %s" % len(modules_timelog)
178 
179  for time_data in modules_timelog:
180  (event_number, module_label, module_name, seconds) = time_data
181 
182  # group times of modules By label or name, TODO: maybe both
183  if groupBy == "module_label":
184  key = module_label
185  else:
186  if groupBy =="name+label":
187  key = module_name + "_" + module_label
188  else:
189  key = module_name
190 
191 
192  try:
193  # is the list for current module initialized?
194  times_bymod[key]
195  except KeyError:
196  #Changing this from a list to a dict (see comments below):
197  #times_bymod[key] = []
198  times_bymod[key] = {}
199  #Running out of memory!
200  #times_bymod[key].append({"label": module_label, "name": module_name, "time": seconds, "event_number": event_number})
201  #Let's do it right:
202  #Instead of times_bymod[key]=[{"label": module_label, "name": module_name, "time": seconds, "event_number": event_number}]
203  #let's do times_bymod[key]={"module_label":{"module_name":[(seconds,event_number)]}} so we do not repeat label and name and especially they are not a pair of key/value
204  #During the first event all the keys will be initialized, then from event 2 on it will be just appending the (seconds,event_number) tuple to the list with the appropriate keys:
205 
206  #Check/Set up the module label dict:
207  try:
208  times_bymod[key][module_label]
209  except KeyError:
210  times_bymod[key].update({module_label:{}})
211 
212  #Check/Set up the module name dict:
213  try:
214  times_bymod[key][module_label][module_name]
215  except KeyError:
216  times_bymod[key][module_label].update({module_name:[]})
217 
218  #We're now ready to add the info as a tuple in the list!
219  times_bymod[key][module_label][module_name].append((seconds,event_number))
220 
221 
222  # calculate Min,Max, Avg, RMS for each module and in this way get the final data to be imported
223  ##for mod_name in times_bymod.keys():
224  ## #copy needed data
225  ## #mod_data = {"label": times_bymod[mod_name][0]["label"], "name": times_bymod[mod_name][0]["name"]}
226  ## #New data structure:
227  ## mod_data = {"label":times_bymod[mod_name].keys()[0],"name":times_bymod[mod_name][times_bymod[mod_name].keys()[0]].keys()[0]}
228  ## # add statistical data
229  ##
230  ## mod_data["stats"] =calc_MinMaxAvgRMS(f_time = lambda x: x["time"], f_evt_num = lambda x: x["event_number"], items = times_bymod[mod_name])
231  ##
232  ## mod_data["stats"]["num_events"] = len(times_bymod[mod_name])
233  ##
234  ## times_bymod[mod_name] = mod_data
235  #Let's rewrite this using the dictionary we now have without any logical change (could do with some...):
236  for key in times_bymod.keys():
237  for label in times_bymod[key].keys():
238  mod_data={'label':label}
239  for name in times_bymod[key][label].keys():
240  mod_data.update({'name':name})
241  mod_data['stats']= calc_MinMaxAvgRMS(f_time= lambda x:x[0],f_evt_num=lambda x:x[1],items=times_bymod[key][label][name])
242  mod_data['stats']['num_events']=len(times_bymod[key][label][name])
243  times_bymod[key]=mod_data
244  return times_bymod
parserTimingReport.processModuleTimeLogData
def processModuleTimeLogData
mod_data[&quot;stats&quot;] =calc_MinMaxAvgRMS(f_time = lambda x: x[&quot;time&quot;], f_evt_num = lambda x: x[&quot;event_num...
Definition: parserTimingReport.py:162
update
#define update(a, b)
Definition: TrackClassifier.cc:10
Generated for CMSSW Reference Manual by doxygen 1.8.5