Merge pull request #741 from maurerle/quiet-output

Output: use logging, remove verbose output by default

podman_compose.py

@@ -14,6 +14,7 @@ import glob
 import hashlib
 import itertools
 import json
+import logging
 import os
 import random
 import re
@@ -78,16 +79,7 @@ def try_float(i, fallback=None):
     return fallback
 
 
-def log(*msgs, sep=" ", end="\n"):
-    try:
-        current_task = asyncio.current_task()
-    except RuntimeError:
-        current_task = None
-    line = (sep.join([str(msg) for msg in msgs])) + end
-    if current_task and not current_task.get_name().startswith("Task"):
-        line = f"[{current_task.get_name()}] " + line
-    sys.stderr.write(line)
-    sys.stderr.flush()
+log = logging.getLogger(__name__)
 
 
 dir_re = re.compile(r"^[~/\.]")
@@ -387,7 +379,7 @@ async def assert_volume(compose, mount_dict):
     proj_name = compose.project_name
     vol_name = vol["name"]
     is_ext = vol.get("external", None)
-    log(f"podman volume inspect {vol_name} || podman volume create {vol_name}")
+    log.debug("podman volume inspect %s || podman volume create %s", vol_name, vol_name)
     # TODO: might move to using "volume list"
     # podman volume list --format '{{.Name}}\t{{.MountPoint}}' \
     #     -f 'label=io.podman.compose.project=HERE'
@@ -563,9 +555,11 @@ def get_secret_args(compose, cnt, secret):
         volume_ref = ["--volume", f"{source_file}:{dest_file}:ro,rprivate,rbind"]
         if uid or gid or mode:
             sec = target if target else secret_name
