Repository: radiocosmology/alpenhorn

Issue:
Refactor duplicate config+db+extension code into a single function
We have the same code for to load the config, start the database, and register extensions duplicated in a couple of places. (Right now it's in `alpenhorn.client` in `_init_config_db` and `init`, as well as `alpenhorn.service` in `cli`.)  Can we refactor it into a function in `alpenhorn/__init__`?

Leaving out the comments, this is the same set of steps that always (should? must?) happen:
```python
    config.load_config()
    extensions.load_extensions()
    db.config_connect()
    extensions.register_type_extensions()
```

Hints from issue comments:
@jrs65: I did have a bit of a think about this. Combining them all isn’t super trivial as the code in client.init needs to do extra steps in between (i.e. creating various tables), that none of the other sections should attempt to do (of course those could just be wrapped in an `if create:` statement, where `create` is some argument on the function).

On 20 May 2017, 01:04 +0100, Davor Cubranic <notifications@github.com>, wrote:
> We have the same code for to load the config, start the database, and register extensions duplicated in a couple of places. (Right now it's in alpenhorn.client in _init_config_db and init, as well as alpenhorn.service in cli.) Can we refactor it into a function in alpenhorn/__init__?
> Leaving out the comments, this is the same set of steps that always (should? must?) happen:
>
>    config.load_config()
>    extensions.load_extensions()
>    db.config_connect()
>    extensions.register_type_extensions()
> —
> You are receiving this because you are subscribed to this thread.
> Reply to this email directly, view it on GitHub, or mute the thread.
@cubranic: You’re right, I missed the bit with table creation in client.init. But there is still the duplication in client._init_config_db and service.cli. We could move _init_config_db to db module and let “client.init” keeps its own flow, which makes sense since it’s a special case.

And since the create_tables is run with “safe=True”, is there any harm in running it when the tables already exist? Does it fail or just silently no-op? (Sorry, typing while offline so can’t lookup the docs.)

> On May 20, 2017, at 3:26 AM, Richard Shaw <notifications@github.com> wrote:
> 
> I did have a bit of a think about this. Combining them all isn’t super trivial as the code in client.init needs to do extra steps in between (i.e. creating various tables), that none of the other sections should attempt to do (of course those could just be wrapped in an `if create:` statement, where `create` is some argument on the function).
> 
> On 20 May 2017, 01:04 +0100, Davor Cubranic <notifications@github.com>, wrote:
> > We have the same code for to load the config, start the database, and register extensions duplicated in a couple of places. (Right now it's in alpenhorn.client in _init_config_db and init, as well as alpenhorn.service in cli.) Can we refactor it into a function in alpenhorn/__init__?
> > Leaving out the comments, this is the same set of steps that always (should? must?) happen:
> >
> > config.load_config()
> > extensions.load_extensions()
> > db.config_connect()
> > extensions.register_type_extensions()
> > —
> > You are receiving this because you are subscribed to this thread.
> > Reply to this email directly, view it on GitHub, or mute the thread.
> —
> You are receiving this because you authored the thread.
> Reply to this email directly, view it on GitHub <https://github.com/radiocosmology/alpenhorn/issues/20#issuecomment-302864664>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAkrOxf5NIlj9NUE2PpRfkwZtZE2E2twks5r7r_ZgaJpZM4NhIIu>.
> 

@jrs65: I think your suggestion for how to do it makes sense. There'll probably be more places that we want to load the `db` from eventually.

I think with `safe=True` there is no harm. However I wanted table creation to be an explicit operation that you have to perform, so it needs to have it's own code path for that.

Solution patch:
diff --git a/alpenhorn/client/acq.py b/alpenhorn/client/acq.py
index 7972341eb..e877fbd92 100644
--- a/alpenhorn/client/acq.py
+++ b/alpenhorn/client/acq.py
@@ -8,8 +8,6 @@
 
 from ..db import ArchiveAcq, ArchiveFile, ArchiveFileCopy, StorageGroup, StorageNode
 
-from .connect_db import config_connect
-
 RE_LOCK_FILE = re.compile(r"^\..*\.lock$")
 
 
diff --git a/alpenhorn/client/cli.py b/alpenhorn/client/cli.py
index 489f32870..36a068744 100644
--- a/alpenhorn/client/cli.py
+++ b/alpenhorn/client/cli.py
@@ -1,11 +1,12 @@
 """Alpenhorn client interface."""
 
+import click
 import datetime
 import logging
-
-import click
 import peewee as pw
 
+from .. import db
+from ..common.util import start_alpenhorn
 from ..db import (
     ArchiveAcq,
     ArchiveFile,
@@ -15,18 +16,75 @@
     StorageNode,
     StorageTransferAction,
 )
-from alpenhorn import config, db, extensions, util
 
 from . import acq, group, node, transport
-from .connect_db import config_connect
 
 log = logging.getLogger(__name__)
 
 
+def _verbosity_from_cli(verbose: int, debug: int, quiet: int) -> int:
+    """Get client verbosity from command line.
+
+    Processes the --verbose, --debug and --quiet flags to determine
+    the requested verbosity."""
+
+    if quiet and verbose:
+        raise click.UsageError("Cannot use both --quiet and --verbose.")
+    if quiet and debug:
+        raise click.UsageError("Cannot use both --quiet and --debug.")
+
+    # Default verbosity is 3.  --quiet decreases it.  --verbose increases it.
+
+    # Max verbosity
+    if debug or verbose > 2:
+        return 5
+    # Min verbosity
+    if quiet > 2:
+        return 1
+
+    return 3 + verbose - quiet
+
+
 @click.group(context_settings={"help_option_names": ["-h", "--help"]})
-def cli():
+@click.option(
+    "--conf",
+    "-c",
+    type=click.Path(exists=True),
+    help="Configuration file to read.",
+    default=None,
+    metavar="FILE",
+)
+@click.option(
+    "--quiet",
+    "-q",
+    help="Decrease verbosity.  May be specified mulitple times: "
+    "once suppresses normal client output, leaving only warning "
+    "and error message.  A second use also suppresses warnings.",
+    count=True,
+)
+@click.option(
+    "--verbose",
+    "-v",
+    help="Increase verbosity.  May be specified mulitple times: "
+    "once enables informational messages.  A second use also "
+    "enables debugging messages.",
+    count=True,
+)
+@click.option(
+    "--debug",
+    help="Maximum verbosity.",
+    is_flag=True,
+    show_default=False,
+    default=False,
+)
+def cli(conf, quiet, verbose, debug):
     """Client interface for alpenhorn."""
 
+    # Initialise alpenhorn
+    start_alpenhorn(
+        conf, client=True, verbosity=_verbosity_from_cli(verbose, debug, quiet)
+    )
+
 
 @cli.command()
 def init():
@@ -36,11 +94,6 @@ def init():
     specified in its configuration.
     """
 
-    # Load the configuration and initialise the database connection
-    config.load_config()
-    extensions.load_extensions()
-    db.config_connect()
-
     # Create any alpenhorn core tables
     core_tables = [
         ArchiveAcq,
@@ -54,9 +107,6 @@ def init():
 
     db.database_proxy.create_tables(core_tables, safe=True)
 
-    # Register the acq/file type extensions
-    extensions.register_type_extensions()
-
     # TODO Create any tables registered by extensions
 
 
@@ -94,8 +144,6 @@ def sync(
     archive (e.g. HPSS, transport disks).
     """
 
-    config_connect()
-
     try:
         from_node = StorageNode.get(name=node_name)
     except pw.DoesNotExist:
@@ -281,8 +329,6 @@ def status(all):
 
     import tabulate
 
-    config_connect()
-
     # Data to fetch from the database (node name, total files, total size)
     query_info = (
         StorageNode.name,
diff --git a/alpenhorn/client/connect_db.py b/alpenhorn/client/connect_db.py
deleted file mode 100644
index bcce27ae2..000000000
--- a/alpenhorn/client/connect_db.py
+++ /dev/null
@@ -1,14 +0,0 @@
-"""Alpenhorn client database initialization functions"""
-
-from alpenhorn import config, db, extensions
-
-
-def config_connect():
-    """Load the config, start the database and register extensions."""
-    # Load the configuration and initialise the database connection
-    config.load_config()
-    extensions.load_extensions()
-    db.config_connect()
-
-    # Register the acq/file type extensions
-    extensions.register_type_extensions()
diff --git a/alpenhorn/client/group.py b/alpenhorn/client/group.py
index 49a06229b..812bf4d96 100644
--- a/alpenhorn/client/group.py
+++ b/alpenhorn/client/group.py
@@ -5,8 +5,6 @@
 
 from ..db import StorageGroup, StorageNode
 
-from .connect_db import config_connect
-
 
 @click.group(context_settings={"help_option_names": ["-h", "--help"]})
 def cli():
diff --git a/alpenhorn/client/node.py b/alpenhorn/client/node.py
index 093d4dc28..ba9559cb6 100644
--- a/alpenhorn/client/node.py
+++ b/alpenhorn/client/node.py
@@ -8,11 +8,9 @@
 import click
 import peewee as pw
 
+from .. import db
+from ..common import util
 from ..db import ArchiveAcq, ArchiveFile, ArchiveFileCopy, StorageGroup, StorageNode
-import alpenhorn.util as util
-from alpenhorn import db
-
-from .connect_db import config_connect
 
 RE_LOCK_FILE = re.compile(r"^\..*\.lock$")
 
diff --git a/alpenhorn/client/transport.py b/alpenhorn/client/transport.py
index 7561d8b5e..c60973c23 100644
--- a/alpenhorn/client/transport.py
+++ b/alpenhorn/client/transport.py
@@ -10,7 +10,6 @@
 from ..db import StorageGroup, StorageNode
 
 from . import node
-from .connect_db import config_connect
 
 # A few utility routines for dealing with filesystems
 MAX_E2LABEL_LEN = 16
diff --git a/alpenhorn/common/config.py b/alpenhorn/common/config.py
index 9123c82e5..f4a6a31d5 100644
--- a/alpenhorn/common/config.py
+++ b/alpenhorn/common/config.py
@@ -6,6 +6,7 @@
 - `/etc/xdg/alpenhorn/alpenhorn.conf`
 - `~/.config/alpenhorn/alpenhorn.conf`
 - `ALPENHORN_CONFIG_FILE` environment variable
+- the path passed via `-c` or `--conf` on the command line
 
 This is in order of increasing precedence, with options in later files
 overriding those in earlier entries. Configuration is merged recursively by
@@ -135,6 +136,9 @@
         pull_bytes_per_second: 20000000
 """
 
+from __future__ import annotations
+
+from click import ClickException
 import logging
 import os
 
@@ -156,7 +160,7 @@
 }
 
 
-def load_config():
+def load_config(cli_conf: os.PathLike, client: bool) -> None:
     """Find and load the configuration from a file."""
 
     global config
@@ -171,8 +175,12 @@ def load_config():
         "~/.config/alpenhorn/alpenhorn.conf",
     ]
 
-    if "ALPENHORN_CONFIG_FILE" in os.environ:
-        config_files.append(os.environ["ALPENHORN_CONFIG_FILE"])
+    enviro_conf = os.environ.get("ALPENHORN_CONFIG_FILE", None)
+    if enviro_conf:
+        config_files.append(enviro_conf)
+
+    if cli_conf:
+        config_files.append(cli_conf)
 
     any_exist = False
 
@@ -181,6 +189,13 @@ def load_config():
         absfile = os.path.abspath(os.path.expanduser(os.path.expandvars(cfile)))
 
         if not os.path.exists(absfile):
+            # Warn if a user-supplied config file is missing
+            if cfile == cli_conf:
+                log.warning(f"Config file {absfile} defined on command line not found.")
+            elif cfile == enviro_conf:
+                log.warning(
+                    f"Config file {absfile} defined by ALPENHORN_CONFIG_FILE not found."
+                )
             continue
 
         any_exist = True
@@ -194,21 +209,15 @@ def load_config():
             config = merge_dict_tree(config, conf)
 
     if not any_exist:
-        raise RuntimeError("No configuration files available.")
-
-
-class ConfigClass(object):
-    """A base for classes that can be configured from a dictionary.
-
-    Note that this configures the class itself, not instances of the class.
-    """
+        if client:
+            exc = ClickException
+        else:
+            exc = RuntimeError
 
-    @classmethod
-    def set_config(cls, configdict):
-        """Configure the class from the supplied `configdict`."""
+        raise exc("No configuration files available.")
 
 
-def merge_dict_tree(a, b):
+def merge_dict_tree(a: dict, b: dict) -> dict:
     """Merge two dictionaries recursively.
 
     The following rules applied:
diff --git a/alpenhorn/common/logger.py b/alpenhorn/common/logger.py
index 5d7abdeec..361d62b9f 100644
--- a/alpenhorn/common/logger.py
+++ b/alpenhorn/common/logger.py
@@ -1,23 +1,45 @@
 """Set up logging for alpenhorn.
 
-This module provides two important functions:
+Basic Configruation
+-------------------
 
-* `init_logging()` should be called as soon as possible after program start
-    to turn on logging to standard error.  Any log messages produced before
-    this call are discarded.
+Both client and server should call the `init_logging()` function as soon as
+possible after program start to turn on logging to standard error.  Any log
+messages produced before this call are discarded.
 
-* `configure_logging()` should be called immediately after the alpenhorn
-    config has been loaded.  It will re-configure the alpenhorn logger
-    based on the alpenhorn configuration, including starting file or syslog-
-    based logging, if requested.
 
-alpenhorn buffers log messages emitted between these two calls and will flush
-them to any additonal log destinations started by `configure_logging` so that
-these messages are not lost.  (This is in addiiton to the messages being sent
-immediately to standard error, which always happens.)
+Server Logging
+--------------
+
+The server should immediately follow the loading of the alpenhorn config
+with a call to `configure_logging()` which will re-configure the alpenhorn
+logger based on the alpenhorn configuration, including starting file or syslog-
+based logging, if requested.  The client should not call this function.
+
+The alpenhorn server buffers log messages emitted between the `init_logging`
+and `configure_logging` calls and will flush them to any additonal log
+destinations started by `configure_logging` so that these messages are not lost.
+(This is in addiiton to the messages being sent immediately to standard error,
+which always happens.)
 
 Note also that between the two calls, the log level of the root logger is
 set to DEBUG.
+
+
+Client Logging
+--------------
+
+The client does not support file or syslog logging, so should _not_ call
+`configure_logging`.  Instead, the client supports five verbosity levels:
+
+    1.  No output on standard out.  Error messages on standard error.
+    2.  No output on standard out.  Warning and error on standard error.
+    3.  Client ouput on standard out.  Warning and error messages on standard error.
+    4.  Client ouput on standard out.  Info, warning, errors on standard error.
+    5.  Client ouput on standard out.  Debug, info, warning, errors on standard error.
+
+The initial verbosity can be specified in the `init_logging` call.  The
+default verbosity is 3.   May be changed at runtime by calling `set_verbosity`.
 """
 
 import socket
@@ -34,15 +56,22 @@
 except ImportError:
     RotatingFileHandler = logging.handlers.RotatingFileHandler
 
-# The log format.  Used by the stderr log and any other log destinations
-log_fmt = logging.Formatter(
+# The log formats.  Used by the stderr log and any other log destinations
+client_fmt = logging.Formatter(
+    "%(levelname)s >> %(message)s",
+    "%b %d %H:%M:%S",
+)
+server_fmt = logging.Formatter(
     "%(asctime)s %(levelname)s >> [%(threadName)s] %(message)s",
     "%b %d %H:%M:%S",
 )
 
-# initialised by init_logging
+# initialised by init_logging; server-only
 log_buffer = None
 
+# Client output suppression.
+_client_echo = True
+
 
 class StartupHandler(logging.handlers.BufferingHandler):
     """Start-up logging handler for alpenhorn.
@@ -103,32 +132,83 @@ def close(self) -> None:
             self.release()
 
 
-def init_logging() -> None:
+def echo(*args, **kwargs) -> None:
+    """Client wrapper for click.echo.
+
+    Suppresses output when verbosity is less than three.
+    """
+    if client_echo:
+        return click.echo(*args, **kwargs)
+
+
+def set_verbosity(verbosity: int) -> None:
+    """Set client verbosity.
+
+    Sets the log level of the root logger based on the
+    requested verbosity level.
+    """
+
+    # Levels 2 and 3 are the same.
+    verbosity_to_level = {
+        1: logging.ERROR,
+        2: logging.WARNING,
+        3: logging.WARNING,
+        4: logging.INFO,
+        5: logging.DEBUG,
+    }
+
+    if verbosity not in verbosity_to_level:
+        raise ValueError(f"Bad verbosity: {verbosity}")
+
+    root_logger = logging.getLogger()
+    root_logger.setLevel(verbosity_to_level[verbosity])
+
+    # Suppress normal client output at low verbosity
+    global _client_echo
+    _client_echo = verbosity >= 3
+
+
+def init_logging(client: bool, verbosity: int | None = None) -> None:
     """Initialise the logger.
 
     This function is called before the config is read.  It sets up logging to
     standard error and also starts a log buffer where messages accumulate
     before the logging facilities defined by the configuration are started.
+
+    Parameters
+    ----------
+    client : bool
+        Is the alpenhorn client being initialised?
+    verbosity : int
+        For clients, the verbosity level to use.  Ignored for servers.
     """
 
     # This is the stderr logger.  It is always present, regardless of logging config
     log_stream = logging.StreamHandler()
-    log_stream.setFormatter(log_fmt)
-
-    # This is the start-up logger.  It buffers messages in memory until configure_logging()
-    # is called, at which point the buffered messages are flushed to a file, if one was
-    # opened, so that messages logged before the start of file logging are recorded,
-    # and then this handler is shut down.
-    global log_buffer
-    log_buffer = StartupHandler(10000)
+    log_stream.setFormatter(client_fmt if client else server_fmt)
 
     # Set up initial logging
     root_logger = logging.getLogger()
-    root_logger.setLevel(logging.DEBUG)
-    root_logger.addHandler(log_buffer)
     root_logger.addHandler(log_stream)
 
-    root_logger.info("Alpenhorn start.")
+    if client:
+        if verbosity is None:
+            verbosity = 3
+        set_verbosity(verbosity)
+    else:
+        root_logger.setLevel(logging.DEBUG)
+
+        # This is the start-up logger for the server.  It buffers messages in memory
+        # until configure_logging() is called, at which point the buffered messages
+        # are flushed to a file, if one was opened, so that messages logged before
+        # the start of file logging are recorded, and then this handler is shut down.
+        global log_buffer
+        log_buffer = StartupHandler(10000)
+
+        root_logger.addHandler(log_buffer)
+
+        # Record server start
+        root_logger.info("Alpenhorn start.")
 
 
 def _max_bytes_from_config(max_bytes: str | float | int) -> int:
@@ -223,8 +303,8 @@ def configure_sys_logging(syslog_config: dict) -> logging.handlers.SysLogHandler
     )
 
     # Format handler
-    global log_fmt
-    handler.setFormatter(log_fmt)
+    global server_fmt
+    handler.setFormatter(server_fmt)
 
     # Log the start of syslogging to the alpenhorn logger.
     # We do this _before_ adding the file handler to prevent
@@ -308,8 +388,8 @@ def configure_file_logging(file_config: dict) -> logging.Handler:
         how = ""
 
     # Format handler
-    global log_fmt
-    handler.setFormatter(log_fmt)
+    global server_fmt
+    handler.setFormatter(server_fmt)
 
     # Log the start of file logging to the alpenhorn logger.
     # We do this _before_ adding the file handler to prevent
diff --git a/alpenhorn/common/util.py b/alpenhorn/common/util.py
index 1a28ca87c..a1246c308 100644
--- a/alpenhorn/common/util.py
+++ b/alpenhorn/common/util.py
@@ -6,11 +6,39 @@
 import hashlib
 import logging
 
-from . import config
+from . import config, extensions, logger
 
 log = logging.getLogger(__name__)
 
 
+def start_alpenhorn(
+    cli_conf: str | None, client: bool, verbosity: int | None = None
+) -> None:
+    """Initialise alpenhorn
+
+    Parameters
+    ----------
+    cli_conf : str or None
+        The config file given on the command line, if any.
+    client : bool
+        Is the alpenhorn client being initialised?
+    verbosity : int, optional
+        For clients, the initial verbosity level.  Ignored for servers.
+    """
+    # Initialise logging
+    logger.init_logging(client=client, verbosity=verbosity)
+
+    # Load the configuration for alpenhorn
+    config.load_config(cli_conf, client=client)
+
+    # Set up server logging based on config
+    if not client:
+        logger.configure_logging()
+
+    # Load alpenhorn extensions
+    extensions.load_extensions()
+
+
 def run_command(
     cmd: list[str], timeout: float | None = None, **kwargs
 ) -> tuple(int | None, str, str):
diff --git a/alpenhorn/server/service.py b/alpenhorn/server/service.py
index d1155fd44..3f9b5df27 100755
--- a/alpenhorn/server/service.py
+++ b/alpenhorn/server/service.py
@@ -5,7 +5,8 @@
 import logging
 
 from .. import db
-from ..common import config, extensions, logger
+from ..common import config
+from ..common.util import start_alpenhorn
 from ..scheduler import FairMultiFIFOQueue, pool
 from . import auto_import, update
 
@@ -23,20 +24,19 @@ def log_exception(*args):
 
 
 @click.command()
-def cli():
+@click.option(
+    "--conf",
+    "-c",
+    type=click.Path(exists=True),
+    help="Configuration file to read.",
+    default=None,
+    metavar="FILE",
+)
+def cli(conf):
     """Alpenhorn data management service."""
 
-    # Initialise logging
-    logger.init_logging()
-
-    # Load the configuration for alpenhorn
-    config.load_config()
-
-    # Set up logging based on config
-    logger.configure_logging()
-
-    # Load alpenhorn extensions
-    extensions.load_extensions()
+    # Initialise alpenhorn
+    start_alpenhorn(conf, client=False)
 
     # Connect to the database
     db.connect()


Test patch:
diff --git a/tests/common/test_config.py b/tests/common/test_config.py
index 87b1afc66..b3a5f2095 100644
--- a/tests/common/test_config.py
+++ b/tests/common/test_config.py
@@ -16,7 +16,7 @@ def test_no_config():
     # Check that alpenhorn fails if it has no appropriate configuration
 
     with pytest.raises(RuntimeError) as excinfo:
-        config.load_config()
+        config.load_config(None, False)
 
     assert "No configuration" in str(excinfo.value)
 
@@ -26,7 +26,7 @@ def test_config_env(fs, monkeypatch):
     fs.create_file("/test/from/env/test.yaml", contents="hello: test\n")
 
     monkeypatch.setenv("ALPENHORN_CONFIG_FILE", "/test/from/env/test.yaml")
-    config.load_config()
+    config.load_config(None, False)
     assert config.config == merge_dict(config._default_config, {"hello": "test"})
 
 
@@ -34,25 +34,25 @@ def test_precendence(fs, monkeypatch):
     # Test the precedence of configuration imported from files is correct
 
     fs.create_file("/etc/alpenhorn/alpenhorn.conf", contents="hello: test\n")
-    config.load_config()
+    config.load_config(None, False)
     assert config.config == merge_dict(config._default_config, {"hello": "test"})
 
     fs.create_file("/etc/xdg/alpenhorn/alpenhorn.conf", contents="hello: test2\n")
-    config.load_config()
+    config.load_config(None, False)
     assert config.config == merge_dict(config._default_config, {"hello": "test2"})
 
     fs.create_file(
         os.path.expanduser("~/.config/alpenhorn/alpenhorn.conf"),
         contents="hello: test3\nmeh: embiggens",
     )
-    config.load_config()
+    config.load_config(None, False)
     assert config.config == merge_dict(
         config._default_config, {"hello": "test3", "meh": "embiggens"}
     )
 
     fs.create_file("/test/from/env/test.yaml", contents="hello: test4\n")
     monkeypatch.setenv("ALPENHORN_CONFIG_FILE", "/test/from/env/test.yaml")
-    config.load_config()
+    config.load_config(None, False)
     assert config.config == merge_dict(
         config._default_config, {"hello": "test4", "meh": "embiggens"}
     )
diff --git a/tests/conftest.py b/tests/conftest.py
index 4f7cf45a8..39cd2503e 100644
--- a/tests/conftest.py
+++ b/tests/conftest.py
@@ -74,7 +74,7 @@ def logger():
     Yields alpenhorn.common.logger.
     """
 
-    alpenhorn.common.logger.init_logging()
+    alpenhorn.common.logger.init_logging(False)
 
     yield alpenhorn.common.logger