Boardwalk CLI: Use python logger; have debug logs (#53)

* start using a logger in place of click.echo

* update format

* use custom clickexception

* update contrib doc

* use individual loggers

* add CLI debug mode

* bump version

* move log config for server

Author: m4wh6k

CONTRIBUTING.md

@@ -53,3 +53,12 @@ enforcement of test coverage.
 
 The boardwalk pip module uses semantic versioning. Please make sure to update
 the VERSION file along with any changes to the package.
+
+### Logging
+Most output should use a logger, with a few exceptions:
+- Raw output streamed from Ansible. Playbook runs should look familiar to
+  Ansible users. Ansible output that has been processed by Boardwalk should be
+  emitted by a logger.
+- Cases where the output of a command is intended to be consumed in a specific
+  format, and the formatting features of a logger aren't useful. Examples
+  include `boardwalk version` and `boardwalk workspace dump`.

VERSION

@@ -1 +1 @@
-0.8.10
+0.8.11

src/boardwalk/ansible.py

@@ -4,16 +4,16 @@
 from __future__ import annotations
 
 import json
+import logging
 import sys
 from functools import partial
 from pathlib import Path
 from typing import TYPE_CHECKING
 
 import ansible_runner
-import click
-from click import ClickException
 
 import boardwalk
+from boardwalk.app_exceptions import BoardwalkException
 
 if TYPE_CHECKING:
     from typing import Any, Optional, TypedDict
@@ -61,6 +61,9 @@ class RunnerPlaybook(TypedDict, total=False):
         vars: dict[str, str | bool]
 
 
+logger = logging.getLogger(__name__)
+
+
 def ansible_runner_cancel_callback(ws: Workspace):
     """
     ansible_runner needs a callback to tell it to stop execution. It returns
@@ -99,11 +102,11 @@ def ansible_runner_errors_to_output(runner: Runner, include_msg: bool = True) ->
                 try:
                     msg.append(event["event_data"]["res"]["msg"])
                 except KeyError:
-                    click.echo("Warning: Event error did not contain msg")
+                    logger.warn("Event error did not contain msg")
                 try:
                     msg.append(event["stdout"])
                 except KeyError:
-                    click.echo("Warning: Event error did not contain stdout")
+                    logger.warn("Event error did not contain stdout")
             output.append(": ".join(msg))
     return "\n".join(output)
 
@@ -161,7 +164,7 @@ def ansible_runner_run_tasks(
     if limit:
         output_msg_prefix = f"{hosts}(limit: {limit}): ansible_runner invocation"
     output_msg = f"{output_msg_prefix}: {invocation_msg}"
-    click.echo(output_msg)
+    logger.info(output_msg)
     runner: Runner = ansible_runner.run(**runner_kwargs)  # type: ignore
     runner_errors = ansible_runner_errors_to_output(runner)
     fail_msg = f"Error:\n{output_msg}\n{runner_errors}"
@@ -181,7 +184,7 @@ def ansible_runner_run_tasks(
 
 def ansible_inventory() -> InventoryData:
     """Uses ansible-inventory to fetch the inventory and returns it as a dict"""
-    click.echo("Processing ansible-inventory")
+    logger.info("Processing ansible-inventory")
     """
     Note that for the moment we have --export set here. --export won't expand Jinja
     expressions and this is done for performance reasons. It's entirely possible
@@ -198,7 +201,7 @@ def ansible_inventory() -> InventoryData:
         suppress_env_files=True,
     )
     if rc != 0:
-        ClickException(f"Failed to render inventory. {err}")
+        BoardwalkException(f"Failed to render inventory. {err}")
 
     return json.loads(out)
 

src/boardwalk/app_exceptions.py

@@ -0,0 +1,20 @@
+"""
+Common application exception classes
+"""
+import logging
+import typing
+
+from click import ClickException
+
+logger = logging.getLogger(__name__)
+
+
+class BoardwalkException(ClickException):
+    """
+    click will handle subclasses of ClickException specially. We override the
+    show method to make log formatting consistent
+    """
+
+    def show(self, file: typing.IO[str] | None = None) -> None:
+
+        logger.error(self.format_message())

src/boardwalk/cli.py

