def injectIntoConfigCache(self, frameworkVersion, scramArch, initCommand, configUrl, configLabel, couchUrl, couchDBName): """ _injectIntoConfigCache_ """ logging.error("Injecting to config cache.\n"); configTempDir = tempfile.mkdtemp() configPath = os.path.join(configTempDir, "cmsswConfig.py") configString = urllib.urlopen(configUrl).read(-1) configFile = open(configPath, "w") configFile.write(configString) configFile.close() scramTempDir = tempfile.mkdtemp() wmcoreBase = getWMBASE() envPath = os.path.normpath(os.path.join(getWMBASE(), "../../../../../../../../apps/wmagent/etc/profile.d/init.sh")) scram = Scram(version = frameworkVersion, architecture = scramArch, directory = scramTempDir, initialise = initCommand, envCmd = "source %s" % envPath) scram.project() scram.runtime() scram("python2.6 %s/../../../bin/inject-to-config-cache %s %s PromptSkimmer cmsdataops %s %s None" % (wmcoreBase, couchUrl, couchDBName, configPath, configLabel)) shutil.rmtree(configTempDir) shutil.rmtree(scramTempDir) return
def injectIntoConfigCache(self, frameworkVersion, scramArch, initCommand, configUrl, configLabel, couchUrl, couchDBName): """ _injectIntoConfigCache_ """ configTempDir = tempfile.mkdtemp() configPath = os.path.join(configTempDir, "cmsswConfig.py") configString = urllib.urlopen(configUrl).read(-1) configFile = open(configPath, "w") configFile.write(configString) configFile.close() scramTempDir = tempfile.mkdtemp() scram = Scram(version = frameworkVersion, architecture = scramArch, directory = scramTempDir, initialise = initCommand) scram.project() scram.runtime() wmcoreBase = getWMBASE() scram("python2.6 %s/bin/inject-to-config-cache %s %s PromptSkimmer cmsdataops %s %s None" % (wmcoreBase, couchUrl, couchDBName, configPath, configLabel)) shutil.rmtree(configTempDir) shutil.rmtree(scramTempDir) return
def createScramEnv(self): scramArchitecture = self.getScramVersion() cmsswVersion = self.getCmsswVersion() self.logger.info( "Creating Scram environment with scram arch: %s and CMSSW version: %s", scramArchitecture, cmsswVersion) scram = Scram( version=cmsswVersion, directory=self.stepSpace.location, architecture=scramArchitecture, initialise=self.step.data.application.setup.softwareEnvironment) scram.project() # creates project area scram.runtime() # creates runtime environment return scram
def injectIntoConfigCache(frameworkVersion, scramArch, initCommand, configUrl, configLabel, couchUrl, couchDBName, envPath=None, binPath=None): """ _injectIntoConfigCache_ """ logging.info("Injecting to config cache.\n") configTempDir = tempfile.mkdtemp() configPath = os.path.join(configTempDir, "cmsswConfig.py") configString = urllib.urlopen(fixCVSUrl(configUrl)).read(-1) configFile = open(configPath, "w") configFile.write(configString) configFile.close() scramTempDir = tempfile.mkdtemp() wmcoreBase = getWMBASE() if not envPath: envPath = os.path.normpath( os.path.join( wmcoreBase, "../../../../../../../../apps/wmagent/etc/profile.d/init.sh")) scram = Scram(version=frameworkVersion, architecture=scramArch, directory=scramTempDir, initialise=initCommand, envCmd="source %s" % envPath) scram.project() scram.runtime() if not binPath: scram( "python2.6 %s/../../../bin/inject-to-config-cache %s %s PromptSkimmer cmsdataops %s %s None" % (wmcoreBase, couchUrl, couchDBName, configPath, configLabel)) else: scram( "python2.6 %s/inject-to-config-cache %s %s PromptSkimmer cmsdataops %s %s None" % (binPath, couchUrl, couchDBName, configPath, configLabel)) shutil.rmtree(configTempDir) shutil.rmtree(scramTempDir) return
def execute(self, emulator=None): """ _execute_ """ stepModule = "WMTaskSpace.%s" % self.stepName if (emulator != None): return emulator.emulate(self.step, self.job) # write the wrapper script to a temporary location # I don't pass it directly through os.system because I don't # trust that there won't be shell-escape shenanigans with # arbitrary input files scramSetup = self.step.application.setup.softwareEnvironment scramCommand = self.step.application.setup.scramCommand scramProject = self.step.application.setup.scramProject scramArch = self.step.application.setup.scramArch cmsswVersion = self.step.application.setup.cmsswVersion jobReportXML = self.step.output.jobReport cmsswCommand = self.step.application.command.executable cmsswConfig = self.step.application.command.configuration cmsswArguments = self.step.application.command.arguments logging.info("Executing MulticoreCMSSW step") multicoreSettings = self.step.application.multicore numberOfCores = multicoreSettings.numberOfCores logging.info("Multicore configured for %s cores" % numberOfCores) #Todo: Create input file list from job writing filelist one per line to filelist = open(multicoreSettings.inputfilelist, 'w') for inputFile in self.job['input_files']: filelist.write("%s\n" % inputFile['lfn']) filelist.close() # # scram bootstrap # scram = Scram( command=scramCommand, version=cmsswVersion, initialise=self.step.application.setup.softwareEnvironment, directory=self.step.builder.workingDir, architecture=scramArch, ) logging.info("Running SCRAM") try: projectOutcome = scram.project() except Exception, ex: msg = "Exception raised while running scram.\n" msg += str(ex) logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(60513, "ScramSetupFailure", msg)
def testC(self): """ test all method calls in test mode """ s = Scram( initialise="/bin/date", architecture="slc5_amd64_gcc454", version="CMSSW_X_Y_Z", directory=self.testDir, test=True ) try: status = s.project() except Exception as ex: msg = "Error running Scram.project:\n %s" % str(ex) self.fail(msg) self.assertEqual(status, 0) self.assertTrue(os.path.exists(s.projectArea)) self.assertTrue("project" in s.lastExecuted) self.assertTrue("CMSSW_X_Y_Z" in s.lastExecuted) try: status = s.runtime() except Exception as ex: msg = "Error running Scram.runtime:\n %s" % str(ex) self.fail(msg) self.assertEqual(status, 0) self.assertTrue("ru -sh" in s.lastExecuted) self.assertTrue("TEST_MODE" in s.runtimeEnv) comm = "echo \"Hello World\"" try: status = s(comm) except Exception as ex: msg = "Failed to call Scram object:\n %s" % str(ex) self.assertEqual(status, 0) self.assertEqual(s.lastExecuted, comm)
def execute(self, emulator=None): """ _execute_ """ stepModule = "WMTaskSpace.%s" % self.stepName if emulator is not None: return emulator.emulate(self.step, self.job) # write the wrapper script to a temporary location # I don't pass it directly through os.system because I don't # trust that there won't be shell-escape shenanigans with # arbitrary input files scramSetup = self.step.application.setup.softwareEnvironment scramCommand = self.step.application.setup.scramCommand scramProject = self.step.application.setup.scramProject scramArch = self.step.application.setup.scramArch cmsswVersion = self.step.application.setup.cmsswVersion jobReportXML = self.step.output.jobReport cmsswCommand = self.step.application.command.executable cmsswConfig = self.step.application.command.configuration cmsswArguments = self.step.application.command.arguments userTarball = ",".join(self.step.user.inputSandboxes) userFiles = ",".join(self.step.user.userFiles) logging.info("User files are %s", userFiles) logging.info("User sandboxes are %s", userTarball) multicoreSettings = self.step.application.multicore try: logging.info("CMSSW configured for %s cores", multicoreSettings.numberOfCores) except AttributeError: logging.info("No value set for multicore.numberOfCores") logging.info("Executing CMSSW step") # # set any global environment variables # try: os.environ["FRONTIER_ID"] = "wmagent_%s" % (self.report.data.workload) except Exception as ex: logging.error("Have critical error in setting FRONTIER_ID: %s", str(ex)) logging.error("Continuing, as this is not a critical function yet.") # # scram bootstrap # scram = Scram( command=scramCommand, version=cmsswVersion, initialise=self.step.application.setup.softwareEnvironment, directory=self.step.builder.workingDir, architecture=scramArch, ) logging.info("Runing SCRAM") try: projectOutcome = scram.project() except Exception as ex: msg = "Exception raised while running scram.\n" msg += str(ex) logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) if projectOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) runtimeOutcome = scram.runtime() if runtimeOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) # # pre scripts # logging.info("Running PRE scripts") for script in self.step.runtime.preScripts: # TODO: Exception handling and error handling & logging scriptProcess = subprocess.Popen( ["/bin/bash"], shell=True, cwd=self.step.builder.workingDir, stdout=subprocess.PIPE, stderr=subprocess.PIPE, stdin=subprocess.PIPE, ) # BADPYTHON scriptProcess.stdin.write("export LD_LIBRARY_PATH=$LD_LIBRARY_PATH\n") invokeCommand = "%s -m WMCore.WMRuntime.ScriptInvoke %s %s \n" % (sys.executable, stepModule, script) logging.info(" Invoking command: %s", invokeCommand) scriptProcess.stdin.write(invokeCommand) stdout, stderr = scriptProcess.communicate() retCode = scriptProcess.returncode if retCode > 0: msg = "Error running command\n%s\n" % invokeCommand msg += "%s\n %s\n %s\n" % (retCode, stdout, stderr) logging.critical("Error running command") logging.critical(msg) raise WMExecutionFailure(50513, "PreScriptFailure", msg) # # pre scripts with scram # logging.info("RUNNING SCRAM SCRIPTS") for script in self.step.runtime.scramPreScripts: # invoke scripts with scram() runtimeDir = getattr(self.step.runtime, "scramPreDir", None) invokeCommand = ( self.step.runtime.invokeCommand if hasattr(self.step.runtime, "invokeCommand") else "%s -m WMCore.WMRuntime.ScriptInvoke %s" % (sys.executable, stepModule) ) invokeCommand += " %s \n" % script retCode = scram(invokeCommand, runtimeDir=runtimeDir) if retCode > 0: msg = "Error running command\n%s\n" % invokeCommand msg += "%s\n " % retCode msg += scram.diagnostic() logging.critical(msg) raise WMExecutionFailure(50513, "PreScriptScramFailure", msg) configPath = "%s/%s-main.sh" % (self.step.builder.workingDir, self.stepName) handle = open(configPath, "w") handle.write(CONFIG_BLOB) handle.close() # spawn this new process # the script looks for: # <SCRAM_COMMAND> <SCRAM_PROJECT> <CMSSW_VERSION> <JOB_REPORT> <EXECUTABLE> <CONFIG> # open the output files stdoutHandle = open(self.step.output.stdout, "w") stderrHandle = open(self.step.output.stderr, "w") args = [ "/bin/bash", configPath, scramSetup, scramArch, scramCommand, scramProject, cmsswVersion, jobReportXML, cmsswCommand, cmsswConfig, userTarball, userFiles, cmsswArguments, ] logging.info("Executing CMSSW. args: %s", args) # at CERN override the environment to work around problem with GSI authentication plugin and EOS if socket.getfqdn().endswith("cern.ch"): returncode = subprocess.call( args, stdout=stdoutHandle, stderr=stderrHandle, env=dict(os.environ, XRD_LOADBALANCERTTL="86400") ) else: returncode = subprocess.call(args, stdout=stdoutHandle, stderr=stderrHandle) self.setCondorChirpAttrDelayed("Chirp_WMCore_cmsRun_ExitCode", returncode) self.setCondorChirpAttrDelayed("Chirp_WMCore_%s_ExitCode" % self.stepName, returncode) stdoutHandle.close() stderrHandle.close() self.step.execution.exitStatus = returncode argsDump = {"arguments": args} if returncode != 0: msg = "Error running cmsRun\n%s\n" % argsDump msg += "Return code: %s\n" % returncode logging.critical(msg) raise WMExecutionFailure(returncode, "CmsRunFailure", msg) try: self.report.parse(jobReportXML, stepName=self.stepName) except Exception as ex: # Catch it if something goes wrong raise WMExecutionFailure(50115, "BadJobReportXML", str(ex)) stepHelper = WMStepHelper(self.step) typeHelper = stepHelper.getTypeHelper() acquisitionEra = self.task.getAcquisitionEra() processingVer = self.task.getProcessingVersion() processingStr = self.task.getProcessingString() validStatus = self.workload.getValidStatus() inputPath = self.task.getInputDatasetPath() globalTag = typeHelper.getGlobalTag() prepID = self.task.getPrepID() cacheUrl, cacheDB, configID = stepHelper.getConfigInfo() self.report.setValidStatus(validStatus=validStatus) self.report.setGlobalTag(globalTag=globalTag) self.report.setPrepID(prepID) self.report.setInputDataset(inputPath=inputPath) self.report.setAcquisitionProcessing( acquisitionEra=acquisitionEra, processingVer=processingVer, processingStr=processingStr ) self.report.setConfigURL(configURL="%s;;%s;;%s" % (cacheUrl, cacheDB, configID)) # Attach info to files self.report.addInfoToOutputFilesForStep(stepName=self.stepName, step=self.step) self.report.checkForOutputFiles(stepName=self.stepName) self.report.checkForAdlerChecksum(stepName=self.stepName) self.report.checkForRunLumiInformation(stepName=self.stepName) if self.step.output.keep != True: self.report.killOutput() else: # Check that we only keep the desired output for module in stepHelper.getIgnoredOutputModules(): self.report.deleteOutputModuleForStep(stepName=self.stepName, moduleName=module) # Add stageout LFN to existing TFileService files reportAnalysisFiles = self.report.getAnalysisFilesFromStep(self.stepName) for reportAnalysisFile in reportAnalysisFiles: newLFN = analysisFileLFN(reportAnalysisFile.fileName, self.step.user.lfnBase, self.job) addAttributesToFile(reportAnalysisFile, pfn=reportAnalysisFile.fileName, lfn=newLFN, validate=False) # Add analysis file entries for additional files listed in workflow for fileName in stepHelper.listAnalysisFiles(): analysisFile = stepHelper.getAnalysisFile(fileName) if os.path.isfile(analysisFile.fileName): newLFN = analysisFileLFN(analysisFile.fileName, analysisFile.lfnBase, self.job) self.report.addAnalysisFile( analysisFile.fileName, lfn=newLFN, Source="UserDefined", pfn=os.path.join(os.getcwd(), analysisFile.fileName), validate=False, ) return
logFormatter = logging.Formatter("%(asctime)s:%(levelname)s:%(module)s:%(message)s") logging.Formatter.converter = time.gmtime logHandler.setFormatter(logFormatter) logging.getLogger().addHandler(logHandler) if ad and not "CRAB3_RUNTIME_DEBUG" in os.environ: startDashboardMonitoring(ad) print("==== CMSSW Stack Execution STARTING at %s ====" % time.asctime(time.gmtime())) scram = Scram( version = opts.cmsswVersion, directory = os.getcwd(), architecture = opts.scramArch, ) print("==== SCRAM Obj CREATED at %s ====" % time.asctime(time.gmtime())) if scram.project() or scram.runtime(): #if any of the two commands fail... msg = scram.diagnostic() handleException("FAILED", EC_CMSMissingSoftware, 'Error setting CMSSW environment: %s' % msg) mintime() sys.exit(EC_CMSMissingSoftware) extractUserSandbox(opts.archiveJob, opts.cmsswVersion) try: jobExitCode = None if opts.scriptExe=='None': print("==== CMSSW JOB Execution started at %s ====" % time.asctime(time.gmtime())) cmssw = executeCMSSWStack(opts, scram) jobExitCode = cmssw.step.execution.exitStatus else: print("==== ScriptEXE Execution started at %s ====" % time.asctime(time.gmtime()))
def execute(self, emulator=None): """ _execute_ """ scramCommand = self.step.application.setup.scramCommand scramArch = self.step.application.setup.scramArch cmsswVersion = self.step.application.setup.cmsswVersion # Are we using emulators again? if (emulator != None): return emulator.emulate(self.step, self.job) overrides = {} if hasattr(self.step, 'override'): overrides = self.step.override.dictionary_() # Set wait to over an hour waitTime = overrides.get( 'waitTime', 3600 + (self.step.retryDelay * self.step.retryCount)) # hardcode CERN Castor T0_CH_CERN_MSS stageout parameters castorStageOutParams = {} castorStageOutParams['command'] = overrides.get('command', "xrdcp") castorStageOutParams['option'] = overrides.get('option', "--cerncastor") castorStageOutParams['phedex-node'] = overrides.get( 'phedex-node', "T2_CH_CERN") castorStageOutParams['lfn-prefix'] = overrides.get( 'lfn-prefix', "root://castorcms.cern.ch//castor/cern.ch/cms") # hardcode CERN EOS T2_CH_CERN stageout parameters eosStageOutParams = {} eosStageOutParams['command'] = overrides.get('command', "xrdcp") eosStageOutParams['option'] = overrides.get('option', "") eosStageOutParams['phedex-node'] = overrides.get( 'phedex-node', "T2_CH_CERN") eosStageOutParams['lfn-prefix'] = overrides.get( 'lfn-prefix', "root://eoscms.cern.ch//eos/cms") # are we using the new stageout method ? useNewStageOutCode = False if getattr(self.step, 'newStageout', False) or \ ('newStageOut' in overrides and overrides.get('newStageOut')): useNewStageOutCode = True try: castorStageOutMgr = StageOutMgr(**castorStageOutParams) eosStageOutMgr = StageOutMgr(**eosStageOutParams) stageInMgr = StageInMgr() deleteMgr = DeleteMgr() except Exception as ex: msg = "Unable to load StageOut/Delete Impl: %s" % str(ex) logging.error(msg) raise WMExecutionFailure(60312, "MgrImplementationError", msg) # prepare output tar file taskName = self.report.getTaskName().split('/')[-1] host = socket.gethostname().split('.')[0] tarName = '%s-%s-%s-%i-logs.tar' % ( self.report.data.workload, taskName, host, self.job["counter"]) tarLocation = os.path.join(self.stepSpace.location, tarName) # check if the cmsswVersion supports edmCopyUtil (min CMSSW_8_X) result = re.match("CMSSW_([0-9]+)_([0-9]+)_([0-9]+).*", cmsswVersion) useEdmCopyUtil = False if result: try: if int(result.group(1)) >= 8: useEdmCopyUtil = True except ValueError: pass # setup Scram needed to run edmCopyUtil if useEdmCopyUtil: scram = Scram( command=scramCommand, version=cmsswVersion, initialise=self.step.application.setup.softwareEnvironment, directory=self.step.builder.workingDir, architecture=scramArch, ) logging.info("Running scram") try: projectOutcome = scram.project() except Exception as ex: msg = "Exception raised while running scram.\n" msg += str(ex) logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) if projectOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) runtimeOutcome = scram.runtime() if runtimeOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) # iterate through input files localLogs = [] deleteLogArchives = [] if useEdmCopyUtil: numberOfFilesPerCopy = 10 else: numberOfFilesPerCopy = 1 for logs in grouper(self.job["input_files"], numberOfFilesPerCopy): copyCommand = "env X509_USER_PROXY=%s edmCopyUtil" % os.environ.get( 'X509_USER_PROXY', None) for log in logs: copyCommand += " %s" % log['lfn'] copyCommand += " %s" % self.step.builder.workingDir # give up after timeout of 1 minute per input file signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(60 * numberOfFilesPerCopy) filesCopied = False try: if useEdmCopyUtil: logging.info("Running edmCopyUtil") retval = scram(copyCommand) if retval == 0: filesCopied = True else: logging.info("Running stageIn") for log in logs: fileInfo = {"LFN": log['lfn']} logArchive = stageInMgr(**fileInfo) if logArchive: filesCopied = True except Alarm: logging.error( "Indefinite hang during edmCopyUtil/stageIn of logArchives" ) except StageOutFailure: logging.error("Unable to stageIn logArchives") except Exception: raise signal.alarm(0) if filesCopied: for log in logs: localLogs.append( os.path.join(self.step.builder.workingDir, os.path.basename(log['lfn']))) deleteLogArchives.append(log) self.report.addInputFile(sourceName="logArchives", lfn=log['lfn']) else: logging.error("Unable to copy logArchives to local disk") if useEdmCopyUtil: with open('scramOutput.log', 'r') as f: logging.error("Scram output: %s", f.read()) for log in logs: self.report.addSkippedFile(log['lfn'], None) # create tarfile if any logArchive copied in if localLogs: tarFile = tarfile.open(tarLocation, 'w:') for log in localLogs: path = log.split('/') tarFile.add(name=log, arcname=os.path.join(path[-3], path[-2], path[-1])) os.remove(log) tarFile.close() else: msg = "Unable to copy any logArchives to local disk" logging.error(msg) raise WMExecutionFailure(60312, "LogCollectError", msg) # now staging out the LogCollect tarfile logging.info("Staging out LogCollect tarfile to Castor and EOS") now = datetime.datetime.now() lfn = "/store/logs/prod/%i/%.2i/%s/%s/%s" % ( now.year, now.month, "WMAgent", self.report.data.workload, os.path.basename(tarLocation)) tarInfo = {'LFN': lfn, 'PFN': tarLocation, 'PNN': None, 'GUID': None} # perform mandatory stage out to CERN Castor signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(waitTime) try: castorStageOutMgr(tarInfo) except Alarm: msg = "Indefinite hang during stageOut of LogCollect to Castor" logging.error(msg) raise WMExecutionFailure(60409, "LogCollectTimeout", msg) except Exception as ex: msg = "Unable to stageOut LogCollect to Castor:\n" msg += str(ex) logging.error(msg) raise WMExecutionFailure(60408, "LogCollectStageOutError", msg) signal.alarm(0) # add to job report self.report.addOutputFile(outputModule="LogCollect", file=tarInfo) outputRef = getattr(self.report.data, self.stepName) outputRef.output.pfn = tarInfo['PFN'] outputRef.output.location = tarInfo['PNN'] outputRef.output.lfn = tarInfo['LFN'] tarInfo = {'LFN': lfn, 'PFN': tarLocation, 'PNN': None, 'GUID': None} # then, perform best effort stage out to CERN EOS signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(waitTime) try: eosStageOutMgr(tarInfo) except Alarm: logging.error( "Indefinite hang during stageOut of LogCollect to EOS") except Exception as ex: logging.error("Unable to stageOut LogCollect to EOS:\n", ex) signal.alarm(0) # we got this far, delete input for log in deleteLogArchives: # give up after timeout of 1 minutes signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(60) try: fileToDelete = { 'LFN': log['lfn'], 'PFN': None, 'PNN': None, 'StageOutCommand': None } deleteMgr(fileToDelete=fileToDelete) except Alarm: logging.error("Indefinite hang during delete of logArchive") except Exception as ex: logging.error("Unable to delete logArchive: %s", ex) signal.alarm(0) return
def execute(self, emulator = None): """ _execute_ """ scramCommand = self.step.application.setup.scramCommand scramArch = self.step.application.setup.scramArch cmsswVersion = self.step.application.setup.cmsswVersion # Are we using emulators again? if (emulator != None): return emulator.emulate( self.step, self.job ) overrides = {} if hasattr(self.step, 'override'): overrides = self.step.override.dictionary_() # Set wait to over an hour waitTime = overrides.get('waitTime', 3600 + (self.step.retryDelay * self.step.retryCount)) # Pull out StageOutMgr Overrides # switch between old stageOut behavior and new, fancy stage out behavior useNewStageOutCode = False if 'newStageOut' in overrides and overrides.get('newStageOut'): useNewStageOutCode = True # hardcode CERN Castor T0_CH_CERN_MSS stageout parameters castorStageOutParams = {} castorStageOutParams['command'] = overrides.get('command', "srmv2-lcg") castorStageOutParams['option'] = overrides.get('option', "") castorStageOutParams['se-name'] = overrides.get('se-name', "srm-cms.cern.ch") castorStageOutParams['phedex-node'] = overrides.get('phedex-node', "T2_CH_CERN") castorStageOutParams['lfn-prefix'] = overrides.get('lfn-prefix', "srm://srm-cms.cern.ch:8443/srm/managerv2?SFN=/castor/cern.ch/cms") # hardcode CERN EOS T2_CH_CERN stageout parameters eosStageOutParams = {} eosStageOutParams['command'] = overrides.get('command', "srmv2-lcg") eosStageOutParams['option'] = overrides.get('option', "") eosStageOutParams['se-name'] = overrides.get('se-name', "srm-eoscms.cern.ch") eosStageOutParams['phedex-node'] = overrides.get('phedex-node', "T2_CH_CERN") eosStageOutParams['lfn-prefix'] = overrides.get('lfn-prefix', "srm://srm-eoscms.cern.ch:8443/srm/v2/server?SFN=/eos/cms") # are we using the new stageout method ? useNewStageOutCode = False if getattr(self.step, 'newStageout', False) or \ ('newStageOut' in overrides and overrides.get('newStageOut')): useNewStageOutCode = True try: if useNewStageOutCode: # is this even working ??? #logging.info("LOGCOLLECT IS USING NEW STAGEOUT CODE") #stageOutMgr = StageOutMgr(retryPauseTime = self.step.retryDelay, # numberOfRetries = self.step.retryCount, # **overrides) #stageInMgr = StageInMgr(retryPauseTime = 0, # numberOfRetries = 0) #deleteMgr = DeleteMgr(retryPauseTime = 0, # numberOfRetries = 0) castorStageOutMgr = StageOutMgr(**castorStageOutParams) eosStageOutMgr = StageOutMgr(**eosStageOutParams) stageInMgr = StageInMgr() deleteMgr = DeleteMgr() else: castorStageOutMgr = StageOutMgr(**castorStageOutParams) eosStageOutMgr = StageOutMgr(**eosStageOutParams) stageInMgr = StageInMgr() deleteMgr = DeleteMgr() except Exception as ex: msg = "Unable to load StageOut/Delete Impl: %s" % str(ex) logging.error(msg) raise WMExecutionFailure(60312, "MgrImplementationError", msg) # prepare output tar file taskName = self.report.getTaskName().split('/')[-1] host = socket.gethostname().split('.')[0] tarName = '%s-%s-%s-%i-logs.tar' % (self.report.data.workload, taskName, host , self.job["counter"]) tarLocation = os.path.join(self.stepSpace.location, tarName) # check if the cmsswVersion supports edmCopyUtil (min CMSSW_8_X) result = re.match("CMSSW_([0-9]+)_([0-9]+)_([0-9]+).*", cmsswVersion) useEdmCopyUtil = False if result: try: if int(result.group(1)) >= 8: useEdmCopyUtil = True except ValueError: pass # setup Scram needed to run edmCopyUtil if useEdmCopyUtil: scram = Scram( command=scramCommand, version=cmsswVersion, initialise=self.step.application.setup.softwareEnvironment, directory=self.step.builder.workingDir, architecture=scramArch, ) logging.info("Running scram") try: projectOutcome = scram.project() except Exception as ex: msg = "Exception raised while running scram.\n" msg += str(ex) logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) if projectOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) runtimeOutcome = scram.runtime() if runtimeOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) # iterate through input files localLogs = [] deleteLogArchives = [] if useEdmCopyUtil: numberOfFilesPerCopy = 10 else: numberOfFilesPerCopy = 1 for logs in grouper(self.job["input_files"], numberOfFilesPerCopy): copyCommand = "env X509_USER_PROXY=%s edmCopyUtil" % os.environ.get('X509_USER_PROXY', None) for log in logs: copyCommand += " %s" % log['lfn'] copyCommand += " %s" % self.step.builder.workingDir # give up after timeout of 1 minute per input file signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(60 * numberOfFilesPerCopy) filesCopied = False try: if useEdmCopyUtil: logging.info("Running edmCopyUtil") retval = scram(copyCommand) if retval == 0: filesCopied = True else: logging.info("Running stageIn") for log in logs: fileInfo = {"LFN": log['lfn']} logArchive = stageInMgr(**fileInfo) if logArchive: filesCopied = True except Alarm: logging.error("Indefinite hang during edmCopyUtil/stageIn of logArchives") except StageOutFailure: logging.error("Unable to stageIn logArchives") except Exception: raise signal.alarm(0) if filesCopied: for log in logs: localLogs.append(os.path.join(self.step.builder.workingDir, os.path.basename(log['lfn']))) deleteLogArchives.append(log) self.report.addInputFile(sourceName = "logArchives", lfn = log['lfn']) else: logging.error("Unable to copy logArchives to local disk") if useEdmCopyUtil: with open('scramOutput.log', 'r') as f: logging.error("Scram output: %s", f.read()) for log in logs: self.report.addSkippedFile(log['lfn'], None) # create tarfile if any logArchive copied in if localLogs: tarFile = tarfile.open(tarLocation, 'w:') for log in localLogs: path = log.split('/') tarFile.add(name = log, arcname = os.path.join(path[-3], path[-2], path[-1])) os.remove(log) tarFile.close() else: msg = "Unable to copy any logArchives to local disk" logging.error(msg) raise WMExecutionFailure(60312, "LogCollectError", msg) # now staging out the LogCollect tarfile logging.info("Staging out LogCollect tarfile to Castor and EOS") now = datetime.datetime.now() lfn = "/store/logs/prod/%i/%.2i/%s/%s/%s" % (now.year, now.month, "WMAgent", self.report.data.workload, os.path.basename(tarLocation)) tarInfo = {'LFN' : lfn, 'PFN' : tarLocation, 'SEName' : None, 'PNN' : None, 'GUID' : None} # perform mandatory stage out to CERN Castor signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(waitTime) try: castorStageOutMgr(tarInfo) except Alarm: msg = "Indefinite hang during stageOut of LogCollect to Castor" logging.error(msg) raise WMExecutionFailure(60409, "LogCollectTimeout", msg) except Exception as ex: msg = "Unable to stageOut LogCollect to Castor:\n" msg += str(ex) logging.error(msg) raise WMExecutionFailure(60408, "LogCollectStageOutError", msg) signal.alarm(0) # add to job report self.report.addOutputFile(outputModule = "LogCollect", file = tarInfo) outputRef = getattr(self.report.data, self.stepName) outputRef.output.pfn = tarInfo['PFN'] outputRef.output.location = tarInfo['PNN'] outputRef.output.lfn = tarInfo['LFN'] tarInfo = {'LFN' : lfn, 'PFN' : tarLocation, 'SEName' : None, 'PNN' : None, 'GUID' : None} # then, perform best effort stage out to CERN EOS signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(waitTime) try: eosStageOutMgr(tarInfo) except Alarm: logging.error("Indefinite hang during stageOut of LogCollect to EOS") except Exception as ex: logging.error("Unable to stageOut LogCollect to EOS:\n", ex) signal.alarm(0) # we got this far, delete input for log in deleteLogArchives: # give up after timeout of 1 minutes signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(60) try: fileToDelete = {'LFN': log['lfn'], 'PFN': None, 'SEName': None, 'PNN': None, 'StageOutCommand': None} deleteMgr(fileToDelete = fileToDelete) except Alarm: logging.error("Indefinite hang during delete of logArchive") except Exception as ex: logging.error("Unable to delete logArchive: %s", ex) signal.alarm(0) return
def execute(self, emulator=None): """ _execute_ """ # Are we using emulators again? if emulator is not None: return emulator.emulate(self.step, self.job) logging.info("Steps.Executors.%s.execute called", self.__class__.__name__) scramCommand = self.step.application.setup.scramCommand cmsswVersion = self.step.application.setup.cmsswVersion scramArch = getSingleScramArch(self.step.application.setup.scramArch) overrideCatalog = getattr(self.step.application, 'overrideCatalog', None) overrides = {} if hasattr(self.step, 'override'): overrides = self.step.override.dictionary_() # Set wait to over an hour waitTime = overrides.get('waitTime', 3600 + (self.step.retryDelay * self.step.retryCount)) # hardcode CERN EOS T2_CH_CERN stageout parameters eosStageOutParams = {} eosStageOutParams['command'] = overrides.get('command', "xrdcp") eosStageOutParams['option'] = overrides.get('option', "--wma-disablewriterecovery") eosStageOutParams['phedex-node'] = overrides.get('phedex-node', "T2_CH_CERN") eosStageOutParams['lfn-prefix'] = overrides.get('lfn-prefix', "root://eoscms.cern.ch//eos/cms") try: eosStageOutMgr = StageOutMgr(**eosStageOutParams) stageInMgr = StageInMgr() deleteMgr = DeleteMgr() except Exception as ex: msg = "Unable to load StageOut/Delete Impl: %s" % str(ex) logging.error(msg) raise WMExecutionFailure(60312, "MgrImplementationError", msg) # prepare output tar file taskName = self.report.getTaskName().split('/')[-1] host = socket.gethostname().split('.')[0] tarName = '%s-%s-%s-%i-logs.tar' % (self.report.data.workload, taskName, host, self.job["counter"]) tarLocation = os.path.join(self.stepSpace.location, tarName) # Supported by any release beyond CMSSW_8_X, however DaviX is broken until CMSSW_10_4_X # see: https://github.com/cms-sw/cmssw/issues/25292 useEdmCopyUtil = True if isCMSSWSupported(cmsswVersion, "CMSSW_10_4_0"): pass elif scramArch.startswith('slc7_amd64_'): msg = "CMSSW too old or not fully functional to support edmCopyUtil, using CMSSW_10_4_0 instead" logging.warning(msg) cmsswVersion = "CMSSW_10_4_0" scramArch = "slc7_amd64_gcc820" elif scramArch.startswith('slc6_amd64_'): msg = "CMSSW too old or not fully functional to support edmCopyUtil, using CMSSW_10_4_0 instead" logging.warning(msg) cmsswVersion = "CMSSW_10_4_0" scramArch = "slc6_amd64_gcc700" else: useEdmCopyUtil = False logging.info("Using edmCopyUtil: %s", useEdmCopyUtil) # setup Scram needed to run edmCopyUtil if useEdmCopyUtil: scram = Scram( command=scramCommand, version=cmsswVersion, initialise=self.step.application.setup.softwareEnvironment, directory=self.step.builder.workingDir, architecture=scramArch, ) logging.info("Running scram") try: projectOutcome = scram.project() except Exception as ex: msg = "Exception raised while running scram.\n" msg += str(ex) logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) if projectOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) runtimeOutcome = scram.runtime() if runtimeOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) # iterate through input files localLogs = [] deleteLogArchives = [] if useEdmCopyUtil: numberOfFilesPerCopy = 10 else: numberOfFilesPerCopy = 1 for logs in grouper(self.job["input_files"], numberOfFilesPerCopy): copyCommand = "env X509_USER_PROXY=%s edmCopyUtil" % os.environ.get('X509_USER_PROXY', None) # specify TFC if necessary if overrideCatalog: copyCommand += " -c %s" % overrideCatalog for log in logs: copyCommand += " %s" % log['lfn'] copyCommand += " %s" % self.step.builder.workingDir # give up after timeout of 1 minute per input file signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(60 * numberOfFilesPerCopy) filesCopied = False try: if useEdmCopyUtil: logging.info("Running edmCopyUtil") retval = scram(copyCommand) if retval == 0: filesCopied = True else: logging.info("Running stageIn") for log in logs: fileInfo = {"LFN": log['lfn']} logArchive = stageInMgr(**fileInfo) if logArchive: filesCopied = True except Alarm: logging.error("Indefinite hang during edmCopyUtil/stageIn of logArchives") except StageOutFailure: logging.error("Unable to stageIn logArchives") except Exception: raise signal.alarm(0) if filesCopied: for log in logs: localLogs.append(os.path.join(self.step.builder.workingDir, os.path.basename(log['lfn']))) deleteLogArchives.append(log) self.report.addInputFile(sourceName="logArchives", lfn=log['lfn']) else: logging.error("Unable to copy logArchives to local disk") for log in logs: self.report.addSkippedFile(log['lfn'], None) # create tarfile if any logArchive copied in if localLogs: with tarfile.open(tarLocation, 'w:') as tarFile: for log in localLogs: path = log.split('/') tarFile.add(name=log, arcname=os.path.join(path[-3], path[-2], path[-1])) os.remove(log) else: msg = "Unable to copy any logArchives to local disk" logging.error(msg) raise WMExecutionFailure(60312, "LogCollectError", msg) # now staging out the LogCollect tarfile logging.info("Staging out LogCollect tarfile to EOS (skipping CASTOR)") now = datetime.datetime.now() lfn = "/store/logs/prod/%i/%.2i/%s/%s/%s" % (now.year, now.month, "WMAgent", self.report.data.workload, os.path.basename(tarLocation)) tarInfo = {'LFN': lfn, 'PFN': tarLocation, 'PNN': None, 'GUID': None} # perform mandatory stage out to CERN EOS signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(waitTime) try: eosStageOutMgr(tarInfo) except Alarm: msg = "Indefinite hang during stageOut of LogCollect to EOS" logging.error(msg) raise WMExecutionFailure(60409, "LogCollectTimeout", msg) except Exception as ex: msg = "Unable to stageOut LogCollect to Castor:\n" msg += str(ex) logging.error(msg) raise WMExecutionFailure(60408, "LogCollectStageOutError", msg) signal.alarm(0) # add to job report self.report.addOutputFile(outputModule="LogCollect", aFile=tarInfo) outputRef = getattr(self.report.data, self.stepName) outputRef.output.pfn = tarInfo['PFN'] outputRef.output.location = tarInfo['PNN'] outputRef.output.lfn = tarInfo['LFN'] # we got this far, delete ALL input files assigned to this job for log in self.job["input_files"]: # give up after timeout of 1 minutes signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(60) try: fileToDelete = {'LFN': log['lfn'], 'PFN': None, 'PNN': None, 'StageOutCommand': None} deleteMgr(fileToDelete=fileToDelete) except Alarm: logging.error("Indefinite hang during delete of logArchive") except Exception as ex: logging.error("Unable to delete logArchive: %s", ex) signal.alarm(0) return
def execute(self, emulator=None): """ _execute_ """ stepModule = "WMTaskSpace.%s" % self.stepName if emulator is not None: return emulator.emulate(self.step, self.job) # write the wrapper script to a temporary location # I don't pass it directly through os.system because I don't # trust that there won't be shell-escape shenanigans with # arbitrary input files scramSetup = self.step.application.setup.softwareEnvironment scramCommand = self.step.application.setup.scramCommand scramProject = self.step.application.setup.scramProject scramArch = self.step.application.setup.scramArch cmsswVersion = self.step.application.setup.cmsswVersion jobReportXML = self.step.output.jobReport cmsswCommand = self.step.application.command.executable cmsswConfig = self.step.application.command.configuration cmsswArguments = self.step.application.command.arguments userTarball = ','.join(self.step.user.inputSandboxes) userFiles = ','.join(self.step.user.userFiles) logging.info('User files are %s', userFiles) logging.info('User sandboxes are %s', userTarball) scramArch = getSingleScramArch(scramArch) multicoreSettings = self.step.application.multicore try: logging.info("CMSSW configured for %s cores and %s event streams", multicoreSettings.numberOfCores, multicoreSettings.eventStreams) except AttributeError: logging.info( "No value set for multicore numberOfCores or eventStreams") logging.info("Executing CMSSW step") # # set any global environment variables # try: os.environ['FRONTIER_ID'] = 'wmagent_%s' % ( self.report.data.workload) except Exception as ex: logging.error('Have critical error in setting FRONTIER_ID: %s', str(ex)) logging.error( 'Continuing, as this is not a critical function yet.') # # scram bootstrap # scram = Scram( command=scramCommand, version=cmsswVersion, initialise=self.step.application.setup.softwareEnvironment, directory=self.step.builder.workingDir, architecture=scramArch, ) logging.info("Runing SCRAM") try: projectOutcome = scram.project() except Exception as ex: msg = "Exception raised while running scram.\n" msg += str(ex) logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) if projectOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) runtimeOutcome = scram.runtime() if runtimeOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) # # pre scripts # logging.info("Running PRE scripts") for script in self.step.runtime.preScripts: # TODO: Exception handling and error handling & logging scriptProcess = subprocess.Popen( ["/bin/bash"], shell=True, cwd=self.step.builder.workingDir, stdout=subprocess.PIPE, stderr=subprocess.PIPE, stdin=subprocess.PIPE, ) # BADPYTHON scriptProcess.stdin.write( "export LD_LIBRARY_PATH=$LD_LIBRARY_PATH\n") invokeCommand = "%s -m WMCore.WMRuntime.ScriptInvoke %s %s \n" % ( sys.executable, stepModule, script) logging.info(" Invoking command: %s", invokeCommand) scriptProcess.stdin.write(invokeCommand) stdout, stderr = scriptProcess.communicate() retCode = scriptProcess.returncode if retCode > 0: msg = "Error running command\n%s\n" % invokeCommand msg += "%s\n %s\n %s\n" % (retCode, stdout, stderr) logging.critical("Error running command") logging.critical(msg) raise WMExecutionFailure(50513, "PreScriptFailure", msg) # # pre scripts with scram # logging.info("RUNNING SCRAM SCRIPTS") for script in self.step.runtime.scramPreScripts: # invoke scripts with scram() runtimeDir = getattr(self.step.runtime, 'scramPreDir', None) invokeCommand = self.step.runtime.invokeCommand if hasattr(self.step.runtime, 'invokeCommand') else \ "%s -m WMCore.WMRuntime.ScriptInvoke %s" % (sys.executable, stepModule) invokeCommand += " %s \n" % script retCode = scram(invokeCommand, runtimeDir=runtimeDir) if retCode > 0: msg = "Error running command\n%s\n" % invokeCommand msg += "%s\n " % retCode msg += scram.diagnostic() logging.critical(msg) raise WMExecutionFailure(50513, "PreScriptScramFailure", msg) configPath = "%s/%s-main.sh" % (self.step.builder.workingDir, self.stepName) handle = open(configPath, 'w') handle.write(CONFIG_BLOB) handle.close() # spawn this new process # the script looks for: # <SCRAM_COMMAND> <SCRAM_PROJECT> <CMSSW_VERSION> <JOB_REPORT> <EXECUTABLE> <CONFIG> # open the output files stdoutHandle = open(self.step.output.stdout, 'w') stderrHandle = open(self.step.output.stderr, 'w') args = [ '/bin/bash', configPath, scramSetup, scramArch, scramCommand, scramProject, cmsswVersion, jobReportXML, cmsswCommand, cmsswConfig, userTarball, userFiles, cmsswArguments ] logging.info("Executing CMSSW. args: %s", args) # possibly needed environment overrides for CMSSW call go here envOverride = {} # work around problem with GSI authentication plugin and EOS at CERN if socket.getfqdn().endswith("cern.ch"): envOverride['XRD_LOADBALANCERTTL'] = "86400" # some libraries linked with CMSSW need HOME in the environment if 'HOME' not in os.environ: envOverride['HOME'] = os.environ.get('PWD', "/") os.environ.update(envOverride) returncode = subprocess.call(args, stdout=stdoutHandle, stderr=stderrHandle) self.setCondorChirpAttrDelayed('Chirp_WMCore_cmsRun_ExitCode', returncode) self.setCondorChirpAttrDelayed( 'Chirp_WMCore_%s_ExitCode' % self.stepName, returncode) stdoutHandle.close() stderrHandle.close() self.step.execution.exitStatus = returncode argsDump = {'arguments': args} if returncode != 0: msg = "Error running cmsRun\n%s\n" % argsDump msg += "Return code: %s\n" % returncode logging.critical(msg) raise WMExecutionFailure(returncode, "CmsRunFailure", msg) try: self.report.parse(jobReportXML, stepName=self.stepName) except Exception as ex: # Catch it if something goes wrong raise WMExecutionFailure(50115, "BadJobReportXML", str(ex)) stepHelper = WMStepHelper(self.step) typeHelper = stepHelper.getTypeHelper() acquisitionEra = self.task.getAcquisitionEra() processingVer = self.task.getProcessingVersion() processingStr = self.task.getProcessingString() validStatus = self.workload.getValidStatus() inputPath = self.task.getInputDatasetPath() globalTag = typeHelper.getGlobalTag() prepID = self.task.getPrepID() campaign = self.workload.getCampaign() cacheUrl, cacheDB, configID = stepHelper.getConfigInfo() self.report.setValidStatus(validStatus=validStatus) self.report.setGlobalTag(globalTag=globalTag) self.report.setCampaign(campaign) self.report.setPrepID(prepID) self.report.setInputDataset(inputPath=inputPath) self.report.setAcquisitionProcessing(acquisitionEra=acquisitionEra, processingVer=processingVer, processingStr=processingStr) self.report.setConfigURL(configURL="%s;;%s;;%s" % (cacheUrl, cacheDB, configID)) # Attach info to files self.report.addInfoToOutputFilesForStep(stepName=self.stepName, step=self.step) self.report.checkForOutputFiles(stepName=self.stepName) self.report.checkForAdlerChecksum(stepName=self.stepName) self.report.checkForRunLumiInformation(stepName=self.stepName) if self.step.output.keep != True: self.report.killOutput() else: # Check that we only keep the desired output for module in stepHelper.getIgnoredOutputModules(): self.report.deleteOutputModuleForStep(stepName=self.stepName, moduleName=module) # Add stageout LFN to existing TFileService files reportAnalysisFiles = self.report.getAnalysisFilesFromStep( self.stepName) for reportAnalysisFile in reportAnalysisFiles: newLFN = analysisFileLFN(reportAnalysisFile.fileName, self.step.user.lfnBase, self.job) addAttributesToFile(reportAnalysisFile, pfn=reportAnalysisFile.fileName, lfn=newLFN, validate=False) # Add analysis file entries for additional files listed in workflow for fileName in stepHelper.listAnalysisFiles(): analysisFile = stepHelper.getAnalysisFile(fileName) if os.path.isfile(analysisFile.fileName): newLFN = analysisFileLFN(analysisFile.fileName, analysisFile.lfnBase, self.job) self.report.addAnalysisFile(analysisFile.fileName, lfn=newLFN, Source='UserDefined', pfn=os.path.join( os.getcwd(), analysisFile.fileName), validate=False) return
#logHandler.setFormatter(logFormatter) #logging.getLogger().addHandler(logHandler) if ad and not "CRAB3_RUNTIME_DEBUG" in os.environ: startDashboardMonitoring(ad) print("==== CMSSW Stack Execution STARTING at %s ====" % time.asctime(time.gmtime())) scr = Scram( version=options.cmsswVersion, directory=os.getcwd(), architecture=options.scramArch, ) print("==== SCRAM Obj CREATED at %s ====" % time.asctime(time.gmtime())) if scr.project() or scr.runtime(): #if any of the two commands fail... dgn = scr.diagnostic() handleException("FAILED", EC_CMSMissingSoftware, 'Error setting CMSSW environment: %s' % dgn) mintime() sys.exit(EC_CMSMissingSoftware) extractUserSandbox(options.archiveJob, options.cmsswVersion) try: jobExitCode = None if options.scriptExe == 'None': print("==== CMSSW JOB Execution started at %s ====" % time.asctime(time.gmtime())) cmsswSt = executeCMSSWStack(options, scr) jobExitCode = cmsswSt.step.execution.exitStatus
logHandler.setFormatter(logFormatter) logging.getLogger().addHandler(logHandler) if ad and not "CRAB3_RUNTIME_DEBUG" in os.environ: startDashboardMonitoring(ad) print("==== CMSSW Stack Execution STARTING at %s ====" % time.asctime(time.gmtime())) scram = Scram( version=opts.cmsswVersion, directory=os.getcwd(), architecture=opts.scramArch, ) print("==== SCRAM Obj CREATED at %s ====" % time.asctime(time.gmtime())) if scram.project() or scram.runtime( ): #if any of the two commands fail... msg = scram.diagnostic() handleException("FAILED", EC_CMSMissingSoftware, 'Error setting CMSSW environment: %s' % msg) mintime() sys.exit(EC_CMSMissingSoftware) extractUserSandbox(opts.archiveJob, opts.cmsswVersion) try: jobExitCode = None if opts.scriptExe == 'None': print("==== CMSSW JOB Execution started at %s ====" % time.asctime(time.gmtime())) cmssw = executeCMSSWStack(opts, scram)
def execute(self, emulator=None): """ _execute_ """ scramCommand = self.step.application.setup.scramCommand scramArch = self.step.application.setup.scramArch cmsswVersion = self.step.application.setup.cmsswVersion scramArch = getSingleScramArch(scramArch) # Are we using emulators again? if emulator is not None: return emulator.emulate(self.step, self.job) overrides = {} if hasattr(self.step, 'override'): overrides = self.step.override.dictionary_() # Set wait to over an hour waitTime = overrides.get('waitTime', 3600 + (self.step.retryDelay * self.step.retryCount)) # hardcode CERN Castor T0_CH_CERN_MSS stageout parameters castorStageOutParams = {} castorStageOutParams['command'] = overrides.get('command', "xrdcp") castorStageOutParams['option'] = overrides.get('option', "--wma-cerncastor") castorStageOutParams['phedex-node'] = overrides.get('phedex-node', "T2_CH_CERN") castorStageOutParams['lfn-prefix'] = overrides.get('lfn-prefix', "root://castorcms.cern.ch//castor/cern.ch/cms") # hardcode CERN EOS T2_CH_CERN stageout parameters eosStageOutParams = {} eosStageOutParams['command'] = overrides.get('command', "xrdcp") eosStageOutParams['option'] = overrides.get('option', "--wma-disablewriterecovery") eosStageOutParams['phedex-node'] = overrides.get('phedex-node', "T2_CH_CERN") eosStageOutParams['lfn-prefix'] = overrides.get('lfn-prefix', "root://eoscms.cern.ch//eos/cms") try: castorStageOutMgr = StageOutMgr(**castorStageOutParams) eosStageOutMgr = StageOutMgr(**eosStageOutParams) stageInMgr = StageInMgr() deleteMgr = DeleteMgr() except Exception as ex: msg = "Unable to load StageOut/Delete Impl: %s" % str(ex) logging.error(msg) raise WMExecutionFailure(60312, "MgrImplementationError", msg) # prepare output tar file taskName = self.report.getTaskName().split('/')[-1] host = socket.gethostname().split('.')[0] tarName = '%s-%s-%s-%i-logs.tar' % (self.report.data.workload, taskName, host, self.job["counter"]) tarLocation = os.path.join(self.stepSpace.location, tarName) # Supported by any release beyond CMSSW_8_X, however DaviX is broken until CMSSW_10_4_X # see: https://github.com/cms-sw/cmssw/issues/25292 useEdmCopyUtil = True if isCMSSWSupported(cmsswVersion, "CMSSW_10_4_0"): pass elif scramArch.startswith('slc6_amd64_'): msg = "CMSSW too old or not fully functional to support edmCopyUtil, using CMSSW_10_4_0 instead" logging.warning(msg) cmsswVersion = "CMSSW_10_4_0" scramArch = "slc6_amd64_gcc700" else: useEdmCopyUtil = False logging.info("Using edmCopyUtil: %s", useEdmCopyUtil) # setup Scram needed to run edmCopyUtil if useEdmCopyUtil: scram = Scram( command=scramCommand, version=cmsswVersion, initialise=self.step.application.setup.softwareEnvironment, directory=self.step.builder.workingDir, architecture=scramArch, ) logging.info("Running scram") try: projectOutcome = scram.project() except Exception as ex: msg = "Exception raised while running scram.\n" msg += str(ex) logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) if projectOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) runtimeOutcome = scram.runtime() if runtimeOutcome > 0: msg = scram.diagnostic() logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(50513, "ScramSetupFailure", msg) # iterate through input files localLogs = [] deleteLogArchives = [] if useEdmCopyUtil: numberOfFilesPerCopy = 10 else: numberOfFilesPerCopy = 1 for logs in grouper(self.job["input_files"], numberOfFilesPerCopy): copyCommand = "env X509_USER_PROXY=%s edmCopyUtil" % os.environ.get('X509_USER_PROXY', None) for log in logs: copyCommand += " %s" % log['lfn'] copyCommand += " %s" % self.step.builder.workingDir # give up after timeout of 1 minute per input file signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(60 * numberOfFilesPerCopy) filesCopied = False try: if useEdmCopyUtil: logging.info("Running edmCopyUtil") retval = scram(copyCommand) if retval == 0: filesCopied = True else: logging.info("Running stageIn") for log in logs: fileInfo = {"LFN": log['lfn']} logArchive = stageInMgr(**fileInfo) if logArchive: filesCopied = True except Alarm: logging.error("Indefinite hang during edmCopyUtil/stageIn of logArchives") except StageOutFailure: logging.error("Unable to stageIn logArchives") except Exception: raise signal.alarm(0) if filesCopied: for log in logs: localLogs.append(os.path.join(self.step.builder.workingDir, os.path.basename(log['lfn']))) deleteLogArchives.append(log) self.report.addInputFile(sourceName="logArchives", lfn=log['lfn']) else: logging.error("Unable to copy logArchives to local disk") for log in logs: self.report.addSkippedFile(log['lfn'], None) # create tarfile if any logArchive copied in if localLogs: tarFile = tarfile.open(tarLocation, 'w:') for log in localLogs: path = log.split('/') tarFile.add(name=log, arcname=os.path.join(path[-3], path[-2], path[-1])) os.remove(log) tarFile.close() else: msg = "Unable to copy any logArchives to local disk" logging.error(msg) raise WMExecutionFailure(60312, "LogCollectError", msg) # now staging out the LogCollect tarfile logging.info("Staging out LogCollect tarfile to Castor and EOS") now = datetime.datetime.now() lfn = "/store/logs/prod/%i/%.2i/%s/%s/%s" % (now.year, now.month, "WMAgent", self.report.data.workload, os.path.basename(tarLocation)) tarInfo = {'LFN': lfn, 'PFN': tarLocation, 'PNN': None, 'GUID': None} # perform mandatory stage out to CERN Castor signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(waitTime) try: castorStageOutMgr(tarInfo) except Alarm: msg = "Indefinite hang during stageOut of LogCollect to Castor" logging.error(msg) raise WMExecutionFailure(60409, "LogCollectTimeout", msg) except Exception as ex: msg = "Unable to stageOut LogCollect to Castor:\n" msg += str(ex) logging.error(msg) raise WMExecutionFailure(60408, "LogCollectStageOutError", msg) signal.alarm(0) # add to job report self.report.addOutputFile(outputModule="LogCollect", aFile=tarInfo) outputRef = getattr(self.report.data, self.stepName) outputRef.output.pfn = tarInfo['PFN'] outputRef.output.location = tarInfo['PNN'] outputRef.output.lfn = tarInfo['LFN'] tarInfo = {'LFN': lfn, 'PFN': tarLocation, 'PNN': None, 'GUID': None} # then, perform best effort stage out to CERN EOS signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(waitTime) try: eosStageOutMgr(tarInfo) except Alarm: logging.error("Indefinite hang during stageOut of LogCollect to EOS") except Exception as ex: logging.error("Unable to stageOut LogCollect to EOS: %s", ex) signal.alarm(0) # we got this far, delete input for log in deleteLogArchives: # give up after timeout of 1 minutes signal.signal(signal.SIGALRM, alarmHandler) signal.alarm(60) try: fileToDelete = {'LFN': log['lfn'], 'PFN': None, 'PNN': None, 'StageOutCommand': None} deleteMgr(fileToDelete=fileToDelete) except Alarm: logging.error("Indefinite hang during delete of logArchive") except Exception as ex: logging.error("Unable to delete logArchive: %s", ex) signal.alarm(0) return
def execute(self, emulator = None): """ _execute_ """ stepModule = "WMTaskSpace.%s" % self.stepName if (emulator != None): return emulator.emulate( self.step, self.job ) # write the wrapper script to a temporary location # I don't pass it directly through os.system because I don't # trust that there won't be shell-escape shenanigans with # arbitrary input files scramSetup = self.step.application.setup.softwareEnvironment scramCommand = self.step.application.setup.scramCommand scramProject = self.step.application.setup.scramProject scramArch = self.step.application.setup.scramArch cmsswVersion = self.step.application.setup.cmsswVersion jobReportXML = self.step.output.jobReport cmsswCommand = self.step.application.command.executable cmsswConfig = self.step.application.command.configuration cmsswArguments = self.step.application.command.arguments logging.info("Executing MulticoreCMSSW step") multicoreSettings = self.step.application.multicore numberOfCores = multicoreSettings.numberOfCores logging.info("Multicore configured for %s cores" % numberOfCores) #Todo: Create input file list from job writing filelist one per line to filelist = open(multicoreSettings.inputfilelist,'w') for inputFile in self.job['input_files']: filelist.write("%s\n" % inputFile['lfn']) filelist.close() # # scram bootstrap # scram = Scram( command = scramCommand, version = cmsswVersion, initialise = self.step.application.setup.softwareEnvironment, directory = self.step.builder.workingDir, architecture = scramArch, ) logging.info("Running SCRAM") try: projectOutcome = scram.project() except Exception, ex: msg = "Exception raised while running scram.\n" msg += str(ex) logging.critical("Error running SCRAM") logging.critical(msg) raise WMExecutionFailure(60513, "ScramSetupFailure", msg)