def process(self, clipboard):
"""
Execute the needed processing code for this Stage
"""
print 'Python apps.SyncSetupStageParallel process : stageId %i' % self.stageId
print 'Python apps.SyncSetupStageParallel process : _rank %i' % self.rank
root = Log.getDefaultLog()
log = Log(root,
"lsst.pexhexamples.apps.SyncSetupStageParallel.process")
lr = LogRec(log, Log.INFO)
lr << "Retrieving Clipboard"
lr << LogRec.endr
propertySet = dafBase.PropertySet()
propertySet.setInt("sliceRank", self.rank)
propertySet.setString("Level", "Debug")
clipboard.put("rankKey", propertySet)
clipboard.setShared("rankKey", True)
lr = LogRec(log, Log.INFO)
lr << "Posted data to be Shared on Clipboard"
lr << LogRec.endr
def process(self):
logging.Trace_setVerbosity("lsst.detection", 5)
logging.Trace(
"lsst.detection.DetectionStage", 3,
'Python DetectionStage process : _rank %i stageId %d' %
(self._rank, self.stageId))
activeClipboard = self.inputQueue.getNextDataset()
###########
#
# Get objects from clipboard
#
triggerEvent = activeClipboard.get('triggerVisitEvent')
filterNameItem = triggerEvent.findUnique('filterName')
filterName = filterNameItem.getValueString()
exposureIdItem = triggerEvent.findUnique('exposureId')
exposureId = exposureIdItem.getValueInt()
visitTimeItem = triggerEvent.findUnique('visitTime')
visitTime = visitTimeItem.getValueDouble()
###########
#
# Log the beginning of Detection stage for this slice
#
LogRec(self.detectionLog, Log.INFO) \
<< "Began detection stage" \
<< DataProperty("exposureId", exposureId) \
<< DataProperty("visitTime", visitTime) \
<< DataProperty("filterName", filterName) \
<< LogRec.endr
#
# Instantiate a Filter object to get the id of filterName
#
dbLocation = dafper.LogicalLocation(
'mysql://lsst10.ncsa.uiuc.edu:3306/test')
filterDB = lsst.afw.image.Filter(dbLocation, filterName)
filterId = filterDB.getId()
logging.Trace("lsst.detection.DetectionStage", 3,
'FilterName %s FilterId %d' % (filterName, filterId))
differenceImageExposure = activeClipboard.get('DifferenceExposure')
diaSourceCollection = Detection.detection(
differenceImageExposure=differenceImageExposure,
policy=self._policy,
filterId=filterId,
useLog=self.detectionLog,
footprintList=None,
)
###########
#
# Post results to clipboard
#
activeClipboard.put('DiaSources', diaSourceCollection)
self.outputQueue.addDataset(activeClipboard)
def tryPostProcess(self, iStage, stage, stagelog):
"""
Executes the try/except construct for Stage postprocess() call
"""
postlog = stagelog.timeBlock("tryPostProcess", self.TRACE - 2)
# Important try - except construct around stage postprocess()
try:
# If no error/exception has been flagged, run postprocess()
# otherwise, simply pass along the Clipboard
if (self.errorFlagged == 0):
processlog = stagelog.timeBlock("postprocess", self.TRACE)
stage.applyPostprocess(self.interQueue)
processlog.done()
else:
postlog.log(self.TRACE,
"Skipping applyPostprocess due to flagged error")
self.transferClipboard(iStage)
except:
trace = "".join(
traceback.format_exception(sys.exc_info()[0],
sys.exc_info()[1],
sys.exc_info()[2]))
postlog.log(Log.FATAL, trace)
# Flag that an exception occurred to guide the framework to skip processing
self.errorFlagged = 1
if (self.failureStageName != None):
if (self.failSerialName !=
"lsst.pex.harness.stage.NoOpSerialProcessing"):
LogRec(postlog, self.VERB2) << "failureStageName exists " \
<< self.failureStageName \
<< "and failSerialName exists " \
<< self.failSerialName \
<< LogRec.endr
inputQueue = self.queueList[iStage - 1]
outputQueue = self.queueList[iStage]
self.failStageObject.initialize(outputQueue, inputQueue)
self.failStageObject.applyPostprocess(self.interQueue)
else:
postlog.log(self.VERB2,
"No SerialProcessing to do for failure stage")
# Post the cliphoard that the Stage failed to transfer to the output queue
self.postOutputClipboard(iStage)
# Done try - except around stage preprocess
postlog.done()
def finish(self, log=None, clipboard=None):
if log:
rec = LogRec(log, Log.INFO)
rec << "PositiveFluxExcursion visit statistics"
rec << {
"numPositiveInBoth": self._numPositiveInBoth,
"numPositiveOnlyInFirst": self._numPositiveOnlyInFirst,
"numPositiveOnlyInSecond": self._numPositiveOnlyInSecond,
"numNegativeOrMissingInBoth": self._numNegativeOrMissingInBoth
}
rec << endr
def finish(self, log=None, clipboard=None):
if log:
rec = LogRec(log, Log.INFO)
rec << "PresentInBothExposuresClassifier visit statistics"
rec << {
"numPresentInBoth": self._numPresentInBoth,
"numPresentOnlyInFirst": self._numPresentOnlyInFirst,
"numPresentOnlyInSecond": self._numPresentOnlyInSecond,
"numMissingInBoth": self._numMissingInBoth
}
rec << endr
def preprocess(self, clipboard):
"""
Execute the needed preprocessing code for this Stage
"""
print 'Python apps.SyncSetupStage preprocess : stageId %i' % self.stageId
print 'Python apps.SyncSetupStage preprocess : _rank %i' % self.rank
root = Log.getDefaultLog()
log = Log(root, "lsst.pexhexamples.apps.SyncSetupStage.preprocess")
lr = LogRec(log, Log.INFO)
lr << "Retrieving Clipboard"
lr << LogRec.endr
propertySet = dafBase.PropertySet()
propertySet.setInt("redHerring", self.rank)
clipboard.put("redKey", propertySet)
lr = LogRec(log, Log.INFO)
lr << "Posted data to Clipboard"
lr << LogRec.endr
def postprocess(self, clipboard):
"""
Execute the needed postprocessing code for SyncSetupStage
"""
print 'Python apps.SyncSetupStage postprocess : stageId %i' % self.stageId
print 'Python apps.SyncSetupStage postprocess : _rank %i' % self.rank
root = Log.getDefaultLog()
log = Log(root, "lsst.pexhexamples.apps.SyncSetupStage.postprocess")
lr = LogRec(log, Log.INFO)
lr << "In SyncSetupStage.postprocess"
lr << LogRec.endr
def process(self, clipboard):
"""
Processing code for this Stage to be executed within a Slice
"""
log = Log(self.log,
"lsst.pexhexamples.pipeline.SampleStageParallel.process")
lr = LogRec(log, Log.INFO)
lr << " rank " + str(self.rank)
lr << " stageId " + str(self.stageId)
lr << " runId " + str(self.runId)
lr << " universeSize " + str(self.universeSize)
lr << " RunMode from Policy " + self.runmode
lr << LogRec.endr
def postprocess(self, clipboard):
"""
Processing code for this Stage to be executed by the main Pipeline
after the completion of Slice process
"""
log = Log(self.log,
"lsst.pexhexamples.pipeline.SampleStageSerial.postprocess")
log.log(Log.INFO, 'Executing SampleStageSerial postprocess')
lr = LogRec(log, Log.INFO)
lr << " rank " + str(self.rank)
lr << " stageId " + str(self.stageId)
lr << " universeSize " + str(self.universeSize)
lr << " RunMode from Policy " + self.runmode
lr << LogRec.endr
def preprocess(self, clipboard):
# do our work
if clipboard is not None:
if not clipboard.contains("width"):
raise RuntimeError("Missing width on clipboard")
if not clipboard.contains("height"):
raise RuntimeError("Missing width on clipboard")
# if you are worried about overhead of formatting a debug message,
# you can wrap it in an if block
if self.log.sends(Log.DEBUG):
# this attaches properties to our message
LogRec(self.log, Log.DEBUG) << "all input data found." \
<< Prop("width", clipboard.get("width")) \
<< Prop("height", clipboard.get("height")) \
<< LogRec.endr
def handleEvents(self, iStage, stagelog):
"""
Handles Events: transmit or receive events as specified by Policy
"""
log = stagelog.timeBlock("handleEvents", self.TRACE - 2)
eventsSystem = events.EventSystem.getDefaultEventSystem()
thisTopic = self.eventTopicList[iStage - 1]
if (thisTopic != "None"):
log.log(self.VERB3, "Processing topic: " + thisTopic)
sliceTopic = self.sliceEventTopicList[iStage - 1]
waitlog = log.timeBlock("eventwait " + sliceTopic, self.TRACE,
"wait for event...")
# Receive the event from the Pipeline
# Call with a timeout , followed by a call to time sleep to free the GIL
# periodically
sleepTimeout = 0.1
transTimeout = 900
inputParamPropertySetPtr = eventsSystem.receive(
sliceTopic, transTimeout)
while (inputParamPropertySetPtr == None):
time.sleep(sleepTimeout)
inputParamPropertySetPtr = eventsSystem.receive(
sliceTopic, transTimeout)
waitlog.done()
LogRec(log, self.TRACE) << "received event; contents: " \
<< inputParamPropertySetPtr \
<< LogRec.endr
self.populateClipboard(inputParamPropertySetPtr, iStage, thisTopic)
log.log(self.VERB3, 'Received event; added payload to clipboard')
else:
log.log(Log.DEBUG, 'No event to handle')
log.done()
def process(self, clipboard):
"""
Execute the needed processing code for this Stage
"""
print 'Python IPDPStage process : _rank %i stageId %d' % (self.rank,
self.stageId)
inputImage = clipboard.get("theProperty")
print "inputImage properties: "
nameList = inputImage.names()
root = Log.getDefaultLog()
log = Log(root, "lsst.pexhexamples.apps.IPDPStageParallel.process")
for name in nameList:
value = inputImage.getString(name)
print name, value
lr = LogRec(log, Log.INFO)
lr << name
lr << value
lr << LogRec.endr
def process(self, clipboard):
"""
Processing code for this Stage to be executed within a Slice
"""
log = Log(
self.log,
"lsst.pexhexamples.pipeline.ShutdownTestStageParallel.process")
i = 0
loopTime = 0.25
while (i < 100):
print "APP STAGE PROCESSING LOOP " + str(i) + " \n"
time.sleep(loopTime)
i = i + 1
lr = LogRec(log, Log.INFO)
lr << " rank " + str(self.rank)
lr << " stageId " + str(self.stageId)
lr << " runId " + str(self.runId)
lr << " universeSize " + str(self.universeSize)
lr << " RunMode from Policy " + self.runmode
lr << LogRec.endr
def detection(differenceImageExposure,
policy,
filterId,
useLog=None,
footprintList=None):
"""Detect and measure objects in an incoming difference image Exposure
Inputs:
- differenceImageExposure: an lsst.afw.image.Exposure containing a difference MaskedImage and WCS
- policy: the policy; required elements are...?
- footprintList: a sequence of detection footprints on which to force measurement
Returns:
- an lsst.afw.detection.SourceVector
"""
if not (useLog):
useLog = ScreenLog()
useLog.setScreenVerbose(True)
logging.Trace("lsst.detection.detection", 3, "filterId = %d" % (filterId))
###########
#
# Get directives from policy
#
thresh = policy.get('thresholdSigma')
nPixMin = policy.get('numPixMinFootprint')
###########
#
# Unpack the MaskedImage from the Exposure
#
img = differenceImageExposure.getMaskedImage()
###########
#
# Crudely estimate noise from mean of variance image - should do sigma clipping
#
varImg = img.getVariance()
noise = math.sqrt(afwImage.mean_channel_value(varImg))
logging.Trace(
"lsst.detection.detection", 3,
"thresholdSigma = %r; noise = %r PixMin = %r" %
(thresh, noise, nPixMin))
LogRec(useLog, Log.INFO) \
<< "Threshold computation" \
<< DataProperty("thresholdSigma", thresh) \
<< DataProperty("noise", noise) \
<< DataProperty("threshold", thresh*noise) \
<< LogRec.endr
###########
#
# Build the DetectionSet for positive sources
#
dsPositive = det.DetectionSetF(
img, det.Threshold(thresh * noise, det.Threshold.VALUE, True), "FP+",
nPixMin)
fpVecPositive = dsPositive.getFootprints()
print "Positive detections: ", len(fpVecPositive)
LogRec(useLog, Log.INFO) \
<< "Positive detections" \
<< DataProperty("nPositive", len(fpVecPositive)) \
<< LogRec.endr
###########
#
# Build the DetectionSet for negative sources
#
dsNegative = det.DetectionSetF(
img, det.Threshold(thresh * noise, det.Threshold.VALUE, False), "FP-",
nPixMin)
fpVecNegative = dsNegative.getFootprints()
print "Negative detections: ", len(fpVecNegative)
LogRec(useLog, Log.INFO) \
<< "Negative detections" \
<< DataProperty("nNegative", len(fpVecNegative)) \
<< LogRec.endr
###########
#
# Measure the FootPrints
#
imgWCS = differenceImageExposure.getWcs()
outputDiaSources = afwDet.DiaSourceVec()
imgMeasure = det.MeasureF(img, "FP+")
id = 0
for i in range(len(fpVecPositive)):
diaPtr = afwDet.DiaSourcePtr()
diaPtr.setId(id)
diaPtr.setFilterId(filterId)
imgMeasure.measureSource(
diaPtr, fpVecPositive[i],
0.0) # NOTE explicit background of zero used for difference image
pixCoord = afwImage.Coord2D(diaPtr.getColc(), diaPtr.getRowc())
skyCoord = imgWCS.colRowToRaDec(pixCoord)
diaPtr.setRa(skyCoord.x())
diaPtr.setDec(skyCoord.y())
outputDiaSources.push_back(diaPtr.get())
id += 1
imgMeasure = det.MeasureF(img, "FP-")
for i in range(len(fpVecNegative)):
diaPtr = afwDet.DiaSourcePtr()
diaPtr.setId(id)
diaPtr.setFilterId(filterId)
imgMeasure.measureSource(
diaPtr, fpVecNegative[i],
0.0) # NOTE explicit background of zero used for difference image
pixCoord = afwImage.Coord2D(diaPtr.getColc(), diaPtr.getRowc())
skyCoord = imgWCS.colRowToRaDec(pixCoord)
diaPtr.setRa(skyCoord.x())
diaPtr.setDec(skyCoord.y())
outputDiaSources.push_back(diaPtr.get())
id += 1
###########
#
# Return the DiaSources
#
return outputDiaSources
def handleEvents(self, iStage, stagelog):
"""
Handles Events: transmit or receive events as specified by Policy
"""
log = stagelog.timeBlock("handleEvents", self.TRACE - 2)
eventsSystem = events.EventSystem.getDefaultEventSystem()
thisTopic = self.eventTopicList[iStage - 1]
thisTopic = thisTopic.strip()
if (thisTopic != "None"):
log.log(self.VERB3, "Processing topic: " + thisTopic)
sliceTopic = "%s_%s" % (thisTopic, self._pipelineName)
waitlog = log.timeBlock("eventwait " + thisTopic, self.TRACE,
"wait for event...")
inputParamPropertySetPtr = self.waitForEvent(thisTopic)
# inputParamPropertySetPtr = eventsSystem.receive(thisTopic, self.eventTimeout)
waitlog.done()
if (inputParamPropertySetPtr != None):
LogRec(log, self.TRACE) << "received event; contents: " \
<< inputParamPropertySetPtr \
<< LogRec.endr
log.log(self.VERB2,
"received event; sending it to Slices " + sliceTopic)
# Pipeline does not disassemble the payload of the event.
# It places the payload on the clipboard with key of the eventTopic
self.populateClipboard(inputParamPropertySetPtr, iStage,
thisTopic)
eventsSystem.createTransmitter(self.eventBrokerHost,
sliceTopic)
eventsSystem.publish(sliceTopic, inputParamPropertySetPtr)
log.log(self.VERB2, "event sent to Slices")
else:
if ((self._stop.isSet())):
# Shutdown event received while waiting for data event
log.log(
self.VERB2,
"Pipeline Shutting down : Shutdown event received.")
else:
# event was not received after a long timeout
# log.log(self.VERB2, "Pipeline Shutting Down: Event timeout self.: No event arrived")
LogRec(log, self.VERB2) << "Pipeline Shutting Down: Event timeout " \
<< str(self.eventTimeout) \
<< "reached: No or next event did not arrive " \
<< LogRec.endr
sys.exit()
else: # This stage has no event dependence
log.log(Log.DEBUG, 'No event to handle')
log.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):
"""
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 tryProcess(self, iStage, stage, stagelog):
"""
Executes the try/except construct for Stage process() call
"""
# Important try - except construct around stage process()
proclog = stagelog.timeBlock("tryProcess", self.TRACE - 2)
stageObject = self.stageList[iStage - 1]
proclog.log(self.VERB3, "Getting process signal from Pipeline")
# Important try - except construct around stage process()
try:
# If no error/exception has been flagged, run process()
# otherwise, simply pass along the Clipboard
if (self.errorFlagged == 0):
processlog = stagelog.timeBlock("process", self.TRACE)
stageObject.applyProcess()
outputQueue = self.queueList[iStage]
clipboard = outputQueue.element()
proclog.log(Log.INFO, "Checking_For_Shotdown")
if clipboard.has_key("noMoreDatasets"):
proclog.log(Log.INFO, "Ready_For_Shutdown")
self.shutdown()
processlog.done()
else:
proclog.log(self.TRACE, "Skipping process due to error")
self.transferClipboard(iStage)
except:
trace = "".join(
traceback.format_exception(sys.exc_info()[0],
sys.exc_info()[1],
sys.exc_info()[2]))
proclog.log(Log.FATAL, trace)
# Flag that an exception occurred to guide the framework to skip processing
self.errorFlagged = 1
# Post the cliphoard that the Stage failed to transfer to the output queue
if (self.failureStageName != None):
if (self.failParallelName !=
"lsst.pex.harness.stage.NoOpParallelProcessing"):
LogRec(proclog, self.VERB2) << "failureStageName exists " \
<< self.failureStageName \
<< "and failParallelName exists " \
<< self.failParallelName \
<< LogRec.endr
inputQueue = self.queueList[iStage - 1]
outputQueue = self.queueList[iStage]
clipboard = inputQueue.element()
clipboard.put("failedInStage", stage.getName())
clipboard.put("failedInStageN", iStage)
clipboard.put("failureType", str(sys.exc_info()[0]))
clipboard.put("failureMessage", str(sys.exc_info()[1]))
clipboard.put("failureTraceback", trace)
self.failStageObject.initialize(outputQueue, inputQueue)
self.failStageObject.applyProcess()
proclog.log(self.TRACE,
"Popping off failure stage Clipboard")
clipboard = outputQueue.getNextDataset()
clipboard.close()
del clipboard
proclog.log(
self.TRACE,
"Erasing and deleting failure stage Clipboard")
else:
proclog.log(
self.VERB2,
"No ParallelProcessing to do for failure stage")
self.postOutputClipboard(iStage)
proclog.log(self.VERB3, "Getting end of process signal from Pipeline")
proclog.done()
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 finish(self, log=None, clipboard=None):
if log:
LogRec(log, Log.INFO) << "ShapeDiffersInExposuresClassifier visit statistics" << \
{ "numDifferentShape": self._numDifferentShape, "numSimilarShape": self._numSimilarShape } << endr
def waitForReady(policy, runid, eventrcvr, logverb, logger):
"""
attempt to wait until all pipelines are configured and running before
sending event data.
"""
# This implimentation tries to wait until all pipelines have reached
# the point of waiting for their first event
# determine whether the pipeline verbosity is enough to get the
# particular "ready" signals we will be looking for
prodthresh = None
if logverb is not None:
prodthresh = run.verbosity2threshold(logverb)
if prodthresh is None and policy.exists("logThreshold"):
prodthresh = policy.get("logThreshold")
timeout = setuptime
pldescs = policy.get("pipelines")
names = pldescs.policyNames(True)
pipelines = []
for pl in names:
plpol = pldescs.getPolicy(pl)
if not plpol.getBool("launch"):
continue
if prodthresh is None or prodthresh > -1:
config = plpol.getPolicy("configuration")
if config.exists("execute"):
config = config.getPolicy("execute")
if config.exists("logThreshold") and \
config.getInt("logThreshold") > -1:
logger.log(
Log.WARN,
"%s pipeline's logging not verbose enough to track its readiness"
% pl)
continue
pipelines.append(pl)
logger.log(Log.DEBUG,
"Waiting for the %s pipeline to be ready..." % pl)
if "IPSD" not in pipelines:
timeout = shortsetuptime # seconds
if len(pipelines) > 0:
logger.log(
Log.INFO,
"Waiting for pipelines to setup (this can take a while)...")
tick = time.time()
while len(pipelines) > 0:
waittime = 1000 * (timeout - int(round(time.time() - tick)))
if waittime > 0:
# waitprops = eventrcvr.receive(waittime)
waitprops = eventrcvr.matchingReceive("LOG", waitLogName,
waittime)
else:
waitprops = None
if waitprops is None:
LogRec(logger, Log.WARN) \
<< "Have yet to hear back from the following pipelines: " +\
", ".join(pipelines) \
<< "Proceeding to send visit events" << LogRec.endr
break
if waitprops.getString("STATUS", "") == "start" and \
waitprops.getString("runId", "") == runid:
pipename = waitprops.getString("pipeline", "unknown")
if pipename in pipelines:
pipelines.remove(pipename)
# pipelines.pop(0)
logger.log(Log.DEBUG, "%s is ready" % pipename)
else:
LogRec(logger, Log.WARN) \
<< "Unable to detect when pipelines are ready" \
<< "Proceeding to send visit events in %d seconds" % \
shortsetuptime \
<< LogRec.endr
time.sleep(shortsetuptime)
return
def startStagesLoop(self):
"""
Method to execute loop over Stages
"""
startStagesLoopLog = self.log.traceBlock("startStagesLoop", self.TRACE)
looplog = TracingLog(self.log, "visit", self.TRACE)
stagelog = TracingLog(looplog, "stage", self.TRACE - 1)
proclog = TracingLog(stagelog, "process", self.TRACE)
visitcount = 0
while True:
time.sleep(self.delayTime)
if ((((self.executionMode == 1) and (visitcount == 1))
or self.forceShutdown == 1)):
LogRec(
looplog, Log.INFO
) << "terminating pipeline and slices after one loop/visit "
self.cppPipeline.invokeShutdown()
#
# Need to shutdown Threads here
#
break
else:
visitcount += 1
looplog.setPreamblePropertyInt("loopnum", visitcount)
looplog.start()
stagelog.setPreamblePropertyInt("loopnum", visitcount)
proclog.setPreamblePropertyInt("loopnum", visitcount)
# synchronize at the top of the Stage loop
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)
self.tryPreProcess(iStage, stage, stagelog)
# if(self.isDataSharingOn):
# self.invokeSyncSlices(iStage, stagelog)
proclog.start("process and wait")
self.cppPipeline.invokeProcess(iStage)
proclog.done()
self.tryPostProcess(iStage, stage, stagelog)
stagelog.done()
time.sleep(self.delayTime)
self.checkExitByStage()
else:
looplog.log(self.VERB2, "Completed Stage Loop")
time.sleep(self.delayTime)
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")
# delete entries on the clipboard
finalClipboard.close()
del finalClipboard
startStagesLoopLog.log(Log.INFO, "Shutting down pipeline")
startStagesLoopLog.done()
self.shutdown()
def configurePipeline(self):
"""
Configure the Pipeline by reading a Policy File
"""
if (self.executePolicy.exists('nSlices')):
self.nSlices = self.executePolicy.getInt('nSlices')
else:
self.nSlices = 0 # default value
self.universeSize = self.nSlices + 1
if (self.executePolicy.exists('barrierDelay')):
self.barrierDelay = self.executePolicy.getDouble('barrierDelay')
else:
self.barrierDelay = 0.000001 # default value
# do some juggling to capture the actual stage policy names. We'll
# use these to assign some logical names to the stages for logging
# purposes. Note, however, that it is only convention that the
# stage policies will be specified as separate files; thus, we need
# a fallback.
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'))
log = Log(self.log, "configurePipeline")
log.log(Log.INFO,
"Logging messages using threshold=%i" % log.getThreshold())
LogRec(log, self.VERB1) << "Configuring pipeline" \
<< Prop("universeSize", self.universeSize) \
<< Prop("runID", self._runId) \
<< Prop("rank", -1) \
<< Prop("workerId", self.workerId) \
<< LogRec.endr
# Configure persistence logical location map with values for directory
# work space locators
dafPersist.LogicalLocation.setLocationMap(psLookup)
log.log(self.VERB2, "eventBrokerHost %s " % self.eventBrokerHost)
log.log(self.VERB2, "barrierDelay %s " % self.barrierDelay)
# Check for eventTimeout
if (self.executePolicy.exists('eventTimeout')):
self.eventTimeout = self.executePolicy.getInt('eventTimeout')
else:
self.eventTimeout = 10000000 # default value is 10 000 000
# Process Application Stages
fullStageList = self.executePolicy.getArray("appStage")
self.nStages = len(fullStageList)
log.log(self.VERB2, "Found %d stages" % len(fullStageList))
fullStageNameList = []
self.stagePolicyList = []
for stagei in xrange(self.nStages):
fullStagePolicy = fullStageList[stagei]
if (fullStagePolicy.exists('serialClass')):
serialName = fullStagePolicy.getString('serialClass')
stagePolicy = fullStagePolicy.get('stagePolicy')
else:
serialName = "lsst.pex.harness.stage.NoOpSerialProcessing"
stagePolicy = None
fullStageNameList.append(serialName)
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)
#
# Configure the Failure Stage
# - Read the policy information
# - Import failure stage Class and make failure stage instance Object
#
self.failureStageName = None
self.failSerialName = None
if (self.executePolicy.exists('failureStage')):
failstg = self.executePolicy.get("failureStage")
self.failureStageName = failstg.get("name")
if (failstg.exists('serialClass')):
self.failSerialName = failstg.getString('serialClass')
failStagePolicy = failstg.get('stagePolicy')
else:
self.failSerialName = "lsst.pex.harness.stage.NoOpSerialProcessing"
failStagePolicy = None
astage = self.failSerialName
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.failureStageName
sysdata["rank"] = -1
sysdata["stageId"] = -1
sysdata["universeSize"] = self.universeSize
sysdata["runId"] = self._runId
if (failStagePolicy != None):
self.failStageObject = FailStageClass(failStagePolicy,
self.log,
self.eventBrokerHost,
sysdata)
else:
self.failStageObject = FailStageClass(None, self.log,
self.eventBrokerHost,
sysdata)
log.log(self.VERB2, "failureStage %s " % self.failureStageName)
log.log(self.VERB2, "failSerialName %s " % self.failSerialName)
# Process Event Topics
self.eventTopicList = []
for item in fullStageList:
self.eventTopicList.append(item.getString("eventTopic"))
# 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)))
log.log(self.VERB3, "Loading in %d shareData flags" % \
len(filter(lambda x: x != "None", self.shareDataList)))
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))
eventsSystem = events.EventSystem.getDefaultEventSystem()
for topic in self.eventTopicList:
if (topic == "None"):
pass
else:
log.log(self.VERB2, "Creating receiver for topic %s" % (topic))
eventsSystem.createReceiver(self.eventBrokerHost, topic)
# Check for executionMode of oneloop
if (self.executePolicy.exists('executionMode') and
(self.executePolicy.getString('executionMode') == "oneloop")):
self.executionMode = 1
# Check for shutdownTopic
if (self.executePolicy.exists('shutdownTopic')):
self.shutdownTopic = self.executePolicy.getString('shutdownTopic')
else:
self.shutdownTopic = "triggerShutdownEvent"
# Check for exitTopic
if (self.executePolicy.exists('exitTopic')):
self.exitTopic = self.executePolicy.getString('exitTopic')
else:
self.exitTopic = None
log.log(self.VERB1, "Pipeline configuration complete")