errbacktrace

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
19 messages Options
Reply | Threaded
Open this post in threaded view
|

errbacktrace

Peter Eisentraut-6
New thread continuing from
<https://www.postgresql.org/message-id/d4903af2-e7b7-b551-71f8-3e4a6bdc2e73@...>.

Here is a extended version of Álvaro's patch that adds an errbacktrace()
function.  You can do two things with this:

- Manually attach it to an ereport() call site that you want to debug.

- Set a configuration parameter like backtrace_function = 'int8in' to
debug ereport()/elog() calls in a specific function.

There was also mention of settings that would automatically produce
backtraces for PANICs etc.  Those could surely be added if there is
enough interest.

For the implementation, I support both backtrace() provided by the OS as
well as using libunwind.  The former seems to be supported by a number
of platforms, including glibc, macOS, and FreeBSD, so maybe we don't
need the libunwind suport.  I haven't found any difference in quality in
the backtraces between the two approaches, but surely that is highly
dependent on the exact configuration.

I would welcome testing in all direction with this, to see how well it
works in different circumstances.

--
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

v2-0001-Add-errbacktrace-and-backtrace_function-GUC.patch (21K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Alvaro Herrera-9
On 2019-Jun-25, Peter Eisentraut wrote:

> Here is a extended version of Álvaro's patch that adds an errbacktrace()
> function.

Great stuff, thanks for working on it.

> You can do two things with this:
>
> - Manually attach it to an ereport() call site that you want to debug.
>
> - Set a configuration parameter like backtrace_function = 'int8in' to
> debug ereport()/elog() calls in a specific function.

WFM.  I tried specifying int4in -- didn't work.  Turns out the errors
are inside another function which is what I have to put in
backtrace_function:

$ PGOPTIONS="-c backtrace_function=pg_strtoint32" psql

alvherre=# select int 'foobar';

2019-06-25 10:03:51.034 -04 [11711] ERROR:  invalid input syntax for type integer: "foobar" at character 12
2019-06-25 10:03:51.034 -04 [11711] BACKTRACE:  postgres: alvherre alvherre [local] SELECT(pg_strtoint32+0xef) [0x55862737bdaf]
        postgres: alvherre alvherre [local] SELECT(int4in+0xd) [0x558627336d7d]
        postgres: alvherre alvherre [local] SELECT(InputFunctionCall+0x7b) [0x55862740b10b]
        postgres: alvherre alvherre [local] SELECT(OidInputFunctionCall+0x48) [0x55862740b378]
        postgres: alvherre alvherre [local] SELECT(coerce_type+0x297) [0x5586270b2f67]
        postgres: alvherre alvherre [local] SELECT(coerce_to_target_type+0x9d) [0x5586270b37ad]
        postgres: alvherre alvherre [local] SELECT(+0x1ed3d8) [0x5586270b83d8]
        postgres: alvherre alvherre [local] SELECT(transformExpr+0x18) [0x5586270bbcc8]
        postgres: alvherre alvherre [local] SELECT(transformTargetEntry+0xb2) [0x5586270c81c2]
        postgres: alvherre alvherre [local] SELECT(transformTargetList+0x58) [0x5586270c9808]
        postgres: alvherre alvherre [local] SELECT(transformStmt+0x9d1) [0x55862708caf1]
        postgres: alvherre alvherre [local] SELECT(parse_analyze+0x57) [0x55862708f177]
        postgres: alvherre alvherre [local] SELECT(pg_analyze_and_rewrite+0x12) [0x5586272d2f02]
        postgres: alvherre alvherre [local] SELECT(+0x4085ca) [0x5586272d35ca]
        postgres: alvherre alvherre [local] SELECT(PostgresMain+0x1a37) [0x5586272d52b7]
        postgres: alvherre alvherre [local] SELECT(+0xbf635) [0x558626f8a635]
        postgres: alvherre alvherre [local] SELECT(PostmasterMain+0xf3e) [0x55862724e27e]
        postgres: alvherre alvherre [local] SELECT(main+0x723) [0x558626f8c603]
        /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xe7) [0x7f99d1931b97]
        postgres: alvherre alvherre [local] SELECT(_start+0x2a) [0x558626f8c6ca]

Didn't think too much about the libunwind format string (or even try to
compile it.)