-            log(
-                f'WARNING: Service {cnt["_service"]} uses secret "{sec}" with uid, gid, or mode.'
-                + " These fields are not supported by this implementation of the Compose file"
+            log.warning(
+                "WARNING: Service %s uses secret %s with uid, gid, or mode."
+                + " These fields are not supported by this implementation of the Compose file",
+                cnt["_service"],
+                sec,
             )
         return volume_ref
     # v3.5 and up added external flag, earlier the spec
@@ -594,11 +588,12 @@ def get_secret_args(compose, cnt, secret):
         if target and target != secret_name:
             raise ValueError(err_str.format(target, secret_name))
         if target:
-            log(
-                'WARNING: Service "{}" uses target: "{}" for secret: "{}".'.format(
-                    cnt["_service"], target, secret_name
-                )
-                + " That is un-supported and a no-op and is ignored."
+            log.warning(
+                'WARNING: Service "%s" uses target: "%s" for secret: "%s".'
+                + " That is un-supported and a no-op and is ignored.",
+                cnt["_service"],
+                target,
+                secret_name,
             )
         return ["--secret", "{}{}".format(secret_name, secret_opts)]
 
@@ -778,7 +773,7 @@ def get_net_args(compose, cnt):
         elif net.startswith("bridge"):
             is_bridge = True
         else:
-            print(f"unknown network_mode [{net}]")
+            log.fatal("unknown network_mode [%s]", net)
             sys.exit(1)
     else:
         is_bridge = True
@@ -921,10 +916,10 @@ async def container_to_args(compose, cnt, detached=True):
     await assert_cnt_nets(compose, cnt)
     podman_args.extend(get_net_args(compose, cnt))
 
-    logging = cnt.get("logging", None)
-    if logging is not None:
-        podman_args.append(f'--log-driver={logging.get("driver", "k8s-file")}')
-        log_opts = logging.get("options") or {}
+    log_config = cnt.get("logging", None)
+    if log_config is not None:
+        podman_args.append(f'--log-driver={log_config.get("driver", "k8s-file")}')
+        log_opts = log_config.get("options") or {}
         podman_args += [f"--log-opt={name}={value}" for name, value in log_opts.items()]
     for secret in cnt.get("secrets", []):
         podman_args.extend(get_secret_args(compose, cnt, secret))
@@ -1154,7 +1149,7 @@ class Podman:
             cmd_args = cmd_args or []
             xargs = self.compose.get_podman_args(cmd) if cmd else []
             cmd_ls = [self.podman_path, *podman_args, cmd] + xargs + cmd_args
-            log(cmd_ls)
+            log.info(str(cmd_ls))
             p = await asyncio.subprocess.create_subprocess_exec(
                 *cmd_ls, stdout=asyncio.subprocess.PIPE, stderr=asyncio.subprocess.PIPE
             )
@@ -1174,7 +1169,7 @@ class Podman:
         cmd_args = list(map(str, cmd_args or []))
         xargs = self.compose.get_podman_args(cmd) if cmd else []
         cmd_ls = [self.podman_path, *podman_args, cmd] + xargs + cmd_args
-        log(" ".join([str(i) for i in cmd_ls]))
+        log.info(" ".join([str(i) for i in cmd_ls]))
         os.execlp(self.podman_path, *cmd_ls)
 
     async def run(
@@ -1191,7 +1186,7 @@ class Podman:
             cmd_args = list(map(str, cmd_args or []))
             xargs = self.compose.get_podman_args(cmd) if cmd else []
             cmd_ls = [self.podman_path, *podman_args, cmd] + xargs + cmd_args
-            log(" ".join([str(i) for i in cmd_ls]))
+            log.info(" ".join([str(i) for i in cmd_ls]))
             if self.dry_run:
                 return None
 
@@ -1225,16 +1220,16 @@ class Podman:
             try:
                 exit_code = await p.wait()
             except asyncio.CancelledError:
-                log("Sending termination signal")
+                log.info("Sending termination signal")
                 p.terminate()
                 try:
                     exit_code = await wait_with_timeout(p.wait(), 10)
                 except TimeoutError:
-                    log("container did not shut down after 10 seconds, killing")
+                    log.warning("container did not shut down after 10 seconds, killing")
                     p.kill()
                     exit_code = await p.wait()
 
-            log(f"exit code: {exit_code}")
+            log.info("exit code: %s", exit_code)
             return exit_code
 
     async def volume_ls(self, proj=None):
@@ -1482,7 +1477,7 @@ class PodmanCompose:
         missing = given - self.all_services
         if missing:
             missing_csv = ",".join(missing)
-            log(f"missing services [{missing_csv}]")
+            log.warning("missing services [%s]", missing_csv)
             sys.exit(1)
 
     def get_podman_args(self, cmd):
@@ -1496,7 +1491,7 @@ class PodmanCompose:
         return xargs
 
     async def run(self):
-        log("podman-compose version: " + __version__)
+        log.info("podman-compose version: %s", __version__)
         args = self._parse_args()
         podman_path = args.podman_path
         if podman_path != "podman":
@@ -1505,7 +1500,7 @@ class PodmanCompose:
             else:
                 # this also works if podman hasn't been installed now
                 if args.dry_run is False:
-                    log(f"Binary {podman_path} has not been found.")
+                    log.fatal("Binary %s has not been found.", podman_path)
                     sys.exit(1)
         self.podman = Podman(self, podman_path, args.dry_run, asyncio.Semaphore(args.parallel))
 
@@ -1519,9 +1514,9 @@ class PodmanCompose:
             except subprocess.CalledProcessError:
                 self.podman_version = None
             if not self.podman_version:
-                log("it seems that you do not have `podman` installed")
+                log.fatal("it seems that you do not have `podman` installed")
                 sys.exit(1)
-            log("using podman version: " + self.podman_version)
+            log.info("using podman version: %s", self.podman_version)
         cmd_name = args.command
         compose_required = cmd_name != "version" and (
             cmd_name != "systemd" or args.action != "create-unit"
@@ -1549,7 +1544,7 @@ class PodmanCompose:
             args.file = list(filter(os.path.exists, default_ls))
         files = args.file
         if not files:
-            log(
+            log.fatal(
                 "no compose.yaml, docker-compose.yml or container-compose.yml file found, "
                 "pass files with -f"
             )
@@ -1557,7 +1552,7 @@ class PodmanCompose:
         ex = map(os.path.exists, files)
         missing = [fn0 for ex0, fn0 in zip(ex, files) if not ex0]
         if missing:
-            log("missing files: ", missing)
+            log.fatal("missing files: %s", missing)
             sys.exit(1)
         # make absolute
         relative_files = files
@@ -1635,7 +1630,7 @@ class PodmanCompose:
         compose["_dirname"] = dirname
         # debug mode
         if len(files) > 1:
-            log(" ** merged:\n", json.dumps(compose, indent=2))
+            log.debug(" ** merged:\n%s", json.dumps(compose, indent=2))
         # ver = compose.get('version', None)
 
         if not project_name:
@@ -1656,7 +1651,7 @@ class PodmanCompose:
         services = compose.get("services", None)
         if services is None:
             services = {}
-            log("WARNING: No services defined")
+            log.warning("WARNING: No services defined")
         # include services with no profile defined or the selected profiles
         services = self._resolve_profiles(services, set(args.profile))
 
@@ -1689,7 +1684,7 @@ class PodmanCompose:
         unused_nets = given_nets - allnets - set(["default"])
         if len(unused_nets):
             unused_nets_str = ",".join(unused_nets)
-            log(f"WARNING: unused networks: {unused_nets_str}")
+            log.warning("WARNING: unused networks: %s", unused_nets_str)
         if len(missing_nets):
             missing_nets_str = ",".join(missing_nets)
             raise RuntimeError(f"missing networks: {missing_nets_str}")
@@ -1800,6 +1795,8 @@ class PodmanCompose:
         if not self.global_args.command or self.global_args.command == "help":
             parser.print_help()
             sys.exit(-1)
+
+        logging.basicConfig(level=("DEBUG" if self.global_args.verbose else "WARN"))
         return self.global_args
 
     @staticmethod
@@ -1887,6 +1884,11 @@ class PodmanCompose:
         parser.add_argument(
             "--parallel", type=int, default=os.environ.get("COMPOSE_PARALLEL_LIMIT", sys.maxsize)
         )
+        parser.add_argument(
+            "--verbose",
+            help="Print debugging output",
+            action="store_true",
+        )
 
 
 podman_compose = PodmanCompose()
@@ -1982,15 +1984,15 @@ async def compose_systemd(compose, args):
         proj_name = compose.project_name
         fn = os.path.expanduser(f"~/{stacks_dir}/{proj_name}.env")
         os.makedirs(os.path.dirname(fn), exist_ok=True)
-        print(f"writing [{fn}]: ...")
+        log.debug("writing [%s]: ...", fn)
         with open(fn, "w", encoding="utf-8") as f:
             for k, v in compose.environ.items():
                 if k.startswith("COMPOSE_") or k.startswith("PODMAN_"):
                     f.write(f"{k}={v}\n")
-        print(f"writing [{fn}]: done.")
-        print("\n\ncreating the pod without starting it: ...\n\n")
+        log.debug("writing [%s]: done.", fn)
+        log.info("\n\ncreating the pod without starting it: ...\n\n")
         process = await asyncio.subprocess.create_subprocess_exec(script, ["up", "--no-start"])
-        print("\nfinal exit code is ", process)
+        log.info("\nfinal exit code is ", process)
         username = getpass.getuser()
         print(
             f"""
@@ -2037,10 +2039,10 @@ ExecStop=/usr/bin/podman pod stop pod_%i
 WantedBy=default.target
 """
         if os.access(os.path.dirname(fn), os.W_OK):
-            print(f"writing [{fn}]: ...")
+            log.debug("writing [%s]: ...", fn)
             with open(fn, "w", encoding="utf-8") as f:
                 f.write(out)
-            print(f"writing [{fn}]: done.")
+            log.debug("writing [%s]: done.", fn)
             print(
                 """
 while in your project type `podman-compose systemd -a register`
@@ -2048,7 +2050,7 @@ while in your project type `podman-compose systemd -a register`
             )
         else:
             print(out)
-            log(f"Could not write to [{fn}], use 'sudo'")
+            log.warning("Could not write to [%s], use 'sudo'", fn)
 
 
 @cmd_run(podman_compose, "pull", "pull stack images")
@@ -2188,7 +2190,7 @@ def get_excluded(compose, args):
         for service in args.services:
             excluded -= compose.services[service]["_deps"]
             excluded.discard(service)
-    log("** excluding: ", excluded)
+    log.debug("** excluding: %s", excluded)
     return excluded
 
 
@@ -2221,10 +2223,10 @@ async def compose_up(compose: PodmanCompose, args):
     )
     diff_hashes = [i for i in hashes if i and i != compose.yaml_hash]
     if args.force_recreate or len(diff_hashes):
-        log("recreating: ...")
+        log.info("recreating: ...")
         down_args = argparse.Namespace(**dict(args.__dict__, volumes=False))
         await compose.commands["down"](compose, down_args)
-        log("recreating: done\n\n")
+        log.info("recreating: done\n\n")
     # args.no_recreate disables check for changes (which is not implemented)
 
     podman_command = "run" if args.detach and not args.no_start else "create"
@@ -2232,7 +2234,7 @@ async def compose_up(compose: PodmanCompose, args):
     await create_pods(compose, args)
     for cnt in compose.containers:
         if cnt["_service"] in excluded:
-            log("** skipping: ", cnt["name"])
+            log.debug("** skipping: %s", cnt["name"])
             continue
         podman_args = await container_to_args(compose, cnt, detached=args.detach)
         subproc = await compose.podman.run([], podman_command, podman_args)
@@ -2264,7 +2266,7 @@ async def compose_up(compose: PodmanCompose, args):
         space_suffix = " " * (max_service_length - len(cnt["_service"]) + 1)
         log_formatter = "{}[{}]{}|\x1b[0m".format(color, cnt["_service"], space_suffix)
         if cnt["_service"] in excluded:
-            log("** skipping: ", cnt["name"])
+            log.debug("** skipping: %s", cnt["name"])
             continue
 
         tasks.add(
@@ -2368,7 +2370,7 @@ async def compose_down(compose, args):
             if cnt["_service"] not in excluded:
                 continue
             vol_names_to_keep.update(get_volume_names(compose, cnt))
-        log("keep", vol_names_to_keep)
+        log.debug("keep %s", vol_names_to_keep)
         for volume_name in await compose.podman.volume_ls():
             if volume_name in vol_names_to_keep:
                 continue
@@ -2643,7 +2645,7 @@ async def compose_unpause(compose, args):
 async def compose_kill(compose, args):
     # to ensure that the user did not execute the command by mistake
     if not args.services and not args.all:
-        print(
+        log.fatal(
             "Error: you must provide at least one service name or use (--all) to kill all services"
         )
         sys.exit()