From c713e3337d1227db68a4088096cd19ffed746e9f Mon Sep 17 00:00:00 2001
From: "Richard W.M. Jones" <rjones@redhat.com>
Date: Wed, 8 Aug 2018 13:50:23 +0100
Subject: [PATCH] python: Try harder to print the full traceback on error.
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

The tracebacks are compressed into a single line because we're using
PyObject_Str, but they are just about usable if not very readable.
For example you would see an error like this:

nbdkit: error: ./python-exception.py: config_complete: error: ['Traceback (most recent call last):\n', '  File "./python-exception.py", line 54, in config_complete\n    raise_error1()\n', '  File "./python-exception.py", line 48, in raise_error1\n    raise_error2()\n', '  File "./python-exception.py", line 45, in raise_error2\n    raise RuntimeError("this is the test string")\n', 'RuntimeError: this is the test string\n']

which can be read by manually unfolding the exception in an editor as:

nbdkit: error: ./python-exception.py: config_complete: error:
Traceback (most recent call last):
  File "./python-exception.py", line 54, in config_complete
    raise_error1()
  File "./python-exception.py", line 48, in raise_error1
    raise_error2()
  File "./python-exception.py", line 45, in raise_error2
    raise RuntimeError("this is the test string")
RuntimeError: this is the test string

This also fixes the Python exception test:

(1) It originally was not testing anything.  Adding ‘set -e’ fixes
that.

(2) The valgrind test is always broken because of Python itself.
Skip the test under valgrind.

(3) This now tests both simple exceptions and full tracebacks.

Tested with Python 2.7.15 & 3.6.6.

(cherry picked from commit 72c0d64a47db642cafa89884f2ee554bd0b8e822)
---
 plugins/python/python.c        | 93 +++++++++++++++++++++++++++++++++++-------
 tests/python-exception.py      | 20 ++++++++-
 tests/test-python-exception.sh | 20 ++++++++-
 3 files changed, 117 insertions(+), 16 deletions(-)

diff --git a/plugins/python/python.c b/plugins/python/python.c
index 7eb91d7..ef1a2cf 100644
--- a/plugins/python/python.c
+++ b/plugins/python/python.c
@@ -129,27 +129,92 @@ python_to_string (PyObject *str)
   return NULL;
 }
 
+/* This is the fallback in case we cannot get the full traceback. */
+static void
+print_python_error (const char *callback, PyObject *error)
+{
+  PyObject *error_str;
+  char *error_cstr = NULL;
+
+  error_str = PyObject_Str (error);
+  error_cstr = python_to_string (error_str);
+  nbdkit_error ("%s: %s: error: %s",
+                script, callback,
+                error_cstr ? error_cstr : "<unknown>");
+  Py_DECREF (error_str);
+  free (error_cstr);
+}
+
+/* Convert the Python traceback to a string and call nbdkit_error.
+ * https://stackoverflow.com/a/15907460/7126113
+ */
+static int
+print_python_traceback (const char *callback,
+                        PyObject *type, PyObject *error, PyObject *traceback)
+{
+  PyObject *module_name, *traceback_module, *format_exception_fn, *rv,
+    *traceback_str;
+  char *traceback_cstr;
+
+#ifdef HAVE_PYSTRING_FROMSTRING
+  module_name = PyString_FromString ("traceback");
+#else
+  module_name = PyUnicode_FromString ("traceback");
+#endif
+  traceback_module = PyImport_Import (module_name);
+  Py_DECREF (module_name);
+
+  /* couldn't 'import traceback' */
+  if (traceback_module == NULL)
+    return -1;
+
+  format_exception_fn = PyObject_GetAttrString (traceback_module,
+                                                "format_exception");
+  if (format_exception_fn == NULL)
+    return -1;
+  if (!PyCallable_Check (format_exception_fn))
+    return -1;
+
+  rv = PyObject_CallFunctionObjArgs (format_exception_fn,
+                                     type, error, traceback, NULL);
+  traceback_str = PyObject_Str (rv);
+  Py_DECREF (rv);
+  traceback_cstr = python_to_string (traceback_str);
+  if (traceback_cstr == NULL) {
+    Py_DECREF (traceback_str);
+    return -1;
+  }
+
+  nbdkit_error ("%s: %s: error: %s",
+                script, callback,
+                traceback_cstr);
+  Py_DECREF (traceback_str);
+  free (traceback_cstr);
+
+  /* This means we succeeded in calling nbdkit_error. */
+  return 0;
+}
+
 static int
 check_python_failure (const char *callback)
 {
   if (PyErr_Occurred ()) {
-    PyObject *type, *error, *traceback, *error_str;
-    char *error_cstr;
+    PyObject *type, *error, *traceback;
 
-    /* Convert the Python exception to a string.
-     * https://stackoverflow.com/a/1418703
-     * But forget about the traceback, it's very hard to print.
-     * https://stackoverflow.com/q/1796510
-     */
     PyErr_Fetch (&type, &error, &traceback);
     PyErr_NormalizeException (&type, &error, &traceback);
-    error_str = PyObject_Str (error);
-    error_cstr = python_to_string (error_str);
-    nbdkit_error ("%s: %s: error: %s",
-                  script, callback,
-                  error_cstr ? error_cstr : "<unknown>");
-    Py_DECREF (error_str);
-    free (error_cstr);
+
+    /* Try to print the full traceback. */
+    if (print_python_traceback (callback, type, error, traceback) == -1) {
+      /* Couldn't do that, so fall back to converting the Python error
+       * to a string.
+       */
+      print_python_error (callback, error);
+    }
+
+    /* In all cases this returns -1 to indicate that a Python error
+     * occurred.
+     */
     return -1;
   }
   return 0;
diff --git a/tests/python-exception.py b/tests/python-exception.py
index 1debf51..739057f 100644
--- a/tests/python-exception.py
+++ b/tests/python-exception.py
@@ -32,10 +32,28 @@
 
 # A dummy python plugin which just raises an exception in config_complete.
 
+test = "simple"
 
-def config_complete():
+def config(k, v):
+    global test
+    if k == "test":
+        test = v
+    else:
+        raise RuntimeError("unknown config parameter")
+
+def raise_error2():
     raise RuntimeError("this is the test string")
 
+def raise_error1():
+    raise_error2()
+
+def config_complete():
+    if test == "simple":
+        raise RuntimeError("this is the test string")
+    elif test == "traceback":
+        raise_error1()
+    else:
+        raise RuntimeError("unknown test")
 
 def open(readonly):
     return 1
diff --git a/tests/test-python-exception.sh b/tests/test-python-exception.sh
index 83999af..fd94827 100755
--- a/tests/test-python-exception.sh
+++ b/tests/test-python-exception.sh
@@ -31,12 +31,30 @@
 # OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
 # SUCH DAMAGE.
 
+set -e
+set -x
+
+# Python language leaks like a sieve as well as a lot of worrying
+# "Conditional jump or move depends on uninitialised value(s)".
+if test -n "$NBDKIT_VALGRIND"; then
+    echo "$0: skipping Python test under valgrind."
+    exit 77
+fi
+
 output=test-python-exception.out
 
 rm -f $output
 
-nbdkit -f -v python ./python-exception.py > $output 2>&1 ||:
+nbdkit -f -v python ./python-exception.py test=simple > $output 2>&1 ||:
+cat $output
 
 grep 'this is the test string' $output
 
+nbdkit -f -v python ./python-exception.py test=traceback > $output 2>&1 ||:
+cat $output
+
+grep 'raise_error1' $output
+grep 'raise_error2' $output
+grep 'this is the test string' $output
+
 rm $output
-- 
1.8.3.1