Add verbose option to install and uninstall

CHANGELOG.md

@@ -4,6 +4,13 @@ All notable changes to this project will be documented in this file.
 The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
 and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html).
 
+## Unreleased
+
+### Added
+
+- Added `verbose` parameter to micropip.install and micropip.uninstall
+  [#60](https://github.com/pyodide/micropip/pull/60)
+
 ## [0.3.0] - 2023/03/29
 
 ### Added

micropip/_commands/install.py

@@ -6,6 +6,7 @@
 
 from .._compat import loadPackage, to_js
 from ..constants import FAQ_URLS
+from ..logging import setup_logging
 from ..transaction import Transaction
 
 
@@ -15,6 +16,8 @@ async def install(
     deps: bool = True,
     credentials: str | None = None,
     pre: bool = False,
+    *,
+    verbose: bool | int = False,
 ) -> None:
     """Install the given package and all of its dependencies.
 
@@ -83,7 +86,13 @@ async def install(
         If ``True``, include pre-release and development versions. By default,
         micropip only finds stable versions.
 
+    verbose :
+        Print more information about the process.
+        By default, micropip is silent. Setting ``verbose=True`` will print
+        similar information as pip.
     """
+    logger = setup_logging(verbose)
+
     ctx = default_environment()
     if isinstance(requirements, str):
         requirements = [requirements]
@@ -107,6 +116,7 @@ async def install(
         deps=deps,
         pre=pre,
         fetch_kwargs=fetch_kwargs,
+        verbose=verbose,
     )
     await transaction.gather_requirements(requirements)
 
@@ -117,6 +127,13 @@ async def install(
             f"See: {FAQ_URLS['cant_find_wheel']}\n"
         )
 
+    package_names = [pkg.name for pkg in transaction.pyodide_packages] + [
+        pkg.name for pkg in transaction.wheels
+    ]
+
+    if package_names:
+        logger.info("Installing collected packages: " + ", ".join(package_names))
+
     wheel_promises = []
     # Install built-in packages
     pyodide_packages = transaction.pyodide_packages
@@ -136,4 +153,12 @@ async def install(
         wheel_promises.append(wheel.install(wheel_base))
 
     await asyncio.gather(*wheel_promises)
+
+    packages = [f"{pkg.name}-{pkg.version}" for pkg in transaction.pyodide_packages] + [
+        f"{pkg.name}-{pkg.version}" for pkg in transaction.wheels
+    ]
+
+    if packages:
+        logger.info("Successfully installed " + ", ".join(packages))
+
     importlib.invalidate_caches()

micropip/_commands/uninstall.py

@@ -1,13 +1,13 @@
 import importlib
 import importlib.metadata
-import warnings
 from importlib.metadata import Distribution
 
 from .._compat import loadedPackages
 from .._utils import get_files_in_distribution, get_root
+from ..logging import setup_logging
 
 
-def uninstall(packages: str | list[str]) -> None:
+def uninstall(packages: str | list[str], *, verbose: bool | int = False) -> None:
     """Uninstall the given packages.
 
     This function only supports uninstalling packages that are installed
@@ -22,7 +22,13 @@ def uninstall(packages: str | list[str]) -> None:
     ----------
     packages
         Packages to uninstall.
+
+    verbose
+        Print more information about the process.
+        By default, micropip is silent. Setting ``verbose=True`` will print
+        similar information as pip.
     """
+    logger = setup_logging(verbose)
 
     if isinstance(packages, str):
         packages = [packages]
@@ -33,14 +39,15 @@ def uninstall(packages: str | list[str]) -> None:
             dist = importlib.metadata.distribution(package)
             distributions.append(dist)
         except importlib.metadata.PackageNotFoundError:
-            warnings.warn(
-                f"WARNING: Skipping '{package}' as it is not installed.", stacklevel=1
-            )
+            logger.warning(f"Skipping '{package}' as it is not installed.")
 
     for dist in distributions:
         # Note: this value needs to be retrieved before removing files, as
         #       dist.name uses metadata file to get the name
         name = dist.name
+        version = dist.version
+
+        logger.info(f"Found existing installation: {name} {version}")
 
         root = get_root(dist)
         files = get_files_in_distribution(dist)
@@ -56,9 +63,8 @@ def uninstall(packages: str | list[str]) -> None:
                     # Since we don't support these, we can ignore them (except for data_files (TODO))
                     continue
 
-                warnings.warn(
-                    f"WARNING: A file '{file}' listed in the metadata of '{dist.name}' does not exist.",
-                    stacklevel=1,
+                logger.warning(
+                    f"A file '{file}' listed in the metadata of '{name}' does not exist.",
                 )
 
                 continue
@@ -73,19 +79,19 @@ def uninstall(packages: str | list[str]) -> None:
             try:
                 directory.rmdir()
             except OSError:
-                warnings.warn(
-                    f"WARNING: A directory '{directory}' is not empty after uninstallation of '{name}'. "
+                logger.warning(
+                    f"A directory '{directory}' is not empty after uninstallation of '{name}'. "
                     "This might cause problems when installing a new version of the package. ",
-                    stacklevel=1,
                 )
 
         if hasattr(loadedPackages, name):
             delattr(loadedPackages, name)
         else:
             # This should not happen, but just in case
-            warnings.warn(
-                f"WARNING: a package '{name}' was not found in loadedPackages.",
-                stacklevel=1,
+            logger.warning(
+                f"a package '{name}' was not found in loadedPackages.",
             )
 
+        logger.info(f"Successfully uninstalled {name}-{version}")
+
     importlib.invalidate_caches()

micropip/logging.py

@@ -0,0 +1,103 @@
+import contextlib
+import logging
+import sys
+from collections.abc import Generator
+from typing import Any
+
+_logger: logging.Logger | None = None
+_indentation: int = 0
+
+
+@contextlib.contextmanager
+def indent_log(num: int = 2) -> Generator[None, None, None]:
+    """
+    A context manager which will cause the log output to be indented for any
+    log messages emitted inside it.
+    """
+    global _indentation
+
+    _indentation += num
+    try:
+        yield
+    finally:
+        _indentation -= num
+
+
+# borrowed from pip._internal.utils.logging
+class IndentingFormatter(logging.Formatter):
+    default_time_format = "%Y-%m-%dT%H:%M:%S"
+
+    def __init__(
+        self,
+        *args: Any,
+        add_timestamp: bool = False,
+        **kwargs: Any,
+    ) -> None:
+        """
+        A logging.Formatter that obeys the indent_log() context manager.
+        :param add_timestamp: A bool indicating output lines should be prefixed
+            with their record's timestamp.
+        """
+        self.add_timestamp = add_timestamp
+        super().__init__(*args, **kwargs)
+
+    def get_message_start(self, formatted: str, levelno: int) -> str:
+        """
+        Return the start of the formatted log message (not counting the
+        prefix to add to each line).
+        """
+        if levelno < logging.WARNING:
+            return ""
+        if levelno < logging.ERROR:
+            return "WARNING: "
+
+        return "ERROR: "
+
+    def format(self, record: logging.LogRecord) -> str:
+        """
+        Calls the standard formatter, but will indent all of the log message
+        lines by our current indentation level.
+        """
+        global _indentation
+
+        formatted = super().format(record)
+        message_start = self.get_message_start(formatted, record.levelno)
+        formatted = message_start + formatted
+
+        prefix = ""
+        if self.add_timestamp:
+            prefix = f"{self.formatTime(record)} "
+        prefix += " " * _indentation
+        formatted = "".join([prefix + line for line in formatted.splitlines(True)])
+        return formatted
+
+
+def _set_formatter_once() -> None:
+    global _logger
+
+    if _logger is not None:
+        return
+
+    _logger = logging.getLogger("micropip")
+
+    ch = logging.StreamHandler(sys.stdout)
+    ch.setLevel(logging.NOTSET)
+    ch.setFormatter(IndentingFormatter())
+
+    _logger.addHandler(ch)
+
+
+def setup_logging(verbosity: int | bool) -> logging.Logger:
+    _set_formatter_once()
+
+    if verbosity >= 2:
+        level_number = logging.DEBUG
+    elif verbosity == 1:  # True == 1
+        level_number = logging.INFO
+    else:
+        level_number = logging.WARNING
+
+    assert _logger
+    _logger.setLevel(level_number)
+
+    return _logger

micropip/transaction.py

@@ -2,6 +2,7 @@
 import hashlib
 import importlib.metadata
 import json
+import logging
 import warnings
 from dataclasses import dataclass, field
 from importlib.metadata import PackageNotFoundError
@@ -29,6 +30,8 @@
 from .externals.pip._internal.utils.wheel import pkg_resources_distribution_for_wheel
 from .package import PackageMetadata
 
+logger = logging.getLogger("micropip")
+
 
 @dataclass
 class WheelInfo:
@@ -237,6 +240,8 @@ class Transaction:
     pyodide_packages: list[PackageMetadata] = field(default_factory=list)
     failed: list[Requirement] = field(default_factory=list)
 
+    verbose: bool | int = False
+
     async def gather_requirements(
         self,
         requirements: list[str],
@@ -258,9 +263,9 @@ async def add_requirement(self, req: str | Requirement) -> None:
         wheel = WheelInfo.from_url(req)
         wheel.check_compatible()
 
-        await self.add_wheel(wheel, extras=set())
+        await self.add_wheel(wheel, extras=set(), specifier="")
 
-    def check_version_satisfied(self, req: Requirement) -> bool:
+    def check_version_satisfied(self, req: Requirement) -> tuple[bool, str]:
         ver = None
         try:
             ver = importlib.metadata.version(req.name)
@@ -270,11 +275,11 @@ def check_version_satisfied(self, req: Requirement) -> bool:
             ver = self.locked[req.name].version
 
         if not ver:
-            return False
+            return False, ""
 
         if req.specifier.contains(ver, prereleases=True):
             # installed version matches, nothing to do
-            return True
+            return True, ver
 
         raise ValueError(
             f"Requested '{req}', " f"but {req.name}=={ver} is already installed"
@@ -330,7 +335,10 @@ def eval_marker(e: dict[str, str]) -> bool:
                 return
         # Is some version of this package is already installed?
         req.name = canonicalize_name(req.name)
-        if self.check_version_satisfied(req):
+
+        satisfied, ver = self.check_version_satisfied(req)
+        if satisfied:
+            logger.info(f"Requirement already satisfied: {req} ({ver})")
             return
 
         # If there's a Pyodide package that matches the version constraint, use
@@ -355,24 +363,49 @@ def eval_marker(e: dict[str, str]) -> bool:
             else:
                 return
 
-        if self.check_version_satisfied(req):
-            # Maybe while we were downloading pypi_json some other branch
-            # installed the wheel?
+        # Maybe while we were downloading pypi_json some other branch
+        # installed the wheel?
+        satisfied, ver = self.check_version_satisfied(req)
+        if satisfied:
+            logger.info(f"Requirement already satisfied: {req} ({ver})")
             return
 
-        await self.add_wheel(wheel, req.extras)
+        await self.add_wheel(wheel, req.extras, specifier=str(req.specifier))
 
     async def add_wheel(
         self,
         wheel: WheelInfo,
         extras: set[str],
+        *,
+        specifier: str = "",
     ) -> None:
+        """
+        Download a wheel, and add its dependencies to the transaction.
+
+        Parameters
+        ----------
+        wheel
+            The wheel to add.
+
+        extras
+            Markers for optional dependencies.
+            For example, `micropip.install("pkg[test]")`
+            will pass `{"test"}` as the extras argument.
+
+        specifier
+            Requirement specifier, used only for logging.
+            For example, `micropip.install("pkg>=1.0.0,!=2.0.0")`
+            will pass `>=1.0.0,!=2.0.0` as the specifier argument.
+        """
         normalized_name = canonicalize_name(wheel.name)
         self.locked[normalized_name] = PackageMetadata(
             name=wheel.name,
             version=str(wheel.version),
         )
 
+        logger.info(f"Collecting {wheel.name}{specifier}")
+        logger.info(f"  Downloading {wheel.url.split('/')[-1]}")
+
         await wheel.download(self.fetch_kwargs)
         if self.deps:
             await self.gather_requirements(wheel.requires(extras))