Fix to flush logging instead of shutting it down at job end

hydra/_internal/hydra.py

@@ -95,11 +95,12 @@ def run(
         config_name: Optional[str],
         task_function: TaskFunction,
         overrides: List[str],
+        with_log_configuration: bool = True,
     ) -> JobReturn:
         cfg = self.compose_config(
             config_name=config_name,
             overrides=overrides,
-            with_log_configuration=True,
+            with_log_configuration=with_log_configuration,
             run_mode=RunMode.RUN,
         )
         HydraConfig.instance().set_config(cfg)
@@ -108,20 +109,22 @@ def run(
             task_function=task_function,
             job_dir_key="hydra.run.dir",
             job_subdir_key=None,
+            configure_logging=with_log_configuration,
         )
 
     def multirun(
         self,
         config_name: Optional[str],
         task_function: TaskFunction,
         overrides: List[str],
+        with_log_configuration: bool = True,
     ) -> Any:
         # Initial config is loaded without strict (individual job configs may have strict).
         cfg = self.compose_config(
             config_name=config_name,
             overrides=overrides,
             strict=False,
-            with_log_configuration=True,
+            with_log_configuration=with_log_configuration,
             run_mode=RunMode.MULTIRUN,
         )
         HydraConfig.instance().set_config(cfg)

hydra/core/utils.py

@@ -83,6 +83,7 @@ def run_job(
     task_function: TaskFunction,
     job_dir_key: str,
     job_subdir_key: Optional[str],
+    configure_logging: bool = True,
 ) -> "JobReturn":
     old_cwd = os.getcwd()
     working_dir = str(OmegaConf.select(config, job_dir_key))