Despite possible shortcomings in the produced backtraces, this is a
*much* more convenient interface than requesting users to attach gdb,
set breakpoint on errfinish, hey why does my SQL not run, "oh you forgot
'cont' in gdb", etc.

> There was also mention of settings that would automatically produce
> backtraces for PANICs etc.  Those could surely be added if there is
> enough interest.

Let's have the basics first, we can add niceties afterwards.  (IMO yes,
we should have backtraces in PANICs and assertion failures).

--
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Ashwin Agrawal
In reply to this post by Peter Eisentraut-6

On Tue, Jun 25, 2019 at 4:08 AM Peter Eisentraut <[hidden email]> wrote:
New thread continuing from
<https://www.postgresql.org/message-id/d4903af2-e7b7-b551-71f8-3e4a6bdc2e73@...>.

Here is a extended version of Álvaro's patch that adds an errbacktrace()
function.  You can do two things with this:

- Manually attach it to an ereport() call site that you want to debug.

- Set a configuration parameter like backtrace_function = 'int8in' to
debug ereport()/elog() calls in a specific function.

Thank You. This is very helpful. Surprised is missing for so long time. We have printing backtrace in Greenplum and its extremely helpful during development and production.

There was also mention of settings that would automatically produce
backtraces for PANICs etc.  Those could surely be added if there is
enough interest.

In Greenplum, we have backtrace enabled for PANICs, SEGV/BUS/ILL and internal ERRORs, proves very helpful.

For the implementation, I support both backtrace() provided by the OS as
well as using libunwind.  The former seems to be supported by a number
of platforms, including glibc, macOS, and FreeBSD, so maybe we don't
need the libunwind suport.  I haven't found any difference in quality in
the backtraces between the two approaches, but surely that is highly
dependent on the exact configuration.

We have implemented it using backtrace(). Also, using addr2line() (or atos for mac) can convert addresses to file and line numbers before printing if available, to take it a step further.
Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Jaime Casanova-4
In reply to this post by Peter Eisentraut-6

On Tue, 25 Jun 2019 at 06:08, Peter Eisentraut <[hidden email]> wrote:
New thread continuing from
<https://www.postgresql.org/message-id/d4903af2-e7b7-b551-71f8-3e4a6bdc2e73@...>.

Here is a extended version of Álvaro's patch that adds an errbacktrace()
function.  You can do two things with this:

- Manually attach it to an ereport() call site that you want to debug.

- Set a configuration parameter like backtrace_function = 'int8in' to
debug ereport()/elog() calls in a specific function.

There was also mention of settings that would automatically produce
backtraces for PANICs etc.  Those could surely be added if there is
enough interest.

For the implementation, I support both backtrace() provided by the OS as
well as using libunwind.  The former seems to be supported by a number
of platforms, including glibc, macOS, and FreeBSD, so maybe we don't
need the libunwind suport.  I haven't found any difference in quality in
the backtraces between the two approaches, but surely that is highly
dependent on the exact configuration.

I would welcome testing in all direction with this, to see how well it
works in different circumstances.


Hi Peter, 

This is certainly a very useful thing. Sadly, it doesn't seem to compile when trying to use libunwind.
I tried it in a Debian 9 machine with gcc 6.3.0 and debian says i installed libunwind8 (1.1)

./configure --prefix=/home/jcasanov/Documentos/pgdg/pgbuild/pg13 --enable-debug --enable-profiling --enable-cassert --enable-depend --with-libunwind

at make i get these errors:
"""
utils/error/elog.o: En la función `set_backtrace':
/home/jcasanov/Documentos/pgdg/projects/postgresql/src/backend/utils/error/elog.c:847: referencia a `_Ux86_64_getcontext' sin definir
/home/jcasanov/Documentos/pgdg/projects/postgresql/src/backend/utils/error/elog.c:848: referencia a `_Ux86_64_init_local' sin definir
/home/jcasanov/Documentos/pgdg/projects/postgresql/src/backend/utils/error/elog.c:850: referencia a `_Ux86_64_step' sin definir
/home/jcasanov/Documentos/pgdg/projects/postgresql/src/backend/utils/error/elog.c:861: referencia a `_Ux86_64_get_reg' sin definir
/home/jcasanov/Documentos/pgdg/projects/postgresql/src/backend/utils/error/elog.c:862: referencia a `_Ux86_64_get_proc_name' sin definir
collect2: error: ld returned 1 exit status
make[2]: *** [postgres] Error 1
make[1]: *** [all-backend-recurse] Error 2
make: *** [all-src-recurse] Error 2
"""
--
Jaime Casanova                      www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Thomas Munro-5
In reply to this post by Peter Eisentraut-6
On Tue, Jun 25, 2019 at 11:08 PM Peter Eisentraut
<[hidden email]> wrote:
> For the implementation, I support both backtrace() provided by the OS as
> well as using libunwind.  The former seems to be supported by a number
> of platforms, including glibc, macOS, and FreeBSD, so maybe we don't
> need the libunwind suport.  I haven't found any difference in quality in
> the backtraces between the two approaches, but surely that is highly
> dependent on the exact configuration.
>
> I would welcome testing in all direction with this, to see how well it
> works in different circumstances.