@@ -3,12 +3,17 @@
 """
 from __future__ import annotations
 
+import logging
+import os
 import signal
+import sys
+from distutils.util import strtobool
 from importlib.metadata import version as lib_version
-from typing import TYPE_CHECKING
+from typing import Literal, TYPE_CHECKING
 
 import click
-from click import ClickException
+
+from boardwalk.app_exceptions import BoardwalkException
 
 from boardwalk.cli_catch import catch, release
 from boardwalk.cli_init import init
@@ -25,6 +30,8 @@
 if TYPE_CHECKING:
     from typing import Any
 
+logger = logging.getLogger(__name__)
+
 terminating = False
 
 
@@ -36,36 +43,68 @@ def handle_signal(sig: int, frame: Any):
     signals sent to child processes (ansible-playbook)
     """
     global terminating
-    click.echo(f"Received signal {sig}")
+    logger.warn(f"Received signal {sig}")
     if not terminating:
         terminating = True
         raise KeyboardInterrupt
     else:
-        click.echo("Boardwalk is already terminating")
+        logger.warn("Boardwalk is already terminating")
 
 
 @click.group()
+@click.option(
+    "--debug/--no-debug",
+    "-D/-nD",
+    help=(
+        "Whether or not output debug messages. Alternatively may be set with"
+        " the BOARDWALK_DEBUG=1 environment variable"
+    ),
+    default=False,
+    show_default=True,
+)
 @click.pass_context
-def cli(ctx: click.Context):
+def cli(ctx: click.Context, debug: bool | Literal[0, 1]):
     """
     Boardwalk is a linear remote execution workflow engine built on top of Ansible.
     See the README.md @ https://github.com/Backblaze/boardwalk for more info
 
     To see more info about any subcommand, do `boardwalk <subcommand> --help`
     """
-    # There's not much we can do without a Boardwalkfile.py. Print help and
-    # exit if it's missing
+    try:
+        debug = strtobool(os.environ["BOARDWALK_DEBUG"])
+    except KeyError:
+        pass
+    except ValueError:
+        raise BoardwalkException(
+            "BOARDWALK_DEBUG env variable has an invalid boolean value"
+        )
+
+    if debug:
+        loglevel = logging.DEBUG
+        logformat = "%(levelname)s:%(name)s:%(threadName)s:%(message)s"
+    else:
+        loglevel = logging.INFO
+        logformat = "%(levelname)s:%(name)s:%(message)s"
+
+    logging.basicConfig(
+        format=logformat,
+        handlers=[logging.StreamHandler(sys.stdout)],
+        level=loglevel,
+    )
+
     signal.signal(signal.SIGINT, handle_signal)
     signal.signal(signal.SIGHUP, handle_signal)
     signal.signal(signal.SIGTERM, handle_signal)
     try:
         get_ws()
     except ManifestNotFound:
-        # The version subcommand is the only one that doesn't need a Boardwalkfile.py
+        # There's not much we can do without a Boardwalkfile.py. Print help and
+        # exit if it's missing. The version subcommand is the only one that
+        # doesn't need a Boardwalkfile.py
         if ctx.invoked_subcommand == "version":
             return
         click.echo(cli.get_help(ctx))
-        raise ClickException("No Boardwalkfile.py found")
+        raise BoardwalkException("No Boardwalkfile.py found")
     except NoActiveWorkspace:
         return
     except WorkspaceNotFound:

src/boardwalk/cli_catch.py

@@ -1,11 +1,15 @@
 """
 catch and release CLI subcommands
 """
+import logging
+
 import click
-from click import ClickException
 
+from boardwalk.app_exceptions import BoardwalkException
 from boardwalk.manifest import get_ws, NoActiveWorkspace
 
