Actions
Bug #21612
opena-c-r with --debug can try to log entire input/output objects, which can be too large for the logging system
Story points:
-
Description
User got this error while running aws-s3-bulk-download.cwl with >6K input URLs, using a-c-r --submit --debug
.
I don't think it actually interfered with the workflow's run at all, but it clogs the logs and looks scary.
IMO a-c-r (along with the rest of our code) should not try to log data that can be arbitrarily large.
Three instances where this came up:
--- Logging error --- Traceback (most recent call last): File "/usr/lib/python3.7/logging/__init__.py", line 1037, in emit stream.write(msg + self.terminator) BlockingIOError: [Errno 11] write could not complete without blocking Call stack: File "/usr/bin/arvados-cwl-runner", line 8, in <module> sys.exit(main()) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/__init__.py", line 440, in main input_required=not workflow_op) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/main.py", line 1302, in main tool, initialized_job_order_object, runtimeContext, logger=_logger File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/executor.py", line 874, in arv_executor self.start_run(runnable, runtimeContext) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/executor.py", line 248, in start_run self.workflow_eval_lock, self.stop_polling) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/task_queue.py", line 85, in add task() File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/command_line_tool.py", line 202, in run self.output_callback(cast(Optional[CWLObjectType], ev), "success") File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/executor.py", line 321, in wrapped_callback cb(obj, st) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow.py", line 429, in receive_output output_callback(output, processStatus) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow_job.py", line 564, in receive_output _logger.debug("[%s] produced output %s", step.name, json_dumps(jobout, indent=4))
--- Logging error --- Traceback (most recent call last): File "/usr/lib/python3.7/logging/__init__.py", line 1037, in emit stream.write(msg + self.terminator) BlockingIOError: [Errno 11] write could not complete without blocking Call stack: File "/usr/bin/arvados-cwl-runner", line 8, in <module> sys.exit(main()) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/__init__.py", line 440, in main input_required=not workflow_op) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/main.py", line 1302, in main tool, initialized_job_order_object, runtimeContext, logger=_logger File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/executor.py", line 863, in arv_executor for runnable in jobiter: File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow.py", line 175, in job yield from job.job(builder.job, output_callbacks, runtimeContext) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow_job.py", line 821, in job for newjob in step.iterable: File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow_job.py", line 751, in try_make_job yield from jobs File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow_job.py", line 77, in job yield from self.step.job(joborder, output_callback, runtimeContext) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow.py", line 462, in job runtimeContext, File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow.py", line 175, in job yield from job.job(builder.job, output_callbacks, runtimeContext) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow_job.py", line 821, in job for newjob in step.iterable: File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow_job.py", line 735, in try_make_job json_dumps(inputobj, indent=4),
--- Logging error --- Traceback (most recent call last): File "/usr/lib/python3.7/logging/__init__.py", line 1037, in emit stream.write(msg + self.terminator) BlockingIOError: [Errno 11] write could not complete without blocking Call stack: File "/usr/bin/arvados-cwl-runner", line 8, in <module> sys.exit(main()) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/__init__.py", line 440, in main input_required=not workflow_op) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/main.py", line 1302, in main tool, initialized_job_order_object, runtimeContext, logger=_logger File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/executor.py", line 874, in arv_executor self.start_run(runnable, runtimeContext) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/executor.py", line 248, in start_run self.workflow_eval_lock, self.stop_polling) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/task_queue.py", line 85, in add task() File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/command_line_tool.py", line 202, in run self.output_callback(cast(Optional[CWLObjectType], ev), "success") File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/arvados_cwl/executor.py", line 321, in wrapped_callback cb(obj, st) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow.py", line 429, in receive_output output_callback(output, processStatus) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow_job.py", line 582, in receive_output self.do_output_callback(final_output_callback) File "/usr/share/python3/dist/python3-arvados-cwl-runner/lib/python3.7/site-packages/cwltool/workflow_job.py", line 541, in do_output_callback _logger.debug("[%s] outputs %s", self.name, json_dumps(wo, indent=4))
Updated by Brett Smith 7 months ago
- Description updated (diff)
- Subject changed from a-c-r with --debug can try to log its entire output, which can be too large for the logging system to a-c-r with --debug can try to log entire input/output objects, which can be too large for the logging system
Actions