More debug logging (#142)

So many errors are swallowed because everything that triggers a ValueError is just ignored. 
This adds a bunch of debug logs to at least be able to debug.

Author: Carreau

micropip/install.py

@@ -154,6 +154,11 @@ async def install(
             pkg.name for pkg in transaction.wheels
         ]
 
+        logger.debug(
+            "Installing packages %r and wheels %r ",
+            transaction.pyodide_packages,
+            transaction.wheels,
+        )
         if package_names:
             logger.info("Installing collected packages: %s", ", ".join(package_names))
 

micropip/package_index.py

@@ -1,4 +1,5 @@
 import json
+import logging
 import string
 import sys
 from collections import defaultdict
@@ -20,6 +21,8 @@
 
 _formatter = string.Formatter()
 
+logger = logging.getLogger("micropip")
+
 
 @dataclass
 class ProjectInfo:
@@ -224,7 +227,11 @@ def _select_parser(content_type: str, pkgname: str) -> Callable[[str], ProjectIn
             return ProjectInfo.from_simple_json_api
         case "application/json":
             return ProjectInfo.from_json_api
-        case "application/vnd.pypi.simple.v1+html" | "text/html":
+        case (
+            "application/vnd.pypi.simple.v1+html"
+            | "text/html"
+            | "text/html; charset=utf-8"
+        ):
             return partial(ProjectInfo.from_simple_html_api, pkgname=pkgname)
         case _:
             raise ValueError(f"Unsupported content type: {content_type}")
@@ -264,21 +271,28 @@ async def query_package(
     )
 
     if index_urls is None:
+        logger.debug("index_urls is None, falling back to default, %s", INDEX_URLS)
         index_urls = INDEX_URLS
     elif isinstance(index_urls, str):
         index_urls = [index_urls]
 
     for url in index_urls:
+        logger.debug("Looping through index urls: %r", url)
         if _contain_placeholder(url):
             url = url.format(package_name=name)
+            logger.debug("Formatting url with package name : %r", url)
         else:
             url = f"{url}/{name}/"
-
+            logger.debug("Url has no placeholder, appending package name : %r", url)
         try:
             metadata, headers = await fetch_string_and_headers(url, _fetch_kwargs)
         except HttpStatusError as e:
             if e.status_code == 404:
+                logger.debug("NotFound (404) for %r, trying next index.", url)
                 continue
+            logger.debug(
+                "Error fetching %r (%s), trying next index.", url, e.status_code
+            )
             raise
 
         content_type = headers.get("content-type", "").lower()

micropip/transaction.py

@@ -146,16 +146,26 @@ def eval_marker(e: dict[str, str]) -> bool:
         try:
             if self.search_pyodide_lock_first:
                 if self._add_requirement_from_pyodide_lock(req):
+                    logger.debug("Transaction: package found in lock file: %r", req)
                     return
 
                 await self._add_requirement_from_package_index(req)
             else:
                 try:
                     await self._add_requirement_from_package_index(req)
                 except ValueError:
+                    logger.debug(
+                        "Transaction: package %r not found in index, will search lock file",
+                        req,
+                    )
+
                     # If the requirement is not found in package index,
                     # we still have a chance to find it from pyodide lockfile.
                     if not self._add_requirement_from_pyodide_lock(req):
+                        logger.debug(
+                            "Transaction: package %r not found in lock file", req
+                        )
+
                         raise
         except ValueError:
             self.failed.append(req)
@@ -187,8 +197,12 @@ async def _add_requirement_from_package_index(self, req: Requirement):
             req.name, self.fetch_kwargs, index_urls=self.index_urls
         )
 
+        logger.debug("Transaction: got metadata %r for requirement %r", metadata, req)
+
         wheel = find_wheel(metadata, req)
 
+        logger.debug("Transaction: Selected wheel: %r", wheel)
+
         # Maybe while we were downloading pypi_json some other branch
         # installed the wheel?
         satisfied, ver = self.check_version_satisfied(req)