@@ -108,7 +109,8 @@ def run_job(
         Path(str(working_dir)).mkdir(parents=True, exist_ok=True)
         os.chdir(working_dir)
 
-        configure_log(config.hydra.job_logging, config.hydra.verbose)
+        if configure_logging:
+            configure_log(config.hydra.job_logging, config.hydra.verbose)
 
         hydra_cfg = OmegaConf.masked_copy(config, "hydra")
         assert isinstance(hydra_cfg, DictConfig)
@@ -123,9 +125,7 @@ def run_job(
             ret.return_value = task_function(task_cfg)
         ret.task_name = JobRuntime.instance().get("name")
 
-        # shut down logging to ensure job log files are closed.
-        # If logging is still required after run_job caller is responsible to re-initialize it.
-        logging.shutdown()
+        _flush_loggers()
 
         return ret
     finally:
@@ -240,3 +240,10 @@ def env_override(env: Dict[str, str]) -> Any:
                 del os.environ[key]
             else:
                 os.environ[key] = value
+
+
+def _flush_loggers() -> None:
+    # Python logging does not have an official API to flush all loggers.
+    # This will have to do.
+    for h_weak_ref in logging._handlerList:  # type: ignore
+        h_weak_ref().flush()

hydra/experimental/compose.py

@@ -34,6 +34,7 @@ def compose(
         run_mode=RunMode.RUN,
         strict=strict,
         from_shell=False,
+        with_log_configuration=False,
     )
     assert isinstance(cfg, DictConfig)
 

hydra/extra/pytest_plugin.py

@@ -34,6 +34,7 @@ def hydra_sweep_runner() -> Callable[
         Optional[List[str]],
         Optional[bool],
         Optional[Path],
+        bool,
     ],
     SweepTaskFunction,
 ]:
@@ -46,6 +47,7 @@ def _(
         overrides: Optional[List[str]],
         strict: Optional[bool] = None,
         temp_dir: Optional[Path] = None,
+        configure_logging: bool = False,
     ) -> SweepTaskFunction:
         sweep = SweepTaskFunction()
         sweep.calling_file = calling_file
@@ -56,6 +58,7 @@ def _(
         sweep.strict = strict
         sweep.overrides = overrides or []
         sweep.temp_dir = str(temp_dir)
+        sweep.configure_logging = configure_logging
         return sweep
 
     return _
@@ -70,6 +73,7 @@ def hydra_task_runner() -> Callable[
         Optional[str],
         Optional[List[str]],
         Optional[bool],
+        bool,
     ],
     TaskTestFunction,
 ]:
@@ -80,6 +84,7 @@ def _(
         config_name: Optional[str],
         overrides: Optional[List[str]] = None,
         strict: Optional[bool] = None,
+        configure_logging: bool = False,
     ) -> TaskTestFunction:
         task = TaskTestFunction()
         task.overrides = overrides or []
@@ -88,6 +93,7 @@ def _(
         task.calling_module = calling_module
         task.config_path = config_path
         task.strict = strict
+        task.configure_logging = configure_logging
         return task
 
     return _

hydra/test_utils/test_utils.py

@@ -50,6 +50,7 @@ def __init__(self) -> None:
         self.strict: Optional[bool] = None
         self.hydra: Optional[Hydra] = None
         self.job_ret: Optional[JobReturn] = None
+        self.configure_logging: bool = False
 
     def __call__(self, cfg: DictConfig) -> Any:
         """
@@ -78,17 +79,21 @@ def __enter__(self) -> "TaskTestFunction":
             assert overrides is not None
             overrides.append(f"hydra.run.dir={self.temp_dir}")
             self.job_ret = self.hydra.run(
-                config_name=config_name, task_function=self, overrides=overrides
+                config_name=config_name,
+                task_function=self,
+                overrides=overrides,
+                with_log_configuration=self.configure_logging,
             )
             return self
         finally:
             GlobalHydra().clear()
 
     def __exit__(self, exc_type: Any, exc_val: Any, exc_tb: Any) -> None:
-        # release log file handles
-        logging.shutdown()
+        # release log file handles.
+        if self.configure_logging:
+            logging.shutdown()
         assert self.temp_dir is not None
-        shutil.rmtree(self.temp_dir)
+        shutil.rmtree(self.temp_dir, ignore_errors=True)
 
 
 class TTaskRunner(Protocol):
@@ -100,6 +105,7 @@ def __call__(
         config_name: Optional[str],
         overrides: Optional[List[str]] = None,
         strict: Optional[bool] = None,
+        configure_logging: bool = False,
     ) -> TaskTestFunction:
         ...
 
@@ -123,6 +129,7 @@ def __init__(self) -> None:
         self.strict: Optional[bool] = None
         self.sweeps = None
         self.returns = None
+        self.configure_logging: bool = False
 
     def __call__(self, cfg: DictConfig) -> Any:
         """
@@ -156,16 +163,21 @@ def __enter__(self) -> "SweepTaskFunction":
             )
 
             self.returns = hydra_.multirun(
-                config_name=config_name, task_function=self, overrides=overrides
+                config_name=config_name,
+                task_function=self,
+                overrides=overrides,
+                with_log_configuration=self.configure_logging,
             )
         finally:
             GlobalHydra().clear()
 
         return self
 
     def __exit__(self, exc_type: Any, exc_val: Any, exc_tb: Any) -> None:
+        if self.configure_logging:
+            logging.shutdown()
         assert self.temp_dir is not None
-        shutil.rmtree(self.temp_dir)
+        shutil.rmtree(self.temp_dir, ignore_errors=True)
 
 
 class TSweepRunner(Protocol):

news/833.bugfix.1

@@ -0,0 +1 @@
+Fix to flush logging instead of shutting it down at job end

news/833.bugfix.2

@@ -0,0 +1 @@
+compose() no longer initialized logging subsystem

noxfile.py

@@ -274,6 +274,30 @@ def lint_plugins(session):
     session.run("mypy", ".", "--strict", silent=SILENT)
 
 
+@nox.session(python=PYTHON_VERSIONS)
+def test_tools(session):
+    install_cmd = ["pip", "install"]
+    _upgrade_basic(session)
+    session.install("pytest")
+    install_hydra(session, install_cmd)
+
+    tools = [
+        x
+        for x in sorted(os.listdir(os.path.join(BASE, "tools")))
+        if not os.path.isfile(x)
+    ]
+
+    for tool in tools:
+        tool_path = os.path.join("tools", tool)
+        session.chdir(BASE)
+        cmd = list(install_cmd) + ["-e", tool_path]
+        session.run(*cmd, silent=SILENT)
+
+        session.run("pytest", tool_path)
+
+    session.chdir(BASE)
+
+
 def _get_standalone_apps_dir():
     standalone_apps_dir = Path(f"{BASE}/tests/standalone_apps")
     apps = [standalone_apps_dir / subdir for subdir in os.listdir(standalone_apps_dir)]
@@ -395,9 +419,7 @@ def test_jupyter_notebooks(session):
         session.skip(
             f"Not testing Jupyter notebook on Python {session.python}, supports [{','.join(versions)}]"
         )
-    # pyzmq 19.0.1 has installation issues on Windows
-    # pytest 6.0 makes deprecation warnings wail on errors, breaking nbval due to a deprecated API usage
-    session.install("jupyter", "nbval", "pyzmq==19.0.0", "pytest==5.4.3")
+    session.install("jupyter", "nbval")
     install_hydra(session, ["pip", "install", "-e"])
     args = pytest_args(
         "--nbval", "examples/jupyter_notebooks/compose_configs_in_notebook.ipynb",
@@ -413,27 +435,3 @@ def test_jupyter_notebooks(session):
         args = pytest_args("--nbval", str(notebook))
         args = [x for x in args if x != "-Werror"]
         session.run(*args, silent=SILENT)
-
-
-@nox.session(python=PYTHON_VERSIONS)
-def test_tools(session):
-    install_cmd = ["pip", "install"]
-    _upgrade_basic(session)
-    session.install("pytest")
-    install_hydra(session, install_cmd)
-
-    tools = [
-        x
-        for x in sorted(os.listdir(os.path.join(BASE, "tools")))
-        if not os.path.isfile(x)
-    ]
-
-    for tool in tools:
-        tool_path = os.path.join("tools", tool)
-        session.chdir(BASE)
-        cmd = list(install_cmd) + ["-e", tool_path]
-        session.run(*cmd, silent=SILENT)
-
-        session.run("pytest", tool_path)
-
-    session.chdir(BASE)

tests/jupyter/%run_test.ipynb

@@ -49,8 +49,8 @@
    ],
    "source": [
     "import tempfile\n",
-    "with tempfile.TemporaryDirectory() as tmpdir:\n",
-    "    %run ../../examples/tutorials/basic/your_first_hydra_app/6_composition/my_app.py hydra.run.dir=$tmpdir"
+    "tmpdir = tempfile.mkdtemp()\n",
+    "%run ../../examples/tutorials/basic/your_first_hydra_app/6_composition/my_app.py hydra.run.dir=$tmpdir"
    ]
   }
  ],
@@ -70,9 +70,9 @@
    "name": "python",
    "nbconvert_exporter": "python",
    "pygments_lexer": "ipython3",
-   "version": "3.8.2"
+   "version": "3.8.0"
   }
  },
  "nbformat": 4,
  "nbformat_minor": 4
-}
+}

tests/test_examples/test_patterns.py

@@ -25,6 +25,7 @@ def test_specializing_config_example(
         config_path="conf",
         config_name="config.yaml",
         overrides=["dataset=cifar10"],
+        configure_logging=True,
     ) as task:
         assert task.job_ret is not None and task.job_ret.cfg == dict(
             dataset=dict(name="cifar10", path="/datasets/cifar10"),

tests/test_examples/test_tutorials_basic.py

@@ -198,6 +198,7 @@ def test_composition_config_example(
         config_path="conf",
         config_name="config.yaml",
         overrides=["schema=school"],
+        configure_logging=True,
     ) as task:
         assert task.job_ret is not None
         assert task.job_ret.cfg == {