Add logging

Author: lrandersson

.github/workflows/main.yml

@@ -153,7 +153,7 @@ jobs:
           AZURE_SIGNTOOL_KEY_VAULT_URL: ${{ secrets.AZURE_SIGNTOOL_KEY_VAULT_URL }}
           CONSTRUCTOR_EXAMPLES_KEEP_ARTIFACTS: "${{ runner.temp }}/examples_artifacts"
           CONSTRUCTOR_SIGNTOOL_PATH: "C:/Program Files (x86)/Windows Kits/10/bin/10.0.26100.0/x86/signtool.exe"
-          CONSTRUCTOR_VERBOSE: 1
+          CONSTRUCTOR_VERBOSE: 0
         run: |
           rm -rf coverage.json
           pytest -vv --cov=constructor --cov-branch tests/test_examples.py

constructor/briefcase.py

@@ -4,6 +4,7 @@
 
 import functools
 import logging
+import os
 import re
 import shutil
 import sys
@@ -249,6 +250,10 @@ class Payload:
     archive_name: str = "payload.tar.gz"
     conda_exe_name: str = "_conda.exe"
 
+    # There might be other ways we want to enable `add_debug_logging`, but it has proven
+    # very useful at least for the CI environment.
+    add_debug_logging: bool = bool(os.environ.get("CI")) and os.environ.get("CI") != "0"
+
     @functools.cached_property
     def root(self) -> Path:
         """Create root upon first access and cache it."""
@@ -332,6 +337,7 @@ def render_templates(self) -> list[str: TemplateFile]:
         context: dict[str, str] = {
             "archive_name": self.archive_name,
             "conda_exe_name": self.conda_exe_name,
+            "add_debug": self.add_debug_logging,
         }
 
         # Render the templates now using jinja and the defined context

constructor/briefcase/pre_uninstall.bat

@@ -1,20 +1,46 @@
-set "INSTDIR=%cd%"
+@echo {{ 'on' if add_debug else 'off' }}
+setlocal
+
+rem Assign INSTDIR and normalize the path
+set "INSTDIR=%~dp0.."
+for %%I in ("%INSTDIR%") do set "INSTDIR=%%~fI"
+
 set "BASE_PATH=%INSTDIR%\base"
 set "PREFIX=%BASE_PATH%"
 set "CONDA_EXE=%INSTDIR%\{{ conda_exe_name }}"
 set "PAYLOAD_TAR=%INSTDIR%\{{ archive_name }}"
 
+{%- if add_debug %}
+rem Get the name of the install directory
+for %%I in ("%INSTDIR%") do set "APPNAME=%%~nxI"
+set "LOG=%TEMP%\%APPNAME%-preuninstall.log"
+
+echo ==== pre_uninstall start ==== >> "%LOG%"
+echo SCRIPT=%~f0 >> "%LOG%"
+echo CWD=%CD% >> "%LOG%"
+echo INSTDIR=%INSTDIR% >> "%LOG%"
+echo BASE_PATH=%BASE_PATH% >> "%LOG%"
+echo CONDA_EXE=%CONDA_EXE% >> "%LOG%"
+echo PAYLOAD_TAR=%PAYLOAD_TAR% >> "%LOG%"
+"%CONDA_EXE%" --version >> "%LOG%" 2>&1
+{%- endif %}
+
+{%- set redir = ' >> "%LOG%" 2>&1' if add_debug else '' %}
+{%- set dump_and_exit = 'type "%LOG%" & exit /b %errorlevel%' if add_debug else 'exit /b %errorlevel%' %}
+
+rem Sanity checks
+if not exist "%CONDA_EXE%" (
+  {% if add_debug %}echo [ERROR] CONDA_EXE not found: "%CONDA_EXE%" >> "%LOG%" & type "%LOG%" & {% endif %}exit /b 10
+)
+
 rem Recreate an empty payload tar. This file was deleted during installation but the
 rem MSI installer expects it to exist.
 type nul > "%PAYLOAD_TAR%"
-
-"%CONDA_EXE%" menuinst --prefix "%BASE_PATH%" --remove
-if errorlevel 1 (
-    echo [ERROR] %CONDA_EXE% failed with exit code %errorlevel%.
-    exit /b %errorlevel%
-)
-"%CONDA_EXE%" constructor uninstall --prefix "%BASE_PATH%"
 if errorlevel 1 (
-    echo [ERROR] %CONDA_EXE% failed with exit code %errorlevel%.
-    exit /b %errorlevel%
+  {% if add_debug %}echo [ERROR] Failed to create "%PAYLOAD_TAR%" >> "%LOG%" & type "%LOG%" & {% endif %}exit /b %errorlevel%
 )
+
+"%CONDA_EXE%" constructor uninstall --prefix "%BASE_PATH%"{{ redir }}
+if errorlevel 1 ( {{ dump_and_exit }} )
+
+exit /b 0

