Fix display to log severity mapping (#83712)

add caplevel to display to pass through
also reverse dict order as 'last update wins'
added tests ... and also log severity to log

Co-authored-by: Sloane Hertel <19572925+s-hertel@users.noreply.github.com>

changelogs/fragments/display_fix_log_severity.yml

@@ -0,0 +1,4 @@
+bugfixes:
+  - display now does a better job of mapping warnings/errors to the proper log severity when using ansible.log. We still use color as a fallback mapping (now prioritiezed by severity) but mostly rely on it beind directly set by warnning/errors calls.
+minor_changes:
+  - ansible.log now also shows log severity field

lib/ansible/utils/display.py

@@ -157,7 +157,7 @@ if getattr(C, 'DEFAULT_LOG_PATH'):
         if not os.path.isdir(path):
             # NOTE: level is kept at INFO to avoid security disclosures caused by certain libraries when using DEBUG
             logging.basicConfig(filename=path, level=logging.INFO,  # DO NOT set to logging.DEBUG
-                                format='%(asctime)s p=%(process)d u=%(user)s n=%(name)s | %(message)s')
+                                format='%(asctime)s p=%(process)d u=%(user)s n=%(name)s %(levelname)s| %(message)s')
 
             logger = logging.getLogger('ansible')
             for handler in logging.root.handlers:
@@ -168,16 +168,16 @@ if getattr(C, 'DEFAULT_LOG_PATH'):
     else:
         print(f"[WARNING]: log file at '{path}' is not writeable and we cannot create it, aborting\n", file=sys.stderr)
 
-# map color to log levels
-color_to_log_level = {C.COLOR_ERROR: logging.ERROR,
-                      C.COLOR_WARN: logging.WARNING,
+# map color to log levels, in order of priority (low to high)
+color_to_log_level = {C.COLOR_DEBUG: logging.DEBUG,
+                      C.COLOR_VERBOSE: logging.INFO,
                       C.COLOR_OK: logging.INFO,
-                      C.COLOR_SKIP: logging.WARNING,
-                      C.COLOR_UNREACHABLE: logging.ERROR,
-                      C.COLOR_DEBUG: logging.DEBUG,
                       C.COLOR_CHANGED: logging.INFO,
+                      C.COLOR_SKIP: logging.WARNING,
                       C.COLOR_DEPRECATE: logging.WARNING,
-                      C.COLOR_VERBOSE: logging.INFO}
+                      C.COLOR_WARN: logging.WARNING,
+                      C.COLOR_UNREACHABLE: logging.ERROR,
+                      C.COLOR_ERROR: logging.ERROR}
 
 b_COW_PATHS = (
     b"/usr/bin/cowsay",
@@ -401,6 +401,7 @@ class Display(metaclass=Singleton):
         screen_only: bool = False,
         log_only: bool = False,
         newline: bool = True,
+        caplevel: int | None = None,
     ) -> None:
         """ Display a message to the user
 
@@ -450,20 +451,28 @@ class Display(metaclass=Singleton):
             #         raise
 
         if logger and not screen_only:
-            self._log(nocolor, color)
+            self._log(nocolor, color, caplevel)
 
     def _log(self, msg: str, color: str | None = None, caplevel: int | None = None):
 
         if logger and (caplevel is None or self.log_verbosity > caplevel):
             msg2 = msg.lstrip('\n')
 
-            lvl = logging.INFO
-            if color:
+            if caplevel is None or caplevel > 0:
+                lvl = logging.INFO
+            elif caplevel == -1:
+                lvl = logging.ERROR
+            elif caplevel == -2:
+                lvl = logging.WARNING
+            elif caplevel == -3:
+                lvl = logging.DEBUG
+            elif color:
                 # set logger level based on color (not great)
+                # but last resort and backwards compatible
                 try:
                     lvl = color_to_log_level[color]
                 except KeyError:
-                    # this should not happen, but JIC
+                    # this should not happen if mapping is updated with new color configs, but JIC
                     raise AnsibleAssertionError('Invalid color supplied to display: %s' % color)
 
             # actually log
@@ -512,10 +521,10 @@ class Display(metaclass=Singleton):
     @_meets_debug
     @_proxy
     def debug(self, msg: str, host: str | None = None) -> None:
-        if host is None:
-            self.display("%6d %0.5f: %s" % (os.getpid(), time.time(), msg), color=C.COLOR_DEBUG)
-        else:
-            self.display("%6d %0.5f [%s]: %s" % (os.getpid(), time.time(), host, msg), color=C.COLOR_DEBUG)
+        prefix = "%6d %0.5f" % (os.getpid(), time.time())
+        if host is not None:
+            prefix += f" [{host}]"
+        self.display(f"{prefix}: {msg}", color=C.COLOR_DEBUG, caplevel=-3)
 
     def get_deprecation_message(
         self,
@@ -594,7 +603,7 @@ class Display(metaclass=Singleton):
             new_msg = "\n[WARNING]: \n%s" % msg
 
         if new_msg not in self._warns:
-            self.display(new_msg, color=C.COLOR_WARN, stderr=True)
+            self.display(new_msg, color=C.COLOR_WARN, stderr=True, caplevel=-2)
             self._warns[new_msg] = 1
 
     @_proxy
@@ -653,7 +662,7 @@ class Display(metaclass=Singleton):
         else:
             new_msg = u"ERROR! %s" % msg
         if new_msg not in self._errors:
-            self.display(new_msg, color=C.COLOR_ERROR, stderr=True)
+            self.display(new_msg, color=C.COLOR_ERROR, stderr=True, caplevel=-1)
             self._errors[new_msg] = 1
 
     @staticmethod

test/integration/targets/ansible_log/logit.yml

@@ -1,4 +1,12 @@
 - hosts: localhost
   gather_facts: false
   tasks:
-    - ping:
+    - name: normal task
+      ping:
+
+    - name: force warning
+      ping:
+      when: "{{pepe}} == 1"
+      vars:
+        lola: 1
+        pepe: lola

test/integration/targets/ansible_log/runme.sh

@@ -4,14 +4,21 @@ set -eux
 
 ALOG=${OUTPUT_DIR}/ansible_log_test.log
 
+# no log enabled
 ansible-playbook logit.yml
+# ensure file is not created
 [ ! -f "${ALOG}" ]
 
+# log enabled
 ANSIBLE_LOG_PATH=${ALOG} ansible-playbook logit.yml
+# ensure log file is created
 [ -f "${ALOG}" ]
-grep -q 'ping' "${ALOG}"
-
+# Ensure tasks and log levels appear
+grep -q '\[normal task\]' "${ALOG}"
+grep -q 'INFO| TASK \[force warning\]' "${ALOG}"
+grep -q 'WARNING| \[WARNING\]: conditional statements' "${ALOG}"
 rm "${ALOG}"
+
 # inline grep should fail if EXEC was present
 set +e
 ANSIBLE_LOG_PATH=${ALOG} ANSIBLE_LOG_VERBOSITY=3 ansible-playbook -v logit.yml | tee /dev/stderr | grep -q EXEC