def catch_sig(sig, frame):
try:
os.remove(pidFile)
except Exception:
pass
# kill
_logger.debug('terminating ...')
commands_get_status_output('kill -9 -- -%s' % os.getpgrp())
# exit
sys.exit(0)
def run(self):
if 'VIRTUAL_ENV' in os.environ:
prefix = os.environ['VIRTUAL_ENV']
else:
prefix = ''
setupStr = 'source {0}/etc/sysconfig/panda_server; '.format(prefix)
runStr = '%s/python -Wignore ' % panda_config.native_python
runStr += panda_config.pandaPython_dir + '/dataservice/forkSetupper.py -i '
runStr += self.fileName
if self.fileName.split('/')[-1].startswith('set.NULL.'):
runStr += ' -t'
comStr = setupStr + runStr
tmpLog.debug(comStr)
commands_get_status_output(comStr)
def getstatusoutput(self, commandStr):
# time stamp
timestamp = datetime.datetime.utcnow().isoformat(' ')
_logger.debug('%s start for "%s"' % (timestamp, commandStr))
self.updateSummary('nQueued', 1)
_logger.debug('%s getting lock' % timestamp)
# get semaphore
self.processLock.acquire()
_logger.debug('%s got lock' % timestamp)
# execute
self.updateSummary('nRunning', 1)
status, output = commands_get_status_output(commandStr)
_logger.debug('%s executed' % timestamp)
self.updateSummary('nRunning', -1)
# release queue
self.processLock.release()
_logger.debug('%s end' % timestamp)
self.updateSummary('nQueued', -1)
# return
return status, output
def _onExit(fname):
commands_get_status_output('rm -rf %s' % fname)
try:
gracePeriod = int(sys.argv[1])
except Exception:
gracePeriod = 3
# current minute
currentMinute = datetime.datetime.utcnow().minute
# kill old process
try:
# time limit
timeLimit = datetime.datetime.utcnow() - datetime.timedelta(
minutes=overallTimeout)
# get process list
scriptName = sys.argv[0]
out = commands_get_status_output(
'env TZ=UTC ps axo user,pid,lstart,args | grep %s' % scriptName)[-1]
for line in out.split('\n'):
items = line.split()
# owned process
if items[0] not in ['sm', 'atlpan', 'pansrv',
'root']: # ['os.getlogin()']: doesn't work in cron
continue
# look for python
if re.search('python', line) is None:
continue
# PID
pid = items[1]
# start time
timeM = re.search('(\S+\s+\d+ \d+:\d+:\d+ \d+)', line)
startTime = datetime.datetime(
*time.strptime(timeM.group(1), '%b %d %H:%M:%S %Y')[:6])
catch_sig(None, None)
time.sleep(5)
# entry
if __name__ == "__main__":
optP = optparse.OptionParser(conflict_handler="resolve")
options, args = optP.parse_args()
try:
# time limit
timeLimit = datetime.datetime.utcnow() - datetime.timedelta(
seconds=overallTimeout - 180)
# get process list
scriptName = sys.argv[0]
out = commands_get_status_output(
'env TZ=UTC ps axo user,pid,lstart,args | grep %s' %
scriptName)[-1]
for line in out.split('\n'):
items = line.split()
# owned process
if not items[0] in ['sm', 'atlpan', 'pansrv', 'root'
]: # ['os.getlogin()']: doesn't work in cron
continue
# look for python
if re.search('python', line) is None:
continue
# PID
pid = items[1]
# start time
timeM = re.search('(\S+\s+\d+ \d+:\d+:\d+ \d+)', line)
startTime = datetime.datetime(
_logger.debug('MemCheck - %s Name=%s VSZ=%s RSS=%s : %s' % (os.getpid(),name,vmSize,vmRSS,str))
except Exception:
type, value, traceBack = sys.exc_info()
_logger.error("memoryCheck() : %s %s" % (type,value))
_logger.debug('MemCheck - %s unknown : %s' % (os.getpid(),str))
return
_memoryCheck("start")
# kill old dq2 process
try:
# time limit
timeLimit = datetime.datetime.utcnow() - datetime.timedelta(hours=2)
# get process list
scriptName = sys.argv[0]
out = commands_get_status_output(
'ps axo user,pid,lstart,args | grep dq2.clientapi | grep -v PYTHONPATH | grep -v grep')[-1]
for line in out.split('\n'):
if line == '':
continue
items = line.split()
# owned process
if not items[0] in ['sm','atlpan','pansrv','root']: # ['os.getlogin()']: doesn't work in cron
continue
# look for python
if re.search('python',line) is None:
continue
# PID
pid = items[1]
# start time
timeM = re.search('(\S+\s+\d+ \d+:\d+:\d+ \d+)',line)
startTime = datetime.datetime(*time.strptime(timeM.group(1),'%b %d %H:%M:%S %Y')[:6])
def process(self, file_name, to_delete=False, test_mode=False, get_log=False, dump_workflow=False):
try:
is_fatal = False
is_OK = True
request_id = None
dump_str = None
with open(file_name) as f:
ops = json.load(f)
user_name = clean_user_id(ops["userName"])
base_platform = ops['data'].get('base_platform')
for task_type in ops['data']['taskParams']:
ops['data']['taskParams'][task_type]['userName'] = user_name
if base_platform:
ops['data']['taskParams'][task_type]['basePlatform'] = base_platform
log_token = '< id="{}" test={} outDS={} >'.format(user_name, test_mode, ops['data']['outDS'])
tmpLog = LogWrapper(self.log, log_token)
tmpLog.info('start {}'.format(file_name))
sandbox_url = os.path.join(ops['data']['sourceURL'], 'cache', ops['data']['sandbox'])
# IO through json files
ops_file = tempfile.NamedTemporaryFile(delete=False, mode='w')
json.dump(ops, ops_file)
ops_file.close()
# execute main in another process to avoid chdir mess
tmp_stat, tmp_out = commands_get_status_output("python {} {} '{}' {} {} '{}' {}".format(
__file__, sandbox_url, log_token, dump_workflow, ops_file.name,
user_name, test_mode))
if tmp_stat:
is_OK = False
tmpLog.error('main execution failed with {}:{}'.format(tmp_stat, tmp_out))
else:
with open(tmp_out.split('\n')[-1]) as tmp_out_file:
is_OK, is_fatal, request_id, dump_str = json.load(tmp_out_file)
try:
os.remove(tmp_out)
except Exception:
pass
if not get_log:
if is_OK:
tmpLog.info('is_OK={} request_id={}'.format(is_OK, request_id))
else:
tmpLog.info('is_OK={} is_fatal={} request_id={}'.format(is_OK, is_fatal, request_id))
if to_delete or (not test_mode and (is_OK or is_fatal)):
dump_str = tmpLog.dumpToString() + dump_str
tmpLog.debug('delete {}'.format(file_name))
try:
os.remove(file_name)
except Exception:
pass
# send notification
if not test_mode and self.taskBuffer is not None:
toAdder = self.taskBuffer.getEmailAddr(user_name)
if toAdder is None or toAdder.startswith('notsend'):
tmpLog.debug('skip to send notification since suppressed')
else:
# message
if is_OK:
mailSubject = "PANDA Notification for Workflow {}".format(ops['data']['outDS'])
mailBody = "Hello,\n\nWorkflow:{} has been accepted with RequestID:{}\n\n".\
format(ops['data']['outDS'], request_id)
else:
mailSubject = "PANDA WARNING for Workflow={}".format(ops['data']['outDS'])
mailBody = "Hello,\n\nWorkflow {} was not accepted\n\n".\
format(ops['data']['outDS'], request_id)
mailBody += "Reason : %s\n" % dump_str
# send
tmpSM = MailUtils().send(toAdder, mailSubject, mailBody)
tmpLog.debug('sent message with {}'.format(tmpSM))
except Exception as e:
is_OK = False
tmpLog.error("failed to run with {} {}".format(str(e), traceback.format_exc()))
if get_log:
ret_val = {'status': is_OK}
if is_OK:
ret_val['log'] = dump_str
else:
if dump_str is None:
ret_val['log'] = tmpLog.dumpToString()
else:
ret_val['log'] = dump_str
return ret_val
def core_exec(sandbox_url, log_token, dump_workflow, ops_file, user_name, test_mode):
tmpLog = LogWrapper(_logger, log_token)
is_OK = True
is_fatal = False
request_id = None
if dump_workflow == 'True':
dump_workflow = True
else:
dump_workflow = False
if test_mode == 'True':
test_mode = True
else:
test_mode = False
try:
with open(ops_file) as f:
ops = json.load(f)
try:
os.remove(ops_file)
except Exception:
pass
# go to temp dir
cur_dir = os.getcwd()
with tempfile.TemporaryDirectory() as tmp_dirname:
os.chdir(tmp_dirname)
# download sandbox
tmpLog.info('downloading sandbox from {}'.format(sandbox_url))
with requests.get(sandbox_url, allow_redirects=True, verify=False, stream=True) as r:
if r.status_code == 400:
tmpLog.error("not found")
is_fatal = True
is_OK = False
elif r.status_code != 200:
tmpLog.error("bad HTTP response {}".format(r.status_code))
is_OK = False
# extract sandbox
if is_OK:
with open(ops['data']['sandbox'], 'wb') as fs:
for chunk in r.raw.stream(1024, decode_content=False):
if chunk:
fs.write(chunk)
fs.close()
tmp_stat, tmp_out = commands_get_status_output(
'tar xvfz {}'.format(ops['data']['sandbox']))
if tmp_stat != 0:
tmpLog.error(tmp_out)
dump_str = 'failed to extract {}'.format(ops['data']['sandbox'])
tmpLog.error(dump_str)
is_fatal = True
is_OK = False
# parse workflow files
if is_OK:
tmpLog.info('parse workflow')
if ops['data']['language'] == 'cwl':
nodes, root_in = pcwl_utils.parse_workflow_file(ops['data']['workflowSpecFile'],
tmpLog)
with open(ops['data']['workflowInputFile']) as workflow_input:
data = yaml.safe_load(workflow_input)
s_id, t_nodes, nodes = pcwl_utils.resolve_nodes(nodes, root_in, data, 0, set(),
ops['data']['outDS'], tmpLog)
workflow_utils.set_workflow_outputs(nodes)
id_node_map = workflow_utils.get_node_id_map(nodes)
[node.resolve_params(ops['data']['taskParams'], id_node_map) for node in nodes]
dump_str = "the description was internally converted as follows\n" \
+ workflow_utils.dump_nodes(nodes)
tmpLog.info(dump_str)
for node in nodes:
s_check, o_check = node.verify()
tmp_str = 'Verification failure in ID:{} {}'.format(node.id, o_check)
if not s_check:
tmpLog.error(tmp_str)
dump_str += tmp_str
dump_str += '\n'
is_fatal = True
is_OK = False
else:
dump_str = "{} is not supported to describe the workflow"
tmpLog.error(dump_str)
is_fatal = True
is_OK = False
# convert to workflow
if is_OK:
workflow_to_submit, dump_str_list = workflow_utils.convert_nodes_to_workflow(nodes)
try:
if workflow_to_submit:
if not test_mode:
tmpLog.info('submit workflow')
wm = ClientManager(host=get_rest_host())
request_id = wm.submit(workflow_to_submit, username=user_name)
else:
dump_str = 'workflow is empty'
tmpLog.error(dump_str)
is_fatal = True
is_OK = False
except Exception as e:
dump_str = 'failed to submit the workflow with {}'.format(str(e))
tmpLog.error('{} {}'.format(dump_str, traceback.format_exc()))
if dump_workflow:
tmpLog.debug('\n' + ''.join(dump_str_list))
os.chdir(cur_dir)
except Exception as e:
is_OK = False
is_fatal = True
tmpLog.error("failed to run with {} {}".format(str(e), traceback.format_exc()))
with tempfile.NamedTemporaryFile(delete=False, mode='w') as tmp_json:
json.dump([is_OK, is_fatal, request_id, tmpLog.dumpToString()], tmp_json)
print(tmp_json.name)
sys.exit(0)
def main(argv=tuple(), tbuf=None, **kwargs):
try:
long
except NameError:
long = int
tmpLog = LogWrapper(_logger, None)
tmpLog.debug("===================== start =====================")
# current minute
currentMinute = datetime.datetime.utcnow().minute
# instantiate TB
if tbuf is None:
from pandaserver.taskbuffer.TaskBuffer import taskBuffer
taskBuffer.init(panda_config.dbhost,
panda_config.dbpasswd,
nDBConnection=1)
else:
taskBuffer = tbuf
# instantiate sitemapper
aSiteMapper = SiteMapper(taskBuffer)
# delete
tmpLog.debug("Del session")
status, retSel = taskBuffer.querySQLS(
"SELECT MAX(PandaID) FROM ATLAS_PANDA.jobsDefined4", {})
if retSel is not None:
try:
maxID = retSel[0][0]
tmpLog.debug("maxID : %s" % maxID)
if maxID is not None:
varMap = {}
varMap[':maxID'] = maxID
varMap[':jobStatus1'] = 'activated'
varMap[':jobStatus2'] = 'waiting'
varMap[':jobStatus3'] = 'failed'
varMap[':jobStatus4'] = 'cancelled'
status, retDel = taskBuffer.querySQLS(
"DELETE FROM ATLAS_PANDA.jobsDefined4 WHERE PandaID<:maxID AND jobStatus IN (:jobStatus1,:jobStatus2,:jobStatus3,:jobStatus4)",
varMap)
except Exception:
pass
# count # of getJob/updateJob in dispatcher's log
try:
# don't update when logrotate is running
timeNow = datetime.datetime.utcnow()
logRotateTime = timeNow.replace(hour=3,
minute=2,
second=0,
microsecond=0)
if (timeNow > logRotateTime and (timeNow-logRotateTime) < datetime.timedelta(minutes=5)) or \
(logRotateTime > timeNow and (logRotateTime-timeNow) < datetime.timedelta(minutes=5)):
tmpLog.debug("skip pilotCounts session for logrotate")
else:
# log filename
dispLogName = '%s/panda-PilotRequests.log' % panda_config.logdir
# time limit
timeLimit = datetime.datetime.utcnow() - datetime.timedelta(
hours=3)
timeLimitS = datetime.datetime.utcnow() - datetime.timedelta(
hours=1)
# check if tgz is required
com = 'head -1 %s' % dispLogName
lostat, loout = commands_get_status_output(com)
useLogTgz = True
if lostat == 0:
match = re.search('^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}',
loout)
if match is not None:
startTime = datetime.datetime(*time.strptime(
match.group(0), '%Y-%m-%d %H:%M:%S')[:6])
# current log contains all info
if startTime < timeLimit:
useLogTgz = False
# log files
dispLogNameList = [dispLogName]
if useLogTgz:
today = datetime.date.today()
dispLogNameList.append('{0}-{1}.gz'.format(
dispLogName, today.strftime('%Y%m%d')))
# delete tmp
commands_get_status_output('rm -f %s.tmp-*' % dispLogName)
# tmp name
tmpLogName = '%s.tmp-%s' % (dispLogName, datetime.datetime.utcnow(
).strftime('%Y-%m-%d-%H-%M-%S'))
# loop over all files
pilotCounts = {}
pilotCountsS = {}
for tmpDispLogName in dispLogNameList:
# expand or copy
if tmpDispLogName.endswith('.gz'):
com = 'gunzip -c %s > %s' % (tmpDispLogName, tmpLogName)
else:
com = 'cp %s %s' % (tmpDispLogName, tmpLogName)
lostat, loout = commands_get_status_output(com)
if lostat != 0:
errMsg = 'failed to expand/copy %s with : %s' % (
tmpDispLogName, loout)
raise RuntimeError(errMsg)
# search string
sStr = '^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}).*'
sStr += 'method=(.+),site=(.+),node=(.+),type=(.+)'
# read
logFH = open(tmpLogName)
for line in logFH:
# check format
match = re.search(sStr, line)
if match is not None:
# check timerange
timeStamp = datetime.datetime(*time.strptime(
match.group(1), '%Y-%m-%d %H:%M:%S')[:6])
if timeStamp < timeLimit:
continue
tmpMethod = match.group(2)
tmpSite = match.group(3)
tmpNode = match.group(4)
tmpType = match.group(5)
# protection against corrupted entries from pilot,
# e.g. pilot reading site json from cvmfs while it was being updated
if tmpSite not in aSiteMapper.siteSpecList:
continue
# sum
pilotCounts.setdefault(tmpSite, {})
pilotCounts[tmpSite].setdefault(tmpMethod, {})
pilotCounts[tmpSite][tmpMethod].setdefault(tmpNode, 0)
pilotCounts[tmpSite][tmpMethod][tmpNode] += 1
# short
if timeStamp > timeLimitS:
if tmpSite not in pilotCountsS:
pilotCountsS[tmpSite] = dict()
if tmpMethod not in pilotCountsS[tmpSite]:
pilotCountsS[tmpSite][tmpMethod] = dict()
if tmpNode not in pilotCountsS[tmpSite][tmpMethod]:
pilotCountsS[tmpSite][tmpMethod][tmpNode] = 0
pilotCountsS[tmpSite][tmpMethod][tmpNode] += 1
# close
logFH.close()
# delete tmp
commands_get_status_output('rm %s' % tmpLogName)
# update
hostID = panda_config.pserverhost.split('.')[0]
tmpLog.debug("pilotCounts session")
retPC = taskBuffer.updateSiteData(hostID, pilotCounts, interval=3)
tmpLog.debug(retPC)
retPC = taskBuffer.updateSiteData(hostID, pilotCountsS, interval=1)
tmpLog.debug(retPC)
except Exception:
errType, errValue = sys.exc_info()[:2]
tmpLog.error("updateJob/getJob : %s %s" % (errType, errValue))
# nRunning
tmpLog.debug("nRunning session")
try:
if (currentMinute / panda_config.nrun_interval
) % panda_config.nrun_hosts == panda_config.nrun_snum:
retNR = taskBuffer.insertnRunningInSiteData()
tmpLog.debug(retNR)
except Exception:
errType, errValue = sys.exc_info()[:2]
tmpLog.error("nRunning : %s %s" % (errType, errValue))
# session for co-jumbo jobs
tmpLog.debug("co-jumbo session")
try:
ret = taskBuffer.getCoJumboJobsToBeFinished(30, 0, 1000)
if ret is None:
tmpLog.debug("failed to get co-jumbo jobs to finish")
else:
coJumboA, coJumboD, coJumboW, coJumboTokill = ret
tmpLog.debug("finish {0} co-jumbo jobs in Active".format(
len(coJumboA)))
if len(coJumboA) > 0:
jobSpecs = taskBuffer.peekJobs(coJumboA,
fromDefined=False,
fromActive=True,
fromArchived=False,
fromWaiting=False)
for jobSpec in jobSpecs:
fileCheckInJEDI = taskBuffer.checkInputFileStatusInJEDI(
jobSpec)
if not fileCheckInJEDI:
jobSpec.jobStatus = 'closed'
jobSpec.jobSubStatus = 'cojumbo_wrong'
jobSpec.taskBufferErrorCode = pandaserver.taskbuffer.ErrorCode.EC_EventServiceInconsistentIn
taskBuffer.archiveJobs([jobSpec], False)
tmpLog.debug("finish {0} co-jumbo jobs in Defined".format(
len(coJumboD)))
if len(coJumboD) > 0:
jobSpecs = taskBuffer.peekJobs(coJumboD,
fromDefined=True,
fromActive=False,
fromArchived=False,
fromWaiting=False)
for jobSpec in jobSpecs:
fileCheckInJEDI = taskBuffer.checkInputFileStatusInJEDI(
jobSpec)
if not fileCheckInJEDI:
jobSpec.jobStatus = 'closed'
jobSpec.jobSubStatus = 'cojumbo_wrong'
jobSpec.taskBufferErrorCode = pandaserver.taskbuffer.ErrorCode.EC_EventServiceInconsistentIn
taskBuffer.archiveJobs([jobSpec], True)
tmpLog.debug("finish {0} co-jumbo jobs in Waiting".format(
len(coJumboW)))
if len(coJumboW) > 0:
jobSpecs = taskBuffer.peekJobs(coJumboW,
fromDefined=False,
fromActive=False,
fromArchived=False,
fromWaiting=True)
for jobSpec in jobSpecs:
fileCheckInJEDI = taskBuffer.checkInputFileStatusInJEDI(
jobSpec)
if not fileCheckInJEDI:
jobSpec.jobStatus = 'closed'
jobSpec.jobSubStatus = 'cojumbo_wrong'
jobSpec.taskBufferErrorCode = pandaserver.taskbuffer.ErrorCode.EC_EventServiceInconsistentIn
taskBuffer.archiveJobs([jobSpec], False, True)
tmpLog.debug("kill {0} co-jumbo jobs in Waiting".format(
len(coJumboTokill)))
if len(coJumboTokill) > 0:
jediJobs = list(coJumboTokill)
nJob = 100
iJob = 0
while iJob < len(jediJobs):
tmpLog.debug(' killing %s' %
str(jediJobs[iJob:iJob + nJob]))
Client.killJobs(jediJobs[iJob:iJob + nJob],
51,
keepUnmerged=True)
iJob += nJob
except Exception:
errStr = traceback.format_exc()
tmpLog.error(errStr)
tmpLog.debug("Fork session")
# thread for fork
class ForkThr(threading.Thread):
def __init__(self, fileName):
threading.Thread.__init__(self)
self.fileName = fileName
def run(self):
if 'VIRTUAL_ENV' in os.environ:
prefix = os.environ['VIRTUAL_ENV']
else:
prefix = ''
setupStr = 'source {0}/etc/sysconfig/panda_server; '.format(prefix)
runStr = '%s/python -Wignore ' % panda_config.native_python
runStr += panda_config.pandaPython_dir + '/dataservice/forkSetupper.py -i '
runStr += self.fileName
if self.fileName.split('/')[-1].startswith('set.NULL.'):
runStr += ' -t'
comStr = setupStr + runStr
tmpLog.debug(comStr)
commands_get_status_output(comStr)
# get set.* files
filePatt = panda_config.logdir + '/' + 'set.*'
fileList = glob.glob(filePatt)
# the max number of threads
maxThr = 10
nThr = 0
# loop over all files
forkThrList = []
timeNow = datetime.datetime.utcnow()
for tmpName in fileList:
if not os.path.exists(tmpName):
continue
try:
# takes care of only recent files
modTime = datetime.datetime(
*(time.gmtime(os.path.getmtime(tmpName))[:7]))
if (timeNow - modTime) > datetime.timedelta(minutes=1) and \
(timeNow - modTime) < datetime.timedelta(hours=1):
cSt, cOut = commands_get_status_output(
'ps aux | grep fork | grep -v PYTH')
# if no process is running for the file
if cSt == 0 and tmpName not in cOut:
nThr += 1
thr = ForkThr(tmpName)
thr.start()
forkThrList.append(thr)
if nThr > maxThr:
break
except Exception:
errType, errValue = sys.exc_info()[:2]
tmpLog.error("%s %s" % (errType, errValue))
# join fork threads
for thr in forkThrList:
thr.join()
# terminate TaskBuffer IF
# taskBufferIF.terminate()
tmpLog.debug("===================== end =====================")