Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Benchmarking original #2

Open
wants to merge 2 commits into
base: master
Choose a base branch
from
Open

Benchmarking original #2

Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
fb2f298
Added timers around IO operations for benchmarking purposes.
Mar 9, 2020
260f426
Added benchmarking for original drifttubemonitoring implementation.
raha67 Mar 30, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
165 changes: 154 additions & 11 deletions charmdet/drifttubeMonitoring.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,7 +1,22 @@
#import yep
import ROOT,os,time,sys,operator,atexit
ROOT.gROOT.ProcessLine('typedef std::unordered_map<int, std::unordered_map<int, std::unordered_map<int, std::vector<MufluxSpectrometerHit*>>>> nestedList;')

#---------log for benchmarking-----------------------------------------------------------
import logging
# Define log file to record output of method execution time as benchmarking
log_file = logging.FileHandler(filename='benchmarking.log', mode='a', encoding='utf-8')
fmt = logging.Formatter()
log_file.setFormatter(fmt)

# Define logger and logger type
logger = logging.Logger(name='benchmarking', level=logging.INFO)
logger.addHandler(log_file)
# logger.info is used to write msg to the log file
# Write the log file's header.
logger.info(msg=time.strftime("%Y-%m-%d %H:%M:%S", time.localtime()))
logger.info(msg='Benchmarking start - Record code execution time :')
logger.info(msg='Method_name wall_time cpu_time')
#--------------------------------------------------------------------
from decorators import *
import __builtin__ as builtin
ROOT.gStyle.SetPalette(ROOT.kGreenPink)
Expand Down Expand Up @@ -164,6 +179,11 @@ def pyExit():
daniel = {}
# For T1 and 2, the survey target is placed above/below the endplates, offset in y.
# For T3 it is placed 7cm in front and for T4 7cm behind the endplate, so there is an offset in z

#benchmarking: calculate time for getting daniel and survey conditions data
wall_time_start = time.time()
cpu_time_start = time.clock()

survey['T1_MA_01']=[ 9.0527, 0.2443, 0.7102 ]
daniel['T1_MA_01']=[244.30,531.85,9052.70]
survey['T1_MA_02']=[ 9.0502, -0.2078, 0.7092 ]
Expand Down Expand Up @@ -272,6 +292,10 @@ def pyExit():
survey['RPC5_L']= [ 20.2852, 1.1677, 1.1945 ]
survey['RPC5_R']= [ 20.2891, -1.2614, 1.1943 ]

cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='Get daniel and survey by hard code%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))

Lcorrection={}
# length of the bolt 150mm on the top and 50mm on the bottom
Lcorrection['T1_MA_01'] = -(20.+150.+8.65)/10.
Expand Down Expand Up @@ -4606,6 +4630,10 @@ def debugRPCYCoordinate():
withCorrections=True
if MCdata: withCorrections=False
if withCorrections:
#calculate time for getting alignCorrection
cpu_time_start = time.clock()
wall_time_start = time.time()

alignCorrection[0]=[ 0, 0, 0] # by hand
alignCorrection[1]=[ 0, 0, 0]
alignCorrection[2]=[ 0, 0, 0]
Expand Down Expand Up @@ -4644,6 +4672,10 @@ def debugRPCYCoordinate():
alignCorrection[30]=[ 0.0, 0, 0]
alignCorrection[31]=[ 0.0, 0, 0]

cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='alignCorrection%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))

slopeX = {2:[-0.001,-0.001,-0.001,-0.001],
3:[-0.0048,-0.0048,-0.0048,-0.0048]} # 7Feb
slopeY = {2:[0.0065,0.0065,0.0065,0.0065]}
Expand Down Expand Up @@ -5409,9 +5441,17 @@ def makeAlignmentConstantsPersistent():
vbot,vtop = strawPositionsBotTop[straw]
strawPositionsP[straw]={'top':[vtop[0],vtop[1],vtop[2]],'bot':[vbot[0],vbot[1],vbot[2]]}
alignConstants={'strawPositions':strawPositionsP,'alignCorrection':alignCorrection}
#benchmarking: calculate time required for dumping "alignConstants"
wall_time_start = time.time()
cpu_time_start = time.clock()

