breaking: replace trace with logging

19 files changed, 214 insertions, 120 deletions

diff --git a/src/setuptools_scm/__init__.py b/src/setuptools_scm/__init__.py
index eccc68f..b29273c 100644
--- a/src/setuptools_scm/__init__.py
+++ b/src/setuptools_scm/__init__.py
@@ -28,6 +28,7 @@ if TYPE_CHECKING:
     from typing import NoReturn
     from . import _types as _t
 
+
 TEMPLATES = {
     ".py": """\
 # file generated by setuptools_scm
@@ -49,9 +50,9 @@ def dump_version(
     target = os.path.normpath(os.path.join(root, write_to))
     ext = os.path.splitext(target)[1]
     template = template or TEMPLATES.get(ext)
-    from ._trace import trace
+    from ._log import log
 
-    trace("dump", write_to, version)
+    log.debug("dump %s into %s", version, write_to)
     if template is None:
         raise ValueError(
             "bad file format: '{}' (of {}) \nonly *.txt and *.py are supported".format(
diff --git a/src/setuptools_scm/_config.py b/src/setuptools_scm/_config.py
index 34745ae..108c86e 100644
--- a/src/setuptools_scm/_config.py
+++ b/src/setuptools_scm/_config.py
@@ -9,17 +9,19 @@ from typing import Any
 from typing import Callable
 from typing import Pattern
 
+from . import _log
 from . import _types as _t
 from ._integration.pyproject_reading import (
     get_args_for_pyproject as _get_args_for_pyproject,
 )
 from ._integration.pyproject_reading import read_pyproject as _read_pyproject
 from ._overrides import read_toml_overrides
-from ._trace import trace
 from ._version_cls import _validate_version_cls
 from ._version_cls import _VersionT
 from ._version_cls import Version as _Version
 
+log = _log.log.getChild("config")
+
 DEFAULT_TAG_REGEX = re.compile(
     r"^(?:[\w-]+-)?(?P<version>[vV]?\d+(?:\.\d+){0,2}[^\+]*)(?:\+.*)?$"
 )
@@ -44,7 +46,7 @@ def _check_tag_regex(value: str | Pattern[str] | None) -> Pattern[str]:
 
 
 def _check_absolute_root(root: _t.PathT, relative_to: _t.PathT | None) -> str:
-    trace("abs root", repr(locals()))
+    log.debug("check absolute root=%s relative_to=%s", root, relative_to)
     if relative_to:
         if (
             os.path.isabs(root)
@@ -61,10 +63,10 @@ def _check_absolute_root(root: _t.PathT, relative_to: _t.PathT | None) -> str:
                 " its the directory %r\n"
                 "assuming the parent directory was passed" % (relative_to,)
             )
-            trace("dir", relative_to)
+            log.debug("dir %s", relative_to)
             root = os.path.join(relative_to, root)
         else:
-            trace("file", relative_to)
+            log.debug("file %s", relative_to)
             root = os.path.join(os.path.dirname(relative_to), root)
     return os.path.abspath(root)
 
diff --git a/src/setuptools_scm/_entrypoints.py b/src/setuptools_scm/_entrypoints.py
index 9b5b093..e353260 100644
--- a/src/setuptools_scm/_entrypoints.py
+++ b/src/setuptools_scm/_entrypoints.py
@@ -8,8 +8,8 @@ from typing import Iterator
 from typing import overload
 from typing import TYPE_CHECKING
 
+from . import _log
 from . import version
-from ._trace import trace
 
 if TYPE_CHECKING:
     from ._config import Configuration
@@ -22,6 +22,9 @@ else:
         pass
 
 
+log = _log.log.getChild("entrypoints")
+
+
 def _version_from_entrypoints(
     config: Configuration, fallback: bool = False
 ) -> version.ScmVersion | None:
@@ -34,11 +37,11 @@ def _version_from_entrypoints(
 
     from .discover import iter_matching_entrypoints
 
-    trace("version_from_ep", entrypoint, root)
+    log.debug("version_from_ep %s in %s", entrypoint, root)
     for ep in iter_matching_entrypoints(root, entrypoint, config):
         fn = ep.load()
         maybe_version: version.ScmVersion | None = fn(root, config=config)
-        trace(ep, version)
+        log.debug("%s found %r", ep, maybe_version)
         if maybe_version is not None:
             return maybe_version
     return None
@@ -80,10 +83,8 @@ def iter_entry_points(
 
 
 def _get_ep(group: str, name: str) -> Any | None:
-    from ._entrypoints import iter_entry_points
-
     for ep in iter_entry_points(group, name):
-        trace("ep found:", ep.name)
+        log.debug("ep found: %s", ep.name)
         return ep.load()
     else:
         return None
diff --git a/src/setuptools_scm/_file_finders/__init__.py b/src/setuptools_scm/_file_finders/__init__.py
index 5a7a1c0..5e3304a 100644
--- a/src/setuptools_scm/_file_finders/__init__.py
+++ b/src/setuptools_scm/_file_finders/__init__.py
@@ -6,9 +6,11 @@ from typing import Callable
 
 from typing_extensions import TypeGuard
 
-from setuptools_scm import _types as _t
-from setuptools_scm._entrypoints import iter_entry_points
-from setuptools_scm._trace import trace
+from .. import _log
+from .. import _types as _t
+from .._entrypoints import iter_entry_points
+
+log = _log.log.getChild("file_finder")
 
 
 def scm_find_files(
@@ -84,7 +86,7 @@ def is_toplevel_acceptable(toplevel: str | None) -> TypeGuard[str]:
     )
     ignored = [os.path.normcase(p) for p in ignored]
 
-    trace(toplevel, ignored)
+    log.debug("toplevel: %r\n    ignored %s", toplevel, ignored)
 
     return toplevel not in ignored
 
diff --git a/src/setuptools_scm/_file_finders/git.py b/src/setuptools_scm/_file_finders/git.py
index f007d5b..917ed1e 100644
--- a/src/setuptools_scm/_file_finders/git.py
+++ b/src/setuptools_scm/_file_finders/git.py
@@ -10,7 +10,6 @@ from . import is_toplevel_acceptable
 from . import scm_find_files
 from .. import _types as _t
 from .._run_cmd import run as _run
-from .._trace import trace
 from ..utils import data_from_mime
 
 log = logging.getLogger(__name__)
@@ -43,7 +42,7 @@ def _git_toplevel(path: str) -> str | None:
             # for this assertion to work. Length of string isn't changed by replace
             # ``\\`` is just and escape for `\`
             out = cwd[: -len(out)]
-        trace("find files toplevel", out)
+        log.debug("find files toplevel %s", out)
         return os.path.normcase(os.path.realpath(out.strip()))
     except subprocess.CalledProcessError:
         # git returned error, we are not in a git repo
@@ -94,7 +93,7 @@ def git_find_files(path: _t.PathT = "") -> list[str]:
         return []
     fullpath = os.path.abspath(os.path.normpath(path))
     if not fullpath.startswith(toplevel):
-        trace("toplevel mismatch", toplevel, fullpath)
+        log.warning("toplevel mismatch computed %s vs resolved %s ", toplevel, fullpath)
     git_files, git_dirs = _git_ls_files_and_dirs(toplevel)
     return scm_find_files(path, git_files, git_dirs)
 
@@ -112,5 +111,5 @@ def git_archive_find_files(path: _t.PathT = "") -> list[str]:
         # Substitutions have not been performed, so not a reliable archive
         return []
 
-    trace("git archive detected - fallback to listing all files")
+    log.warning("git archive detected - fallback to listing all files")
     return scm_find_files(path, set(), set(), force_all_files=True)
diff --git a/src/setuptools_scm/_file_finders/hg.py b/src/setuptools_scm/_file_finders/hg.py
index 8f777ea..e1aa1bd 100644
--- a/src/setuptools_scm/_file_finders/hg.py
+++ b/src/setuptools_scm/_file_finders/hg.py
@@ -1,5 +1,6 @@
 from __future__ import annotations
 
+import logging
 import os
 import subprocess
 
@@ -7,9 +8,10 @@ from .. import _types as _t
 from .._file_finders import is_toplevel_acceptable
 from .._file_finders import scm_find_files
 from .._run_cmd import run as _run
-from .._trace import trace
 from ..utils import data_from_mime
 
+log = logging.getLogger(__name__)
+
 
 def _hg_toplevel(path: str) -> str | None:
     try:
@@ -66,5 +68,5 @@ def hg_archive_find_files(path: _t.PathT = "") -> list[str]:
         # Ensure file is valid
         return []
 
-    trace("hg archive detected - fallback to listing all files")
+    log.warning("hg archive detected - fallback to listing all files")
     return scm_find_files(path, set(), set(), force_all_files=True)
diff --git a/src/setuptools_scm/_log.py b/src/setuptools_scm/_log.py
index e69de29..35c050d 100644
--- a/src/setuptools_scm/_log.py
+++ b/src/setuptools_scm/_log.py
@@ -0,0 +1,94 @@
+"""
+logging helpers, supports vendoring
+"""
+from __future__ import annotations
+
+import contextlib
+import logging
+import os
+import sys
+from typing import IO
+from typing import Iterator
+
+log = logging.getLogger(__name__.rsplit(".", 1)[0])
+log.propagate = False
+
+
+class AlwaysStdErrHandler(logging.StreamHandler):  # type: ignore[type-arg]
+    def __init___(self) -> None:
+        super().__init__(sys.stderr)
+
+    @property  # type: ignore [override]
+    def stream(self) -> IO[str]:
+        return sys.stderr
+
+    @stream.setter
+    def stream(self, value: IO[str]) -> None:
+        assert value is sys.stderr
+
+
+def make_default_handler() -> logging.Handler:
+    try:
+        from rich.console import Console
+
+        console = Console(stderr=True)
+        from rich.logging import RichHandler
+
+        return RichHandler(console=console)
+    except ImportError:
+        handler = AlwaysStdErrHandler()
+        handler.setFormatter(logging.Formatter("%(levelname)s %(name)s %(message)s"))
+        return handler
+
+
+_default_handler = make_default_handler()
+
+log.addHandler(_default_handler)
+
+
+def _default_log_level() -> str | int:
+    val: str = os.environ.get("SETUPTOOLS_SCM_DEBUG", "")
+    level: str | int
+    if val:
+        level = logging.DEBUG
+        levelname: str | int = logging.getLevelName(val)
+        if isinstance(levelname, int):
+            level = val
+        else:
+            level = logging.WARNING
+    else:
+        level = logging.WARNING
+    return level
+
+
+log.setLevel(_default_log_level())
+
+
+@contextlib.contextmanager
+def defer_to_pytest() -> Iterator[None]:
+    log.propagate = True
+    old_level = log.level
+    log.setLevel(logging.NOTSET)
+    log.removeHandler(_default_handler)
+    try:
+        yield
+    finally:
+        log.addHandler(_default_handler)
+        log.propagate = False
+        log.setLevel(old_level)
+
+
+@contextlib.contextmanager
+def enable_debug(handler: logging.Handler = _default_handler) -> Iterator[None]:
+    log.addHandler(handler)
+    old_level = log.level
+    log.setLevel(logging.DEBUG)
+    old_handler_level = handler.level
+    handler.setLevel(logging.DEBUG)
+    try:
+        yield
+    finally:
+        log.setLevel(old_level)
+        handler.setLevel(old_handler_level)
+        if handler is not _default_handler:
+            log.removeHandler(handler)
diff --git a/src/setuptools_scm/_overrides.py b/src/setuptools_scm/_overrides.py
index f08f170..6279377 100644
--- a/src/setuptools_scm/_overrides.py
+++ b/src/setuptools_scm/_overrides.py
@@ -4,9 +4,11 @@ import os
 from typing import Any
 
 from . import _config
+from . import _log
 from . import version
 from ._integration.pyproject_reading import lazy_toml_load
-from ._trace import trace
+
+log = _log.log.getChild("overrides")
 
 PRETEND_KEY = "SETUPTOOLS_SCM_PRETEND_VERSION"
 PRETEND_KEY_NAMED = PRETEND_KEY + "_FOR_{name}"
@@ -30,7 +32,7 @@ def _read_pretended_version_for(
     tries ``SETUPTOOLS_SCM_PRETEND_VERSION``
     and ``SETUPTOOLS_SCM_PRETEND_VERSION_FOR_$UPPERCASE_DIST_NAME``
     """
-    trace("dist name:", config.dist_name)
+    log.debug("dist name: %s", config.dist_name)
 
     pretended = read_named_env(name="PRETEND_VERSION", dist_name=config.dist_name)
 
diff --git a/src/setuptools_scm/_run_cmd.py b/src/setuptools_scm/_run_cmd.py
index b528504..39898b0 100644
--- a/src/setuptools_scm/_run_cmd.py
+++ b/src/setuptools_scm/_run_cmd.py
@@ -3,11 +3,14 @@ from __future__ import annotations
 import os
 import shlex
 import subprocess
+import textwrap
 from typing import Mapping
 
-from . import _trace
+from . import _log
 from . import _types as _t
 
+log = _log.log.getChild("run_cmd")
+
 
 def no_git_env(env: Mapping[str, str]) -> dict[str, str]:
     # adapted from pre-commit
@@ -21,7 +24,7 @@ def no_git_env(env: Mapping[str, str]) -> dict[str, str]:
     # GIT_INDEX_FILE: Causes 'error invalid object ...' during commit
     for k, v in env.items():
         if k.startswith("GIT_"):
-            _trace.trace(k, v)
+            log.debug("%s: %s", k, v)
     return {
         k: v
         for k, v in env.items()
@@ -71,12 +74,12 @@ def run(
         cmd = shlex.split(cmd)
     else:
         cmd = [os.fspath(x) for x in cmd]
-    if trace:
-        _trace.trace_command(cmd, cwd)
+    cmd_4_trace = " ".join(map(_unsafe_quote_for_display, cmd))
+    log.debug("at %s\n    $ %s ", cwd, cmd_4_trace)
     res = subprocess.run(
         cmd,
         capture_output=True,
-        cwd=str(cwd),
+        cwd=os.fspath(cwd),
         env=dict(
             avoid_pip_isolation(no_git_env(os.environ)),
             # os.environ,
@@ -94,11 +97,17 @@ def run(
             res.stderr = ensure_stripped_str(res.stderr)
     if trace:
         if res.stdout:
-            _trace.trace("out:\n", res.stdout, indent=True)
+            log.debug("out:\n%s", textwrap.indent(res.stdout, "    "))
         if res.stderr:
-            _trace.trace("err:\n", res.stderr, indent=True)
+            log.debug("err:\n%s", textwrap.indent(res.stderr, "    "))
         if res.returncode:
-            _trace.trace("ret:", res.returncode)
+            log.debug("ret: %s", res.returncode)
     if check:
         res.check_returncode()
     return res
+
+
+def _unsafe_quote_for_display(item: _t.PathT) -> str:
+    # give better results than shlex.join in our cases
+    text = os.fspath(item)
+    return text if all(c not in text for c in " {[:") else f'"{text}"'
diff --git a/src/setuptools_scm/_trace.py b/src/setuptools_scm/_trace.py
deleted file mode 100644
index cf5fcfa..0000000
--- a/src/setuptools_scm/_trace.py
+++ /dev/null
@@ -1,30 +0,0 @@
-from __future__ import annotations
-
-import os
-import sys
-import textwrap
-from typing import Sequence
-
-from . import _types as _t
-
-DEBUG: bool = bool(os.environ.get("SETUPTOOLS_SCM_DEBUG"))
-
-
-def trace(*k: object, indent: bool = False) -> None:
-    if not DEBUG:
-        if indent and len(k) > 1:
-            k = (k[0],) + tuple(textwrap.indent(str(s), "    ") for s in k[1:])
-        print(*k, file=sys.stderr, flush=True)
-
-
-def _unsafe_quote_for_display(item: _t.PathT) -> str:
-    # give better results than shlex.join in our cases
-    text = os.fspath(item)
-    return text if all(c not in text for c in " {[:") else f'"{text}"'
-
-
-def trace_command(cmd: Sequence[_t.PathT], cwd: _t.PathT) -> None:
-    if not DEBUG:
-        return
-    cmd_4_trace = " ".join(map(_unsafe_quote_for_display, cmd))
-    trace(f"---\n > {cwd}\\$ ", cmd_4_trace, indent=True)
diff --git a/src/setuptools_scm/_version_cls.py b/src/setuptools_scm/_version_cls.py
index f6e87a8..e62c9fa 100644
--- a/src/setuptools_scm/_version_cls.py
+++ b/src/setuptools_scm/_version_cls.py
@@ -38,8 +38,9 @@ def _version_as_tuple(version_str: str) -> tuple[int | str, ...]:
     try:
         parsed_version = Version(version_str)
     except InvalidVersion:
-        log = getLogger("setuptools_scm")
-        log.exception("failed to parse version %s", version_str)
+        log = getLogger(__name__).parent
+        assert log is not None
+        log.error("failed to parse version %s", version_str)
         return (version_str,)
     else:
         version_fields: tuple[int | str, ...] = parsed_version.release
diff --git a/src/setuptools_scm/discover.py b/src/setuptools_scm/discover.py
index 2bd01e9..47e08e7 100644
--- a/src/setuptools_scm/discover.py
+++ b/src/setuptools_scm/discover.py
@@ -4,9 +4,11 @@ import os
 from typing import Iterable
 from typing import Iterator
 
+from . import _log
 from . import _types as _t
 from ._config import Configuration
-from ._trace import trace
+
+log = _log.log.getChild("discover")
 
 
 def walk_potential_roots(
@@ -40,7 +42,7 @@ def match_entrypoint(root: _t.PathT, name: str) -> bool:
     if os.path.exists(os.path.join(root, name)):
         if not os.path.isabs(name):
             return True
-        trace("ignoring bad ep", name)
+        log.debug("ignoring bad ep %s", name)
 
     return False
 
@@ -56,12 +58,12 @@ def iter_matching_entrypoints(
         read ``search_parent_directories``, write found parent to ``parent``.
     """
 
-    trace("looking for ep", entrypoint, root)
+    log.debug("looking for ep %s in %s", entrypoint, root)
     from ._entrypoints import iter_entry_points
 
     for wd in walk_potential_roots(root, config.search_parent_directories):
         for ep in iter_entry_points(entrypoint):
             if match_entrypoint(wd, ep.name):
-                trace("found ep", ep, "in", wd)
+                log.debug("found ep %s in %s", ep, wd)
                 config.parent = wd
                 yield ep
diff --git a/src/setuptools_scm/fallbacks.py b/src/setuptools_scm/fallbacks.py
index 89d3418..818c09d 100644
--- a/src/setuptools_scm/fallbacks.py
+++ b/src/setuptools_scm/fallbacks.py
@@ -1,5 +1,6 @@
 from __future__ import annotations
 
+import logging
 import os
 from pathlib import Path
 from typing import TYPE_CHECKING
@@ -8,17 +9,18 @@ if TYPE_CHECKING:
     from . import _types as _t
 from . import Configuration
 from .utils import data_from_mime
-from ._trace import trace
 from .version import meta
 from .version import ScmVersion
 from .version import tag_to_version
 
+log = logging.getLogger(__name__)
+
 _UNKNOWN = "UNKNOWN"
 
 
 def parse_pkginfo(root: _t.PathT, config: Configuration) -> ScmVersion | None:
     pkginfo = Path(root) / "PKG-INFO"
-    trace("pkginfo", pkginfo)
+    log.debug("pkginfo %s", pkginfo)
     data = data_from_mime(pkginfo)
     version = data.get("Version", _UNKNOWN)
     if version != _UNKNOWN:
@@ -37,6 +39,6 @@ def fallback_version(root: _t.PathT, config: Configuration) -> ScmVersion | None
             if version is not None:
                 return meta(str(version), preformatted=True, config=config)
     if config.fallback_version is not None:
-        trace("FALLBACK")
+        log.debug("FALLBACK %s", config.fallback_version)
         return meta(config.fallback_version, preformatted=True, config=config)
     return None
diff --git a/src/setuptools_scm/git.py b/src/setuptools_scm/git.py
index 484bd4d..aa82538 100644
--- a/src/setuptools_scm/git.py
+++ b/src/setuptools_scm/git.py
@@ -1,5 +1,6 @@
 from __future__ import annotations
 
+import logging
 import os
 import re
 import warnings
@@ -13,7 +14,6 @@ from typing import TYPE_CHECKING
 
 from . import _types as _t
 from . import Configuration
-from ._trace import trace
 from .scm_workdir import Workdir
 from .utils import _CmdResult
 from .utils import data_from_mime
@@ -25,7 +25,7 @@ from .version import tag_to_version
 
 if TYPE_CHECKING:
     from . import hg_git
-
+log = logging.getLogger(__name__)
 
 REF_TAG_RE = re.compile(r"(?<=\btag: )([^,]+)\b")
 DESCRIBE_UNSUPPORTED = "%(describe"
@@ -68,7 +68,7 @@ class GitWorkdir(Workdir):
             # for this assertion to work.  Length of string isn't changed by replace
             # ``\\`` is just and escape for `\`
             real_wd = wd[: -len(real_wd)]
-        trace("real root", real_wd)
+        log.debug("real root %s", real_wd)
         if not samefile(real_wd, wd):
             return None
 
@@ -84,10 +84,10 @@ class GitWorkdir(Workdir):
     def get_branch(self) -> str | None:
         branch, err, ret = self.do_ex_git(["rev-parse", "--abbrev-ref", "HEAD"])
         if ret:
-            trace("branch err", branch, err, ret)
+            log.info("branch= err %s %s %s", branch, err, ret)
             branch, err, ret = self.do_ex_git(["symbolic-ref", "--short", "HEAD"])
             if ret:
-                trace("branch err (symbolic-ref)", branch, err, ret)
+                log.warning("branch err (symbolic-ref): %s %s %s", branch, err, ret)
                 return None
         return branch
 
@@ -96,12 +96,12 @@ class GitWorkdir(Workdir):
             ["-c", "log.showSignature=false", "log", "-n", "1", "HEAD", "--format=%cI"]
         )
         if ret:
-            trace("timestamp err", timestamp, err, ret)
+            log.warning("timestamp err %s %s %s", timestamp, err, ret)
             return None
         # TODO, when dropping python3.6 use fromiso
         date_part = timestamp.split("T")[0]
         if "%c" in date_part:
-            trace("git too old -> timestamp is ", timestamp)
+            log.warning("git too old -> timestamp is %s", timestamp)
             return None
         return datetime.strptime(date_part, r"%Y-%m-%d").date()
 
@@ -285,7 +285,7 @@ def archival_to_version(
     data: dict[str, str], config: Configuration
 ) -> ScmVersion | None:
     node: str | None
-    trace("data", data)
+    log.debug("data %s", data)
     archival_describe = data.get("describe-name", DESCRIBE_UNSUPPORTED)
     if DESCRIBE_UNSUPPORTED in archival_describe:
         warnings.warn("git archive did not support describe output")
diff --git a/src/setuptools_scm/hg.py b/src/setuptools_scm/hg.py
index e7295bc..d1f6102 100644
--- a/src/setuptools_scm/hg.py
+++ b/src/setuptools_scm/hg.py
@@ -1,12 +1,12 @@
 from __future__ import annotations
 
 import datetime
+import logging
 import os
 from pathlib import Path
 from typing import TYPE_CHECKING
 
 from . import Configuration
-from ._trace import trace
 from ._version_cls import Version
 from .scm_workdir import Workdir
 from .utils import data_from_mime
@@ -20,6 +20,8 @@ if TYPE_CHECKING:
 
 from ._run_cmd import run as _run
 
+log = logging.getLogger(__name__)
+
 
 class HgWorkdir(Workdir):
     COMMAND = "hg"
@@ -52,7 +54,7 @@ class HgWorkdir(Workdir):
         node_date = datetime.date.fromisoformat(dirty_date if dirty else node_date_str)
 
         if node.count("0") == len(node):
-            trace("initial node", self.path)
+            log.debug("initial node %s", self.path)
             return meta(
                 "0.0", config=config, dirty=dirty, branch=branch, node_date=node_date
             )
@@ -97,7 +99,7 @@ class HgWorkdir(Workdir):
                 return meta(tag, config=config, node_date=node_date)
 
         except ValueError as e:
-            trace("error", e)
+            log.exception("error %s", e)
             pass  # unpacking failed, old hg
 
         return None
@@ -162,7 +164,7 @@ def parse(root: _t.PathT, config: Configuration) -> ScmVersion | None:
 
 
 def archival_to_version(data: dict[str, str], config: Configuration) -> ScmVersion:
-    trace("data", data)
+    log.debug("data %s", data)
     node = data.get("node", "")[:12]
     if node:
         node = "h" + node
diff --git a/src/setuptools_scm/hg_git.py b/src/setuptools_scm/hg_git.py
index f7ea883..461215b 100644
--- a/src/setuptools_scm/hg_git.py
+++ b/src/setuptools_scm/hg_git.py
@@ -1,18 +1,20 @@
 from __future__ import annotations
 
+import logging
 import os
 from contextlib import suppress
 from datetime import date
 from datetime import datetime
 
 from . import _types as _t
-from ._trace import trace
 from .git import GitWorkdir
 from .hg import HgWorkdir
 from .utils import _CmdResult
 from .utils import do_ex
 from .utils import require_command
 
+log = logging.getLogger(__name__)
+
 _FAKE_GIT_DESCRIBE_ERROR = _CmdResult("<>hg git failed", "", 1)
 
 
@@ -34,14 +36,14 @@ class GitWorkdirHgClient(GitWorkdir, HgWorkdir):
     def get_branch(self) -> str | None:
         res = self.do_ex('hg id -T "{bookmarks}"')
         if res.returncode:
-            trace("branch err", res)
+            log.info("branch err %s", res)
             return None
         return res.out
 
     def get_head_date(self) -> date | None:
         date_part, err, ret = self.do_ex('hg log -r . -T "{shortdate(date)}"')
         if ret:
-            trace("head date err", date_part, err, ret)
+            log.info("head date err %s %s %s", date_part, err, ret)
             return None
         return datetime.strptime(date_part, r"%Y-%m-%d").date()
 
@@ -80,7 +82,7 @@ class GitWorkdirHgClient(GitWorkdir, HgWorkdir):
             git_node = self._hg2git(hg_node)
 
             if git_node is None:
-                trace("Cannot get git node so we use hg node", hg_node)
+                log.debug("Cannot get git node so we use hg node %s", hg_node)
 
                 if hg_node == "0" * len(hg_node):
                     # mimic Git behavior
@@ -127,7 +129,7 @@ class GitWorkdirHgClient(GitWorkdir, HgWorkdir):
                 tag = hg_tag
                 break
         else:
-            trace("tag not found", hg_tags, git_tags)
+            logging.warning("tag not found hg=%s git=%s", hg_tags, git_tags)
             return _FAKE_GIT_DESCRIBE_ERROR
 
         out, _, ret = self.do_ex(["hg", "log", "-r", f"'{tag}'::.", "-T", "."])
@@ -141,5 +143,5 @@ class GitWorkdirHgClient(GitWorkdir, HgWorkdir):
 
         if self.is_dirty():
             desc += "-dirty"
-        trace("desc", desc)
+        log.debug("faked describe %r", desc)
         return _CmdResult(desc, "", 0)
diff --git a/src/setuptools_scm/integration.py b/src/setuptools_scm/integration.py
index 1d600e2..4c7cb25 100644
--- a/src/setuptools_scm/integration.py
+++ b/src/setuptools_scm/integration.py
@@ -1,5 +1,6 @@
 from __future__ import annotations
 
+import logging
 import os
 import warnings
 from typing import Any
@@ -14,9 +15,9 @@ from . import Configuration
 from ._integration.setuptools import (
     read_dist_name_from_setup_cfg as _read_dist_name_from_setup_cfg,
 )
-from ._trace import trace
 from ._version_cls import _validate_version_cls
 
+log = logging.getLogger(__name__)
 if TYPE_CHECKING:
     pass
 
@@ -82,11 +83,11 @@ def version_keyword(
     if dist.metadata.version is not None:
         warnings.warn(f"version of {dist_name} already set")
         return
-    trace(
-        "version keyword",
+    log.debug(
+        "version keyword %r",
         vars(dist.metadata),
     )
-    trace("dist", id(dist), id(dist.metadata))
+    log.debug("dist %s %s", id(dist), id(dist.metadata))
 
     if dist_name is None:
         dist_name = _read_dist_name_from_setup_cfg()
@@ -98,11 +99,11 @@ def version_keyword(
 
 
 def infer_version(dist: setuptools.Distribution) -> None:
-    trace(
-        "finalize hook",
+    log.debug(
+        "finalize hook %r",
         vars(dist.metadata),
     )
-    trace("dist", id(dist), id(dist.metadata))
+    log.debug("dist %s %s", id(dist), id(dist.metadata))
     if dist.metadata.version is not None:
         return  # metadata already added by hook
     dist_name = dist.metadata.name
@@ -115,6 +116,6 @@ def infer_version(dist: setuptools.Distribution) -> None:
     try:
         config = Configuration.from_file(dist_name=dist_name)
     except LookupError as e:
-        trace(e)
+        log.exception(e)
     else:
         _assign_version(dist, config)
diff --git a/src/setuptools_scm/utils.py b/src/setuptools_scm/utils.py
index f74740b..6233a3a 100644
--- a/src/setuptools_scm/utils.py
+++ b/src/setuptools_scm/utils.py
@@ -5,8 +5,9 @@ from __future__ import annotations
 
 import logging
 import subprocess
-import sys
+import textwrap
 import warnings
+from pathlib import Path
 from types import CodeType
 from types import FunctionType
 from typing import NamedTuple
@@ -14,7 +15,6 @@ from typing import Sequence
 from typing import TYPE_CHECKING
 
 from . import _run_cmd
-from . import _trace
 
 if TYPE_CHECKING:
     from . import _types as _t
@@ -35,18 +35,18 @@ def do_ex(cmd: _t.CMD_TYPE, cwd: _t.PathT = ".") -> _CmdResult:
 
 def do(cmd: _t.CMD_TYPE, cwd: _t.PathT = ".") -> str:
     out, err, ret = do_ex(cmd, cwd)
-    if ret and not _trace.DEBUG:
+    if ret and log.getEffectiveLevel() > logging.DEBUG:
         print(err)
     return out
 
 
 def data_from_mime(path: _t.PathT) -> dict[str, str]:
-    with open(path, encoding="utf-8") as fp:
-        content = fp.read()
-    _trace.trace("content", repr(content))
+    content = Path(path).read_text(encoding="utf-8")
+    log.debug("mime %s content:\n%s", path, textwrap.indent(content, "    "))
     # the complex conditions come from reading pseudo-mime-messages
     data = dict(x.split(": ", 1) for x in content.splitlines() if ": " in x)
-    _trace.trace("data", data)
+
+    log.debug("mime %s data:\n%s", path, data)
     return data
 
 
@@ -59,12 +59,11 @@ def function_has_arg(fn: object | FunctionType, argname: str) -> bool:
 def has_command(name: str, args: Sequence[str] = ["help"], warn: bool = True) -> bool:
     try:
         p = _run_cmd.run([name, *args], cwd=".", timeout=5)
-    except OSError:
-        _trace.trace(*sys.exc_info())
+    except OSError as e:
+        log.exception("command %s missing: %s", name, e)
         res = False
     except subprocess.TimeoutExpired as e:
-        log.info(e)
-        _trace.trace(e)
+        log.warning("command %s timed out %s", name, e)
         res = False
 
     else:
diff --git a/src/setuptools_scm/version.py b/src/setuptools_scm/version.py
index 36bc7df..f077280 100644
--- a/src/setuptools_scm/version.py
+++ b/src/setuptools_scm/version.py
@@ -1,6 +1,7 @@
 from __future__ import annotations
 
 import dataclasses
+import logging
 import os
 import re
 import warnings
@@ -28,7 +29,9 @@ if TYPE_CHECKING:
 from ._version_cls import Version as PkgVersion, _VersionT
 from . import _version_cls as _v
 from . import _config
-from ._trace import trace
+
+log = logging.getLogger(__name__)
+
 
 SEMVER_MINOR = 2
 SEMVER_PATCH = 3
@@ -55,19 +58,19 @@ def _parse_version_tag(
             "suffix": match.group(0)[match.end(key) :],
         }
 
-    trace(f"tag '{tag}' parsed to {result}")
+    log.debug(f"tag '{tag}' parsed to {result}")
     return result
 
 
 def callable_or_entrypoint(group: str, callable_or_name: str | Any) -> Any:
-    trace("ep", (group, callable_or_name))
+    log.debug("ep %r %r", group, callable_or_name)
 
     if callable(callable_or_name):
         return callable_or_name
     from ._entrypoints import iter_entry_points
 
     for ep in iter_entry_points(group, callable_or_name):
-        trace("ep found:", ep.name)
+        log.debug("ep found: %s", ep.name)
         return ep.load()
 
 
@@ -77,7 +80,7 @@ def tag_to_version(
     """
     take a tag that might be prefixed with a keyword and return only the version part
     """
-    trace("tag", tag)
+    log.debug("tag %s", tag)
 
     tagdict = _parse_version_tag(tag, config)
     if not isinstance(tagdict, dict) or not tagdict.get("version", None):
@@ -85,7 +88,7 @@ def tag_to_version(
         return None
 
     version_str = tagdict["version"]
-    trace("version pre parse", version_str)
+    log.debug("version pre parse %s", version_str)
 
     if tagdict.get("suffix", ""):
         warnings.warn(
@@ -95,7 +98,7 @@ def tag_to_version(
         )
 
     version: _VersionT = config.version_cls(version_str)
-    trace("version", repr(version))
+    log.debug("version=%r", version)
 
     return version
 
@@ -187,7 +190,7 @@ def meta(
     node_date: date | None = None,
 ) -> ScmVersion:
     parsed_version = _parse_tag(tag, preformatted, config)
-    trace("version", tag, "->", parsed_version)
+    log.info("version %s -> %s", tag, parsed_version)
     assert parsed_version is not None, "Can't parse version %s" % tag
     return ScmVersion(
         parsed_version,
@@ -389,18 +392,18 @@ def postrelease_version(version: ScmVersion) -> str:
 
 
 def format_version(version: ScmVersion, **config: Any) -> str:
-    trace("scm version", version)
-    trace("config", config)
+    log.debug("scm version %s", version)
+    log.debug("config %s", config)
     if version.preformatted:
         assert isinstance(version.tag, str)
         return version.tag
     main_version = _entrypoints._call_version_scheme(
         version, "setuptools_scm.version_scheme", config["version_scheme"], None
     )
-    trace("version", main_version)
+    log.debug("version %s", main_version)
     assert main_version is not None
     local_version = _entrypoints._call_version_scheme(
         version, "setuptools_scm.local_scheme", config["local_scheme"], "+unknown"
     )
-    trace("local_version", local_version)
+    log.debug("local_version %s", local_version)
     return main_version + local_version