Initial version

README.md

@@ -1,5 +1,83 @@
 # vmodule
 
+This is a tiny project with no deps to add extra levels to stdlib logging, and
+also something you can run from your main that processes logger-specific
+verbosity.
+
+This is inspired by glog, which considers VLOG(1) to be a more restrictive
+version of LOG(INFO).  For simplicity we just map that onto numeric severities.
+
+Here's a combined demo of how you might use this library -- we don't depend on
+`click` but you certainly can:
+
+```py
+from logging import getLogger
+from typing import Optional
+
+import click
+
+from vmodule import VLOG_1, VLOG_2, vmodule_init
+
+LOG = getLogger(__name__)
+
+
+@click.command()
+@click.option("-v", type=int)
+@click.option("--vmodule")
+def main(v: Optional[int], vmodule: Optional[str]) -> None:
+    vmodule_init(v, vmodule)
+    LOG.warning("Warn")
+    LOG.info("Starting up")
+    LOG.log(VLOG_1, "Verbose %d", 1)
+    LOG.log(VLOG_2, "Verbose %d", 2)
+    LOG.debug("foo")
+
+
+if __name__ == "__main__":
+    main()
+```
+
+If you're writing a library, it's even easier:
+
+```py
+from logging import getLogger
+from vmodule import VLOG_1
+
+LOG = getLogger(__name__)
+
+def foo(...):
+    LOG.info("Starting up")
+    LOG.log(VLOG_1, "Verbose %d", 1)
+```
+
+
+# Command line parsing
+
+If you use the example above,
+
+```
+(unset)  -> WARNING
+-v 0     -> INFO
+-v 1     -> VLOG_1
+-v 2     -> VLOG_2
+-v 3     -> VLOG_3
+-v 10    -> DEBUG (by accident)
+```
+
+You can also specify those same numbers with `--vmodule` although there are two
+gotchas:
+
+1. You CLI's logger is quite possibly called `"__main__"`.
+2. This doesn't take wildcards or use hierarchy.  You need to specify actual
+   logger names.
+
+
+```
+--vmodule filelock=10,concurrent.futures=0
+
+sets filelock to DEBUG
+sets concurrent.futures to INFO
+```
 
 # Version Compat
 

setup.cfg

