Add "verbosity 3" and tweak console output a bit (#104)

* Hide additional debug info behind verbosity 3 (-vvv)

* Ensure deterministic sorted order of unknown_names

This will be useful when multiprocessing comes online in which case the
order of names with the same frequency would be up to which worker
finished first. This prevents that.

* Don't repeat decorators of verbosity options

* Use "bright_black" for debug information

which is hopefully more generally visible.

Author: lagru

docs/command_line.md

@@ -60,9 +60,9 @@ Options:
                          Will add to '--allow-errors'.
   --no-cache             Ignore pre-existing cache and don't create a new one.
   -v, --verbose          Print more details. Use once to show information
-                         messages. Use '-vv' to print debug messages.
+                         messages. Use -vv to print debug messages.
   -q, --quiet            Print less details. Use once to hide warnings. Use
-                         '-qq' to completely silence output.
+                         -qq to completely silence output.
   -h, --help             Show this message and exit.
 ```
 
@@ -84,8 +84,8 @@ Usage: docstub clean [OPTIONS]
 
 Options:
   -v, --verbose  Print more details. Use once to show information messages.
-                 Use '-vv' to print debug messages.
-  -q, --quiet    Print less details. Use once to hide warnings. Use '-qq' to
+                 Use -vv to print debug messages.
+  -q, --quiet    Print less details. Use once to hide warnings. Use -qq to
                  completely silence output.
   -h, --help     Show this message and exit.
 ```

src/docstub-stubs/_cli.pyi

@@ -5,7 +5,7 @@ import shutil
 import sys
 import time
 from collections import Counter
-from collections.abc import Iterable, Sequence
+from collections.abc import Callable, Iterable, Sequence
 from contextlib import contextmanager
 from pathlib import Path
 from typing import Literal
@@ -30,15 +30,16 @@ logger: logging.Logger
 def _cache_dir_in_cwd() -> Path: ...
 def _load_configuration(config_paths: list[Path] | None = ...) -> Config: ...
 def _calc_verbosity(
-    *, verbose: Literal[0, 1, 2], quiet: Literal[0, 1, 2]
-) -> Literal[-2, -1, 0, 1, 2]: ...
+    *, verbose: Literal[0, 1, 3], quiet: Literal[0, 1, 2]
+) -> Literal[-2, -1, 0, 1, 2, 3]: ...
 def _collect_type_info(
     root_path: Path, *, ignore: Sequence[str] = ..., cache: bool = ...
 ) -> tuple[dict[str, PyImport], dict[str, PyImport]]: ...
-def _format_unknown_names(unknown_names: Iterable[str]) -> str: ...
+def _format_unknown_names(names: Iterable[str]) -> str: ...
 def log_execution_time() -> None: ...
 @click.group()
 def cli() -> None: ...