I like it.

Works out of the box on my macOS machine, but for FreeBSD I had to add
-lexecinfo to LIBS.

--
Thomas Munro
https://enterprisedb.com


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Dmitry Dolgov
> On Sat, Jun 29, 2019 at 7:41 AM Jaime Casanova <[hidden email]> wrote:
>
> This is certainly a very useful thing. Sadly, it doesn't seem to compile when
> trying to use libunwind.

Yeah, the same for me. To make it works I've restricted libunwind to local
unwinding only:

    #ifdef USE_LIBUNWIND
    #define UNW_LOCAL_ONLY
    #include <libunwind.h>
    #endif

And result looks pretty nice:

2019-07-08 17:24:08.406 CEST [31828] ERROR:  invalid input syntax for
type integer: "foobar" at character 12
2019-07-08 17:24:08.406 CEST [31828] BACKTRACE:  #0
pg_strtoint32+0x1d1 [0x000055fa389bcbbe]
        #1  int4in+0xd [0x000055fa38976d7b]
        #2  InputFunctionCall+0x6f [0x000055fa38a488e9]
        #3  OidInputFunctionCall+0x44 [0x000055fa38a48b0d]
        #4  stringTypeDatum+0x33 [0x000055fa386e222e]
        #5  coerce_type+0x26d [0x000055fa386ca14d]
        #6  coerce_to_target_type+0x79 [0x000055fa386c9494]
        #7  transformTypeCast+0xaa [0x000055fa386d0042]
        #8  transformExprRecurse+0x22f [0x000055fa386cf650]
        #9  transformExpr+0x1a [0x000055fa386cf30a]
        #10 transformTargetEntry+0x79 [0x000055fa386e1131]
        #11 transformTargetList+0x86 [0x000055fa386e11ce]
        #12 transformSelectStmt+0xa1 [0x000055fa386a29c9]
        #13 transformStmt+0x9d [0x000055fa386a345a]
        #14 transformOptionalSelectInto+0x94 [0x000055fa386a3f49]
        #15 transformTopLevelStmt+0x15 [0x000055fa386a3f88]
        #16 parse_analyze+0x4e [0x000055fa386a3fef]
        #17 pg_analyze_and_rewrite+0x3e [0x000055fa3890cfa5]
        #18 exec_simple_query+0x35b [0x000055fa3890d5b5]
        #19 PostgresMain+0x91f [0x000055fa3890f7a8]
        #20 BackendRun+0x1ac [0x000055fa3887ed17]
        #21 BackendStartup+0x15c [0x000055fa38881ea1]
        #22 ServerLoop+0x1e6 [0x000055fa388821bb]
        #23 PostmasterMain+0x1101 [0x000055fa388835a1]
        #24 main+0x21a [0x000055fa387db1a9]
        #25 __libc_start_main+0xe7 [0x00007f3d1a607fa7]
        #26 _start+0x2a [0x000055fa3858e4ea]


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Alvaro Herrera-9
On 2019-Jul-08, Dmitry Dolgov wrote:

> > On Sat, Jun 29, 2019 at 7:41 AM Jaime Casanova <[hidden email]> wrote:
> >
> > This is certainly a very useful thing. Sadly, it doesn't seem to compile when
> > trying to use libunwind.
>
> Yeah, the same for me. To make it works I've restricted libunwind to local
> unwinding only:
>
>     #ifdef USE_LIBUNWIND
>     #define UNW_LOCAL_ONLY
>     #include <libunwind.h>
>     #endif

