RO log using StreamHandler, implicitly added to manifest

Author: stain

cwltool/main.py

@@ -466,8 +466,7 @@ def main(argsl=None,                   # type: List[str]
     _logger.addHandler(stderr_handler)
     # pre-declared for finally block
     workflowobj = None
-    prov_log_handler = None  # type: Optional[logging.FileHandler]
-    prov_log_handler_file = None  # type: Optional[IO[Any]]
+    prov_log_handler = None  # type: Optional[logging.StreamHandler]
     try:
         if args is None:
             if argsl is None:
@@ -544,14 +543,11 @@ def main(argsl=None,                   # type: List[str]
             if not args.compute_checksum:
                 _logger.error("--provenance incompatible with --no-compute-checksum")
                 return 1
-            runtimeContext.research_obj = ResearchObject(
+            ro = ResearchObject(
                 temp_prefix_ro=args.tmpdir_prefix, orcid=args.orcid,
                 full_name=args.cwl_full_name)
-            assert runtimeContext.research_obj.folder
-            prov_log_handler_filename = os.path.join(
-                runtimeContext.research_obj.folder, "log")
-            prov_log_handler = logging.FileHandler(
-                str(prov_log_handler_filename))
+            log_file_io = ro.open_log_file_for_activity(ro.engine_uuid)
+            prov_log_handler = logging.StreamHandler(log_file_io)
             class ProvLogFormatter(logging.Formatter):
                 """Enforce ISO8601 with both T and Z."""
                 def __init__(self):  # type: () -> None
@@ -566,12 +562,13 @@ def formatTime(self, record, datefmt=None):
                     return with_msecs
             prov_log_handler.setFormatter(ProvLogFormatter())
             _logger.addHandler(prov_log_handler)
+            _logger.debug("[provenance] Logging to %s", log_file_io)
 
         if loadingContext is None:
             loadingContext = LoadingContext(vars(args))
         else:
             loadingContext = loadingContext.copy()
-        loadingContext.research_obj = runtimeContext.research_obj
+        loadingContext.research_obj = ro
         loadingContext.disable_js_validation = \
             args.disable_js_validation or (not args.do_validate)
         loadingContext.construct_tool_object = getdefault(
@@ -795,9 +792,15 @@ def loc_to_path(obj):
             assert prov_dep
             research_obj.generate_snapshot(prov_dep)
             if prov_log_handler:
-                prov_log_handler.close()
+                # Stop logging so we won't half-log adding ourself to RO
+                _logger.debug(u"[provenance] Closing provenance log file %s",
+                    prov_log_handler)
                 _logger.removeHandler(prov_log_handler)
-                research_obj.write_log(prov_log_handler_filename)
+                # Ensure last log lines are written out
+                prov_log_handler.flush()
+                # Underlying WritableBagFile will add the tagfile to the manifest
+                prov_log_handler.stream.close()
+                prov_log_handler.close()
             research_obj.close(args.provenance)
 
         _logger.removeHandler(stderr_handler)