+def _add_verbosity_options(func: Callable) -> Callable: ...
 @cli.command()
 def run(
     *,

src/docstub-stubs/_report.pyi

@@ -4,7 +4,7 @@ import dataclasses
 import logging
 from pathlib import Path
 from textwrap import indent
-from typing import Any, ClassVar, Self, TextIO
+from typing import Any, ClassVar, Literal, Self, TextIO
 
 import click
 
@@ -54,4 +54,6 @@ class ReportHandler(logging.StreamHandler):
     def emit(self, record: logging.LogRecord) -> None: ...
     def emit_grouped(self) -> None: ...
 
-def setup_logging(*, verbosity: int, group_errors: bool) -> ReportHandler: ...
+def setup_logging(
+    *, verbosity: Literal[-2, -1, 0, 1, 2, 3], group_errors: bool
+) -> ReportHandler: ...

src/docstub/_cli.py

@@ -81,19 +81,19 @@ def _calc_verbosity(*, verbose, quiet):
 
     Parameters
     ----------
-    verbose : {0, 1, 2}
+    verbose : {0, 1, 3}
     quiet : {0, 1, 2}
 
     Returns
     -------
-    verbosity : {-2, -1, 0, 1, 2}
+    verbosity : {-2, -1, 0, 1, 2, 3}
     """
     if verbose and quiet:
         raise click.UsageError(
             "Options '-v/--verbose' and '-q/--quiet' cannot be used together"
         )
     verbose -= quiet
-    verbose = min(2, max(-2, verbose))  # Limit to range [-2, 2]
+    verbose = min(3, max(-2, verbose))  # Limit to range [-2, 3]
     return verbose
 
 
@@ -156,24 +156,38 @@ def _collect_type_info(root_path, *, ignore=(), cache=False):
     return types, collected_type_prefixes
 
 
-def _format_unknown_names(unknown_names):
+def _format_unknown_names(names):
     """Format unknown type names as a list for printing.
 
     Parameters
     ----------
-    unknown_names : Iterable[str]
+    names : Iterable[str]
 
     Returns
     -------
     formatted : str
         A multiline string.
+
+    Examples
+    --------
+    >>> names = ["path-like", "values", "arrays", "values"] + ["string"] * 11
+    >>> print(_format_unknown_names(names))
+    11  string
+     2  values
+     1  arrays
+     1  path-like
     """
-    lines = [click.style(f"Unknown type names: {len(unknown_names)}", bold=True)]
-    counter = Counter(unknown_names)
-    sorted_item_counts = sorted(counter.items(), key=lambda x: x[1], reverse=True)
-    for item, count in sorted_item_counts:
-        lines.append(f"    {item} (x{count})")
-    return "\n".join(lines)
+    counter = Counter(names)
+    sorted_alphabetical = sorted(counter.items(), key=lambda x: x[0])
+    sorted_by_frequency = sorted(sorted_alphabetical, key=lambda x: x[1], reverse=True)
+
+    lines = []
+    pad_left = len(str(sorted_by_frequency[0][1]))
+    for item, count in sorted_by_frequency:
+        count_fmt = f"{count}".rjust(pad_left)
+        lines.append(f"{count_fmt}  {item}")
+    formatted = "\n".join(lines)
+    return formatted
 
 
 @contextmanager
@@ -208,6 +222,34 @@ def cli():
     """Generate Python stub files from docstrings."""
 
 
+def _add_verbosity_options(func):
+    """Add verbose and quiet command line options.
+
+    Parameters
+    ----------
+    func : Callable
+
+    Returns
+    -------
+    decorated : Callable
+    """
+    func = click.option(
+        "-q",
+        "--quiet",
+        count=True,
+        help="Print less details. Use once to hide warnings. "
+        "Use -qq to completely silence output.",
+    )(func)
+    func = click.option(
+        "-v",
+        "--verbose",
+        count=True,
+        help="Print more details. Use once to show information messages. "
+        "Use -vv to print debug messages.",
+    )(func)
+    return func
+
+
 # Preserve click.command below to keep type checker happy
 # docstub: off
 @cli.command()
@@ -269,20 +311,7 @@ def cli():
     is_flag=True,
     help="Ignore pre-existing cache and don't create a new one.",
 )
-@click.option(
-    "-v",
-    "--verbose",
-    count=True,
-    help="Print more details. Use once to show information messages. "
-    "Use '-vv' to print debug messages.",
-)
-@click.option(
-    "-q",
-    "--quiet",
-    count=True,
-    help="Print less details. Use once to hide warnings. "
-    "Use '-qq' to completely silence output.",
-)
+@_add_verbosity_options
 @click.help_option("-h", "--help")
 @log_execution_time()
 def run(
@@ -426,7 +455,11 @@ def run(
     if syntax_error_count:
         logger.warning("Syntax errors: %i", syntax_error_count)
     if unknown_type_names:
-        logger.warning(_format_unknown_names(unknown_type_names))
+        logger.warning(
+            "Unknown type names: %i",
+            len(unknown_type_names),
+            extra={"details": _format_unknown_names(unknown_type_names)},
+        )
     if total_errors:
         logger.error("Total errors: %i", total_errors)
 
@@ -440,20 +473,7 @@ def run(
 # docstub: off
 @cli.command()
 # docstub: on
-@click.option(
-    "-v",
-    "--verbose",
-    count=True,
-    help="Print more details. Use once to show information messages. "
-    "Use '-vv' to print debug messages.",
-)
-@click.option(
-    "-q",
-    "--quiet",
-    count=True,
-    help="Print less details. Use once to hide warnings. "
-    "Use '-qq' to completely silence output.",
-)
+@_add_verbosity_options
 @click.help_option("-h", "--help")
 def clean(verbose, quiet):
     """Clean the cache.

src/docstub/_report.py

@@ -190,7 +190,7 @@ class ReportHandler(logging.StreamHandler):
     """
 
     level_to_color = {  # noqa: RUF012
-        logging.DEBUG: "white",
+        logging.DEBUG: "bright_black",
         logging.INFO: "cyan",
         logging.WARNING: "yellow",
         logging.ERROR: "red",
@@ -238,7 +238,7 @@ def format(self, record):
         if record.levelno >= logging.WARNING:
             msg = click.style(msg, bold=True)
         if record.levelno == logging.DEBUG:
-            msg = click.style(msg, fg="white")
+            msg = click.style(msg, fg=self.level_to_color[record.levelno])
 
         # Prefix with a colored log ID, fallback to first char of level name
         log_id = getattr(record, "log_id", record.levelname[0])
@@ -327,11 +327,11 @@ def emit_grouped(self):
 
 
 def setup_logging(*, verbosity, group_errors):
-    """
+    """Setup logging to stderr for docstub's main process.
 
     Parameters
     ----------
-    verbosity : int
+    verbosity : {-2, -1, 0, 1, 2, 3}
     group_errors : bool
 
     Returns
@@ -344,11 +344,21 @@ def setup_logging(*, verbosity, group_errors):
         0: logging.WARNING,
         1: logging.INFO,
         2: logging.DEBUG,
+        3: logging.DEBUG,
     }
 
     format_ = "%(message)s"
-    if verbosity >= 2:
-        format_ += " [loc=%(pathname)s:%(lineno)d, func=%(funcName)s, time=%(asctime)s]"
+    if verbosity >= 3:
+        debug_info = (
+            "logger = '%(name)s'",
+            "loc    = '%(pathname)s:%(lineno)d'",
+            "func   = '%(funcName)s'",
+            "proc   = '%(processName)s'",
+            "thread = '%(threadName)s'",
+            "time   = '%(asctime)s'",
+        )
+        debug_info = indent(",\n".join(debug_info), prefix="    ")
+        format_ = f"{format_}\n  [\n{debug_info}\n  ]"
 
     formatter = logging.Formatter(format_)
     handler = ReportHandler(group_errors=group_errors)