refactor: make a new package "log"

- log.py -> cloudinit/log/loggers.py
- move logging helpers from util.py into cloudinit/log/log_util.py
- expose all of these functions in __init__.py

cloudinit/cmd/clean.py

@@ -11,15 +11,14 @@
 import os
 import sys
 
-from cloudinit import settings
+from cloudinit import log, settings
 from cloudinit.distros import uses_systemd
 from cloudinit.net.netplan import CLOUDINIT_NETPLAN_FILE
 from cloudinit.stages import Init
 from cloudinit.subp import ProcessExecutionError, runparts, subp
 from cloudinit.util import (
     del_dir,
     del_file,
-    error,
     get_config_logfiles,
     is_link,
     write_file,
@@ -144,12 +143,12 @@ def remove_artifacts(init, remove_logs, remove_seed=False, remove_config=None):
             else:
                 del_file(path)
         except OSError as e:
-            error("Could not remove {0}: {1}".format(path, str(e)))
+            log.error("Could not remove {0}: {1}".format(path, str(e)))
             return 1
     try:
         runparts(settings.CLEAN_RUNPARTS_DIR)
     except Exception as e:
-        error(
+        log.error(
             f"Failure during run-parts of {settings.CLEAN_RUNPARTS_DIR}: {e}"
         )
         return 1
@@ -176,7 +175,7 @@ def handle_clean_args(name, args):
         try:
             subp(cmd, capture=False)
         except ProcessExecutionError as e:
-            error(
+            log.error(
                 'Could not reboot this system using "{0}": {1}'.format(
                     cmd, str(e)
                 )

cloudinit/cmd/cloud_id.py

@@ -10,8 +10,8 @@
 
 from cloudinit.cmd.devel import read_cfg_paths
 from cloudinit.cmd.status import RunningStatus, get_status_details
+from cloudinit.log import error
 from cloudinit.sources import METADATA_UNKNOWN, canonical_cloud_id
-from cloudinit.util import error
 
 NAME = "cloud-id"
 

cloudinit/cmd/main.py

@@ -115,7 +115,7 @@ def log_ppid(distro, bootstage_name):
 def welcome(action, msg=None):
     if not msg:
         msg = welcome_format(action)
-    util.multi_log("%s\n" % (msg), console=False, stderr=True, log=LOG)
+    log.multi_log("%s\n" % (msg), console=False, stderr=True, log=LOG)
     return msg
 
 

cloudinit/config/cc_disk_setup.py

@@ -12,7 +12,7 @@
 import shlex
 from pathlib import Path
 
-from cloudinit import subp, util
+from cloudinit import log, subp, util
 from cloudinit.cloud import Cloud
 from cloudinit.config import Config
 from cloudinit.config.schema import MetaSchema

cloudinit/config/cc_final_message.py

@@ -9,7 +9,7 @@
 
 import logging
 
-from cloudinit import templater, util, version
+from cloudinit import log, templater, util, version
 from cloudinit.cloud import Cloud
 from cloudinit.config import Config
 from cloudinit.config.schema import MetaSchema
@@ -57,7 +57,7 @@ def handle(name: str, cfg: Config, cloud: Cloud, args: list) -> None:
             "datasource": str(cloud.datasource),
         }
         subs.update(dict([(k.upper(), v) for k, v in subs.items()]))
-        util.multi_log(
+        log.multi_log(
             "%s\n" % (templater.render_string(msg_in, subs)),
             console=False,
             stderr=True,

cloudinit/config/cc_keys_to_console.py

@@ -11,7 +11,7 @@
 import logging
 import os
 
-from cloudinit import subp, util
+from cloudinit import log, subp, util
 from cloudinit.cloud import Cloud
 from cloudinit.config import Config
 from cloudinit.config.schema import MetaSchema
@@ -64,7 +64,7 @@ def handle(name: str, cfg: Config, cloud: Cloud, args: list) -> None:
     try:
         cmd = [helper_path, ",".join(fp_blacklist), ",".join(key_blacklist)]
         (stdout, _stderr) = subp.subp(cmd)
-        util.multi_log("%s\n" % (stdout.strip()), stderr=False, console=True)
+        log.multi_log("%s\n" % (stdout.strip()), stderr=False, console=True)
     except Exception:
         LOG.warning("Writing keys to the system console failed!")
         raise

cloudinit/config/cc_mounts.py

@@ -16,7 +16,7 @@
 import re
 from typing import Dict, List, Optional, Tuple, cast
 
-from cloudinit import subp, util
+from cloudinit import log, subp, util
 from cloudinit.cloud import Cloud
 from cloudinit.config import Config
 from cloudinit.config.schema import MetaSchema

cloudinit/config/cc_resizefs.py

@@ -15,7 +15,7 @@
 import stat
 from typing import Optional
 
-from cloudinit import lifecycle, subp, util
+from cloudinit import lifecycle, log, subp, util
 from cloudinit.cloud import Cloud
 from cloudinit.config import Config
 from cloudinit.config.schema import MetaSchema

cloudinit/config/cc_set_passwords.py

@@ -12,7 +12,7 @@
 from string import ascii_letters, digits
 from typing import List
 
-from cloudinit import features, lifecycle, subp, util
+from cloudinit import features, lifecycle, log, subp, util
 from cloudinit.cloud import Cloud
 from cloudinit.config import Config
 from cloudinit.config.schema import MetaSchema
@@ -220,7 +220,7 @@ def handle(name: str, cfg: Config, cloud: Cloud, args: list) -> None:
                 "Set the following 'random' passwords\n",
                 "\n".join(randlist),
             )
-            util.multi_log(
+            log.multi_log(
                 "%s\n%s\n" % blurb, stderr=False, fallback_to_stdout=False
             )
 

cloudinit/config/cc_ssh_authkey_fingerprints.py

@@ -9,7 +9,7 @@
 import hashlib
 import logging
 
-from cloudinit import ssh_util, util
+from cloudinit import log, ssh_util, util
 from cloudinit.cloud import Cloud
 from cloudinit.config import Config
 from cloudinit.config.schema import MetaSchema
@@ -67,7 +67,7 @@ def _pprint_key_entries(
             "%sno authorized SSH keys fingerprints found for user %s.\n"
             % (prefix, user)
         )
-        util.multi_log(message, console=True, stderr=False)
+        log.multi_log(message, console=True, stderr=False)
         return
     tbl_fields = [
         "Keytype",
@@ -97,7 +97,7 @@ def _pprint_key_entries(
     ]
     lines.extend(authtbl_lines)
     for line in lines:
-        util.multi_log(
+        log.multi_log(
             text="%s%s\n" % (prefix, line), stderr=False, console=True
         )
 

cloudinit/config/cc_ubuntu_pro.py

@@ -8,7 +8,7 @@
 from typing import Any, List
 from urllib.parse import urlparse
 
-from cloudinit import subp, util
+from cloudinit import log, subp, util
 from cloudinit.cloud import Cloud
 from cloudinit.config import Config
 from cloudinit.config.schema import MetaSchema

cloudinit/config/schema.py

@@ -35,10 +35,10 @@
 from cloudinit.cmd.devel import read_cfg_paths
 from cloudinit.handlers import INCLUSION_TYPES_MAP, type_from_starts_with
 from cloudinit.helpers import Paths
+from cloudinit.log import error
 from cloudinit.sources import DataSourceNotFoundException
 from cloudinit.temp_utils import mkdtemp
 from cloudinit.util import (
-    error,
     get_modules_from_dir,
     load_text_file,
     load_yaml,

cloudinit/distros/networking.py

@@ -2,7 +2,7 @@
 import logging
 import os
 
-from cloudinit import net, subp, util
+from cloudinit import log, net, subp, util
 from cloudinit.distros.parsers import ifconfig
 from cloudinit.net.netops.iproute2 import Iproute2
 

cloudinit/distros/package_management/apt.py

@@ -7,7 +7,7 @@
 import time
 from typing import Any, Iterable, List, Mapping, Optional, Sequence, cast
 
-from cloudinit import helpers, subp, util
+from cloudinit import helpers, log, subp, util
 from cloudinit.distros.package_management.package_manager import (
     PackageManager,
     UninstalledPackages,

cloudinit/log/__init__.py

@@ -0,0 +1,30 @@
+# This file is part of cloud-init. See LICENSE file for license information.
+
+from cloudinit.log.log_util import error, log_time, logexc, multi_log
+from cloudinit.log.loggers import (
+    DEPRECATED,
+    TRACE,
+    CustomLoggerType,
+    LogExporter,
+    configure_root_logger,
+    flush_loggers,
+    reset_logging,
+    setup_basic_logging,
+    setup_logging,
+)
+
+__all__ = [
+    "CustomLoggerType",
+    "DEPRECATED",
+    "LogExporter",
+    "TRACE",
+    "configure_root_logger",
+    "error",
+    "flush_loggers",
+    "logexc",
+    "log_time",
+    "multi_log",
+    "reset_logging",
+    "setup_basic_logging",
+    "setup_logging",
+]

cloudinit/log/log_util.py

@@ -0,0 +1,120 @@
+import logging
+import os
+import sys
+import time
+
+
+def logexc(
+    log, msg, *args, log_level: int = logging.WARNING, exc_info=True
+) -> None:
+    log.log(log_level, msg, *args)
+    log.debug(msg, exc_info=exc_info, *args)
+
+
+class log_time:
+    """
+    Log time that it takes for context to run if the time exceeds a threshold.
+
+    :param msg: Name of the thing that is being measured
+    :param threshold: Threashold, in seconds. When the context exceeds this
+        threshold, a log will be made.
+    :param skip_log: Do not log a message. If a message would have been
+        logged it can be accessed from the context manager's 'output' variable
+        This is useful for consolidating the message with other logs.
+
+    usage:
+
+        this call:
+
+        ```
+        with log_time("Configuring the network"):
+            run_configure()
+        ```
+
+        might produce this log:
+
+        ```
+            Configuring the network took 0.02 seconds
+        ```
+    """
+
+    def __init__(self, msg, threshold: float = 0.01, skip_log: bool = False):
+        self._msg = msg
+        self._threshold = threshold
+        self._skip_log = skip_log
+        self.output = ""
+        self.start = 0.0
+
+    def __enter__(self):
+        self.start = time.monotonic()
+
+    def __exit__(self, exc_type, exc_val, exc_tb):
+        delta = time.monotonic() - self.start
+        if delta > self._threshold:
+            if not self._skip_log:
+                LOG.debug("%s took %0.3f seconds", self._msg, delta)
+            self.output = f"{self._msg} took {delta:.3f} seconds"
+
+
+def write_to_console(conpath, text):
+    with open(conpath, "w") as wfh:
+        wfh.write(text)
+        wfh.flush()
+
+
+def multi_log(
+    text,
+    console=True,
+    stderr=True,
+    log=None,
+    log_level=logging.DEBUG,
+    fallback_to_stdout=True,
+):
+    if stderr:
+        sys.stderr.write(text)
+    if console:
+        conpath = "/dev/console"
+        writing_to_console_worked = False
+        if os.path.exists(conpath):
+            try:
+                write_to_console(conpath, text)
+                writing_to_console_worked = True
+            except OSError:
+                console_error = "Failed to write to /dev/console"
+                sys.stdout.write(f"{console_error}\n")
+                if log:
+                    log.log(logging.WARNING, console_error)
+
+        if fallback_to_stdout and not writing_to_console_worked:
+            # A container may lack /dev/console (arguably a container bug).
+            # Additionally, /dev/console may not be writable to on a VM (again
+            # likely a VM bug or virtualization bug).
+            #
+            # If either of these is the case, then write output to stdout.
+            # This will result in duplicate stderr and stdout messages if
+            # stderr was True.
+            #
+            # even though systemd might have set up output to go to
+            # /dev/console, the user may have configured elsewhere via
+            # cloud-config 'output'.  If there is /dev/console, messages will
+            # still get there.
+            sys.stdout.write(text)
+    if log:
+        if text[-1] == "\n":
+            log.log(log_level, text[:-1])
+        else:
+            log.log(log_level, text)
+
+
+def error(msg, rc=1, fmt="Error:\n{}", sys_exit=False):
+    r"""Print error to stderr and return or exit
+
+    @param msg: message to print
+    @param rc: return code (default: 1)
+    @param fmt: format string for putting message in (default: 'Error:\n {}')
+    @param sys_exit: exit when called (default: false)
+    """
+    print(fmt.format(msg), file=sys.stderr)
+    if sys_exit:
+        sys.exit(rc)
+    return rc

cloudinit/net/__init__.py

@@ -14,7 +14,7 @@
 from typing import Any, Callable, Dict, List, Optional, Tuple
 from urllib.parse import urlparse
 
-from cloudinit import subp, util
+from cloudinit import log, subp, util
 from cloudinit.net.netops.iproute2 import Iproute2
 from cloudinit.url_helper import UrlError, readurl
 

cloudinit/signal_handler.py

@@ -11,7 +11,7 @@
 import sys
 from io import StringIO
 
-from cloudinit import util
+from cloudinit import log
 from cloudinit import version as vr
 
 LOG = logging.getLogger(__name__)
@@ -44,7 +44,7 @@ def _handle_exit(signum, frame):
     contents = StringIO()
     contents.write("%s\n" % (msg))
     _pprint_frame(frame, 1, BACK_FRAME_TRACE_DEPTH, contents)
-    util.multi_log(contents.getvalue(), log=LOG, log_level=logging.ERROR)
+    log.multi_log(contents.getvalue(), log=LOG, log_level=logging.ERROR)
     sys.exit(rc)
 
 

cloudinit/sources/DataSourceScaleway.py

@@ -19,7 +19,7 @@
 from urllib3.connection import HTTPConnection
 from urllib3.poolmanager import PoolManager
 
-from cloudinit import dmi, sources, url_helper, util
+from cloudinit import dmi, log, sources, url_helper, util
 from cloudinit.event import EventScope, EventType
 from cloudinit.net.dhcp import NoDHCPLeaseError
 from cloudinit.net.ephemeral import EphemeralDHCPv4, EphemeralIPv6Network