pkl = Pickler(ftemp)
pkl.dump(alignConstants,'alignConstants')

cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='add alignConstants to file%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))

def importAlignmentConstants():
global alignConstants
alignConstants = {}
Expand All @@ -5422,14 +5462,24 @@ def importAlignmentConstants():
strawPositionsBotTop[hit.GetDetectorID()]=correctAlignment(hit)
print "importing alignment constants from code"
return
#benchmarking: calculate time required for unpickling "alignConstants"
wall_time_start = time.time()
cpu_time_start = time.clock()
upkl = Unpickler(sTree.GetCurrentFile())
try:
alignConstants = upkl.load('alignConstants')
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='importAlignmentConstants from file%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
print "importing alignment constants from file",sTree.GetCurrentFile().GetName()
strawPosition()
except:
print "loading of alignment constants failed for file",sTree.GetCurrentFile().GetName()
def importRTrel():
#benchmarking: calculate time required for importing RTrelations
wall_time_start = time.time()
cpu_time_start = time.clock()

for fname in fnames:
if len(fnames)==1: f=sTree.GetCurrentFile()
else: f = ROOT.TFile.Open(fname)
Expand All @@ -5444,6 +5494,11 @@ def importRTrel():
except:
print "loading of RT failed for file",rname
if len(fnames)!=1: f.Close()

cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='importRTrel%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))

importRTCorrection()
def importRTCorrection():
pars = {}
Expand Down Expand Up @@ -5507,7 +5562,16 @@ def analyzeRTrel():
zeroFieldData=['SPILLDATA_8000_0515970150_20180715_220030.root']
def init(database='muflux_RTrelations.pkl',remake=False,withReco=False):
global withTDC,RTrelations

wall_time_start = time.time()
cpu_time_start = time.clock()

if os.path.exists(database): RTrelations = pickle.load(open(database))

cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='loading_muflux_RTrelations%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))

N = sTree.GetEntries()
if not RTrelations.has_key(rname) or remake:
withTDC = False
Expand All @@ -5518,8 +5582,17 @@ def init(database='muflux_RTrelations.pkl',remake=False,withReco=False):
RTrelations[rname] = {'tMinAndTmax':h['tMinAndTmax']}
for s in h['tMinAndTmax']: RTrelations[rname]['rt'+s] = h['rt'+s]
fpkl=open(database,'w')

wall_time_start = time.time()
cpu_time_start = time.clock()

pickle.dump(RTrelations,fpkl)
fpkl.close()

cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='writing_muflux_RTrelations%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))

