Expressiontool timer (#1681)

* increase default eval_timeout value

Increasing eval_timeout from 20 to 60 seconds.

 The longer default time allows for smooth
running on systems with increased I/O timings (such as
HPC systems with network based file systems).

* Add log information when eval-timeout is exceeded

Added logger output when timer has been triggered.
This also stops the truncation of stdout and stderr.

* Add eval_timeout control to validate_js_expressions

For consistency with other expression tools,
eval_timeout is now used for controlling the timeout
of the validate_js_expression steps. This has
involved adding eval_timeout to LoadingContext
(mirroring RuntimeContext).

Author: douglowe

cwltool/argparser.py

@@ -226,9 +226,9 @@ def arg_parser() -> argparse.ArgumentParser:
     parser.add_argument(
         "--eval-timeout",
         help="Time to wait for a Javascript expression to evaluate before giving "
-        "an error, default 20s.",
+        "an error, default 60s.",
         type=float,
-        default=20,
+        default=60,
     )
 
     provgroup = parser.add_argument_group(

cwltool/context.py

@@ -102,6 +102,7 @@ def __init__(self, kwargs: Optional[Dict[str, Any]] = None) -> None:
         self.relax_path_checks = False  # type: bool
         self.singularity = False  # type: bool
         self.podman = False  # type: bool
+        self.eval_timeout = 60  # type: float
 
         super().__init__(kwargs)
 
@@ -164,7 +165,7 @@ def __init__(self, kwargs: Optional[Dict[str, Any]] = None) -> None:
         self.js_console = False  # type: bool
         self.job_script_provider = None  # type: Optional[DependenciesConfiguration]
         self.select_resources = None  # type: Optional[select_resources_callable]
-        self.eval_timeout = 20  # type: float
+        self.eval_timeout = 60  # type: float
         self.postScatterEval = (
             None
         )  # type: Optional[Callable[[CWLObjectType], Optional[CWLObjectType]]]

cwltool/process.py

@@ -731,6 +731,7 @@ def __init__(
                     self.doc_schema.names[avroname],
                     validate_js_options,
                     self.container_engine,
+                    loadingContext.eval_timeout,
                 )
 
         dockerReq, is_req = self.get_requirement("DockerRequirement")

cwltool/sandboxjs.py

@@ -285,11 +285,23 @@ def process_finished() -> bool:
                         pipes[1].write(buf)
         except OSError:
             break
-    timer.cancel()
 
     stdin_buf.close()
-    stdoutdata = stdout_buf.getvalue()[: -len(PROCESS_FINISHED_STR) - 1]
-    stderrdata = stderr_buf.getvalue()[: -len(PROCESS_FINISHED_STR) - 1]
+
+    if not timer.is_alive():
+        _logger.info("Expression Tool stopped because time limit has been exceeded.")
+        _logger.info(
+            "Time limit is {} seconds. This can be increased using the --eval-timeout flag.\n".format(
+                timeout
+            )
+        )
+        stdoutdata = stdout_buf.getvalue()
+        stderrdata = stderr_buf.getvalue()
+    else:
+        stdoutdata = stdout_buf.getvalue()[: -len(PROCESS_FINISHED_STR) - 1]
+        stderrdata = stderr_buf.getvalue()[: -len(PROCESS_FINISHED_STR) - 1]
+
+    timer.cancel()
 
     nodejs.poll()
 

cwltool/validate_js.py

@@ -134,6 +134,7 @@ def jshint_js(
     globals: Optional[List[str]] = None,
     options: Optional[Dict[str, Union[List[str], str, int]]] = None,
     container_engine: str = "docker",
+    eval_timeout: float = 60,
 ) -> JSHintJSReturn:
     if globals is None:
         globals = []
@@ -164,7 +165,7 @@ def jshint_js(
     returncode, stdout, stderr = exec_js_process(
         "validateJS(%s)"
         % json_dumps({"code": js_text, "options": options, "globals": globals}),
-        timeout=30,
+        timeout=eval_timeout,
         context=jshint_functions_text,
         container_engine=container_engine,
     )
@@ -216,6 +217,7 @@ def validate_js_expressions(
     schema: Schema,
     jshint_options: Optional[Dict[str, Union[List[str], str, int]]] = None,
     container_engine: str = "docker",
+    eval_timeout: float = 60,
 ) -> None:
 
     if tool.get("requirements") is None:
@@ -236,7 +238,11 @@ def validate_js_expressions(
 
     for i, expression_lib_line in enumerate(expression_lib):
         expression_lib_line_errors, expression_lib_line_globals = jshint_js(
-            expression_lib_line, js_globals, jshint_options, container_engine
+            expression_lib_line,
+            js_globals,
+            jshint_options,
+            container_engine,
+            eval_timeout,
         )
         js_globals.extend(expression_lib_line_globals)
         print_js_hint_messages(
@@ -262,7 +268,11 @@ def validate_js_expressions(
                 code_fragment = unscanned_str[scan_slice[0] + 1 : scan_slice[1]]
                 code_fragment_js = code_fragment_to_js(code_fragment, "")
                 expression_errors, _ = jshint_js(
-                    code_fragment_js, js_globals, jshint_options, container_engine
+                    code_fragment_js,
+                    js_globals,
+                    jshint_options,
+                    container_engine,
+                    eval_timeout,
                 )
                 print_js_hint_messages(expression_errors, source_line)
 

tests/test_singularity_versions.py

@@ -1,16 +1,16 @@
 """Test singularity{,-ce} & apptainer versions."""
+from subprocess import check_output  # nosec
+
 import cwltool.singularity
 from cwltool.singularity import (
     get_version,
     is_apptainer_1_or_newer,
     is_version_2_6,
-    is_version_3_or_newer,
     is_version_3_1_or_newer,
     is_version_3_4_or_newer,
+    is_version_3_or_newer,
 )
 
-from subprocess import check_output  # nosec
-
 
 def reset_singularity_version_cache() -> None:
     """Reset the cache for testing."""