On Wed, Aug 8, 2018 at 4:07 PM Richard W.M. Jones <rjones@redhat.com> wrote:
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

It would be nicer to join the lines before logging, but having the info in
the log is good enough.
 

This also fixes the Python exception test which, it turned out, was
not testing anything.  It now tests both simple exceptions and
tracebacks.

Tested with Python 2.7.15 & 3.6.6.
---
 plugins/python/python.c        | 92 ++++++++++++++++++++++++++++------
 tests/python-exception.py      | 20 +++++++-
 tests/test-python-exception.sh | 13 ++++-
 3 files changed, 109 insertions(+), 16 deletions(-)

diff --git a/plugins/python/python.c b/plugins/python/python.c
index 7eb91d7..3450b9b 100644
--- a/plugins/python/python.c
+++ b/plugins/python/python.c
@@ -129,27 +129,91 @@ 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);
+  traceback_cstr = python_to_string (traceback_str);
+  if (traceback_cstr == NULL) {
+    Py_DECREF (rv);
+    return -1;
+  }
+
+  nbdkit_error ("%s: %s: error: %s",
+                script, callback,
+                traceback_cstr);

Can we simplify this these 2 calls?

    nbdkit_error ("%s: %s: error", script, callback);
    PyErr_PrintEx (0);

See https://docs.python.org/3.6/c-api/exceptions.html#c.PyErr_PrintEx

In this case we don't to fallback to the simple error print.
 
+  Py_DECREF (rv);
+  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..7120132 100755
--- a/tests/test-python-exception.sh
+++ b/tests/test-python-exception.sh
@@ -31,12 +31,23 @@
 # OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
 # SUCH DAMAGE.

+set -e
+set -x
+
 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
--
2.18.0