From b8b6b855d589a173ee9b0e59e1143475be80bc21 Mon Sep 17 00:00:00 2001
From: Marina Golosova <golosova.marina@gmail.com>
Date: Tue, 10 Jul 2018 16:51:13 +0300
Subject: [PATCH] pyDKB/logging: fix issue with multiline log message with
 arguments...

...and simplify logic of multiline formatting.

Previously multiline message with arguments would fail with error:
```
>>> pyDKB.logger.error("%(line1)s\n%(line2)s", {"line1": "First line",
... "line2": "Second line"})
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/logging/__init__.py", line 723,
in emit
    msg = self.format(record)
  File "/usr/lib/python2.6/site-packages/logging/__init__.py", line 609,
in format
    return fmt.format(record)
  File "/home/mgolosova/dkb/Utils/Dataflow/pyDKB/common/_logging.py",
line 162, in format
    result = (msg + extra + '\n'.join(lines[1:])) % record.__dict__
KeyError: 'line2'
```

Now the whole message goes to the `logger.Formatter.format()` function,
thus message with argumets works perfectly fine. Then we format the
suffix (as it is definitely the same for every line), and then
`formatExtra()` just adds prefixes for extra lines and suffixes to all
lines. It also saves from specific `formatException()` method, called
from `logger.Formatter.format()`, as we do not need to think about
prefixes and suffixes before the message is fully formatted and appended
with traceback info.

It also affects alignment: now suffix is aligned for all lines, not only
traceback ones.
---
 Utils/Dataflow/pyDKB/common/_logging.py | 36 +++++++++----------------
 1 file changed, 12 insertions(+), 24 deletions(-)

diff --git a/Utils/Dataflow/pyDKB/common/_logging.py b/Utils/Dataflow/pyDKB/common/_logging.py
index 8abb372a5..240fce093 100644
--- a/Utils/Dataflow/pyDKB/common/_logging.py
+++ b/Utils/Dataflow/pyDKB/common/_logging.py
@@ -102,55 +102,43 @@ def splitFormat(self, fmt):
             format = fmt
         return format, suffix
 
-    def formatExtra(self, lines, suffix=None, prefix="  (==) ", align=False):
+    def formatSuffix(self, record):
+        """ Return formatted suffix. """
+        return self._suffix % record.__dict__
+
+    def formatExtra(self, lines, prefix="  (==) ", suffix='', align=False):
         """ Format extra lines of the log message (traceback, ...).
 
         Parameter 'align' shows whether the suffix should be aligned
         to the right (by the longest line), or to the left (as for normal
         log messages).
         """
-        if suffix is None:
-            suffix = self._suffix
         if isinstance(lines, list) and len(lines):
             max_len = len(max(lines, key=len))
+            # Need to add prefix len (in case that the longest line is
+            # among those that will be prefixed).
+            max_len += len(prefix)
             if suffix and align:
                 line_fmt = "%%(line)-%ds" % max_len
             else:
                 line_fmt = "%(line)s"
-            extra = prefix + line_fmt % {'line': lines[0]} + suffix
+            extra = line_fmt % {'line': lines[0]} + suffix
             for line in lines[1:]:
-                extra += "\n" + prefix + line_fmt % {'line': line} + suffix
+                extra += "\n" + line_fmt % {'line': prefix + line} + suffix
         else:
             extra = ""
         return extra
 
-    def formatException(self, ei):
-        """ Format traceback as extra lines. """
-        s = super(MultilineFormatter, self).formatException(ei)
-        lines = s.splitlines()
-        exc_text = self.formatExtra(lines, align=True)
-        return exc_text
-
     def format(self, record):
         """ Format multiline message.
 
         Second and further lines from initial message are formatted
         'extra' lines.
         """
-        lines = record.msg.splitlines()
-        msg = lines[0] if lines else ''
-        extra = self.formatExtra(lines[1:])
-        if extra and extra[:1] != '\n':
-            extra = '\n' + extra
-        record.msg = msg
         formatted = super(MultilineFormatter, self).format(record)
         lines = formatted.splitlines()
-        msg = (lines[0] + self._suffix) if lines else ''
-        if len(lines) > 1:
-            extra += '\n'
-        # Need to expand suffixes (as they are added after parent`s
-        # 'format()' operation).
-        result = (msg + extra + '\n'.join(lines[1:])) % record.__dict__
+        suffix = self.formatSuffix(record)
+        result = self.formatExtra(lines, suffix=suffix, align=True)
         return result