constructor/briefcase/run_installation.bat

@@ -1,20 +1,61 @@
-set "INSTDIR=%cd%"
+@echo {{ 'on' if add_debug else 'off' }}
+setlocal
+
+rem Assign INSTDIR and normalize the path
+set "INSTDIR=%~dp0.."
+for %%I in ("%INSTDIR%") do set "INSTDIR=%%~fI"
+
 set "BASE_PATH=%INSTDIR%\base"
 set "PREFIX=%BASE_PATH%"
 set "CONDA_EXE=%INSTDIR%\{{ conda_exe_name }}"
 set "PAYLOAD_TAR=%INSTDIR%\{{ archive_name }}"
 
-echo Unpacking payload...
-"%CONDA_EXE%" constructor extract --prefix "%INSTDIR%" --tar-from-stdin < "%PAYLOAD_TAR%"
-"%CONDA_EXE%" constructor --prefix "%BASE_PATH%" --extract-conda-pkgs
-
+set CONDA_EXTRA_SAFETY_CHECKS=no
 set CONDA_PROTECT_FROZEN_ENVS=0
-set "CONDA_ROOT_PREFIX=%BASE_PATH%"
 set CONDA_SAFETY_CHECKS=disabled
-set CONDA_EXTRA_SAFETY_CHECKS=no
+set "CONDA_ROOT_PREFIX=%BASE_PATH%"
 set "CONDA_PKGS_DIRS=%BASE_PATH%\pkgs"
 
-"%CONDA_EXE%" install --offline --file "%BASE_PATH%\conda-meta\initial-state.explicit.txt" -yp "%BASE_PATH%"
+{%- if add_debug %}
+rem Get the name of the install directory
+for %%I in ("%INSTDIR%") do set "APPNAME=%%~nxI"
+set "LOG=%TEMP%\%APPNAME%-postinstall.log"
+
+echo ==== run_installation start ==== >> "%LOG%"
+echo SCRIPT=%~f0 >> "%LOG%"
+echo CWD=%CD% >> "%LOG%"
+echo INSTDIR=%INSTDIR% >> "%LOG%"
+echo BASE_PATH=%BASE_PATH% >> "%LOG%"
+echo CONDA_EXE=%CONDA_EXE% >> "%LOG%"
+echo PAYLOAD_TAR=%PAYLOAD_TAR% >> "%LOG%"
+{%- endif %}
+
+{%- set redir = ' >> "%LOG%" 2>&1' if add_debug else '' %}
+{%- set dump_and_exit = 'type "%LOG%" & exit /b %errorlevel%' if add_debug else 'exit /b %errorlevel%' %}
+
+rem Sanity checks
+if not exist "%CONDA_EXE%" (
+  {% if add_debug %}echo [ERROR] CONDA_EXE not found: "%CONDA_EXE%" >> "%LOG%" & type "%LOG%" & {% endif %}exit /b 10
+)
+if not exist "%PAYLOAD_TAR%" (
+  {% if add_debug %}echo [ERROR] PAYLOAD_TAR not found: "%PAYLOAD_TAR%" >> "%LOG%" & type "%LOG%" & {% endif %}exit /b 11
+)
+
+echo Unpacking payload...
+rem "%CONDA_EXE%" constructor extract --prefix "%INSTDIR%" --tar-from-stdin < "%PAYLOAD_TAR%"{{ redir }}
+"%CONDA_EXE%" constructor --prefix "%INSTDIR%" --extract-tarball < "%PAYLOAD_TAR%"{{ redir }}
+if errorlevel 1 ( {{ dump_and_exit }} )
+
+rem "%CONDA_EXE%" constructor --prefix "%BASE_PATH%" --extract-conda-pkgs{{ redir }}
+"%CONDA_EXE%" constructor --prefix "%BASE_PATH%" --extract-conda-pkgs{{ redir }}
+if errorlevel 1 ( {{ dump_and_exit }} )
+
+if not exist "%BASE_PATH%" (
+  {% if add_debug %}echo [ERROR] "%BASE_PATH%" not found! >> "%LOG%" & type "%LOG%" & {% endif %}exit /b 12
+)
+
+"%CONDA_EXE%" install --offline --file "%BASE_PATH%\conda-meta\initial-state.explicit.txt" -yp "%BASE_PATH%"{{ redir }}
+if errorlevel 1 ( {{ dump_and_exit }} )
 
 rem Delete the payload to save disk space.
 rem A truncated placeholder of 0 bytes is recreated during uninstall

tests/test_examples.py

@@ -339,10 +339,11 @@ def _sentinel_file_checks(example_path, install_dir):
 
 
 def is_admin() -> bool:
