X-Git-Url: https://git.arvados.org/arvados.git/blobdiff_plain/a9a677e1655c461e742e46cc3c239f8605f4fc6b..60d986b8908487c086eb4e402ac69669cb26108b:/sdk/cwl/arvados_cwl/__init__.py?ds=sidebyside diff --git a/sdk/cwl/arvados_cwl/__init__.py b/sdk/cwl/arvados_cwl/__init__.py index afe7f5a5ef..02eca644d3 100644 --- a/sdk/cwl/arvados_cwl/__init__.py +++ b/sdk/cwl/arvados_cwl/__init__.py @@ -17,17 +17,21 @@ import pkg_resources # part of setuptools from cwltool.errors import WorkflowException import cwltool.main import cwltool.workflow +import cwltool.process import schema_salad +from schema_salad.sourceline import SourceLine import arvados import arvados.config +from arvados.keep import KeepClient +from arvados.errors import ApiError from .arvcontainer import ArvadosContainer, RunnerContainer from .arvjob import ArvadosJob, RunnerJob, RunnerTemplate -from. runner import Runner, upload_instance +from. runner import Runner, upload_docker, upload_job_order, upload_workflow_deps from .arvtool import ArvadosCommandTool from .arvworkflow import ArvadosWorkflow, upload_workflow -from .fsaccess import CollectionFsAccess +from .fsaccess import CollectionFsAccess, CollectionFetcher, collectionResolver from .perf import Perf from .pathmapper import FinalOutputPathMapper from ._version import __version__ @@ -42,6 +46,9 @@ logger = logging.getLogger('arvados.cwl-runner') metrics = logging.getLogger('arvados.cwl-runner.metrics') logger.setLevel(logging.INFO) +arvados.log_handler.setFormatter(logging.Formatter( + '%(asctime)s %(name)s %(levelname)s: %(message)s', + '%Y-%m-%d %H:%M:%S')) class ArvCwlRunner(object): """Execute a CWL tool or workflow, submit work (using either jobs or @@ -49,7 +56,7 @@ class ArvCwlRunner(object): """ - def __init__(self, api_client, work_api=None, keep_client=None, output_name=None, output_tags=None): + def __init__(self, api_client, work_api=None, keep_client=None, output_name=None, output_tags=None, num_retries=4): self.api = api_client self.processes = {} self.lock = threading.Lock() @@ -57,7 +64,7 @@ class ArvCwlRunner(object): self.final_output = None self.final_status = None self.uploaded = {} - self.num_retries = 4 + self.num_retries = num_retries self.uuid = None self.stop_polling = threading.Event() self.poll_api = None @@ -72,7 +79,9 @@ class ArvCwlRunner(object): else: self.keep_client = arvados.keep.KeepClient(api_client=self.api, num_retries=self.num_retries) - for api in ["jobs", "containers"]: + self.work_api = None + expected_api = ["jobs", "containers"] + for api in expected_api: try: methods = self.api._rootDesc.get('resources')[api]['methods'] if ('httpMethod' in methods['create'] and @@ -81,14 +90,18 @@ class ArvCwlRunner(object): break except KeyError: pass + if not self.work_api: if work_api is None: raise Exception("No supported APIs") else: - raise Exception("Unsupported API '%s'" % work_api) + raise Exception("Unsupported API '%s', expected one of %s" % (work_api, expected_api)) def arv_make_tool(self, toolpath_object, **kwargs): kwargs["work_api"] = self.work_api + kwargs["fetcher_constructor"] = partial(CollectionFetcher, + api_client=self.api, + keep_client=self.keep_client) if "class" in toolpath_object and toolpath_object["class"] == "CommandLineTool": return ArvadosCommandTool(self, toolpath_object, **kwargs) elif "class" in toolpath_object and toolpath_object["class"] == "Workflow": @@ -117,7 +130,7 @@ class ArvCwlRunner(object): uuid = event["object_uuid"] with self.lock: j = self.processes[uuid] - logger.info("Job %s (%s) is Running", j.name, uuid) + logger.info("%s %s is Running", self.label(j), uuid) j.running = True j.update_pipeline_component(event["properties"]["new_attributes"]) elif event["properties"]["new_attributes"]["state"] in ("Complete", "Failed", "Cancelled", "Final"): @@ -125,48 +138,59 @@ class ArvCwlRunner(object): try: self.cond.acquire() j = self.processes[uuid] - txt = self.work_api[0].upper() + self.work_api[1:-1] - logger.info("%s %s (%s) is %s", txt, j.name, uuid, event["properties"]["new_attributes"]["state"]) + logger.info("%s %s is %s", self.label(j), uuid, event["properties"]["new_attributes"]["state"]) with Perf(metrics, "done %s" % j.name): j.done(event["properties"]["new_attributes"]) self.cond.notify() finally: self.cond.release() + def label(self, obj): + return "[%s %s]" % (self.work_api[0:-1], obj.name) + def poll_states(self): """Poll status of jobs or containers listed in the processes dict. Runs in a separate thread. """ - while True: - self.stop_polling.wait(15) - if self.stop_polling.is_set(): - break - with self.lock: - keys = self.processes.keys() - if not keys: - continue + try: + while True: + self.stop_polling.wait(15) + if self.stop_polling.is_set(): + break + with self.lock: + keys = self.processes.keys() + if not keys: + continue - if self.work_api == "containers": - table = self.poll_api.container_requests() - elif self.work_api == "jobs": - table = self.poll_api.jobs() + if self.work_api == "containers": + table = self.poll_api.container_requests() + elif self.work_api == "jobs": + table = self.poll_api.jobs() - try: - proc_states = table.list(filters=[["uuid", "in", keys]]).execute(num_retries=self.num_retries) - except Exception as e: - logger.warn("Error checking states on API server: %s", e) - continue - - for p in proc_states["items"]: - self.on_message({ - "object_uuid": p["uuid"], - "event_type": "update", - "properties": { - "new_attributes": p - } - }) + try: + proc_states = table.list(filters=[["uuid", "in", keys]]).execute(num_retries=self.num_retries) + except Exception as e: + logger.warn("Error checking states on API server: %s", e) + continue + + for p in proc_states["items"]: + self.on_message({ + "object_uuid": p["uuid"], + "event_type": "update", + "properties": { + "new_attributes": p + } + }) + except: + logger.error("Fatal error in state polling thread.", exc_info=(sys.exc_info()[1] if self.debug else False)) + self.cond.acquire() + self.processes.clear() + self.cond.notify() + self.cond.release() + finally: + self.stop_polling.set() def get_uploaded(self): return self.uploaded.copy() @@ -174,15 +198,25 @@ class ArvCwlRunner(object): def add_uploaded(self, src, pair): self.uploaded[src] = pair - def check_writable(self, obj): + def check_features(self, obj): if isinstance(obj, dict): + if obj.get("class") == "InitialWorkDirRequirement": + if self.work_api == "containers": + raise UnsupportedRequirement("InitialWorkDirRequirement not supported with --api=containers") if obj.get("writable"): - raise UnsupportedRequirement("InitialWorkDir feature 'writable: true' not supported") + raise SourceLine(obj, "writable", UnsupportedRequirement).makeError("InitialWorkDir feature 'writable: true' not supported") + if obj.get("class") == "CommandLineTool": + if self.work_api == "containers": + if obj.get("stdin"): + raise SourceLine(obj, "stdin", UnsupportedRequirement).makeError("Stdin redirection currently not suppported with --api=containers") + if obj.get("stderr"): + raise SourceLine(obj, "stderr", UnsupportedRequirement).makeError("Stderr redirection currently not suppported with --api=containers") for v in obj.itervalues(): - self.check_writable(v) - if isinstance(obj, list): - for v in obj: - self.check_writable(v) + self.check_features(v) + elif isinstance(obj, list): + for i,v in enumerate(obj): + with SourceLine(obj, i, UnsupportedRequirement): + self.check_features(v) def make_output_collection(self, name, tagsString, outputObj): outputObj = copy.deepcopy(outputObj) @@ -268,6 +302,12 @@ class ArvCwlRunner(object): if self.work_api == "containers": try: current = self.api.containers().current().execute(num_retries=self.num_retries) + except ApiError as e: + # Status code 404 just means we're not running in a container. + if e.resp.status != 404: + logger.info("Getting current container: %s", e) + return + try: self.api.containers().update(uuid=current['uuid'], body={ 'output': self.final_output_collection.portable_data_hash(), @@ -285,24 +325,53 @@ class ArvCwlRunner(object): def arv_executor(self, tool, job_order, **kwargs): self.debug = kwargs.get("debug") - tool.visit(self.check_writable) + tool.visit(self.check_features) - useruuid = self.api.users().current().execute()["uuid"] - self.project_uuid = kwargs.get("project_uuid") if kwargs.get("project_uuid") else useruuid + self.project_uuid = kwargs.get("project_uuid") self.pipeline = None make_fs_access = kwargs.get("make_fs_access") or partial(CollectionFsAccess, api_client=self.api, keep_client=self.keep_client) self.fs_access = make_fs_access(kwargs["basedir"]) - if kwargs.get("create_template"): - tmpl = RunnerTemplate(self, tool, job_order, kwargs.get("enable_reuse")) - tmpl.save() - # cwltool.main will write our return value to stdout. - return tmpl.uuid - - if kwargs.get("create_workflow") or kwargs.get("update_workflow"): - return upload_workflow(self, tool, job_order, self.project_uuid, kwargs.get("update_workflow")) + if not kwargs.get("name"): + kwargs["name"] = self.name = tool.tool.get("label") or tool.metadata.get("label") or os.path.basename(tool.tool["id"]) + + # Upload direct dependencies of workflow steps, get back mapping of files to keep references. + # Also uploads docker images. + upload_workflow_deps(self, tool) + + # Reload tool object which may have been updated by + # upload_workflow_deps + tool = self.arv_make_tool(tool.doc_loader.idx[tool.tool["id"]], + makeTool=self.arv_make_tool, + loader=tool.doc_loader, + avsc_names=tool.doc_schema, + metadata=tool.metadata) + + # Upload local file references in the job order. + job_order = upload_job_order(self, "%s input" % kwargs["name"], + tool, job_order) + + existing_uuid = kwargs.get("update_workflow") + if existing_uuid or kwargs.get("create_workflow"): + # Create a pipeline template or workflow record and exit. + if self.work_api == "jobs": + tmpl = RunnerTemplate(self, tool, job_order, + kwargs.get("enable_reuse"), + uuid=existing_uuid, + submit_runner_ram=kwargs.get("submit_runner_ram"), + name=kwargs["name"]) + tmpl.save() + # cwltool.main will write our return value to stdout. + return (tmpl.uuid, "success") + elif self.work_api == "containers": + return (upload_workflow(self, tool, job_order, + self.project_uuid, + uuid=existing_uuid, + submit_runner_ram=kwargs.get("submit_runner_ram"), + name=kwargs["name"]), + "success") self.ignore_docker_for_reuse = kwargs.get("ignore_docker_for_reuse") @@ -310,7 +379,6 @@ class ArvCwlRunner(object): kwargs["enable_reuse"] = kwargs.get("enable_reuse") kwargs["use_container"] = True kwargs["tmpdir_prefix"] = "tmp" - kwargs["on_error"] = "continue" kwargs["compute_checksum"] = kwargs.get("compute_checksum") if self.work_api == "containers": @@ -323,33 +391,51 @@ class ArvCwlRunner(object): kwargs["docker_outdir"] = "$(task.outdir)" kwargs["tmpdir"] = "$(task.tmpdir)" - upload_instance(self, shortname(tool.tool["id"]), tool, job_order) - runnerjob = None if kwargs.get("submit"): + # Submit a runner job to run the workflow for us. if self.work_api == "containers": if tool.tool["class"] == "CommandLineTool": + kwargs["runnerjob"] = tool.tool["id"] + upload_dependencies(self, + kwargs["name"], + tool.doc_loader, + tool.tool, + tool.tool["id"], + False) runnerjob = tool.job(job_order, self.output_callback, **kwargs).next() else: - runnerjob = RunnerContainer(self, tool, job_order, kwargs.get("enable_reuse"), self.output_name, self.output_tags) - else: - runnerjob = RunnerJob(self, tool, job_order, kwargs.get("enable_reuse"), self.output_name, self.output_tags) - - if not kwargs.get("submit") and "cwl_runner_job" not in kwargs and not self.work_api == "containers": + runnerjob = RunnerContainer(self, tool, job_order, kwargs.get("enable_reuse"), + self.output_name, + self.output_tags, + submit_runner_ram=kwargs.get("submit_runner_ram"), + name=kwargs.get("name"), + on_error=kwargs.get("on_error"), + submit_runner_image=kwargs.get("submit_runner_image")) + elif self.work_api == "jobs": + runnerjob = RunnerJob(self, tool, job_order, kwargs.get("enable_reuse"), + self.output_name, + self.output_tags, + submit_runner_ram=kwargs.get("submit_runner_ram"), + name=kwargs.get("name"), + on_error=kwargs.get("on_error"), + submit_runner_image=kwargs.get("submit_runner_image")) + + if not kwargs.get("submit") and "cwl_runner_job" not in kwargs and self.work_api == "jobs": # Create pipeline for local run self.pipeline = self.api.pipeline_instances().create( body={ "owner_uuid": self.project_uuid, - "name": shortname(tool.tool["id"]), + "name": kwargs["name"] if kwargs.get("name") else shortname(tool.tool["id"]), "components": {}, "state": "RunningOnClient"}).execute(num_retries=self.num_retries) logger.info("Pipeline instance %s", self.pipeline["uuid"]) if runnerjob and not kwargs.get("wait"): runnerjob.run(wait=kwargs.get("wait")) - return runnerjob.uuid + return (runnerjob.uuid, "success") self.poll_api = arvados.api('v1') self.polling_thread = threading.Thread(target=self.poll_states) @@ -374,6 +460,10 @@ class ArvCwlRunner(object): loopperf.__enter__() for runnable in jobiter: loopperf.__exit__() + + if self.stop_polling.is_set(): + break + if runnable: with Perf(metrics, "run"): runnable.run(**kwargs) @@ -395,7 +485,7 @@ class ArvCwlRunner(object): if sys.exc_info()[0] is KeyboardInterrupt: logger.error("Interrupted, marking pipeline as failed") else: - logger.error("Caught unhandled exception, marking pipeline as failed. Error was: %s", sys.exc_info()[1], exc_info=(sys.exc_info()[1] if self.debug else False)) + logger.error("Execution failed: %s", sys.exc_info()[1], exc_info=(sys.exc_info()[1] if self.debug else False)) if self.pipeline: self.api.pipeline_instances().update(uuid=self.pipeline["uuid"], body={"state": "Failed"}).execute(num_retries=self.num_retries) @@ -423,14 +513,11 @@ class ArvCwlRunner(object): self.final_output, self.final_output_collection = self.make_output_collection(self.output_name, self.output_tags, self.final_output) self.set_crunch_output() - if self.final_status != "success": - raise WorkflowException("Workflow failed.") - if kwargs.get("compute_checksum"): adjustDirObjs(self.final_output, partial(getListing, self.fs_access)) adjustFileObjs(self.final_output, partial(compute_checksums, self.fs_access)) - return self.final_output + return (self.final_output, self.final_status) def versionstring(): @@ -488,9 +575,10 @@ def arg_parser(): # type: () -> argparse.ArgumentParser default=True, dest="submit") exgroup.add_argument("--local", action="store_false", help="Run workflow on local host (submits jobs to Arvados).", default=True, dest="submit") - exgroup.add_argument("--create-template", action="store_true", help="Create an Arvados pipeline template.") - exgroup.add_argument("--create-workflow", action="store_true", help="Create an Arvados workflow.") - exgroup.add_argument("--update-workflow", type=str, metavar="UUID", help="Update existing Arvados workflow with uuid.") + exgroup.add_argument("--create-template", action="store_true", help="(Deprecated) synonym for --create-workflow.", + dest="create_workflow") + exgroup.add_argument("--create-workflow", action="store_true", help="Create an Arvados workflow (if using the 'containers' API) or pipeline template (if using the 'jobs' API). See --api.") + exgroup.add_argument("--update-workflow", type=str, metavar="UUID", help="Update an existing Arvados workflow or pipeline template with the given UUID.") exgroup = parser.add_mutually_exclusive_group() exgroup.add_argument("--wait", action="store_true", help="After submitting workflow runner job, wait for completion.", @@ -498,6 +586,12 @@ def arg_parser(): # type: () -> argparse.ArgumentParser exgroup.add_argument("--no-wait", action="store_false", help="Submit workflow runner job and exit.", default=True, dest="wait") + exgroup = parser.add_mutually_exclusive_group() + exgroup.add_argument("--log-timestamps", action="store_true", help="Prefix logging lines with timestamp", + default=True, dest="log_timestamps") + exgroup.add_argument("--no-log-timestamps", action="store_false", help="No timestamp on logging lines", + default=True, dest="log_timestamps") + parser.add_argument("--api", type=str, default=None, dest="work_api", help="Select work submission API, one of 'jobs' or 'containers'. Default is 'jobs' if that API is available, otherwise 'containers'.") @@ -506,6 +600,22 @@ def arg_parser(): # type: () -> argparse.ArgumentParser help="Compute checksum of contents while collecting outputs", dest="compute_checksum") + parser.add_argument("--submit-runner-ram", type=int, + help="RAM (in MiB) required for the workflow runner job (default 1024)", + default=1024) + + parser.add_argument("--submit-runner-image", type=str, + help="Docker image for workflow runner job, default arvados/jobs:%s" % __version__, + default=None) + + parser.add_argument("--name", type=str, + help="Name to use for workflow execution instance.", + default=None) + + parser.add_argument("--on-error", type=str, + help="Desired workflow behavior when a step fails. One of 'stop' or 'continue'. " + "Default is 'continue'.", default="continue", choices=("stop", "continue")) + parser.add_argument("workflow", type=str, nargs="?", default=None, help="The workflow to execute") parser.add_argument("job_order", nargs=argparse.REMAINDER, help="The input object to the workflow.") @@ -528,7 +638,25 @@ def main(args, stdout, stderr, api_client=None, keep_client=None): job_order_object = None arvargs = parser.parse_args(args) - if (arvargs.create_template or arvargs.create_workflow or arvargs.update_workflow) and not arvargs.job_order: + + if arvargs.version: + print versionstring() + return + + if arvargs.update_workflow: + if arvargs.update_workflow.find('-7fd4e-') == 5: + want_api = 'containers' + elif arvargs.update_workflow.find('-p5p6p-') == 5: + want_api = 'jobs' + else: + want_api = None + if want_api and arvargs.work_api and want_api != arvargs.work_api: + logger.error('--update-workflow arg {!r} uses {!r} API, but --api={!r} specified'.format( + arvargs.update_workflow, want_api, arvargs.work_api)) + return 1 + arvargs.work_api = want_api + + if (arvargs.create_workflow or arvargs.update_workflow) and not arvargs.job_order: job_order_object = ({}, "") add_arv_hints() @@ -536,7 +664,11 @@ def main(args, stdout, stderr, api_client=None, keep_client=None): try: if api_client is None: api_client=arvados.api('v1', model=OrderedJsonModel()) - runner = ArvCwlRunner(api_client, work_api=arvargs.work_api, keep_client=keep_client, output_name=arvargs.output_name, output_tags=arvargs.output_tags) + if keep_client is None: + keep_client = arvados.keep.KeepClient(api_client=api_client, num_retries=4) + runner = ArvCwlRunner(api_client, work_api=arvargs.work_api, keep_client=keep_client, + num_retries=4, output_name=arvargs.output_name, + output_tags=arvargs.output_tags) except Exception as e: logger.error(e) return 1 @@ -552,8 +684,17 @@ def main(args, stdout, stderr, api_client=None, keep_client=None): metrics.setLevel(logging.DEBUG) logging.getLogger("cwltool.metrics").setLevel(logging.DEBUG) + if arvargs.log_timestamps: + arvados.log_handler.setFormatter(logging.Formatter( + '%(asctime)s %(name)s %(levelname)s: %(message)s', + '%Y-%m-%d %H:%M:%S')) + else: + arvados.log_handler.setFormatter(logging.Formatter('%(name)s %(levelname)s: %(message)s')) + arvargs.conformance_test = None arvargs.use_container = True + arvargs.relax_path_checks = True + arvargs.validate = None return cwltool.main.main(args=arvargs, stdout=stdout, @@ -562,4 +703,11 @@ def main(args, stdout, stderr, api_client=None, keep_client=None): makeTool=runner.arv_make_tool, versionfunc=versionstring, job_order_object=job_order_object, - make_fs_access=partial(CollectionFsAccess, api_client=api_client)) + make_fs_access=partial(CollectionFsAccess, + api_client=api_client, + keep_client=keep_client), + fetcher_constructor=partial(CollectionFetcher, + api_client=api_client, + keep_client=keep_client), + resolver=partial(collectionResolver, api_client), + logger_handler=arvados.log_handler)