Ah, yes.  unwind's manpage says:

  Normally, libunwind supports both local and remote unwinding (the latter will
  be explained in the next section). However, if you tell libunwind that your
  program only needs local unwinding, then a special implementation can be
  selected which may run much faster than the generic implementation which
  supports both kinds of unwinding. To select this optimized version, simply
  define the macro UNW_LOCAL_ONLY before including the headerfile <libunwind.h>.

so I agree with unconditionally defining that symbol.

Nitpicking dept: I think in these tests:

+   if (!edata->backtrace &&
+       edata->funcname &&
+       backtrace_function[0] &&
+       strcmp(backtrace_function, edata->funcname) == 0)
+       set_backtrace(edata, 2);

we should test for backtrace_function[0] before edata->funcname, since
it seems more likely to be unset.

--
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Peter Eisentraut-6
After further research I'm thinking about dropping the libunwind
support.  The backtrace()/backtrace_symbols() API is more widely
available: darwin, freebsd, linux, netbsd, openbsd (via port), solaris,
and of course it's built-in, whereas libunwind is only available for
linux, freebsd, hpux, solaris, and requires an external dependency.

--
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Peter Eisentraut-6
On 2019-07-09 11:43, Peter Eisentraut wrote:
> After further research I'm thinking about dropping the libunwind
> support.  The backtrace()/backtrace_symbols() API is more widely
> available: darwin, freebsd, linux, netbsd, openbsd (via port), solaris,
> and of course it's built-in, whereas libunwind is only available for
> linux, freebsd, hpux, solaris, and requires an external dependency.

Here is an updated patch without the libunwind support, some minor
cleanups, documentation, and automatic back traces from assertion failures.

--
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

