python: Try harder to print the full traceback on error.

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.

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;

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

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