@@ -46,7 +46,7 @@ include = vmodule/*
 omit = vmodule/tests/*
 
 [coverage:report]
-fail_under = 70
+fail_under = 90
 precision = 1
 show_missing = True
 skip_covered = True

vmodule/__init__.py

@@ -2,3 +2,64 @@
     from .version import __version__
 except ImportError:
     __version__ = "dev"
+
+import logging
+from typing import IO, Optional
+
+LOG = logging.getLogger(__name__)
+
+# My coding religion doesn't allow for import-time side effects that could break
+# if imports are reordered.  These constants are _not_ injected into the
+# `logging` module because of that.
+
+VLOG_1 = logging.INFO - 1
+VLOG_2 = logging.INFO - 2
+VLOG_3 = logging.INFO - 3
+
+# However, logging itself needs to know about them in order to reasonably format
+# log messages.  This is idempotent, and shouldn't step too badly on other
+# people's custom log levels.
+
+logging.addLevelName(VLOG_1, "VLOG_1")
+logging.addLevelName(VLOG_2, "VLOG_2")
+logging.addLevelName(VLOG_3, "VLOG_3")
+
+DEFAULT_FORMAT = "%(asctime)-15s %(levelname)-8s %(name)s:%(lineno)s %(message)s"
+# TODO glog format too, or another compact format that includes thread id
+
+
+def vmodule_init(
+    v: Optional[int],
+    vmodule: Optional[str],
+    format: Optional[str] = None,
+    stream: Optional[IO[str]] = None,
+) -> None:
+    if v is None:
+        level = logging.WARNING
+    elif v == 0:
+        level = logging.INFO
+    else:
+        level = logging.INFO - v
+
+    logging.basicConfig(level=level, format=format or DEFAULT_FORMAT, stream=stream)
+
+    if vmodule:
+        LOG.log(VLOG_1, "Parse vmodule: %r", vmodule)
+        for item in vmodule.split(","):
+            LOG.log(VLOG_2, "Item: %r", item)
+            k, _, v = item.partition("=")
+
+            # N.b. getLogger takes no args other than the dotted name, and
+            # logging.PlaceHolder is both not public and doesn't keep track of
+            # the desired level.  This must work regardless of whether the
+            # normal use has actually called getLogger yet, which is a big
+            # reason why we don't have a custom Logger class.
+            logging.getLogger(k).setLevel(logging.INFO - int(v))
+
+
+__all__ = [
+    "vmodule_init",
+    "VLOG_1",
+    "VLOG_2",
+    "VLOG_3",
+]

vmodule/tests/__init__.py

@@ -1,5 +1,5 @@
-# from .foo import FooTest
+from .core import CoreTest
 
 __all__ = [
-    # "FooTest",
+    "CoreTest",
 ]

vmodule/tests/core.py

@@ -0,0 +1,127 @@
+import io
+import logging
+import re
+import unittest
+
+import vmodule
+
+LOG_LINE_TIMESTAMP_RE = re.compile(r"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} ", re.M)
+LOG_LINE_NUMERIC_LINE_RE = re.compile(r"^([A-Z0-9_]+\s+[a-z_.]+:)\d+(?= )", re.M)
+
+
+def log_some_messages():
+    logging.getLogger("a.b.c").warning("Warn")
+    logging.getLogger("a.b.c").info("Info")
+    logging.getLogger("a.b.c").debug("Debug")
+    logging.getLogger("x.y.z").log(vmodule.VLOG_1, "Vlog %d", 1)
+    logging.getLogger("x.y.z").log(vmodule.VLOG_2, "Vlog %d", 2)
+
+
+class CoreTest(unittest.TestCase):
+    def test_defaults(self):
+        # let basicConfig do its work
+        del logging.root.handlers[:]
+        # clear out anything that might have leaked in from another test
+        logging.Logger.manager.loggerDict = {}
+
+        stream = io.StringIO()
+        vmodule.vmodule_init(None, "", stream=stream)
+
+        log_some_messages()
+
+        output = LOG_LINE_TIMESTAMP_RE.sub("", stream.getvalue())
+        output = LOG_LINE_NUMERIC_LINE_RE.sub(lambda m: (m.group(1) + "<n>"), output)
+        self.assertEqual(
+            """\
+WARNING  a.b.c:<n> Warn
+""",
+            output,
+        )
+
+    def test_root_verbosity_zero_is_info(self):
+        # let basicConfig do its work
+        del logging.root.handlers[:]
+        # clear out anything that might have leaked in from another test
+        logging.Logger.manager.loggerDict = {}
+
+        stream = io.StringIO()
+        vmodule.vmodule_init(0, "", stream=stream)
+
+        log_some_messages()
+
+        output = LOG_LINE_TIMESTAMP_RE.sub("", stream.getvalue())
+        output = LOG_LINE_NUMERIC_LINE_RE.sub(lambda m: (m.group(1) + "<n>"), output)
+        self.assertEqual(
+            """\
+WARNING  a.b.c:<n> Warn
+INFO     a.b.c:<n> Info
+""",
+            output,
+        )
+
+    def test_root_verbosity(self):
+        # let basicConfig do its work
+        del logging.root.handlers[:]
+        # clear out anything that might have leaked in from another test
+        logging.Logger.manager.loggerDict = {}
+
+        stream = io.StringIO()
+        vmodule.vmodule_init(1, "", stream=stream)
+
+        log_some_messages()
+
+        output = LOG_LINE_TIMESTAMP_RE.sub("", stream.getvalue())
+        output = LOG_LINE_NUMERIC_LINE_RE.sub(lambda m: (m.group(1) + "<n>"), output)
+        self.assertEqual(
+            """\
+WARNING  a.b.c:<n> Warn
+INFO     a.b.c:<n> Info
+VLOG_1   x.y.z:<n> Vlog 1
+""",
+            output,
+        )
+
+    def test_vmodule_verbosity(self):
+        # let basicConfig do its work
+        del logging.root.handlers[:]
+        # clear out anything that might have leaked in from another test
+        logging.Logger.manager.loggerDict = {}
+
+        stream = io.StringIO()
+        vmodule.vmodule_init(None, "x.y.z=1", stream=stream)
+
+        log_some_messages()
+
+        output = LOG_LINE_TIMESTAMP_RE.sub("", stream.getvalue())
+        output = LOG_LINE_NUMERIC_LINE_RE.sub(lambda m: (m.group(1) + "<n>"), output)
+        self.assertEqual(
+            """\
+WARNING  a.b.c:<n> Warn
+VLOG_1   x.y.z:<n> Vlog 1
+""",
+            output,
+        )
+
+    def test_debug_is_ten(self):
+        # let basicConfig do its work
+        del logging.root.handlers[:]
+        # clear out anything that might have leaked in from another test
+        logging.Logger.manager.loggerDict = {}
+
+        stream = io.StringIO()
+        vmodule.vmodule_init(10, "", stream=stream)
+
+        log_some_messages()
+
+        output = LOG_LINE_TIMESTAMP_RE.sub("", stream.getvalue())
+        output = LOG_LINE_NUMERIC_LINE_RE.sub(lambda m: (m.group(1) + "<n>"), output)
+        self.assertEqual(
+            """\
+WARNING  a.b.c:<n> Warn
+INFO     a.b.c:<n> Info
+DEBUG    a.b.c:<n> Debug
+VLOG_1   x.y.z:<n> Vlog 1
+VLOG_2   x.y.z:<n> Vlog 2
+""",
+            output,
+        )