v3-0001-Add-backtrace-support.patch (20K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Alvaro Herrera-9
On 2019-Jul-22, Peter Eisentraut wrote:

> On 2019-07-09 11:43, Peter Eisentraut wrote:
> > After further research I'm thinking about dropping the libunwind
> > support.  The backtrace()/backtrace_symbols() API is more widely
> > available: darwin, freebsd, linux, netbsd, openbsd (via port), solaris,
> > and of course it's built-in, whereas libunwind is only available for
> > linux, freebsd, hpux, solaris, and requires an external dependency.
>
> Here is an updated patch without the libunwind support, some minor
> cleanups, documentation, and automatic back traces from assertion failures.

The only possibly complaint I see is that the backtrace support in
ExceptionalCondition does not work for Windows eventlog/console ... but
that seems moot since Windows does not have backtrace support anyway.

+1 to get this patch in at this stage; we can further refine (esp. add
Windows support) later, if need be.

https://stackoverflow.com/questions/26398064/counterpart-to-glibcs-backtrace-and-backtrace-symbols-on-windows

--
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Tom Lane-2
In reply to this post by Peter Eisentraut-6
Peter Eisentraut <[hidden email]> writes:
> Here is an updated patch without the libunwind support, some minor
> cleanups, documentation, and automatic back traces from assertion failures.

Just noticing that ExceptionalCondition has an "fflush(stderr);"
in front of what you added --- perhaps you should also add one
after the backtrace_symbols_fd call?  It's not clear to me that
that function guarantees to fflush, nor do I want to assume that
abort() does.

                        regards, tom lane


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Tom Lane-2
I wrote:
> Just noticing that ExceptionalCondition has an "fflush(stderr);"
> in front of what you added --- perhaps you should also add one
> after the backtrace_symbols_fd call?  It's not clear to me that
> that function guarantees to fflush, nor do I want to assume that
> abort() does.

Oh, wait, it's writing to fileno(stderr) so it couldn't be
buffering anything.  Disregard ...

                        regards, tom lane


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Thomas Munro-5
In reply to this post by Peter Eisentraut-6
On Tue, Jul 23, 2019 at 6:19 AM Peter Eisentraut
<[hidden email]> wrote:
> On 2019-07-09 11:43, Peter Eisentraut wrote:
> > After further research I'm thinking about dropping the libunwind
> > support.  The backtrace()/backtrace_symbols() API is more widely
> > available: darwin, freebsd, linux, netbsd, openbsd (via port), solaris,
> > and of course it's built-in, whereas libunwind is only available for
> > linux, freebsd, hpux, solaris, and requires an external dependency.
>
> Here is an updated patch without the libunwind support, some minor
> cleanups, documentation, and automatic back traces from assertion failures.

Now works out of the box on FreeBSD.  The assertion thing is a nice touch.

I wonder if it'd make sense to have a log_min_backtrace GUC that you
could set to error/fatal/panicwhatever (perhaps in a later patch).

--
Thomas Munro
https://enterprisedb.com


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Pavel Stehule
In reply to this post by Alvaro Herrera-9
Hi

so I agree with unconditionally defining that symbol.

Nitpicking dept: I think in these tests:

+   if (!edata->backtrace &&
+       edata->funcname &&
+       backtrace_function[0] &&
+       strcmp(backtrace_function, edata->funcname) == 0)
+       set_backtrace(edata, 2);


If I understand well, backtrace is displayed only when edata->funcname is same like backtrace_function GUC. Isn't it too strong limit?

For example, I want to see backtrace for all PANIC level errors on production, and I would not to limit the source function?

Regards

Pavel



 
we should test for backtrace_function[0] before edata->funcname, since
it seems more likely to be unset.

--
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services




Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Peter Eisentraut-6
On 2019-08-12 13:19, Pavel Stehule wrote:
> If I understand well, backtrace is displayed only when edata->funcname
> is same like backtrace_function GUC. Isn't it too strong limit?
>
> For example, I want to see backtrace for all PANIC level errors on
> production, and I would not to limit the source function?

We can add additional ways to invoke this once we have the basic
functionality in.

--
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Pavel Stehule


po 12. 8. 2019 v 19:06 odesílatel Peter Eisentraut <[hidden email]> napsal:
On 2019-08-12 13:19, Pavel Stehule wrote:
> If I understand well, backtrace is displayed only when edata->funcname
> is same like backtrace_function GUC. Isn't it too strong limit?
>
> For example, I want to see backtrace for all PANIC level errors on
> production, and I would not to limit the source function?

We can add additional ways to invoke this once we have the basic
functionality in.

ok

Pavel

--
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Peter Eisentraut-6
In reply to this post by Peter Eisentraut-6
On 2019-07-22 20:19, Peter Eisentraut wrote:
> On 2019-07-09 11:43, Peter Eisentraut wrote:
>> After further research I'm thinking about dropping the libunwind
>> support.  The backtrace()/backtrace_symbols() API is more widely
>> available: darwin, freebsd, linux, netbsd, openbsd (via port), solaris,
>> and of course it's built-in, whereas libunwind is only available for
>> linux, freebsd, hpux, solaris, and requires an external dependency.
>
> Here is an updated patch without the libunwind support, some minor
> cleanups, documentation, and automatic back traces from assertion failures.

Another updated version.

I have changed the configuration setting to backtrace_functions plural,
so that you can debug more than one location at once.  I had originally
wanted to do that but using existing functions like
SplitIdentifierString() resulted in lots of complications with error
handling (inside error handling!).  So here I just hand-coded the list
splitting.  Seems simple enough.

I think this patch is now good to go from my perspective.

--
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

v4-0001-Add-backtrace-support.patch (22K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Alvaro Herrera-9
On 2019-Aug-13, Peter Eisentraut wrote:

> I have changed the configuration setting to backtrace_functions plural,
> so that you can debug more than one location at once.  I had originally
> wanted to do that but using existing functions like
> SplitIdentifierString() resulted in lots of complications with error
> handling (inside error handling!).  So here I just hand-coded the list
> splitting.  Seems simple enough.

Hmm ... but is that the natural way to write this?  I would have thought
you'd split the list at config-read time (the assign hook for the GUC)
and turn it into a List of simple strings.  Then you don't have to
loop strtok() on each errfinish().

--
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Reply | Threaded
Open this post in threaded view
|

Re: errbacktrace

Tom Lane-2
In reply to this post by Peter Eisentraut-6
Peter Eisentraut <[hidden email]> writes:
> I have changed the configuration setting to backtrace_functions plural,
> so that you can debug more than one location at once.  I had originally
> wanted to do that but using existing functions like
> SplitIdentifierString() resulted in lots of complications with error
> handling (inside error handling!).  So here I just hand-coded the list
> splitting.  Seems simple enough.

I think it's a pretty bad idea for anything invocable from elog to
trample on the process-wide strtok() state.  Even if there's no
conflict today, there will be one eventually, unless you are going
to adopt the position that nobody else is allowed to use strtok().

                        regards, tom lane