From a63438cb5b12e2a6973fb0e1b0b9ebce2f8116b6 Mon Sep 17 00:00:00 2001
From: melanie witt <melwittt@gmail.com>
Date: Thu, 14 Dec 2017 18:37:12 +0000
Subject: [PATCH] Truncate error_summary if exc_info not explicitly passed

Currently, when logging at level >= WARNING, exception information is
added to the log message as an "error summary" for operators. The error
summary includes the exception type and the message. However, when the
exception is a _Remote exception generated from oslo.messaging and sent
over RPC, the full traceback from the exception is appended to the
exception message [1] to preserve it. So, the error summary ends up
outputting the full traceback, unintentionally.

This truncates the error_summary to keep only the first line unless
exc_info was explicitly passed, via LOG.exception(), for example.

Closes-Bug: #1729475

[1] https://github.com/openstack/oslo.messaging/blob/8d42484/oslo_messaging/_drivers/common.py#L208

Change-Id: I2e4e356d23dff2e6ac1946fe9e994c4d962ab55a
---
 oslo_log/formatters.py          |  7 +++++++
 oslo_log/tests/unit/test_log.py | 24 ++++++++++++++++++++++++
 2 files changed, 31 insertions(+)

diff --git a/oslo_log/formatters.py b/oslo_log/formatters.py
index eaf83e68..9277856c 100644
--- a/oslo_log/formatters.py
+++ b/oslo_log/formatters.py
@@ -156,6 +156,13 @@ def _get_error_summary(record):
                 exc_info[0],
                 exc_info[1],
             )[0].rstrip()
+            # If the exc_info wasn't explicitly passed to us, take only the
+            # first line of it. _Remote exceptions from oslo.messaging append
+            # the full traceback to the exception message, so we want to avoid
+            # outputting the traceback unless we've been passed exc_info
+            # directly (via LOG.exception(), for example).
+            if not record.exc_info:
+                error_summary = error_summary.split('\n', 1)[0]
         except TypeError as type_err:
             # Work around https://bugs.python.org/issue28603
             error_summary = "<exception with %s>" % six.text_type(type_err)
diff --git a/oslo_log/tests/unit/test_log.py b/oslo_log/tests/unit/test_log.py
index b656d8f9..c8270577 100644
--- a/oslo_log/tests/unit/test_log.py
+++ b/oslo_log/tests/unit/test_log.py
@@ -541,6 +541,30 @@ class JSONFormatterTestCase(LogTestBase):
         self.assertIn('error_summary', data)
         self.assertEqual('', data['error_summary'])
 
+    def test_exception_without_exc_info_passed(self):
+        ctxt = _fake_context()
+        ctxt.request_id = six.text_type('99')
+        try:
+            raise RuntimeError('test_exception\ntraceback\nfrom\nremote error')
+        except RuntimeError:
+            self.log.warning('testing', context=ctxt)
+        data = jsonutils.loads(self.stream.getvalue())
+        self.assertIn('error_summary', data)
+        self.assertEqual('RuntimeError: test_exception', data['error_summary'])
+
+    def test_exception_with_exc_info_passed(self):
+        ctxt = _fake_context()
+        ctxt.request_id = six.text_type('99')
+        try:
+            raise RuntimeError('test_exception\ntraceback\nfrom\nremote error')
+        except RuntimeError:
+            self.log.exception('testing', context=ctxt)
+        data = jsonutils.loads(self.stream.getvalue())
+        self.assertIn('error_summary', data)
+        self.assertEqual('RuntimeError: test_exception'
+                         '\ntraceback\nfrom\nremote error',
+                         data['error_summary'])
+
     def test_fallback(self):
         if not formatters._HAVE_JSONUTILS_FALLBACK:
             self.skipTest("need the fallback parameter of "