From 1478e35c0bbba37f38eaad9ed6b2fcfe8d6393c5 Mon Sep 17 00:00:00 2001 From: Rebecca Turner Date: Wed, 7 Jul 2021 14:29:15 -0400 Subject: [PATCH] Add logging for package installation completion Currently, tox-poetry-installer logs when it submits a dependency to the (possibly-parallel) executor for installation, but not when the installation is finished; this commit adds a log message when the installation actually starts (in contrast with when the job is queued) and a log message when the installation completes, along with the wall time it took. Rationale: I've noticed in some cases when running under Python 3.10 packages take much longer to install -- this logging should help pinpoint culprits. --- tox_poetry_installer/installer.py | 12 ++++++++++-- 1 file changed, 10 insertions(+), 2 deletions(-) diff --git a/tox_poetry_installer/installer.py b/tox_poetry_installer/installer.py index bbde07f..e570da9 100644 --- a/tox_poetry_installer/installer.py +++ b/tox_poetry_installer/installer.py @@ -5,6 +5,7 @@ import concurrent.futures import contextlib import typing +from datetime import datetime from typing import Sequence from typing import Set @@ -46,6 +47,13 @@ def install( installed: Set[PoetryPackage] = set() + def logged_install(dependency: PoetryPackage) -> None: + start = datetime.now() + logger.debug(f"Installing {dependency}") + pip.install(dependency) + end = datetime.now() + logger.debug(f"Finished installing {dependency} in {end - start}") + @contextlib.contextmanager def _optional_parallelize(): """A bit of cheat, really @@ -66,8 +74,8 @@ def install( for dependency in packages: if dependency not in installed: installed.add(dependency) - logger.debug(f"Installing {dependency}") - executor(pip.install, dependency) + logger.debug(f"Queuing {dependency}") + executor(logged_install, dependency) else: logger.debug(f"Skipping {dependency}, already installed") logger.debug("Waiting for installs to finish...")