--no-warnings includes schema-salad; --validate should complain to stdout

Author: mr-c

cwltool/loghandler.py

@@ -11,7 +11,7 @@
 
 
 def configure_logging(
-    stderr_handler: logging.Handler,
+    err_handler: logging.Handler,
     no_warnings: bool,
     quiet: bool,
     debug: bool,
@@ -21,25 +21,29 @@ def configure_logging(
 ) -> None:
     """Configure logging."""
     rdflib_logger = logging.getLogger("rdflib.term")
-    rdflib_logger.addHandler(stderr_handler)
+    rdflib_logger.addHandler(err_handler)
     rdflib_logger.setLevel(logging.ERROR)
     deps_logger = logging.getLogger("galaxy.tool_util.deps")
-    deps_logger.addHandler(stderr_handler)
+    deps_logger.addHandler(err_handler)
     ss_logger = logging.getLogger("salad")
-    ss_logger.addHandler(stderr_handler)
     if no_warnings:
-        stderr_handler.setLevel(logging.ERROR)
-    if quiet:
+        err_handler.setLevel(logging.ERROR)
+        ss_logger.setLevel(logging.ERROR)
+    elif quiet:
         # Silence STDERR, not an eventual provenance log file
-        stderr_handler.setLevel(logging.WARN)
+        err_handler.setLevel(logging.WARN)
+        ss_logger.setLevel(logging.WARN)
+    else:
+        err_handler.setLevel(logging.INFO)
+        ss_logger.setLevel(logging.INFO)
     if debug:
         # Increase to debug for both stderr and provenance log file
         base_logger.setLevel(logging.DEBUG)
-        stderr_handler.setLevel(logging.DEBUG)
+        err_handler.setLevel(logging.DEBUG)
         rdflib_logger.setLevel(logging.DEBUG)
         deps_logger.setLevel(logging.DEBUG)
     fmtclass = coloredlogs.ColoredFormatter if enable_color else logging.Formatter
     formatter = fmtclass("%(levelname)s %(message)s")
     if timestamps:
         formatter = fmtclass("[%(asctime)s] %(levelname)s %(message)s", "%Y-%m-%d %H:%M:%S")
-    stderr_handler.setFormatter(formatter)
+    err_handler.setFormatter(formatter)

cwltool/main.py

@@ -967,12 +967,6 @@ def main(
         stdout = cast(IO[str], stdout)
 
     _logger.removeHandler(defaultStreamHandler)
-    stderr_handler = logger_handler
-    if stderr_handler is not None:
-        _logger.addHandler(stderr_handler)
-    else:
-        coloredlogs.install(logger=_logger, stream=stderr)
-        stderr_handler = _logger.handlers[-1]
     workflowobj = None
     prov_log_handler: Optional[logging.StreamHandler[ProvOut]] = None
     global docker_exe
@@ -997,6 +991,13 @@ def main(
                 if not args.cidfile_dir:
                     args.cidfile_dir = os.getcwd()
                 del args.record_container_id
+        if logger_handler is not None:
+            err_handler = logger_handler
+            _logger.addHandler(err_handler)
+        else:
+            coloredlogs.install(logger=_logger, stream=stdout if args.validate else stderr)
+            err_handler = _logger.handlers[-1]
+        logging.getLogger("salad").handlers = _logger.handlers
 
         if runtimeContext is None:
             runtimeContext = RuntimeContext(vars(args))
@@ -1015,7 +1016,7 @@ def main(
                 setattr(args, key, val)
 
         configure_logging(
-            stderr_handler,
+            err_handler,
             args.no_warnings,
             args.quiet,
             runtimeContext.debug,
@@ -1413,8 +1414,7 @@ def loc_to_path(obj: CWLObjectType) -> None:
                 # public API for logging.StreamHandler
                 prov_log_handler.close()
             close_ro(research_obj, args.provenance)
-
-        _logger.removeHandler(stderr_handler)
+        _logger.removeHandler(err_handler)
         _logger.addHandler(defaultStreamHandler)
 
 

tests/test_examples.py

@@ -1820,9 +1820,9 @@ def test_validate_optional_src_with_mandatory_sink() -> None:
         ["--validate", get_data("tests/wf/optional_src_mandatory_sink.cwl")]
     )
     assert exit_code == 0
-    stderr = re.sub(r"\s\s+", " ", stderr)
-    assert 'Source \'opt_file\' of type ["null", "File"] may be incompatible' in stderr
-    assert "with sink 'r' of type \"File\"" in stderr
+    stdout = re.sub(r"\s\s+", " ", stdout)
+    assert 'Source \'opt_file\' of type ["null", "File"] may be incompatible' in stdout
+    assert "with sink 'r' of type \"File\"" in stdout
 
 
 def test_res_req_expr_float_1_0() -> None:
@@ -1875,12 +1875,11 @@ def test_invalid_nested_array() -> None:
         ]
     )
     assert exit_code == 1, stderr
-    stderr = re.sub(r"\n\s+", " ", stderr)
-    stderr = re.sub(r"\s\s+", " ", stderr)
-    assert "Tool definition failed validation:" in stderr
+    stdout = re.sub(r"\s\s+", " ", stdout)
+    assert "Tool definition failed validation:" in stdout
     assert (
         "tests/nested-array.cwl:6:5: Field 'type' references unknown identifier 'string[][]'"
-    ) in stderr
+    ) in stdout
 
 
 def test_input_named_id() -> None:

tests/test_validate.py

@@ -1,5 +1,7 @@
 """Tests --validation."""
 
+import io
+import logging
 import re
 
 from .util import get_data, get_main_output
@@ -43,13 +45,83 @@ def test_validate_with_invalid_input_object() -> None:
         ]
     )
     assert exit_code == 1
