Fix --pip-log re-use. (#2570)

Previously, when only 1 resolve target was specified, a `--pip-log`
would be re-used which would append the current Pip log outout with the
prior output. For a normal PEX build, this was potentially confusing,
but for a `pex3 lock` command it could lead to errors since the log is
used to generate the lock.

Fixes #2568

pex/pip/log_analyzer.py

@@ -7,7 +7,6 @@
 import subprocess
 from abc import abstractmethod
 
-from pex.common import safe_delete
 from pex.jobs import Job
 from pex.typing import TYPE_CHECKING, Generic
 
@@ -75,13 +74,11 @@ def __init__(
         process,  # type: subprocess.Popen
         log,  # type: str
         log_analyzers,  # type: Iterable[LogAnalyzer]
-        preserve_log=False,  # type: bool
         finalizer=None,  # type: Optional[Callable[[int], None]]
     ):
         # type: (...) -> None
         self._log = log
         self._log_analyzers = list(log_analyzers)
-        self._preserve_log = preserve_log
         super(LogScrapeJob, self).__init__(command, process, finalizer=finalizer, context="pip")
 
     def _check_returncode(self, stderr=None):
@@ -126,7 +123,4 @@ def _check_returncode(self, stderr=None):
             with open(self._log, "rb") as fp:
                 analyzed_stderr = fp.read()
 
-        if not self._preserve_log:
-            safe_delete(self._log)
-
         super(LogScrapeJob, self)._check_returncode(stderr=(stderr or b"") + analyzed_stderr)

pex/pip/tool.py

@@ -590,13 +590,6 @@ def spawn_download_distributions(
 
         popen_kwargs = {}
         finalizer = None
-
-        preserve_log = log is not None
-        if preserve_log:
-            TRACER.log(
-                "Preserving `pip download` log at {log_path}".format(log_path=log),
-                V=ENV.PEX_VERBOSE,
-            )
         log = log or os.path.join(safe_mkdtemp(prefix="pex-pip-log."), "pip.log")
 
         # N.B.: The `pip -q download ...` command is quiet but
@@ -637,9 +630,7 @@ def finalizer(_):
             extra_env=extra_env,
             **popen_kwargs
         )
-        return LogScrapeJob(
-            command, process, log, log_analyzers, preserve_log=preserve_log, finalizer=finalizer
-        )
+        return LogScrapeJob(command, process, log, log_analyzers, finalizer=finalizer)
 
     def _ensure_wheel_installed(self, package_index_configuration=None):
         # type: (Optional[PackageIndexConfiguration]) -> None

pex/resolve/abbreviated_platforms.py

@@ -62,7 +62,9 @@ def parse_tags(output):
     )
     job = SpawnedJob.stdout(
         job=pip.spawn_debug(
-            platform_spec=platform_spec, manylinux=manylinux, log=pip_configuration.log
+            platform_spec=platform_spec,
+            manylinux=manylinux,
+            log=pip_configuration.log.path if pip_configuration.log else None,
         ),
         result_func=parse_tags,
     )
