def testBlock(self):
log = BlockTimingLog(self.log, "test")
log.setThreshold(BlockTimingLog.INSTRUM)
btl = log.createForBlock("api")
btl.log(Log.INFO, "message")
btl.done()
del btl
def testBlock(self):
log = BlockTimingLog(self.log, "test")
log.setThreshold(BlockTimingLog.INSTRUM)
btl = log.createForBlock("api")
btl.log(Log.INFO, "message")
btl.done()
del btl
class BlockTimingLogTestCase(unittest.TestCase):
def setUp(self):
self.log = BlockTimingLog(Log.getDefaultLog(), "test")
def tearDown(self):
del self.log
def testINSTRUMValue(self):
self.assertEqual(BlockTimingLog.INSTRUM, -3)
def testCreate(self):
btl = self.log.createForBlock("api")
self.assertEqual(btl.getInstrumentationLevel(), BlockTimingLog.INSTRUM)
self.assertEqual(btl.getFunctionName(), "api")
btl = self.log.createForBlock("api", BlockTimingLog.INSTRUM+1)
self.assertEqual(btl.getInstrumentationLevel(), -2)
def testBlock(self):
log = BlockTimingLog(self.log, "test")
log.setThreshold(BlockTimingLog.INSTRUM)
btl = log.createForBlock("api")
btl.log(Log.INFO, "message")
btl.done()
del btl
def testStart(self):
log = BlockTimingLog(self.log, "test")
log.setThreshold(BlockTimingLog.INSTRUM)
log.start("Test run")
log.done()
def testSysData(self):
lr = LogRecord(0, 0, True)
self.log.setUsageFlags(self.log.SUTIME)
self.log.addUsageProps(lr)
ps = lr.getProperties()
self.assertTrue(ps.exists("usertime"))
self.assertTrue(ps.exists("systemtime"))
self.assertFalse(ps.exists("nswap"))
lr = LogRecord(0, 0, True)
self.log.setUsageFlags(self.log.ALLUDATA)
self.log.addUsageProps(lr)
ps = lr.getProperties()
self.assertTrue(ps.exists("usertime"))
self.assertTrue(ps.exists("systemtime"))
self.assertTrue(ps.exists("maxrss"))
self.assertTrue(ps.exists("nswap"))
self.assertTrue(ps.exists("blocksin"))
self.assertTrue(ps.exists("blocksout"))
def initializeQueues(self):
"""
Initialize the Queue List
"""
log = Log(self.log, "initializeQueues")
queuelog = BlockTimingLog(self.log, "initializeQueues", self.TRACE)
queuelog.start()
for iQueue in range(1, self.nStages+1+1):
queue = Queue()
self.queueList.append(queue)
queuelog.done()
class BlockTimingLogTestCase(unittest.TestCase):
def setUp(self):
self.log = BlockTimingLog(Log.getDefaultLog(), "test")
def tearDown(self):
del self.log
def testINSTRUMValue(self):
self.assertEqual(BlockTimingLog.INSTRUM, -3)
def testCreate(self):
btl = self.log.createForBlock("api")
self.assertEqual(btl.getInstrumentationLevel(), BlockTimingLog.INSTRUM)
self.assertEqual(btl.getFunctionName(), "api")
btl = self.log.createForBlock("api", BlockTimingLog.INSTRUM + 1)
self.assertEqual(btl.getInstrumentationLevel(), -2)
def testBlock(self):
log = BlockTimingLog(self.log, "test")
log.setThreshold(BlockTimingLog.INSTRUM)
btl = log.createForBlock("api")
btl.log(Log.INFO, "message")
btl.done()
del btl
def testStart(self):
log = BlockTimingLog(self.log, "test")
log.setThreshold(BlockTimingLog.INSTRUM)
log.start("Test run")
log.done()
def testSysData(self):
lr = LogRecord(0, 0, True)
self.log.setUsageFlags(self.log.SUTIME)
self.log.addUsageProps(lr)
ps = lr.getProperties()
self.assertTrue(ps.exists("usertime"))
self.assertTrue(ps.exists("systemtime"))
self.assertFalse(ps.exists("nswap"))
lr = LogRecord(0, 0, True)
self.log.setUsageFlags(self.log.ALLUDATA)
self.log.addUsageProps(lr)
ps = lr.getProperties()
self.assertTrue(ps.exists("usertime"))
self.assertTrue(ps.exists("systemtime"))
self.assertTrue(ps.exists("maxrss"))
self.assertTrue(ps.exists("nswap"))
self.assertTrue(ps.exists("blocksin"))
self.assertTrue(ps.exists("blocksout"))
def _inputSetup(stage):
"""Set up an InputStage."""
if not stage.log:
stage.log = BlockTimingLog(Log.getDefaultLog(),
"pex.harness.iostage.input")
else:
stage.log = BlockTimingLog(stage.log, "iostage.input")
defaultFile = pexPolicy.DefaultPolicyFile("pex_harness",
"InputStageDictionary.paf",
"policy")
defaults = pexPolicy.Policy.createPolicy(defaultFile,
defaultFile.getRepositoryPath())
stage.policy.mergeDefaults(defaults)
if stage.policy.exists('parameters.butler'):
stage.butler = _makeButler(stage.policy)
else:
stage.butler = None
def _read(item, cppType, pythonType, storageInfo, additionalData, persistence,
log):
# Create a list of Storages for the item based on policy.
storageList = dafPersist.StorageList()
for storageName, location in storageInfo:
logLoc = dafPersist.LogicalLocation(location, additionalData)
if not logLoc.locString().startswith("mysql:"):
_waitForPath(logLoc.locString(), log)
log.log(Log.INFO - 1,
"loading %s from %s" % (item, logLoc.locString()))
storage = persistence.getRetrieveStorage(storageName, logLoc)
storageList.append(storage)
iolog = BlockTimingLog(log, "read_without_butler", Log.INFO - 1)
iolog.start("load of %s" % (item, ))
# Retrieve the item.
itemData = persistence.unsafeRetrieve(cppType, storageList, additionalData)
# Cast the SWIGged Persistable to a more useful type.
cvt = getattr(pythonType, "swigConvert")
finalItem = cvt(itemData)
iolog.done()
# If Persistable and subclasses are NOT wrapped using SWIG_SHARED_PTR,
# then one must make sure that the wrapper for the useful type owns
# the pointer (rather than the wrapper for the original Persistable).
# The following lines accomplish this:
#itemData.this.disown()
#finalItem.this.acquire()
# Put the item on the clipboard
return finalItem
def initializeStages(self):
"""
Initialize the Stage List
"""
log = Log(self.log, "initializeStages")
istageslog = BlockTimingLog(self.log, "initializeStages", self.TRACE)
istageslog.start()
for iStage in range(1, self.nStages+1):
# Make a Policy object for the Stage Policy file
stagePolicy = self.stagePolicyList[iStage-1]
# Make an instance of the specifies Application Stage
# Use a constructor with the Policy as an argument
StageClass = self.stageClassList[iStage-1]
sysdata = {}
# sysdata["name"] = self._pipelineName
sysdata["name"] = self.stageNames[iStage-1]
sysdata["rank"] = self._rank
sysdata["stageId"] = iStage
sysdata["universeSize"] = self.universeSize
sysdata["runId"] = self._runId
# Here
if (stagePolicy != "None"):
stageObject = StageClass(stagePolicy, self.log, self.eventBrokerHost, sysdata)
# (self, policy=None, log=None, eventBroker=None, sysdata=None, callSetup=True):
else:
stageObject = StageClass(None, self.log, self.eventBrokerHost, sysdata)
inputQueue = self.queueList[iStage-1]
outputQueue = self.queueList[iStage]
# stageObject.setLookup(self._lookup)
stageObject.initialize(outputQueue, inputQueue)
self.stageList.append(stageObject)
istageslog.done()
def initializeQueues(self):
"""
Initialize the Queue List
"""
log = Log(self.log, "initializeQueues")
queuelog = BlockTimingLog(self.log, "initializeQueues", self.TRACE)
queuelog.start()
for iQueue in range(1, self.nStages + 1 + 1):
queue = Queue()
self.queueList.append(queue)
queuelog.done()
def initializeStages(self):
"""
Initialize the Stage List
"""
log = Log(self.log, "initializeStages")
istageslog = BlockTimingLog(self.log, "initializeStages", self.TRACE)
istageslog.start()
for iStage in range(1, self.nStages + 1):
# Make a Policy object for the Stage Policy file
stagePolicy = self.stagePolicyList[iStage - 1]
# Make an instance of the specifies Application Stage
# Use a constructor with the Policy as an argument
StageClass = self.stageClassList[iStage - 1]
sysdata = {}
# sysdata["name"] = self._pipelineName
sysdata["name"] = self.stageNames[iStage - 1]
sysdata["rank"] = self._rank
sysdata["stageId"] = iStage
sysdata["universeSize"] = self.universeSize
sysdata["runId"] = self._runId
# Here
if (stagePolicy != "None"):
stageObject = StageClass(stagePolicy, self.log,
self.eventBrokerHost, sysdata)
# (self, policy=None, log=None, eventBroker=None, sysdata=None, callSetup=True):
else:
stageObject = StageClass(None, self.log, self.eventBrokerHost,
sysdata)
inputQueue = self.queueList[iStage - 1]
outputQueue = self.queueList[iStage]
# stageObject.setLookup(self._lookup)
stageObject.initialize(outputQueue, inputQueue)
self.stageList.append(stageObject)
istageslog.done()
# Create the queues
q1 = lsst.pex.harness.Queue.Queue()
q2 = lsst.pex.harness.Queue.Queue()
q3 = lsst.pex.harness.Queue.Queue()
q4 = lsst.pex.harness.Queue.Queue()
sysdata = {}
sysdata["name"] = "testPipeline"
sysdata["rank"] = 0
sysdata["stageId"] = 1
sysdata["universeSize"] = 100
sysdata["runId"] = "testrun"
eventBrokerHost = "lsst4.ncsa.uiuc.edu"
ScreenLog.createDefaultLog(True)
log = BlockTimingLog(Log.getDefaultLog(), "TestIO", BlockTimingLog.INSTRUM)
log.setUsageFlags(log.ALLUDATA)
log.setThreshold(log.DEBUG)
log.log(log.INFO, "hello")
# Create and initialize the stages
outputStage = lsst.pex.harness.IOStage.OutputStageParallel(outputPolicy, log, eventBrokerHost, sysdata)
outputStage.initialize(q2, q1)
sysdata["rank"] = -1
inputStage = lsst.pex.harness.IOStage.InputStageSerial(inputPolicy, log, eventBrokerHost, sysdata)
inputStage.initialize(q4, q3)
# Note: no direct connection between the stages!
# Create the event PropertySet
event = lsst.daf.base.PropertySet()
def testStart(self):
log = BlockTimingLog(self.log, "test")
log.setThreshold(BlockTimingLog.INSTRUM)
log.start("Test run")
log.done()
def setUp(self):
self.log = BlockTimingLog(Log.getDefaultLog(), "test")
def startStagesLoop(self):
"""
Method to execute loop over Stages
"""
startStagesLoopLog = self.log.timeBlock("startStagesLoop", self.TRACE)
looplog = BlockTimingLog(self.log, "visit", self.TRACE)
stagelog = BlockTimingLog(looplog, "stage", self.TRACE - 1)
proclog = BlockTimingLog(stagelog, "process", self.TRACE)
visitcount = 0
self.threadBarrier(0)
while True:
if (((self.executionMode == 1) and (visitcount == 1))):
LogRec(
looplog,
Log.INFO) << "terminating pipeline after one loop/visit "
#
# Need to shutdown Threads here
#
break
else:
visitcount += 1
looplog.setPreamblePropertyInt("LOOPNUM", visitcount)
looplog.start()
stagelog.setPreamblePropertyInt("LOOPNUM", visitcount)
proclog.setPreamblePropertyInt("LOOPNUM", visitcount)
# self.cppPipeline.invokeContinue()
self.startInitQueue(
) # place an empty clipboard in the first Queue
self.errorFlagged = 0
for iStage in range(1, self.nStages + 1):
stagelog.setPreamblePropertyInt("STAGEID", iStage)
stagelog.start(self.stageNames[iStage - 1] + " loop")
proclog.setPreamblePropertyInt("STAGEID", iStage)
stage = self.stageList[iStage - 1]
self.handleEvents(iStage, stagelog)
# synchronize before preprocess
self.threadBarrier(iStage)
self.tryPreProcess(iStage, stage, stagelog)
# synchronize after preprocess, before process
self.threadBarrier(iStage)
# synchronize after process, before postprocess
self.threadBarrier(iStage)
self.tryPostProcess(iStage, stage, stagelog)
# synchronize after postprocess
self.threadBarrier(iStage)
stagelog.done()
self.checkExitByStage()
else:
looplog.log(self.VERB2, "Completed Stage Loop")
self.checkExitByVisit()
# Uncomment to print a list of Citizens after each visit
# print datap.Citizen_census(0,0), "Objects:"
# print datap.Citizen_census(datap.cout,0)
looplog.log(Log.DEBUG, 'Retrieving finalClipboard for deletion')
finalQueue = self.queueList[self.nStages]
finalClipboard = finalQueue.getNextDataset()
looplog.log(Log.DEBUG, "deleting final clipboard")
looplog.done()
# delete entries on the clipboard
finalClipboard.close()
del finalClipboard
startStagesLoopLog.log(Log.INFO, "Shutting down pipeline")
self.shutdown()
startStagesLoopLog.done()
def configureSlice(self):
"""
Configure the slice via reading a Policy file
"""
log = Log(self.log, "configureSlice")
conflog = BlockTimingLog(self.log, "configureSlice", self.TRACE)
conflog.start()
stgcfg = self.executePolicy.getArray("appStage")
self.stageNames = []
for subpol in stgcfg:
stageName = subpol.get("name")
self.stageNames.append(stageName)
self.executePolicy.loadPolicyFiles()
# Obtain the working directory space locators
psLookup = lsst.daf.base.PropertySet()
if (self.executePolicy.exists('dir')):
dirPolicy = self.executePolicy.get('dir')
shortName = None
if (dirPolicy.exists('shortName')):
shortName = dirPolicy.get('shortName')
if shortName == None:
shortName = self.pipelinePolicyName.split('.')[0]
dirs = Directories(dirPolicy, shortName, self._runId)
psLookup = dirs.getDirs()
if (self.executePolicy.exists('database.url')):
psLookup.set('dbUrl', self.executePolicy.get('database.url'))
LogRec(log, self.VERB1) << "Configuring Slice" \
<< Prop("universeSize", self.universeSize) \
<< Prop("runID", self._runId) \
<< Prop("rank", self._rank) \
<< LogRec.endr;
# Configure persistence logical location map with values for directory
# work space locators
dafPersist.LogicalLocation.setLocationMap(psLookup)
# Check for eventTimeout
if (self.executePolicy.exists('eventTimeout')):
self.eventTimeout = self.executePolicy.getInt('eventTimeout')
else:
self.eventTimeout = 10000000 # default value
# Process Application Stages
fullStageList = self.executePolicy.getArray("appStage")
self.nStages = len(fullStageList)
log.log(self.VERB2, "Found %d stages" % len(fullStageList))
# extract the stage class name and associated policy file.
fullStageNameList = [ ]
self.stagePolicyList = [ ]
for stagei in xrange(self.nStages):
fullStagePolicy = fullStageList[stagei]
if (fullStagePolicy.exists('parallelClass')):
parallelName = fullStagePolicy.getString('parallelClass')
stagePolicy = fullStagePolicy.get('stagePolicy')
else:
parallelName = "lsst.pex.harness.stage.NoOpParallelProcessing"
stagePolicy = None
fullStageNameList.append(parallelName)
self.stagePolicyList.append(stagePolicy)
if self.stageNames[stagei] is None:
self.stageNames[stagei] = fullStageNameList[-1].split('.')[-1]
log.log(self.VERB3,
"Stage %d: %s: %s" % (stagei+1, self.stageNames[stagei],
fullStageNameList[-1]))
for astage in fullStageNameList:
fullStage = astage.strip()
tokenList = astage.split('.')
classString = tokenList.pop()
classString = classString.strip()
package = ".".join(tokenList)
# For example package -> lsst.pex.harness.App1Stage classString -> App1Stage
AppStage = __import__(package, globals(), locals(), [classString], -1)
StageClass = getattr(AppStage, classString)
self.stageClassList.append(StageClass)
log.log(self.VERB2, "Imported Stage Classes")
#
# Configure the Failure Stage
# - Read the policy information
# - Import failure stage Class and make failure stage instance Object
#
self.failureStageName = None
self.failParallelName = None
if (self.executePolicy.exists('failureStage')):
failstg = self.executePolicy.get("failureStage")
self.failureStageName = failstg.get("name")
if (failstg.exists('parallelClass')):
self.failParallelName = failstg.getString('parallelClass')
failStagePolicy = failstg.get('stagePolicy')
else:
self.failParallelName = "lsst.pex.harness.stage.NoOpParallelProcessing"
failStagePolicy = None
astage = self.failParallelName
tokenList = astage.split('.')
failClassString = tokenList.pop()
failClassString = failClassString.strip()
package = ".".join(tokenList)
# For example package -> lsst.pex.harness.App1Stage classString -> App1Stage
FailAppStage = __import__(package, globals(), locals(), [failClassString], -1)
FailStageClass = getattr(FailAppStage, failClassString)
sysdata = {}
# sysdata["name"] = self._pipelineName
sysdata["name"] = self.failureStageName
sysdata["rank"] = self._rank
sysdata["stageId"] = -1
sysdata["universeSize"] = self.universeSize
sysdata["runId"] = self._runId
if (failStagePolicy != None):
self.failStageObject = FailStageClass(failStagePolicy, self.log, self.eventBrokerHost, sysdata)
# (self, policy=None, log=None, eventBroker=None, sysdata=None, callSetup=True):
else:
self.failStageObject = FailStageClass(None, self.log, self.eventBrokerHost, sysdata)
log.log(self.VERB2, "failureStage %s " % self.failureStageName)
log.log(self.VERB2, "failParallelName %s " % self.failParallelName)
# Process Event Topics
self.eventTopicList = [ ]
self.sliceEventTopicList = [ ]
for item in fullStageList:
self.eventTopicList.append(item.getString("eventTopic"))
self.sliceEventTopicList.append(item.getString("eventTopic"))
# Check for executionMode of oneloop
if (self.executePolicy.exists('executionMode') and (self.executePolicy.getString('executionMode') == "oneloop")):
self.executionMode = 1
# Process Share Data Schedule
self.shareDataList = []
for item in fullStageList:
shareDataStage = False
if (item.exists('shareData')):
shareDataStage = item.getBool('shareData')
self.shareDataList.append(shareDataStage)
log.log(self.VERB3, "Loading in %d trigger topics" % \
len(filter(lambda x: x != "None", self.eventTopicList)))
for iStage in xrange(len(self.eventTopicList)):
item = self.eventTopicList[iStage]
if self.eventTopicList[iStage] != "None":
log.log(self.VERB3, "eventTopic%d: %s" % (iStage+1, item))
else:
log.log(Log.DEBUG, "eventTopic%d: %s" % (iStage+1, item))
count = 0
for item in self.eventTopicList:
newitem = "%s_%s" % (item, self._pipelineName)
self.sliceEventTopicList[count] = newitem
count += 1
eventsSystem = events.EventSystem.getDefaultEventSystem()
for topic in self.sliceEventTopicList:
if (topic == "None_" + self._pipelineName):
pass
else:
eventsSystem.createReceiver(self.eventBrokerHost, topic)
log.log(self.VERB3, "Creating receiver %s" % (topic))
conflog.done()
log.log(self.VERB1, "Slice configuration complete");
def startStagesLoop(self):
"""
Method to execute loop over Stages
"""
startStagesLoopLog = self.log.timeBlock("startStagesLoop", self.TRACE)
looplog = BlockTimingLog(self.log, "visit", self.TRACE)
stagelog = BlockTimingLog(looplog, "stage", self.TRACE-1)
proclog = BlockTimingLog(stagelog, "process", self.TRACE)
visitcount = 0
self.threadBarrier(0)
while True:
if (((self.executionMode == 1) and (visitcount == 1))):
LogRec(looplog, Log.INFO) << "terminating pipeline after one loop/visit "
#
# Need to shutdown Threads here
#
break
else:
visitcount += 1
looplog.setPreamblePropertyInt("LOOPNUM", visitcount)
looplog.start()
stagelog.setPreamblePropertyInt("LOOPNUM", visitcount)
proclog.setPreamblePropertyInt("LOOPNUM", visitcount)
# self.cppPipeline.invokeContinue()
self.startInitQueue() # place an empty clipboard in the first Queue
self.errorFlagged = 0
for iStage in range(1, self.nStages+1):
stagelog.setPreamblePropertyInt("STAGEID", iStage)
stagelog.start(self.stageNames[iStage-1] + " loop")
proclog.setPreamblePropertyInt("STAGEID", iStage)
stage = self.stageList[iStage-1]
self.handleEvents(iStage, stagelog)
# synchronize before preprocess
self.threadBarrier(iStage)
self.tryPreProcess(iStage, stage, stagelog)
# synchronize after preprocess, before process
self.threadBarrier(iStage)
# synchronize after process, before postprocess
self.threadBarrier(iStage)
self.tryPostProcess(iStage, stage, stagelog)
# synchronize after postprocess
self.threadBarrier(iStage)
stagelog.done()
self.checkExitByStage()
else:
looplog.log(self.VERB2, "Completed Stage Loop")
self.checkExitByVisit()
# Uncomment to print a list of Citizens after each visit
# print datap.Citizen_census(0,0), "Objects:"
# print datap.Citizen_census(datap.cout,0)
looplog.log(Log.DEBUG, 'Retrieving finalClipboard for deletion')
finalQueue = self.queueList[self.nStages]
finalClipboard = finalQueue.getNextDataset()
looplog.log(Log.DEBUG, "deleting final clipboard")
looplog.done()
# delete entries on the clipboard
finalClipboard.close()
del finalClipboard
startStagesLoopLog.log(Log.INFO, "Shutting down pipeline");
self.shutdown()
startStagesLoopLog.done()
# Create the queues
q1 = lsst.pex.harness.Queue.Queue()
q2 = lsst.pex.harness.Queue.Queue()
q3 = lsst.pex.harness.Queue.Queue()
q4 = lsst.pex.harness.Queue.Queue()
sysdata = {}
sysdata["name"] = "testPipeline"
sysdata["rank"] = 0
sysdata["stageId"] = 1
sysdata["universeSize"] = 100
sysdata["runId"] = "testrun"
eventBrokerHost = "lsst4.ncsa.uiuc.edu"
ScreenLog.createDefaultLog(True)
log = BlockTimingLog(Log.getDefaultLog(), "TestIO", BlockTimingLog.INSTRUM)
log.setUsageFlags(log.ALLUDATA)
log.setThreshold(log.DEBUG)
log.log(log.INFO, "hello")
# Create and initialize the stages
outputStage = lsst.pex.harness.IOStage.OutputStageParallel(
outputPolicy, log, eventBrokerHost, sysdata)
outputStage.initialize(q2, q1)
sysdata["rank"] = -1
inputStage = lsst.pex.harness.IOStage.InputStageSerial(inputPolicy, log,
eventBrokerHost,
sysdata)
inputStage.initialize(q4, q3)
# Note: no direct connection between the stages!
def startStagesLoop(self):
"""
Execute the Stage loop. The loop progressing in step with
the analogous stage loop in the central Pipeline by means of
MPI Bcast and Barrier calls.
"""
startStagesLoopLog = self.log.timeBlock("startStagesLoop", self.TRACE)
looplog = BlockTimingLog(self.log, "visit", self.TRACE)
stagelog = BlockTimingLog(looplog, "stage", self.TRACE)
self.log.log(Log.INFO, "Begin startStagesLoopLog")
self.threadBarrier()
visitcount = 0
while True:
self.log.log(
Log.INFO,
"visitcount %d %s " % (visitcount, datetime.datetime.now()))
if ((self.executionMode == 1) and (visitcount == 1)):
LogRec(looplog, Log.INFO) << "terminating Slice Stage Loop "
# self.cppPipeline.invokeShutdown()
break
visitcount += 1
looplog.setPreamblePropertyInt("LOOPNUM", visitcount)
stagelog.setPreamblePropertyInt("LOOPNUM", visitcount)
# stagelog.setPreamblePropertyInt("stagename", visitcount)
timesVisitStart = os.times()
# looplog.setPreamblePropertyFloat("usertime", timesVisitStart[0])
# looplog.setPreamblePropertyFloat("systemtime", timesVisitStart[1])
looplog.setPreamblePropertyDouble("usertime", timesVisitStart[0])
looplog.setPreamblePropertyDouble("systemtime", timesVisitStart[1])
looplog.start()
self.startInitQueue(
) # place an empty clipboard in the first Queue
self.errorFlagged = 0
for iStage in range(1, self.nStages + 1):
stagelog.setPreamblePropertyInt("STAGEID", iStage)
stagelog.setPreamblePropertyString("stagename",
self.stageNames[iStage - 1])
stagelog.start(self.stageNames[iStage - 1] + " loop")
stagelog.log(Log.INFO,
"Begin stage loop iteration iStage %d " % iStage)
stageObject = self.stageList[iStage - 1]
self.handleEvents(iStage, stagelog)
# synchronize before preprocess
self.threadBarrier()
# synchronize after preprocess, before process
self.threadBarrier()
self.tryProcess(iStage, stageObject, stagelog)
# synchronize after process, before postprocess
self.threadBarrier()
# synchronize after postprocess
self.threadBarrier()
stagelog.log(self.TRACE,
"End stage loop iteration iStage %d " % iStage)
stagelog.log(
Log.INFO, "End stage loop iteration : ErrorCheck \
iStage %d stageName %s errorFlagged_%d " %
(iStage, self.stageNames[iStage - 1], self.errorFlagged))
stagelog.done()
looplog.log(self.VERB2, "Completed Stage Loop")
# If no error/exception was flagged, then clear the final Clipboard in the final Queue
if self.errorFlagged == 0:
looplog.log(Log.DEBUG,
"Retrieving final Clipboard for deletion")
finalQueue = self.queueList[self.nStages]
finalClipboard = finalQueue.getNextDataset()
finalClipboard.close()
del finalClipboard
looplog.log(Log.DEBUG, "Deleted final Clipboard")
else:
looplog.log(self.VERB3, "Error flagged on this visit")
timesVisitDone = os.times()
utime = timesVisitDone[0] - timesVisitStart[0]
stime = timesVisitDone[1] - timesVisitStart[1]
wtime = timesVisitDone[4] - timesVisitStart[4]
totalTime = utime + stime
looplog.log(
Log.INFO,
"visittimes : utime %.4f stime %.4f total %.4f wtime %.4f" %
(utime, stime, totalTime, wtime))
# looplog.setPreamblePropertyFloat("usertime", timesVisitDone[0])
# looplog.setPreamblePropertyFloat("systemtime", timesVisitDone[1])
looplog.setPreamblePropertyDouble("usertime", timesVisitDone[0])
looplog.setPreamblePropertyDouble("systemtime", timesVisitDone[1])
looplog.done()
try:
memmsg = "mem:"
with open("/proc/%d/status" % os.getpid(), "r") as f:
for l in f:
m = re.match(r'Vm(Size|RSS|Peak|HWM):\s+(\d+ \wB)', l)
if m:
memmsg += " %s=%s" % m.groups()
looplog.log(Log.INFO, memmsg)
except:
pass
# LogRec(looplog, Log.INFO) << Prop("usertime", utime) \
# << Prop("systemtime", stime) \
# << LogRec.endr;
startStagesLoopLog.done()
def _trace(self, where, lev=TRACE):
out = BlockTimingLog(self.log, where, lev)
out.start()
return out
def _trace(self, where, lev=TRACE):
out = BlockTimingLog(self.log, where, lev)
out.start()
return out
def testStart(self):
log = BlockTimingLog(self.log, "test")
log.setThreshold(BlockTimingLog.INSTRUM)
log.start("Test run")
log.done()
def setUp(self):
self.log = BlockTimingLog(Log.getDefaultLog(), "test")
def configureSlice(self):
"""
Configure the slice via reading a Policy file
"""
log = Log(self.log, "configureSlice")
conflog = BlockTimingLog(self.log, "configureSlice", self.TRACE)
conflog.start()
stgcfg = self.executePolicy.getArray("appStage")
self.stageNames = []
for subpol in stgcfg:
stageName = subpol.get("name")
self.stageNames.append(stageName)
self.executePolicy.loadPolicyFiles()
# Obtain the working directory space locators
psLookup = lsst.daf.base.PropertySet()
if (self.executePolicy.exists('dir')):
dirPolicy = self.executePolicy.get('dir')
shortName = None
if (dirPolicy.exists('shortName')):
shortName = dirPolicy.get('shortName')
if shortName == None:
shortName = self.pipelinePolicyName.split('.')[0]
dirs = Directories(dirPolicy, shortName, self._runId)
psLookup = dirs.getDirs()
if (self.executePolicy.exists('database.url')):
psLookup.set('dbUrl', self.executePolicy.get('database.url'))
LogRec(log, self.VERB1) << "Configuring Slice" \
<< Prop("universeSize", self.universeSize) \
<< Prop("runID", self._runId) \
<< Prop("rank", self._rank) \
<< LogRec.endr
# Configure persistence logical location map with values for directory
# work space locators
dafPersist.LogicalLocation.setLocationMap(psLookup)
# Check for eventTimeout
if (self.executePolicy.exists('eventTimeout')):
self.eventTimeout = self.executePolicy.getInt('eventTimeout')
else:
self.eventTimeout = 10000000 # default value
# Process Application Stages
fullStageList = self.executePolicy.getArray("appStage")
self.nStages = len(fullStageList)
log.log(self.VERB2, "Found %d stages" % len(fullStageList))
# extract the stage class name and associated policy file.
fullStageNameList = []
self.stagePolicyList = []
for stagei in xrange(self.nStages):
fullStagePolicy = fullStageList[stagei]
if (fullStagePolicy.exists('parallelClass')):
parallelName = fullStagePolicy.getString('parallelClass')
stagePolicy = fullStagePolicy.get('stagePolicy')
else:
parallelName = "lsst.pex.harness.stage.NoOpParallelProcessing"
stagePolicy = None
fullStageNameList.append(parallelName)
self.stagePolicyList.append(stagePolicy)
if self.stageNames[stagei] is None:
self.stageNames[stagei] = fullStageNameList[-1].split('.')[-1]
log.log(
self.VERB3, "Stage %d: %s: %s" %
(stagei + 1, self.stageNames[stagei], fullStageNameList[-1]))
for astage in fullStageNameList:
fullStage = astage.strip()
tokenList = astage.split('.')
classString = tokenList.pop()
classString = classString.strip()
package = ".".join(tokenList)
# For example package -> lsst.pex.harness.App1Stage classString -> App1Stage
AppStage = __import__(package, globals(), locals(), [classString],
-1)
StageClass = getattr(AppStage, classString)
self.stageClassList.append(StageClass)
log.log(self.VERB2, "Imported Stage Classes")
#
# Configure the Failure Stage
# - Read the policy information
# - Import failure stage Class and make failure stage instance Object
#
self.failureStageName = None
self.failParallelName = None
if (self.executePolicy.exists('failureStage')):
failstg = self.executePolicy.get("failureStage")
self.failureStageName = failstg.get("name")
if (failstg.exists('parallelClass')):
self.failParallelName = failstg.getString('parallelClass')
failStagePolicy = failstg.get('stagePolicy')
else:
self.failParallelName = "lsst.pex.harness.stage.NoOpParallelProcessing"
failStagePolicy = None
astage = self.failParallelName
tokenList = astage.split('.')
failClassString = tokenList.pop()
failClassString = failClassString.strip()
package = ".".join(tokenList)
# For example package -> lsst.pex.harness.App1Stage classString -> App1Stage
FailAppStage = __import__(package, globals(), locals(),
[failClassString], -1)
FailStageClass = getattr(FailAppStage, failClassString)
sysdata = {}
# sysdata["name"] = self._pipelineName
sysdata["name"] = self.failureStageName
sysdata["rank"] = self._rank
sysdata["stageId"] = -1
sysdata["universeSize"] = self.universeSize
sysdata["runId"] = self._runId
if (failStagePolicy != None):
self.failStageObject = FailStageClass(failStagePolicy,
self.log,
self.eventBrokerHost,
sysdata)
# (self, policy=None, log=None, eventBroker=None, sysdata=None, callSetup=True):
else:
self.failStageObject = FailStageClass(None, self.log,
self.eventBrokerHost,
sysdata)
log.log(self.VERB2, "failureStage %s " % self.failureStageName)
log.log(self.VERB2, "failParallelName %s " % self.failParallelName)
# Process Event Topics
self.eventTopicList = []
self.sliceEventTopicList = []
for item in fullStageList:
self.eventTopicList.append(item.getString("eventTopic"))
self.sliceEventTopicList.append(item.getString("eventTopic"))
# Check for executionMode of oneloop
if (self.executePolicy.exists('executionMode') and
(self.executePolicy.getString('executionMode') == "oneloop")):
self.executionMode = 1
# Process Share Data Schedule
self.shareDataList = []
for item in fullStageList:
shareDataStage = False
if (item.exists('shareData')):
shareDataStage = item.getBool('shareData')
self.shareDataList.append(shareDataStage)
log.log(self.VERB3, "Loading in %d trigger topics" % \
len(filter(lambda x: x != "None", self.eventTopicList)))
for iStage in xrange(len(self.eventTopicList)):
item = self.eventTopicList[iStage]
if self.eventTopicList[iStage] != "None":
log.log(self.VERB3, "eventTopic%d: %s" % (iStage + 1, item))
else:
log.log(Log.DEBUG, "eventTopic%d: %s" % (iStage + 1, item))
count = 0
for item in self.eventTopicList:
newitem = "%s_%s" % (item, self._pipelineName)
self.sliceEventTopicList[count] = newitem
count += 1
eventsSystem = events.EventSystem.getDefaultEventSystem()
for topic in self.sliceEventTopicList:
if (topic == "None_" + self._pipelineName):
pass
else:
eventsSystem.createReceiver(self.eventBrokerHost, topic)
log.log(self.VERB3, "Creating receiver %s" % (topic))
conflog.done()
log.log(self.VERB1, "Slice configuration complete")
def startStagesLoop(self):
"""
Execute the Stage loop. The loop progressing in step with
the analogous stage loop in the central Pipeline by means of
MPI Bcast and Barrier calls.
"""
startStagesLoopLog = self.log.timeBlock("startStagesLoop", self.TRACE)
looplog = BlockTimingLog(self.log, "visit", self.TRACE)
stagelog = BlockTimingLog(looplog, "stage", self.TRACE)
self.log.log(Log.INFO, "Begin startStagesLoopLog")
self.threadBarrier()
visitcount = 0
while True:
self.log.log(Log.INFO, "visitcount %d %s " % (visitcount, datetime.datetime.now()))
if ((self.executionMode == 1) and (visitcount == 1)):
LogRec(looplog, Log.INFO) << "terminating Slice Stage Loop "
# self.cppPipeline.invokeShutdown()
break
visitcount += 1
looplog.setPreamblePropertyInt("LOOPNUM", visitcount)
stagelog.setPreamblePropertyInt("LOOPNUM", visitcount)
# stagelog.setPreamblePropertyInt("stagename", visitcount)
timesVisitStart = os.times()
# looplog.setPreamblePropertyFloat("usertime", timesVisitStart[0])
# looplog.setPreamblePropertyFloat("systemtime", timesVisitStart[1])
looplog.setPreamblePropertyDouble("usertime", timesVisitStart[0])
looplog.setPreamblePropertyDouble("systemtime", timesVisitStart[1])
looplog.start()
self.startInitQueue() # place an empty clipboard in the first Queue
self.errorFlagged = 0
for iStage in range(1, self.nStages+1):
stagelog.setPreamblePropertyInt("STAGEID", iStage)
stagelog.setPreamblePropertyString("stagename", self.stageNames[iStage-1])
stagelog.start(self.stageNames[iStage-1] + " loop")
stagelog.log(Log.INFO, "Begin stage loop iteration iStage %d " % iStage)
stageObject = self.stageList[iStage-1]
self.handleEvents(iStage, stagelog)
# synchronize before preprocess
self.threadBarrier()
# synchronize after preprocess, before process
self.threadBarrier()
self.tryProcess(iStage, stageObject, stagelog)
# synchronize after process, before postprocess
self.threadBarrier()
# synchronize after postprocess
self.threadBarrier()
stagelog.log(self.TRACE, "End stage loop iteration iStage %d " % iStage)
stagelog.log(Log.INFO, "End stage loop iteration : ErrorCheck \
iStage %d stageName %s errorFlagged_%d " % (iStage, self.stageNames[iStage-1], self.errorFlagged) )
stagelog.done()
looplog.log(self.VERB2, "Completed Stage Loop")
# If no error/exception was flagged, then clear the final Clipboard in the final Queue
if self.errorFlagged == 0:
looplog.log(Log.DEBUG,
"Retrieving final Clipboard for deletion")
finalQueue = self.queueList[self.nStages]
finalClipboard = finalQueue.getNextDataset()
finalClipboard.close()
del finalClipboard
looplog.log(Log.DEBUG, "Deleted final Clipboard")
else:
looplog.log(self.VERB3, "Error flagged on this visit")
timesVisitDone = os.times()
utime = timesVisitDone[0] - timesVisitStart[0]
stime = timesVisitDone[1] - timesVisitStart[1]
wtime = timesVisitDone[4] - timesVisitStart[4]
totalTime = utime + stime
looplog.log(Log.INFO, "visittimes : utime %.4f stime %.4f total %.4f wtime %.4f" % (utime, stime, totalTime, wtime) )
# looplog.setPreamblePropertyFloat("usertime", timesVisitDone[0])
# looplog.setPreamblePropertyFloat("systemtime", timesVisitDone[1])
looplog.setPreamblePropertyDouble("usertime", timesVisitDone[0])
looplog.setPreamblePropertyDouble("systemtime", timesVisitDone[1])
looplog.done()
try:
memmsg = "mem:"
with open("/proc/%d/status" % os.getpid(), "r") as f:
for l in f:
m = re.match(r'Vm(Size|RSS|Peak|HWM):\s+(\d+ \wB)', l)
if m:
memmsg += " %s=%s" % m.groups()
looplog.log(Log.INFO, memmsg)
except:
pass
# LogRec(looplog, Log.INFO) << Prop("usertime", utime) \
# << Prop("systemtime", stime) \
# << LogRec.endr;
startStagesLoopLog.done()
def _output(stage, policy, clipboard, log):
"""Perform the actual persistence.
@param stage The stage requesting output.
@param policy The policy for the stage.
@param clipboard The clipboard for the stage. The persisted objects are taken from this.
@param log A logger for messages.
"""
if not policy.exists('parameters.outputItems'):
# Propagate the clipboard to the output queue, but otherwise
# do nothing.
log.log(Log.WARN, "No outputItems found")
return
mainAdditionalData = lsst.pex.harness.Utils.createAdditionalData(
stage, policy, clipboard)
# Create a persistence object using policy, if present.
if policy.exists('parameters.persistence'):
persistencePolicy = pexPolicy.Policy(
policy.getPolicy('parameters.persistence'))
else:
persistencePolicy = pexPolicy.Policy()
persistence = dafPersist.Persistence.getPersistence(persistencePolicy)
# Iterate over items in OutputItems policy.
outputPolicy = policy.getPolicy('parameters.outputItems')
itemNames = outputPolicy.policyNames(True)
somethingWasOutput = False
for item in itemNames:
additionalData = mainAdditionalData.deepCopy()
itemPolicy = outputPolicy.getPolicy(item)
# Skip the item if it is not required and is not present.
itemRequired = itemPolicy.exists('required') and \
itemPolicy.getBool('required')
if not clipboard.contains(item):
if itemRequired:
raise RuntimeError, 'Missing output item: ' + item
else:
continue
itemData = clipboard.get(item)
# Add the item name to the additionalData.
additionalData.set('itemName', item)
if itemPolicy.exists('datasetId'):
dsPolicy = itemPolicy.getPolicy('datasetId')
ds = Dataset(dsPolicy.get('datasetType'))
ds.ids = {}
if dsPolicy.exists('set'):
setPolicy = dsPolicy.getPolicy('set')
for param in setPolicy.paramNames():
ds.ids[param] = setPolicy.get(param)
additionalData.set(param, setPolicy.get(param))
if dsPolicy.exists('fromJobIdentity'):
jobIdentity = clipboard.get(
policy.get('inputKeys.jobIdentity'))
for id in dsPolicy.getStringArray('fromJobIdentity'):
ds.ids[id] = jobIdentity[id]
additionalData.set(id, jobIdentity[id])
outputKey = policy.get('outputKeys.outputDatasets')
dsList = clipboard.get(outputKey)
if dsList is None:
dsList = []
clipboard.put(outputKey, dsList)
dsList.append(ds)
if stage.butler is not None:
# Use the butler to figure out storage and locations.
# Write Using Butler
iolog = BlockTimingLog(log, "write_using_butler", Log.INFO - 1)
iolog.start("persisting %s as %s with keys %s" %
(item, ds.type, ds.ids))
stage.butler.put(itemData, ds.type, dataId=ds.ids)
iolog.done()
somethingWasOutput = True
continue
# Get the item's StoragePolicy.
if itemPolicy.isArray('storagePolicy'):
policyList = itemPolicy.getPolicyArray('storagePolicy')
else:
policyList = []
policyList.append(itemPolicy.getPolicy('storagePolicy'))
# Create a list of Storages for the item based on policy.
storageList = dafPersist.StorageList()
for storagePolicy in policyList:
storageName = storagePolicy.getString('storage')
location = storagePolicy.getString('location')
logLoc = dafPersist.LogicalLocation(location, additionalData)
log.log(Log.INFO - 1,
"persisting %s to %s" % (item, logLoc.locString()))
additionalData.add('StorageLocation.' + storageName,
logLoc.locString())
mainAdditionalData.add('StorageLocation.' + storageName,
logLoc.locString())
storage = persistence.getPersistStorage(storageName, logLoc)
storageList.append(storage)
# Persist the item.
# Write Without Butler
iolog = BlockTimingLog(log, "write_without_butler", Log.INFO - 1)
iolog.start("persisting %s" % (item, ))
if hasattr(itemData, '__deref__'):
persistence.persist(itemData.__deref__(), storageList,
additionalData)
else:
persistence.persist(itemData, storageList, additionalData)
iolog.done()
somethingWasOutput = True
if not somethingWasOutput:
log.log(Log.WARN, "No items were output")