+logger = logging.getLogger(__name__)
+
 
 @click.command(
     "catch",
@@ -16,8 +20,8 @@ def catch():
     try:
         ws = get_ws()
     except NoActiveWorkspace as e:
-        raise ClickException(e.message)
-    click.echo(f"Using workspace: {ws.name}")
+        raise BoardwalkException(e.message)
+    logger.info(f"Using workspace: {ws.name}")
     ws.catch()
 
 
@@ -30,6 +34,6 @@ def release():
     try:
         ws = get_ws()
     except NoActiveWorkspace as e:
-        raise ClickException(e.message)
-    click.echo(f"Using workspace: {ws.name}")
+        raise BoardwalkException(e.message)
+    logger.info(f"Using workspace: {ws.name}")
     ws.release()

src/boardwalk/cli_init.py

@@ -3,11 +3,12 @@
 """
 from __future__ import annotations
 
+import logging
+
 from pathlib import Path
 from typing import TYPE_CHECKING, TypedDict
 
 import click
-from click import ClickException
 
 from boardwalk.ansible import (
     ansible_runner_run_tasks,
@@ -16,6 +17,7 @@
     AnsibleRunnerGeneralError,
     AnsibleRunnerUnreachableHost,
 )
+from boardwalk.app_exceptions import BoardwalkException
 from boardwalk.host import Host
 from boardwalk.manifest import get_ws, NoActiveWorkspace, Workspace
 
@@ -34,6 +36,9 @@ class runnerKwargs(TypedDict, total=False):
         timeout: int
 
 
+logger = logging.getLogger(__name__)
+
+
 @click.command(short_help="Inits local workspace state by getting host facts")
 @click.option(
     "--limit",
@@ -58,13 +63,13 @@ def init(ctx: click.Context, limit: str, retry: bool):
     """
     if retry and limit not in ["all", ""]:
         # We don't allow limit and retry to be specified together at the moment
-        raise ClickException("--limit and --retry cannot be supplied together")
+        raise BoardwalkException("--limit and --retry cannot be supplied together")
 
     try:
         ws = get_ws()
     except NoActiveWorkspace as e:
-        raise ClickException(e.message)
-    click.echo(f"Using workspace: {ws.name}")
+        raise BoardwalkException(e.message)
+    logger.info(f"Using workspace: {ws.name}")
 
     ws.assert_host_pattern_unchanged()
 
@@ -84,7 +89,7 @@ def init(ctx: click.Context, limit: str, retry: bool):
     }
     if retry:
         if not retry_file_path.exists():
-            raise ClickException("No retry file exists")
+            raise BoardwalkException("No retry file exists")
         runner_kwargs["limit"] = f"@{str(retry_file_path)}"
 
     # Save the host pattern we are initializing with. If the pattern changes after
@@ -109,10 +114,10 @@ def init(ctx: click.Context, limit: str, retry: bool):
         # we try to print out some debug info and bail
         for event in e.runner.events:
             try:
-                click.echo(event["stdout"])
+                logger.error(event["stdout"])
             except KeyError:
                 pass
-        raise ClickException("Failed to start fact gathering")
+        raise BoardwalkException("Failed to start fact gathering")
 
     # Clear the retry file after we use it to start fresh before we build a new one
     retry_file_path.unlink(missing_ok=True)
@@ -131,11 +136,11 @@ def init(ctx: click.Context, limit: str, retry: bool):
 
     # Note if any hosts were unreachable
     if hosts_were_unreachable:
-        click.echo("Some hosts were unreachable. Consider running again with --retry")
+        logger.warn("Some hosts were unreachable. Consider running again with --retry")
 
     # If we didn't find any hosts, raise an exception
     if len(ws.state.hosts) == 0:
-        raise ClickException("No hosts gathered")
+        raise BoardwalkException("No hosts gathered")
 
 
 def add_gathered_facts_to_state(event: RunnerEvent, ws: Workspace):
@@ -164,9 +169,9 @@ def handle_failed_init_hosts(event: RunnerEvent, retry_file_path: Path):
         event["event"] == "runner_on_unreachable"
         or event["event"] == "runner_on_failed"
     ):
-        click.echo(event["stdout"])
+        logger.warn(event["stdout"])
         with open(retry_file_path, "a") as file:
             file.write(f"{event['event_data']['host']}\n")
     # If no hosts matched or there are warnings, write them out
     if event["event"] == "warning" or event["event"] == "playbook_on_no_hosts_matched":
-        click.echo(event["stdout"])
+        logger.warn(event["stdout"])

src/boardwalk/cli_login.py

@@ -6,8 +6,7 @@
 import click
 from boardwalkd.protocol import Client
 
-from click import ClickException
-
+from boardwalk.app_exceptions import BoardwalkException
 from boardwalk.manifest import get_boardwalkd_url
 
 
@@ -19,4 +18,4 @@ def login():
     try:
         asyncio.run(client.api_login())
     except ConnectionRefusedError:
-        raise ClickException(f"Unable to reach {url}")
+        raise BoardwalkException(f"Unable to reach {url}")