From bc753e22b465b9e711ad23c95a03977b5bc7347e Mon Sep 17 00:00:00 2001
From: Dmitry Tantsur <dtantsur@protonmail.com>
Date: Mon, 23 May 2022 16:51:18 +0200
Subject: [PATCH] Fix logging in the baremetal CLI

* Ask openstacksdk to log to stderr instead of stdout, otherwise its
  warnings break parsing the output.
* Respect the --verbose flag (same as --debug but without tracebacks).
* Do not propagate log records that are handled by either openstacksdk's
  or ours logging code.

Change-Id: Ia191ab32f0d4f8f50cb266332d4f4bc96619cb58
---
 ironicclient/shell.py                         | 32 +++++++++++++------
 .../notes/logging-9c452e4869d80de9.yaml       |  9 ++++++
 2 files changed, 32 insertions(+), 9 deletions(-)
 create mode 100644 releasenotes/notes/logging-9c452e4869d80de9.yaml

diff --git a/ironicclient/shell.py b/ironicclient/shell.py
index 22bf3a32b..37892c5a1 100644
--- a/ironicclient/shell.py
+++ b/ironicclient/shell.py
@@ -170,21 +170,35 @@ class App(app.App):
         )
         return parser
 
+    # This is the openstacksdk default value
+    _STREAM_FORMAT = '%(asctime)s %(levelname)s: %(name)s %(message)s'
+
     def _configure_ironic_logging(self):
-        openstack.enable_logging(debug=self.options.debug)
-        # NOTE(dtantsur): I wish logging.basicConfig worked.. but it does not.
+        debug_enabled = self.options.debug or self.options.verbose_level > 1
+
+        openstack.enable_logging(debug=debug_enabled, stream=sys.stderr,
+                                 format_template=self._STREAM_FORMAT,
+                                 # No fancy formatting if debug is off
+                                 format_stream=debug_enabled)
+        # NOTE(dtantsur): prevent openstack logging from appearing again in the
+        # cliff handlers
+        for name in ('openstack', 'keystoneauth'):
+            logger = logging.getLogger(name)
+            logger.propagate = False
+
+        # NOTE(dtantsur): I wish logging.basicConfig worked, but at this point
+        # cliff has already started configuring logging.
         for name in ('ironicclient', 'ironic_inspector_client'):
             logger = logging.getLogger(name)
             logger.setLevel(
-                logging.DEBUG if self.options.debug else logging.WARNING)
-            # warnings are already configured by something else, only configure
+                logging.DEBUG if debug_enabled else logging.WARNING)
+            # warnings are already configured by cliff, only configure
             # debug logging for ironic.
-            if not logger.handlers and self.options.debug:
-                handler = logging.StreamHandler()
-                handler.setFormatter(logging.Formatter(
-                    # This is the openstacksdk default value
-                    '%(asctime)s %(levelname)s: %(name)s %(message)s'))
+            if not logger.handlers and debug_enabled:
+                handler = logging.StreamHandler(stream=sys.stderr)
+                handler.setFormatter(logging.Formatter(self._STREAM_FORMAT))
                 logger.addHandler(handler)
+                logger.propagate = False
 
     def initialize_app(self, argv):
         super(App, self).initialize_app(argv)
diff --git a/releasenotes/notes/logging-9c452e4869d80de9.yaml b/releasenotes/notes/logging-9c452e4869d80de9.yaml
new file mode 100644
index 000000000..24f2311e9
--- /dev/null
+++ b/releasenotes/notes/logging-9c452e4869d80de9.yaml
@@ -0,0 +1,9 @@
+---
+fixes:
+  - |
+    OpenStackSDK log messages are no longer sent to stdout and no longer break
+    parsing the output.
+  - |
+    The logging configuration now respects the ``--verbose`` flag.
+  - |
+    Some warnings are no longer duplicated.