else:
h['tMinAndTmax'] = RTrelations[rname]['tMinAndTmax']
for s in h['tMinAndTmax']: h['rt'+s] = RTrelations[rname]['rt'+s]
Expand Down Expand Up @@ -7626,7 +7699,7 @@ def recoStep0():
RTrelations = {'tMinAndTmax':h['tMinAndTmax']}
for s in h['tMinAndTmax']: RTrelations['rt'+s] = h['rt'+s]
makeRTrelPersistent(RTrelations)
def recoStep1(PR=11):
def recoStep1(PR=11,cpu_time_start=time.clock(), wall_time_start=time.time()):
# make fitted tracks
#disableBranches()
global MCdata
Expand Down Expand Up @@ -7672,9 +7745,13 @@ def recoStep1(PR=11):
ftemp=sTree.GetCurrentFile()
ftemp.Write("",ROOT.TFile.kOverwrite)
ftemp.Close()
print "finished adding fitted tracks",options.listOfFiles
# Benchmarking: calculate time required for executing recoStep1 (start times via function params)
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='recoStep1%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
print "finished adding fitted tracks", options.listOfFiles
print "make suicid"
os.system('kill '+str(os.getpid()))
os.system('kill ' + str(os.getpid()))
def getParOfRTcorrectio():
keys = h.keys()
for x in keys:
Expand All @@ -7685,15 +7762,15 @@ def getParOfRTcorrectio():
txt+=" %7.5F, "%(x)
txt+=']'
print txt.replace(', ]',']')
def recoStep2():
def recoStep2(cpu_time_start, wall_time_start):
# refit tracks with improved RT relation
global MCdata
fGenFitArray = ROOT.TClonesArray("genfit::Track")
fGenFitArray.BypassStreamer(ROOT.kTRUE)
fitTracks = sTree.Branch("FitTracks_refitted", fGenFitArray,32000,-1)
fTrackInfoArray = ROOT.TClonesArray("TrackInfo")
fTrackInfoArray.BypassStreamer(ROOT.kTRUE)
TrackInfos = sTree.Branch("TrackInfos_refitted", fTrackInfoArray,32000,-1)
TrackInfos = sTree.Branch("TrackInfos_refitted", fTrackInfoArray,32000,-1)
if sTree.GetBranch('MCTrack'): MCdata = True
for n in range(sTree.GetEntries()):
if n%10000==0: print "Now at event",n,"of",sTree.GetEntries(),sTree.GetCurrentFile().GetName(),time.ctime()
Expand All @@ -7713,9 +7790,13 @@ def recoStep2():
ftemp=sTree.GetCurrentFile()
ftemp.Write("",ROOT.TFile.kOverwrite)
ftemp.Close()
print "finished adding fitted tracks",options.listOfFiles
# Benchmarking: calculate time required for executing recoStep2 (start times via function params)
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='recoStep2%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
print "finished adding fitted tracks", options.listOfFiles
print "make suicid"
os.system('kill '+str(os.getpid()))
os.system('kill ' + str(os.getpid()))
def recoMuonTaggerTracks():
global MCdata
global sTree
Expand Down Expand Up @@ -7805,7 +7886,9 @@ def anaResiduals():
print " --- printScalers()"
print " --- init(): outdated! do boostrapping, determine RT relation using fitted tracks, do plotBiasedResiduals and plotRPCExtrap with TDC"
print " --- momResolution(), with MC data"

#benchmarking: calculate time required for running drifttubesmonitoring.py without passing any command arguments
cpu_time_start = time.clock()
wall_time_start = time.time()
vetoLayer = []
database='muflux_RTrelations.pkl'
if sTree.GetBranch('MCTrack'):
Expand All @@ -7814,22 +7897,43 @@ def anaResiduals():
elif sTree.GetCurrentFile().GetKey('RT'):
importRTrel()
elif os.path.exists(database):

wall_time_start = time.time()
cpu_time_start = time.clock()

RTrelations = pickle.load(open(database))

cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='loading_RTrelations%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))