-    try:
-        return ctypes.windll.shell32.IsUserAnAdmin()
-    except Exception:
-        return False
+    #try:
+    #    return ctypes.windll.shell32.IsUserAnAdmin()
+    #except Exception:
+    #    return False
+    return False
 
 
 def calculate_msi_install_path(installer: Path) -> Path:
@@ -355,6 +356,7 @@ def calculate_msi_install_path(installer: Path) -> Path:
     else:
         local_dir = os.environ.get("LOCALAPPDATA", str(Path.home() / r"AppData\Local"))
         root_dir = Path(local_dir) / "Programs"
+        root_dir.mkdir(parents=True, exist_ok=True)
 
     assert root_dir.is_dir()  # Sanity check to avoid strange unexpected errors
     return Path(root_dir) / dir_name
@@ -388,8 +390,13 @@ def _run_installer_msi(
         "/qn",
     ]
 
-    log_path = Path(os.environ.get("TEMP")) / (install_dir.name + ".log")
+    log_path = Path(os.environ.get("TEMP")) / (install_dir.name + "-install.log")
     cmd.extend(["/L*V", str(log_path)])
+
+    post_install_log = Path(os.environ.get("TEMP")) / (install_dir.name + "-postinstall.log")
+    if post_install_log.exists():
+        os.remove(post_install_log)
+
     try:
         process = _execute(cmd, installer_input=installer_input, timeout=timeout, check=check)
     except subprocess.CalledProcessError as e:
@@ -401,9 +408,23 @@ def _run_installer_msi(
                 log_path.read_text(encoding="utf-16", errors="replace")[-15000:]
             )  # last 15k chars
             print(f"\n=== MSI LOG {log_path} END ===")
+        if post_install_log.exists():
+            print(f"\n=== MSI POST INSTALL LOG {post_install_log} START ===")
+            print(post_install_log.read_text(encoding="utf-8", errors="replace"))
+            print(f"\n=== MSI POST INSTALL LOG {log_path} END ===")
+        else:
+            print(f"\n(post-install log not found at {post_install_log})\n")
         raise e
     if check:
         print("A check for MSI Installers not yet implemented")
+
+    # Sanity check the installation directory
+    expected_items = [install_dir / "base", install_dir / "base" / "conda-meta", install_dir / "_conda.exe"]
+    missing_items = [item for item in expected_items if not item.exists()]
+    if missing_items:
+        missing_items_string = "\n".join(missing_items)
+        raise Exception(f"Sanity check failed, unable to find expected paths: \n{missing_items_string}")
+
     return process
 
 
@@ -419,7 +440,45 @@ def _run_uninstaller_msi(
         str(installer),
         "/qn",
     ]
-    process = _execute(cmd, timeout=timeout, check=check)
+
+    # Temporary debug
+    print("base exists:", (install_dir / "base").exists())
+    print("conda-meta exists:", (install_dir / "base" / "conda-meta").exists())
+    print("conda-meta history exists:", (install_dir / "base" / "conda-meta" / "history").exists())
+
+    print(f"\n=== Top-level contents of {install_dir} ===")
+    for p in sorted(install_dir.iterdir()):
+        kind = "DIR " if p.is_dir() else "FILE"
+        print(f"{kind:4} {p.name}")
+
+    # Add MSI verbose log file
+    log_path = Path(os.environ.get("TEMP")) / (install_dir.name + "-uninstall.log")
+    cmd.extend(["/L*V", str(log_path)])
+
+    # Add log file for pre_uninstall.bat
+    pre_uninstall_log = Path(os.environ.get("TEMP")) / (install_dir.name + "-preuninstall.log")
+    if pre_uninstall_log.exists():
+        os.remove(pre_uninstall_log)
+    try:
+        process = _execute(cmd, installer_input = None, timeout=timeout, check=check)
+    except subprocess.CalledProcessError:
+        # Dump pre-uninstall log
+        if pre_uninstall_log.exists():
+            print(f"\n=== PRE-UNINSTALL LOG {pre_uninstall_log} START ===")
+            print(pre_uninstall_log.read_text(encoding="utf-8", errors="replace")[-15000:])
+            print(f"=== PRE-UNINSTALL LOG {pre_uninstall_log} END ===\n")
+        else:
+            print(f"\n(pre-uninstall log not found at {pre_uninstall_log})\n")
+
+        # Dump MSI uninstall log (often UTF-16)
+        if log_path.exists():
+            print(f"\n=== MSI UNINSTALL LOG {log_path} START ===")
+            print(log_path.read_text(encoding="utf-16", errors="replace")[-15000:])  # last 15k chars
+            print(f"=== MSI UNINSTALL LOG {log_path} END ===\n")
+        else:
+            print(f"\n(msi uninstall log not found at {log_path})\n")
+        raise
+
     if check:
         # TODO:
         # Check log and if there are remaining files, similar to the exe installers