commit b50715a58514a3543e9759a4d1a093ac49955226
author Mike Frysinger <vapier@chromium.org> Sat Feb 29 11:01:27 2020 -0500
committer Mike Frysinger <vapier@chromium.org> Fri Mar 20 00:59:33 2020 -0400
tree fc07132dccccbbcc5ef58d0e97bf3e5cf2054ef7
parent fb95d5b1a4d5029a4c516af0e15546e23e9b8dfe

cros_venv: add extended debugging info to creation log

This log isn't normally shown anywhere, only when there are failures,
so add some extended debugging information to it.  This will help us
debug the current failures on the bots.

BUG=chromium:1052692
TEST=CQ passes

Change-Id: If9bb5f2fadd111e20dffe9a530c8a488f8a0e357

venv/cros_venv/scripts/create_venv.py

diff --git a/venv/cros_venv/scripts/create_venv.py b/venv/cros_venv/scripts/create_venv.py
index 2864d1b..543ab7e 100644
--- a/venv/cros_venv/scripts/create_venv.py
+++ b/venv/cros_venv/scripts/create_venv.py
@@ -16,6 +16,7 @@
 
 import argparse
 import logging
+import sys
 
 from cros_venv import venvlib
 
@@ -32,7 +33,14 @@
     with open(args.reqs_file, 'r') as f:
         spec = venvlib.make_spec(f)
     venv = venvlib.VersionedVenv(spec)
-    print(venv.ensure())
+    try:
+        print(venv.ensure())
+        logging.debug('Log file can be found at: %s', venv.logfile)
+    except Exception:
+        logging.error('Creating venv with reqs file "%s" failed',
+                      args.reqs_file, exc_info=True)
+        logging.error('Dumping entire creation log:\n%s', venv.logdata)
+        sys.exit(1)
 
 
 def configure_logging(verbose):

venv/cros_venv/venvlib.py

diff --git a/venv/cros_venv/venvlib.py b/venv/cros_venv/venvlib.py
index b0eef45..7035b97 100644
--- a/venv/cros_venv/venvlib.py
+++ b/venv/cros_venv/venvlib.py
@@ -9,14 +9,17 @@
 from __future__ import unicode_literals
 
 import collections
+import distutils.util
 import functools
 import hashlib
 import itertools
 import json
 import os
+import platform
 import shutil
 import subprocess
 import sys
+import sysconfig
 import tempfile
 import warnings
 
@@ -103,6 +106,30 @@
             self._check_or_create()
         return self._paths.venvdir
 
+    @property
+    def logfile(self):
+        """Show path to internal log file."""
+        return self._paths.logfile
+
+    @property
+    def logdata(self):
+        """Get any internal logged data."""
+        with open(self._paths.logfile) as fp:
+            return fp.read()
+
+    def _log_env(self, logfile):
+        """Log details about the active runtime for debugging."""
+        def get_var(var):
+            return sysconfig.get_config_var(var)
+        logfile.writelines([
+            'venv spec: %s\n' % (self._spec,),
+            'Distutils platform tag: %s\n' % (distutils.util.get_platform(),),
+            'Python implementation: %s\n' % (platform.python_implementation(),),
+        ])
+        for var in ('py_version_nodot', 'SOABI', 'Py_DEBUG', 'WITH_PYMALLOC',
+                    'Py_UNICODE_SIZE'):
+            logfile.write('sysconfig %s: %s\n' % (var, get_var(var)))
+
     def _check_or_create(self):
         """Check virtualenv, creating it if it is not created."""
         try:
@@ -116,6 +143,7 @@
         """Create virtualenv."""
         with open(self._paths.logfile, 'w') as logfile, \
              _make_reqs_file(self._spec) as reqs_file:
+            self._log_env(logfile)
             _create_venv(venvdir=self._paths.venvdir,
                          logfile=logfile)
             _install_reqs_file(python_path=self._paths.python,
@@ -241,7 +269,7 @@
 
 def _install_reqs_file(python_path, reqs_path, logfile):
     """Install reqs file using pip."""
-    command = [python_path, '-m', 'pip', 'install',
+    command = [python_path, '-m', 'pip', 'install', '-vvv',
                '--no-index', '-f', 'file://' + _PACKAGE_DIR, '-r', reqs_path]
     _log_check_call(command, logfile=logfile)