-    stderr = re.sub(r"\s\s+", " ", stderr)
-    assert "Invalid job input record" in stderr
+    stdout = re.sub(r"\s\s+", " ", stdout)
+    assert "Invalid job input record" in stdout
     assert (
         "tests/wf/1st-workflow_bad_inputs.yml:2:1: * the 'ex' field is not "
-        "valid because the value is not string" in stderr
+        "valid because the value is not string" in stdout
     )
     assert (
         "tests/wf/1st-workflow_bad_inputs.yml:1:1: * the 'inp' field is not "
-        "valid because is not a dict. Expected a File object." in stderr
+        "valid because is not a dict. Expected a File object." in stdout
+    )
+
+
+def test_validate_quiet() -> None:
+    """Ensure that --validate --quiet prints the correct amount of information."""
+    exit_code, stdout, stderr = get_main_output(
+        [
+            "--validate",
+            "--quiet",
+            get_data("tests/CometAdapter.cwl"),
+        ]
+    )
+    assert exit_code == 0
+    stdout = re.sub(r"\s\s+", " ", stdout)
+    assert "INFO" not in stdout
+    assert "INFO" not in stderr
+    assert "tests/CometAdapter.cwl:9:3: object id" in stdout
+    assert "tests/CometAdapter.cwl#out' previously defined" in stdout
+
+
+def test_validate_no_warnings() -> None:
+    """Ensure that --validate --no-warnings doesn't print any warnings."""
+    exit_code, stdout, stderr = get_main_output(
+        [
+            "--validate",
+            "--no-warnings",
+            get_data("tests/CometAdapter.cwl"),
+        ]
     )
+    assert exit_code == 0
+    stdout = re.sub(r"\s\s+", " ", stdout)
+    stderr = re.sub(r"\s\s+", " ", stderr)
+    assert "INFO" not in stdout
+    assert "INFO" not in stderr
+    assert "WARNING" not in stdout
+    assert "WARNING" not in stderr
+    assert "tests/CometAdapter.cwl:9:3: object id" not in stdout
+    assert "tests/CometAdapter.cwl:9:3: object id" not in stderr
+    assert "tests/CometAdapter.cwl#out' previously defined" not in stdout
+    assert "tests/CometAdapter.cwl#out' previously defined" not in stderr
+
+
+def test_validate_custom_logger() -> None:
+    """Custom log handling test."""
+    custom_log = io.StringIO()
+    handler = logging.StreamHandler(custom_log)
+    handler.setLevel(logging.DEBUG)
+    exit_code, stdout, stderr = get_main_output(
+        [
+            "--validate",
+            get_data("tests/CometAdapter.cwl"),
+        ],
+        logger_handler=handler,
+    )
+    custom_log_text = custom_log.getvalue()
+    assert exit_code == 0
+    custom_log_text = re.sub(r"\s\s+", " ", custom_log_text)
+    stdout = re.sub(r"\s\s+", " ", stdout)
+    stderr = re.sub(r"\s\s+", " ", stderr)
+    assert "INFO" not in stdout
+    assert "INFO" not in stderr
+    assert "INFO" in custom_log_text
+    assert "WARNING" not in stdout
+    assert "WARNING" not in stderr
+    assert "WARNING" in custom_log_text
+    assert "tests/CometAdapter.cwl:9:3: object id" not in stdout
+    assert "tests/CometAdapter.cwl:9:3: object id" not in stderr
+    assert "tests/CometAdapter.cwl:9:3: object id" in custom_log_text
+    assert "tests/CometAdapter.cwl#out' previously defined" not in stdout
+    assert "tests/CometAdapter.cwl#out' previously defined" not in stderr
+    assert "tests/CometAdapter.cwl#out' previously defined" in custom_log_text

tests/util.py

@@ -11,7 +11,7 @@
 from collections.abc import Generator, Mapping
 from contextlib import ExitStack
 from pathlib import Path
-from typing import Optional, Union
+from typing import Any, Optional, Union
 
 import pytest
 
@@ -88,6 +88,7 @@ def get_main_output(
     replacement_env: Optional[Mapping[str, str]] = None,
     extra_env: Optional[Mapping[str, str]] = None,
     monkeypatch: Optional[pytest.MonkeyPatch] = None,
+    **extra_kwargs: Any,
 ) -> tuple[Optional[int], str, str]:
     """Run cwltool main.
 
@@ -113,7 +114,7 @@ def get_main_output(
             monkeypatch.setenv(k, v)
 
     try:
-        rc = main(argsl=args, stdout=stdout, stderr=stderr)
+        rc = main(argsl=args, stdout=stdout, stderr=stderr, **extra_kwargs)
     except SystemExit as e:
         if isinstance(e.code, int):
             rc = e.code