Here's a patch implementing traceback support for PL/Python mentioned in
http://archives.postgresql.org/pgsql-hackers/2010-12/msg01991.php. It's
an incremental patch on top of the plpython-refactor patch sent eariler.
Git branch for this patch:
https://github.com/wulczer/postgres/tree/tracebacks.
It's a variant of
http://archives.postgresql.org/pgsql-patches/2006-02/msg00288.php with a
few more twists.
For errors originating from Python exceptions add the traceback as the
message detail. The patch tries to mimick Python's traceback.py module
behaviour as close as possible, icluding interleaving stack frames with
source code lines in the detail message. Any Python developer should
instantly recognize these kind of error reporting, it looks almost the
same as an error in the interactive Python shell.
A future optimisation might be not splitting the procedure source each
time a traceback is generated, but for now it's probably not the most
important scenario to optimise for.
Cheers,
Jan
diff --git a/src/pl/plpython/expected/plpython_do.out b/src/pl/plpython/expected/plpython_do.out
index a21b088..fb0f0e5 100644
*** a/src/pl/plpython/expected/plpython_do.out
--- b/src/pl/plpython/expected/plpython_do.out
*************** NOTICE: This is plpythonu.
*** 3,6 ****
--- 3,9 ----
CONTEXT: PL/Python anonymous code block
DO $$ nonsense $$ LANGUAGE plpythonu;
ERROR: NameError: global name 'nonsense' is not defined
+ DETAIL: Traceback (most recent call last):
+ PL/Python anonymous code block, line 1, in <module>
+ nonsense
CONTEXT: PL/Python anonymous code block
diff --git a/src/pl/plpython/expected/plpython_error.out b/src/pl/plpython/expected/plpython_error.out
index 70890a8..fe8a91f 100644
*** a/src/pl/plpython/expected/plpython_error.out
--- b/src/pl/plpython/expected/plpython_error.out
*************** SELECT sql_syntax_error();
*** 11,16 ****
--- 11,19 ----
WARNING: plpy.SPIError: unrecognized error in PLy_spi_execute_query
CONTEXT: PL/Python function "sql_syntax_error"
ERROR: plpy.SPIError: syntax error at or near "syntax"
+ DETAIL: Traceback (most recent call last):
+ PL/Python function "sql_syntax_error", line 1, in <module>
+ plpy.execute("syntax error")
CONTEXT: PL/Python function "sql_syntax_error"
/* check the handling of uncaught python exceptions
*/
*************** CREATE FUNCTION exception_index_invalid(
*** 20,25 ****
--- 23,31 ----
LANGUAGE plpythonu;
SELECT exception_index_invalid('test');
ERROR: IndexError: list index out of range
+ DETAIL: Traceback (most recent call last):
+ PL/Python function "exception_index_invalid", line 1, in <module>
+ return args[1]
CONTEXT: PL/Python function "exception_index_invalid"
/* check handling of nested exceptions
*/
*************** SELECT exception_index_invalid_nested();
*** 32,37 ****
--- 38,46 ----
WARNING: plpy.SPIError: unrecognized error in PLy_spi_execute_query
CONTEXT: PL/Python function "exception_index_invalid_nested"
ERROR: plpy.SPIError: function test5(unknown) does not exist
+ DETAIL: Traceback (most recent call last):
+ PL/Python function "exception_index_invalid_nested", line 1, in <module>
+ rv = plpy.execute("SELECT test5('foo')")
CONTEXT: PL/Python function "exception_index_invalid_nested"
/* a typo
*/
*************** SELECT invalid_type_uncaught('rick');
*** 50,55 ****
--- 59,67 ----
WARNING: plpy.SPIError: unrecognized error in PLy_spi_prepare
CONTEXT: PL/Python function "invalid_type_uncaught"
ERROR: plpy.SPIError: type "test" does not exist
+ DETAIL: Traceback (most recent call last):
+ PL/Python function "invalid_type_uncaught", line 3, in <module>
+ SD["plan"] = plpy.prepare(q, [ "test" ])
CONTEXT: PL/Python function "invalid_type_uncaught"
/* for what it's worth catch the exception generated by
* the typo, and return None
*************** SELECT invalid_type_reraised('rick');
*** 100,105 ****
--- 112,120 ----
WARNING: plpy.SPIError: unrecognized error in PLy_spi_prepare
CONTEXT: PL/Python function "invalid_type_reraised"
ERROR: plpy.Error: type "test" does not exist
+ DETAIL: Traceback (most recent call last):
+ PL/Python function "invalid_type_reraised", line 6, in <module>
+ plpy.error(str(ex))
CONTEXT: PL/Python function "invalid_type_reraised"
/* no typo no messing about
*/
*************** SELECT valid_type('rick');
*** 119,121 ****
--- 134,231 ----
(1 row)
+ /* error in nested functions to get a traceback
+ */
+ CREATE FUNCTION nested_error() RETURNS text
+ AS
+ 'def fun1():
+ plpy.error("boom")
+
+ def fun2():
+ fun1()
+
+ def fun3():
+ fun2()
+
+ fun3()
+ return "not reached"
+ '
+ LANGUAGE plpythonu;
+ SELECT nested_error();
+ ERROR: plpy.Error: boom
+ DETAIL: Traceback (most recent call last):
+ PL/Python function "nested_error", line 10, in <module>
+ fun3()
+ PL/Python function "nested_error", line 8, in fun3
+ fun2()
+ PL/Python function "nested_error", line 5, in fun2
+ fun1()
+ PL/Python function "nested_error", line 2, in fun1
+ plpy.error("boom")
+ CONTEXT: PL/Python function "nested_error"
+ /* raising plpy.Error is just like calling plpy.error
+ */
+ CREATE FUNCTION nested_error_raise() RETURNS text
+ AS
+ 'def fun1():
+ raise plpy.Error("boom")
+
+ def fun2():
+ fun1()
+
+ def fun3():
+ fun2()
+
+ fun3()
+ return "not reached"
+ '
+ LANGUAGE plpythonu;
+ SELECT nested_error_raise();
+ ERROR: plpy.Error: boom
+ DETAIL: Traceback (most recent call last):
+ PL/Python function "nested_error_raise", line 10, in <module>
+ fun3()
+ PL/Python function "nested_error_raise", line 8, in fun3
+ fun2()
+ PL/Python function "nested_error_raise", line 5, in fun2
+ fun1()
+ PL/Python function "nested_error_raise", line 2, in fun1
+ raise plpy.Error("boom")
+ CONTEXT: PL/Python function "nested_error_raise"
+ /* using plpy.warning should not produce a traceback
+ */
+ CREATE FUNCTION nested_warning() RETURNS text
+ AS
+ 'def fun1():
+ plpy.warning("boom")
+
+ def fun2():
+ fun1()
+
+ def fun3():
+ fun2()
+
+ fun3()
+ return "you''ve been warned"
+ '
+ LANGUAGE plpythonu;
+ SELECT nested_warning();
+ WARNING: boom
+ CONTEXT: PL/Python function "nested_warning"
+ nested_warning
+ --------------------
+ you've been warned
+ (1 row)
+
+ /* AttirbuteError at toplevel used to give segfaults with the traceback
+ */
+ CREATE FUNCTION toplevel_attribute_error() RETURNS void AS
+ $$
+ plpy.nonexistent
+ $$ LANGUAGE plpythonu;
+ SELECT toplevel_attribute_error();
+ ERROR: AttributeError: 'module' object has no attribute 'nonexistent'
+ DETAIL: Traceback (most recent call last):
+ PL/Python function "toplevel_attribute_error", line 2, in <module>
+ plpy.nonexistent
+ CONTEXT: PL/Python function "toplevel_attribute_error"
diff --git a/src/pl/plpython/expected/plpython_test.out b/src/pl/plpython/expected/plpython_test.out
index d92c987..f3bdb3b 100644
*** a/src/pl/plpython/expected/plpython_test.out
--- b/src/pl/plpython/expected/plpython_test.out
*************** CONTEXT: PL/Python function "elog_test"
*** 74,77 ****
--- 74,80 ----
WARNING: warning
CONTEXT: PL/Python function "elog_test"
ERROR: plpy.Error: error
+ DETAIL: Traceback (most recent call last):
+ PL/Python function "elog_test", line 10, in <module>
+ plpy.error('error')
CONTEXT: PL/Python function "elog_test"
diff --git a/src/pl/plpython/plpython.c b/src/pl/plpython/plpython.c
index 67eb0f3..8e549bd 100644
*** a/src/pl/plpython/plpython.c
--- b/src/pl/plpython/plpython.c
*************** typedef int Py_ssize_t;
*** 71,76 ****
--- 71,77 ----
*/
#if PY_MAJOR_VERSION >= 3
#define PyInt_FromLong(x) PyLong_FromLong(x)
+ #define PyInt_AsLong(x) PyLong_AsLong(x)
#endif
/*
*************** typedef struct PLyProcedure
*** 208,213 ****
--- 209,215 ----
* type */
bool is_setof; /* true, if procedure returns result set */
PyObject *setof; /* contents of result set. */
+ char *src; /* textual procedure code, after mangling */
char **argnames; /* Argument names */
PLyTypeInfo args[FUNC_MAX_ARGS];
int nargs;
*************** static char *PLy_procedure_name(PLyProce
*** 288,294 ****
static void
PLy_elog(int, const char *,...)
__attribute__((format(printf, 2, 3)));
! static char *PLy_traceback(int *);
static void *PLy_malloc(size_t);
static void *PLy_malloc0(size_t);
--- 290,296 ----
static void
PLy_elog(int, const char *,...)
__attribute__((format(printf, 2, 3)));
! static void PLy_traceback(char **, char **, int*, int *);
static void *PLy_malloc(size_t);
static void *PLy_malloc0(size_t);
*************** PLy_function_handler(FunctionCallInfo fc
*** 1056,1064 ****
PLy_function_delete_args(proc);
if (has_error)
! ereport(ERROR,
! (errcode(ERRCODE_DATA_EXCEPTION),
! errmsg("error fetching next item from iterator")));
/* Disconnect from the SPI manager before returning */
if (SPI_finish() != SPI_OK_FINISH)
--- 1058,1064 ----
PLy_function_delete_args(proc);
if (has_error)
! PLy_elog(ERROR, "error fetching next item from iterator");
/* Disconnect from the SPI manager before returning */
if (SPI_finish() != SPI_OK_FINISH)
*************** PLy_procedure_create(HeapTuple procTup,
*** 1523,1528 ****
--- 1523,1529 ----
proc->is_setof = procStruct->proretset;
proc->setof = NULL;
proc->argnames = NULL;
+ proc->src = NULL;
PG_TRY();
{
*************** PLy_procedure_compile(PLyProcedure *proc
*** 1590,1595 ****
--- 1591,1598 ----
* insert the function code into the interpreter
*/
msrc = PLy_procedure_munge_source(proc->pyname, src);
+ /* Save the mangled source for later inclusion in tracebacks */
+ proc->src = PLy_strdup(msrc);
crv = PyRun_String(msrc, Py_file_input, proc->globals, NULL);
pfree(msrc);
*************** PLy_procedure_delete(PLyProcedure *proc)
*** 1687,1692 ****
--- 1690,1697 ----
if (proc->argnames && proc->argnames[i])
PLy_free(proc->argnames[i]);
}
+ if (proc->src)
+ PLy_free(proc->src);
if (proc->argnames)
PLy_free(proc->argnames);
}
*************** PLy_exception_set_plural(PyObject *exc,
*** 3564,3625 ****
* the current Python error, previously set by PLy_exception_set().
* This should be used to propagate Python errors into PG. If fmt is
* NULL, the Python error becomes the primary error message, otherwise
! * it becomes the detail.
*/
static void
PLy_elog(int elevel, const char *fmt,...)
{
! char *xmsg;
! int xlevel;
! StringInfoData emsg;
! xmsg = PLy_traceback(&xlevel);
if (fmt)
{
! initStringInfo(&emsg);
for (;;)
{
va_list ap;
bool success;
va_start(ap, fmt);
! success = appendStringInfoVA(&emsg, dgettext(TEXTDOMAIN, fmt), ap);
va_end(ap);
if (success)
break;
! enlargeStringInfo(&emsg, emsg.maxlen);
}
}
PG_TRY();
{
if (fmt)
! ereport(elevel,
! (errmsg("%s", emsg.data),
! (xmsg) ? errdetail("%s", xmsg) : 0));
else
ereport(elevel,
! (errmsg("%s", xmsg)));
}
PG_CATCH();
{
! if (fmt)
! pfree(emsg.data);
if (xmsg)
pfree(xmsg);
PG_RE_THROW();
}
PG_END_TRY();
! if (fmt)
! pfree(emsg.data);
if (xmsg)
pfree(xmsg);
}
static char *
! PLy_traceback(int *xlevel)
{
PyObject *e,
*v,
--- 3569,3698 ----
* the current Python error, previously set by PLy_exception_set().
* This should be used to propagate Python errors into PG. If fmt is
* NULL, the Python error becomes the primary error message, otherwise
! * it becomes the detail. If there is a Python traceback, it is also put
! * in the detail.
*/
static void
PLy_elog(int elevel, const char *fmt,...)
{
! char *fmsg = NULL;
! char *emsg = NULL;
! char *xmsg = NULL;
! int tb_depth = 0;
! int errorposition = 0;
! /* this is a no-op if there is no current Python exception */
! PLy_traceback(&emsg, &xmsg, &tb_depth, &errorposition);
if (fmt)
{
! StringInfoData si;
! initStringInfo(&si);
for (;;)
{
va_list ap;
bool success;
va_start(ap, fmt);
! success = appendStringInfoVA(&si, dgettext(TEXTDOMAIN, fmt), ap);
va_end(ap);
if (success)
break;
! enlargeStringInfo(&si, si.maxlen);
}
+ fmsg = si.data;
}
PG_TRY();
{
+ /* If we have a format string, it should be the main error message and
+ * the emsg + traceback the detailed message.
+ *
+ * If we don't have fmsg, we should use emsg as the main error message
+ * (and failing that just say "no exception data") and put the
+ * traceback in the detail.
+ *
+ * The traceback is present if tb_depth > 0.
+ */
if (fmt)
! {
! if (tb_depth > 0)
! {
! ereport(elevel,
! (errmsg("%s", fmsg),
! emsg ? errdetail("%s\n%s", emsg, xmsg) : 0));
! }
! else
! {
! ereport(elevel,
! (errmsg("%s", fmsg),
! emsg ? errdetail("%s", emsg) : 0));
! }
! }
else
+ {
ereport(elevel,
! (errmsg("%s", emsg ? emsg : "no exception data"),
! (tb_depth > 0) ? errdetail("%s", xmsg) : 0));
! }
}
PG_CATCH();
{
! if (fmsg)
! pfree(fmsg);
! if (emsg)
! pfree(emsg);
if (xmsg)
pfree(xmsg);
PG_RE_THROW();
}
PG_END_TRY();
! pfree(emsg);
if (xmsg)
pfree(xmsg);
}
+ /* Get the given source line as a palloc'd string */
static char *
! get_source_line(char *src, int lineno)
! {
! char *s;
! char *next;
! int current = 0;
!
! next = src;
! while (current != lineno)
! {
! s = next;
! next = strchr(s + 1, '\n');
! current++;
! if (next == NULL)
! break;
! }
!
! if (current != lineno)
! return NULL;
!
! while (s && isspace(*s))
! s++;
!
! if (next == NULL)
! return pstrdup(s);
!
! return pnstrdup(s, next - s);
! }
!
! /*
! * Extract a Python traceback from the current exception.
! *
! * The exception error message is returned in emsg, the traceback in xmsg (both
! * as palloc's strings) and the traceback depth in tb_depth. errorposition is
! * the position of the error pointer, currently always set to 0, but we could
! * try to extract it for syntax errors.
! */
! static void
! PLy_traceback(char **emsg, char **xmsg, int *tb_depth, int *errorposition)
{
PyObject *e,
*v,
*************** PLy_traceback(int *xlevel)
*** 3630,3635 ****
--- 3703,3709 ----
char *e_module_s = NULL;
PyObject *vob = NULL;
char *vstr;
+ StringInfoData estr;
StringInfoData xstr;
/*
*************** PLy_traceback(int *xlevel)
*** 3641,3653 ****
* oops, no exception, return
*/
if (e == NULL)
! {
! *xlevel = WARNING;
! return NULL;
! }
PyErr_NormalizeException(&e, &v, &tb);
! Py_XDECREF(tb);
e_type_o = PyObject_GetAttrString(e, "__name__");
e_module_o = PyObject_GetAttrString(e, "__module__");
--- 3715,3725 ----
* oops, no exception, return
*/
if (e == NULL)
! return;
PyErr_NormalizeException(&e, &v, &tb);
!
! /* format the exception and its value and put it in emsg */
e_type_o = PyObject_GetAttrString(e, "__name__");
e_module_o = PyObject_GetAttrString(e, "__module__");
*************** PLy_traceback(int *xlevel)
*** 3661,3702 ****
else
vstr = "unknown";
! initStringInfo(&xstr);
if (!e_type_s || !e_module_s)
{
if (PyString_Check(e))
/* deprecated string exceptions */
! appendStringInfoString(&xstr, PyString_AsString(e));
else
/* shouldn't happen */
! appendStringInfoString(&xstr, "unrecognized exception");
}
/* mimics behavior of traceback.format_exception_only */
else if (strcmp(e_module_s, "builtins") == 0
|| strcmp(e_module_s, "__main__") == 0
|| strcmp(e_module_s, "exceptions") == 0)
! appendStringInfo(&xstr, "%s", e_type_s);
else
! appendStringInfo(&xstr, "%s.%s", e_module_s, e_type_s);
! appendStringInfo(&xstr, ": %s", vstr);
Py_XDECREF(e_type_o);
Py_XDECREF(e_module_o);
Py_XDECREF(vob);
Py_XDECREF(v);
-
- /*
- * intuit an appropriate error level based on the exception type
- */
- if (PLy_exc_error && PyErr_GivenExceptionMatches(e, PLy_exc_error))
- *xlevel = ERROR;
- else if (PLy_exc_fatal && PyErr_GivenExceptionMatches(e, PLy_exc_fatal))
- *xlevel = FATAL;
- else
- *xlevel = ERROR;
-
Py_DECREF(e);
- return xstr.data;
}
/* python module code */
--- 3733,3870 ----
else
vstr = "unknown";
! initStringInfo(&estr);
if (!e_type_s || !e_module_s)
{
if (PyString_Check(e))
/* deprecated string exceptions */
! appendStringInfoString(&estr, PyString_AsString(e));
else
/* shouldn't happen */
! appendStringInfoString(&estr, "unrecognized exception");
}
/* mimics behavior of traceback.format_exception_only */
else if (strcmp(e_module_s, "builtins") == 0
|| strcmp(e_module_s, "__main__") == 0
|| strcmp(e_module_s, "exceptions") == 0)
! appendStringInfo(&estr, "%s", e_type_s);
else
! appendStringInfo(&estr, "%s.%s", e_module_s, e_type_s);
! appendStringInfo(&estr, ": %s", vstr);
!
! *emsg = estr.data;
!
! /* now format the traceback and put it in xmsg */
! *tb_depth = 0;
! initStringInfo(&xstr);
! /* Mimick Python traceback reporting as close as possible */
! appendStringInfoString(&xstr, "Traceback (most recent call last):");
! while (tb != NULL && tb != Py_None)
! {
! PyObject *volatile tb_prev = NULL;
! PyObject *volatile frame = NULL;
! PyObject *volatile code = NULL;
! PyObject *volatile name = NULL;
! PyObject *volatile lineno = NULL;
!
! PG_TRY();
! {
! lineno = PyObject_GetAttrString(tb, "tb_lineno");
! if (lineno == NULL)
! elog(ERROR, "could not get line number from Python traceback");
!
! frame = PyObject_GetAttrString(tb, "tb_frame");
! if (frame == NULL)
! elog(ERROR, "could not get frame from Python traceback");
!
! code = PyObject_GetAttrString(frame, "f_code");
! if (code == NULL)
! elog(ERROR, "could not get code object from Python frame");
!
! name = PyObject_GetAttrString(code, "co_name");
! if (name == NULL)
! elog(ERROR, "could not get function name from Python code object");
! }
! PG_CATCH();
! {
! Py_XDECREF(frame);
! Py_XDECREF(code);
! Py_XDECREF(name);
! Py_XDECREF(lineno);
! PG_RE_THROW();
! }
! PG_END_TRY();
!
! /* The first frame always points at <module>, skip it */
! if (*tb_depth > 0)
! {
! char *proname;
! char *fname;
! char *line;
! long plain_lineno;
!
! /*
! * The second frame points at the internal function, but to mimick
! * Python error reporting we want to say <module>
! */
! if (*tb_depth == 1)
! fname = "<module>";
! else
! fname = PyString_AsString(name);
!
! proname = PLy_procedure_name(PLy_curr_procedure);
! plain_lineno = PyInt_AsLong(lineno);
!
! if (proname == NULL)
! appendStringInfo(
! &xstr, "\n PL/Python anonymous code block, line %ld, in %s",
! plain_lineno - 1, fname);
! else
! appendStringInfo(
! &xstr, "\n PL/Python function \"%s\", line %ld, in %s",
! proname, plain_lineno - 1, fname);
!
! if (PLy_curr_procedure)
! {
! /*
! * If we know the current procedure, append the exact line from
! * the source, again mimicking Python's traceback.py module
! * behaviour. We could store the already line-splitted source
! * to avoid splitting it every time, but producing a traceback
! * is not the most important scenario to optimise for.
! */
! line = get_source_line(PLy_curr_procedure->src, plain_lineno);
! if (line != NULL)
! {
! appendStringInfo(&xstr, "\n %s", line);
! pfree(line);
! }
! }
! }
!
! Py_DECREF(frame);
! Py_DECREF(code);
! Py_DECREF(name);
! Py_DECREF(lineno);
!
! /* Release the current frame and go to the next one */
! tb_prev = tb;
! tb = PyObject_GetAttrString(tb, "tb_next");
! Assert(tb_prev != Py_None);
! Py_DECREF(tb_prev);
! if (tb == NULL)
! elog(ERROR, "could not traverse Python traceback");
! (*tb_depth)++;
! }
!
! /* Return the traceback */
! *xmsg = xstr.data;
Py_XDECREF(e_type_o);
Py_XDECREF(e_module_o);
Py_XDECREF(vob);
Py_XDECREF(v);
Py_DECREF(e);
}
/* python module code */
diff --git a/src/pl/plpython/sql/plpython_error.sql b/src/pl/plpython/sql/plpython_error.sql
index 5ca6849..e9b819c 100644
*** a/src/pl/plpython/sql/plpython_error.sql
--- b/src/pl/plpython/sql/plpython_error.sql
*************** return None
*** 107,109 ****
--- 107,178 ----
LANGUAGE plpythonu;
SELECT valid_type('rick');
+
+ /* error in nested functions to get a traceback
+ */
+ CREATE FUNCTION nested_error() RETURNS text
+ AS
+ 'def fun1():
+ plpy.error("boom")
+
+ def fun2():
+ fun1()
+
+ def fun3():
+ fun2()
+
+ fun3()
+ return "not reached"
+ '
+ LANGUAGE plpythonu;
+
+ SELECT nested_error();
+
+ /* raising plpy.Error is just like calling plpy.error
+ */
+ CREATE FUNCTION nested_error_raise() RETURNS text
+ AS
+ 'def fun1():
+ raise plpy.Error("boom")
+
+ def fun2():
+ fun1()
+
+ def fun3():
+ fun2()
+
+ fun3()
+ return "not reached"
+ '
+ LANGUAGE plpythonu;
+
+ SELECT nested_error_raise();
+
+ /* using plpy.warning should not produce a traceback
+ */
+ CREATE FUNCTION nested_warning() RETURNS text
+ AS
+ 'def fun1():
+ plpy.warning("boom")
+
+ def fun2():
+ fun1()
+
+ def fun3():
+ fun2()
+
+ fun3()
+ return "you''ve been warned"
+ '
+ LANGUAGE plpythonu;
+
+ SELECT nested_warning();
+
+ /* AttirbuteError at toplevel used to give segfaults with the traceback
+ */
+ CREATE FUNCTION toplevel_attribute_error() RETURNS void AS
+ $$
+ plpy.nonexistent
+ $$ LANGUAGE plpythonu;
+
+ SELECT toplevel_attribute_error();
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