if not RTrelations.has_key(rname):
print "You should run init() to determine the RT relations or use _RT file"
else:
h['tMinAndTmax'] = RTrelations[rname]['tMinAndTmax']
for s in h['tMinAndTmax']: h['rt'+s] = RTrelations[rname]['rt'+s]
withCorrections = False
importAlignmentConstants()
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='NoCommand%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
#
if options.command == "recoStep0":
#benchmarking: calculate time required for running recoStep0
cpu_time_start = time.clock()
wall_time_start = time.time()
withTDC=False
print "make clean TDC distributions"
importAlignmentConstants()
recoStep0()
print "finished making RT relations"
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='recoStep0%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
elif options.command == "recoStep1":
#benchmarking: calculate time required for running this script by passing recoStep1 as argument
cpu_time_start = time.clock()
wall_time_start = time.time()
if sTree.GetBranch('MCTrack'):
MCdata = True
withDefaultAlignment = True
Expand All @@ -7843,8 +7947,11 @@ def anaResiduals():
withCorrections = True
print "add fitted tracks"
importAlignmentConstants()
recoStep1(PR=11)
recoStep1(PR=11,cpu_time_start = cpu_time_start, wall_time_start = wall_time_start)
elif options.command == "recoStep2":
#benchmarking: calculate time required for running this script by passing recoStep2 as argument
cpu_time_start = time.clock()
wall_time_start = time.time()
if sTree.GetBranch('MCTrack'):
MCdata = True
withDefaultAlignment = True
Expand All @@ -7858,8 +7965,11 @@ def anaResiduals():
withCorrections = True
print "add refitted tracks"
importAlignmentConstants()
recoStep2()
recoStep2(cpu_time_start, wall_time_start)
elif options.command == "anaResiduals":
#benchmarking: calculate time required for running this script by "anaResiduals" argument as command
cpu_time_start = time.clock()
wall_time_start = time.time()
ROOT.gROOT.SetBatch(True)
if sTree.GetEntries()>0:
if sTree.GetBranch('MCTrack'):
Expand All @@ -7871,7 +7981,13 @@ def anaResiduals():
anaResiduals()
print "finished with analysis step",options.listOfFiles
else: print "no events, exit ",sTree.GetCurrentFile()
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='anaResiduals%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
elif options.command == "alignment":
#benchmarking: calculate time required for running this script by "alignment" argument as command
cpu_time_start = time.clock()
wall_time_start = time.time()
ROOT.gROOT.SetBatch(True)
if sTree.GetBranch('MCTrack'):
MCdata = True
Expand All @@ -7888,22 +8004,43 @@ def anaResiduals():
plotBiasedResiduals(PR=13,minP=10)
ut.writeHists(h,'histos-residuals-'+rname)
hitMapsFromFittedTracks()
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='alignment%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
elif options.command == "plotResiduals":
#benchmarking: calculate time required for running this script by "plotResiduals" argument as command
cpu_time_start = time.clock()
wall_time_start = time.time()
print "reading histograms with residuals"
ut.readHists(h,options.listOfFiles)
plotBiasedResiduals(onlyPlotting=True)
if h.has_key('RPCResY_10'):
plotRPCExtrap(onlyPlotting=True)
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='plotResiduals%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
elif options.command == "recoMuonTaggerTracks":
#benchmarking: calculate time required for running this script by "recoMuonTaggerTracks" argument as command
cpu_time_start = time.clock()
wall_time_start = time.time()
importAlignmentConstants()
recoMuonTaggerTracks()
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='recoMuonTaggerTracks%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
elif options.command == "momResolution":
#benchmarking: calculate time required for running this script by "momResolution" argument as command
cpu_time_start = time.clock()
wall_time_start = time.time()
MCdata = True
withDefaultAlignment = True
sigma_spatial = 0.25
withCorrections = False
importAlignmentConstants()
momResolution(PR=1,onlyPlotting=False)
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='momResolution%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
elif options.command == "splitOffBoostedEvents": splitOffBoostedEvents()
elif options.command == "countTracks": countTracks()
elif options.command == "plotDTPoints": plotDTPoints()
Expand All @@ -7919,6 +8056,9 @@ def anaResiduals():
elif options.command == "MCJpsiProd":
MCJpsiProd()
elif options.command == "test":
#benchmarking: calculate time required for running this script by "test" argument as command
cpu_time_start = time.clock()
wall_time_start = time.time()
yep.start('output.prof')
for x in sTree.GetListOfBranches(): sTree.SetBranchStatus(x.GetName(),0)
# sTree.SetBranchStatus('RPCTrackY',1)
Expand All @@ -7927,4 +8067,7 @@ def anaResiduals():
rc=sTree.GetEvent(n)
yep.stop()
print "finished"
cpu_time_end = time.clock()
wall_time_end = time.time()
logger.info(msg='test%15.6f%13.6f' % (wall_time_end - wall_time_start, cpu_time_end - cpu_time_start))
#alignConstants.pop('strawPositions') # if recorded alignment constants should not be used.