@@ -179,7 +181,7 @@ def create(
         # call to `pip -v debug ...` in _calculate_tags above. We do the same for the cached case
         # since this can be very useful information when investigating why Pip did not select a
         # particular wheel for an abbreviated --platform.
-        with safe_open(pip_configuration.log, "a") as fp:
+        with safe_open(pip_configuration.log.path, "a") as fp:
             print(
                 "Read {count} compatible tags for abbreviated --platform {platform} from:".format(
                     count=len(compatibility_tags), platform=platform

pex/resolve/lockfile/updater.py

@@ -28,7 +28,7 @@
 from pex.resolve.lockfile.model import Lockfile
 from pex.resolve.requirement_configuration import RequirementConfiguration
 from pex.resolve.resolved_requirement import ArtifactURL, Fingerprint
-from pex.resolve.resolver_configuration import PipConfiguration, ReposConfiguration
+from pex.resolve.resolver_configuration import PipConfiguration, PipLog, ReposConfiguration
 from pex.result import Error, ResultError, catch, try_
 from pex.sorted_tuple import SortedTuple
 from pex.targets import Target, Targets
@@ -657,7 +657,7 @@ def create(
         max_jobs,  # type: int
         use_pip_config,  # type: bool
         dependency_configuration,  # type: DependencyConfiguration
-        pip_log,  # type: Optional[str]
+        pip_log,  # type: Optional[PipLog]
     ):
         # type: (...) -> LockUpdater
 

pex/resolve/resolver_configuration.py

@@ -180,6 +180,12 @@ def allow_wheel(self, project_name):
         return self.allow_wheels and project_name not in self.only_builds
 
 
+@attr.s(frozen=True)
+class PipLog(object):
+    path = attr.ib()  # type: str
+    user_specified = attr.ib()  # type: bool
+
+
 @attr.s(frozen=True)
 class PipConfiguration(object):
     repos_configuration = attr.ib(default=ReposConfiguration())  # type: ReposConfiguration
@@ -188,7 +194,7 @@ class PipConfiguration(object):
     allow_prereleases = attr.ib(default=False)  # type: bool
     transitive = attr.ib(default=True)  # type: bool
     max_jobs = attr.ib(default=DEFAULT_MAX_JOBS)  # type: int
-    log = attr.ib(default=None)  # type: Optional[str]
+    log = attr.ib(default=None)  # type: Optional[PipLog]
     version = attr.ib(default=None)  # type: Optional[PipVersionValue]
     resolver_version = attr.ib(default=None)  # type: Optional[ResolverVersion.Value]
     allow_version_fallback = attr.ib(default=True)  # type: bool

pex/resolve/resolver_options.py

@@ -25,6 +25,7 @@
     LockRepositoryConfiguration,
     PexRepositoryConfiguration,
     PipConfiguration,
+    PipLog,
     PreResolvedConfiguration,
     ReposConfiguration,
     ResolverVersion,
@@ -326,6 +327,7 @@ def __init__(self, *args, **kwargs):
         super(HandlePipDownloadLogAction, self).__init__(*args, **kwargs)
 
     def __call__(self, parser, namespace, value, option_str=None):
+        pip_log = None  # type: Optional[PipLog]
         if option_str.startswith("--no"):
             if value:
                 raise ArgumentError(
@@ -336,8 +338,28 @@ def __call__(self, parser, namespace, value, option_str=None):
                     ),
                 )
         elif not value:
-            value = os.path.join(tempfile.mkdtemp(prefix="pex-pip-log."), "pip.log")
-        setattr(namespace, self.dest, value)
+            pip_log = PipLog(
+                path=os.path.join(tempfile.mkdtemp(prefix="pex-pip-log."), "pip.log"),
+                user_specified=False,
+            )
+        else:
+            path = os.path.realpath(value)
+            if os.path.exists(path):
+                if not os.path.isfile(path):
+                    raise ArgumentError(
+                        self,
+                        "The requested `--pip-log` of {path} is a directory.\n"
+                        "The `--pip-log` argument must be either an existing file path, in which "
+                        "case the file will be truncated to receive a fresh log, or else a "
+                        "non-existent path, in which case it will be created. Note that using the "
+                        "same `--pip-log` path in concurrent Pex executions is not "
+                        "supported.".format(path=path),
+                    )
+                # N.B.: This truncates the file in a way compatible with Python 2.7 (os.truncate
+                # was introduced in 3.3).
+                open(path, "w").close()
+            pip_log = PipLog(path=value, user_specified=True)
+        setattr(namespace, self.dest, pip_log)
 
 
 def register_pip_log(parser):
@@ -349,13 +371,17 @@ def register_pip_log(parser):
         dest="pip_log",
         default=PipConfiguration().log,
         action=HandlePipDownloadLogAction,
-        help="Preserve the `pip download` log and print its location to stderr.",
+        help=(
+            "With no argument, preserve the `pip download` log and print its location to stderr. "
+            "With a log path argument, truncate the log if it exists and create it if it does not "
+            "already exist, and send Pip log output there."
+        ),
     )
 
 
 def get_pip_log(options):
-    # type: (Namespace) -> Optional[str]
-    return cast("Optional[str]", options.pip_log)
+    # type: (Namespace) -> Optional[PipLog]
+    return cast("Optional[PipLog]", options.pip_log)
 
 
 def register_use_pip_config(parser):

pex/resolver.py

@@ -35,7 +35,7 @@
 from pex.requirements import LocalProjectRequirement
 from pex.resolve.downloads import get_downloads_dir
 from pex.resolve.requirement_configuration import RequirementConfiguration
-from pex.resolve.resolver_configuration import BuildConfiguration, ResolverVersion
+from pex.resolve.resolver_configuration import BuildConfiguration, PipLog, ResolverVersion
 from pex.resolve.resolvers import (
     ResolvedDistribution,
     Resolver,
@@ -48,6 +48,7 @@
 from pex.tracer import TRACER
 from pex.typing import TYPE_CHECKING
 from pex.util import CacheHelper
+from pex.variables import ENV
 
 if TYPE_CHECKING:
     from typing import (
@@ -80,13 +81,13 @@ class PipLogManager(object):
     @classmethod
     def create(
         cls,
-        log,  # type: Optional[str]
+        log,  # type: Optional[PipLog]
         targets,  # type: Sequence[Target]
     ):
         # type: (...) -> PipLogManager
         log_by_target = {}  # type: Dict[Target, str]
         if log and len(targets) == 1:
-            log_by_target[targets[0]] = log
+            log_by_target[targets[0]] = log.path
         elif log:
             log_dir = safe_mkdtemp(prefix="pex-pip-log.")
             log_by_target.update(
@@ -95,7 +96,7 @@ def create(
             )
         return cls(log=log, log_by_target=log_by_target)
 
-    log = attr.ib()  # type: Optional[str]
+    log = attr.ib()  # type: Optional[PipLog]
     _log_by_target = attr.ib()  # type: Mapping[Target, str]
 
     @staticmethod
@@ -112,11 +113,14 @@ def _target_id(target):
 
     def finalize_log(self):
         # type: () -> None
+        if not self.log:
+            return
+
         target_count = len(self._log_by_target)
         if target_count <= 1:
             return
 
-        with safe_open(self.log, "a") as out_fp:
+        with safe_open(self.log.path, "a") as out_fp:
             for index, (target, log) in enumerate(self._log_by_target.items(), start=1):
                 prefix = "{index}/{count}]{target}".format(
                     index=index, count=target_count, target=self._target_id(target)
@@ -149,7 +153,7 @@ class DownloadRequest(object):
     package_index_configuration = attr.ib(default=None)  # type: Optional[PackageIndexConfiguration]
     build_configuration = attr.ib(default=BuildConfiguration())  # type: BuildConfiguration
     observer = attr.ib(default=None)  # type: Optional[ResolveObserver]
-    pip_log = attr.ib(default=None)  # type: Optional[str]
+    pip_log = attr.ib(default=None)  # type: Optional[PipLog]
     pip_version = attr.ib(default=None)  # type: Optional[PipVersionValue]
     resolver = attr.ib(default=None)  # type: Optional[Resolver]
     dependency_configuration = attr.ib(
@@ -172,7 +176,14 @@ def download_distributions(self, dest=None, max_parallel_jobs=None):
         dest = dest or safe_mkdtemp(
             prefix="resolver_download.", dir=safe_mkdir(get_downloads_dir())
         )
+
         log_manager = PipLogManager.create(self.pip_log, self.targets)
+        if self.pip_log and not self.pip_log.user_specified:
+            TRACER.log(
+                "Preserving `pip download` log at {log_path}".format(log_path=self.pip_log.path),
+                V=ENV.PEX_VERBOSE,
+            )
+
         spawn_download = functools.partial(self._spawn_download, dest, log_manager)
         with TRACER.timed(
             "Resolving for:\n  {}".format(
@@ -1046,7 +1057,7 @@ def resolve(
     max_parallel_jobs=None,  # type: Optional[int]
     ignore_errors=False,  # type: bool
     verify_wheels=True,  # type: bool
-    pip_log=None,  # type: Optional[str]
+    pip_log=None,  # type: Optional[PipLog]
     pip_version=None,  # type: Optional[PipVersionValue]
     resolver=None,  # type: Optional[Resolver]
     use_pip_config=False,  # type: bool
@@ -1220,7 +1231,7 @@ def _download_internal(
     dest=None,  # type: Optional[str]
     max_parallel_jobs=None,  # type: Optional[int]
     observer=None,  # type: Optional[ResolveObserver]
-    pip_log=None,  # type: Optional[str]
+    pip_log=None,  # type: Optional[PipLog]
     pip_version=None,  # type: Optional[PipVersionValue]
     resolver=None,  # type: Optional[Resolver]
     dependency_configuration=DependencyConfiguration(),  # type: DependencyConfiguration
@@ -1299,7 +1310,7 @@ def download(
     dest=None,  # type: Optional[str]
     max_parallel_jobs=None,  # type: Optional[int]
     observer=None,  # type: Optional[ResolveObserver]
-    pip_log=None,  # type: Optional[str]
+    pip_log=None,  # type: Optional[PipLog]
     pip_version=None,  # type: Optional[PipVersionValue]
     resolver=None,  # type: Optional[Resolver]
     use_pip_config=False,  # type: bool

tests/integration/resolve/test_issue_2568.py

@@ -0,0 +1,43 @@
+# Copyright 2024 Pex project contributors.
+# Licensed under the Apache License, Version 2.0 (see LICENSE).
+
+from __future__ import absolute_import
+
+import re
+from textwrap import dedent
+
+from pex import targets
+from testing.cli import run_pex3
+from testing.pytest.tmp import Tempdir
+
+
+def test_independent_logs_for_independent_runs(tmpdir):
+    # type: (Tempdir) -> None
+
+    lock = tmpdir.join("lock.json")
+    log = tmpdir.join("pip.log")
+    run_pex3(
+        "lock", "sync", "--lock", lock, "--pip-log", log, "ansicolors==1.1.8", "cowsay==6.0"
+    ).assert_success()
+    target = str(targets.current().platform.tag)
+    run_pex3("lock", "sync", "--lock", lock, "--pip-log", log, "ansicolors==1.1.8").assert_success(
+        expected_error_re=r".*{footer}$".format(
+            footer=re.escape(
+                dedent(
+                    """\
+                    Updates for lock generated by {target}:
+                      Deleted cowsay 6
+                    Updates to lock input requirements:
+                      Deleted 'cowsay==6.0'
+                    """
+                ).format(target=target)
+            )
+        ),
+        re_flags=re.DOTALL,
+    )
+    run_pex3("lock", "sync", "--lock", lock, "--pip-log", log, "ansicolors==1.1.8").assert_success(
+        expected_error_re=r".*No updates for lock generated by {target}\.$".format(
+            target=re.escape(target)
+        ),
+        re_flags=re.DOTALL,
+    )

tests/pip/test_log_analyzer.py

@@ -94,10 +94,8 @@ def assert_job_failure(
             process=process,
             log=log,
             log_analyzers=log_analyzers,
-            preserve_log=False,
             finalizer=lambda code: finalized.append(code),
         ).wait()
-    assert not os.path.exists(log)
     assert [42] == finalized
     return str(exc_info.value)