Обсуждение: Proposal "stack trace" like debugging option in PostgreSQL

Dear community,


Sorry if this is not the right place for proposing new features. Also,
sorry if I'm proposing something already existing.

I do currently use the "debug" extension to better understand the
entrophy of my application regarding database.

But in production this is not possible, and I would to propose a feature
that has less impact over production then a debug extension: a
stacktrace of calls.

Simular to Java stack traces, but disabled by default. When enabled, In
case of an event like "duplicate key" (or a function raise exception) or
other similar problems that wont allow the database to execute the SQL
command,the strack trace will bring the complete list of function call.

This would help to track down problems that escaped the development and
test environments, and reached the production systems.


If this feature already exists, please kindly point me to the docs. If
not, please consider adding this in a future release.


Thanks,


--
Atenciosamente,

Edson Carlos Ericksson Richter

On 07/30/2016 10:52 AM, Edson Richter wrote:
> Dear community,
>
>
> Sorry if this is not the right place for proposing new features. Also,
> sorry if I'm proposing something already existing.
>
> I do currently use the "debug" extension to better understand the
> entrophy of my application regarding database.

Can you be more specific about what you mean by debug extension?

It might help provide folks with an idea of what you are looking for.

>
> But in production this is not possible, and I would to propose a feature
> that has less impact over production then a debug extension: a
> stacktrace of calls.
>
> Simular to Java stack traces, but disabled by default. When enabled, In
> case of an event like "duplicate key" (or a function raise exception) or
> other similar problems that wont allow the database to execute the SQL
> command,the strack trace will bring the complete list of function call.

Have you tried cranking up the log level:

https://www.postgresql.org/docs/9.5/static/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-WHEN

to one of the debug levels. Though that will result in a lot of log
output if you leave it on for any length of time.

>
> This would help to track down problems that escaped the development and
> test environments, and reached the production systems.
>
>
> If this feature already exists, please kindly point me to the docs. If
> not, please consider adding this in a future release.
>
>
> Thanks,
>
>


--
Adrian Klaver
adrian.klaver@aklaver.com

Edson Richter <edsonrichter@hotmail.com> writes:
> But in production this is not possible, and I would to propose a feature
> that has less impact over production then a debug extension: a
> stacktrace of calls.

> Simular to Java stack traces, but disabled by default. When enabled, In
> case of an event like "duplicate key" (or a function raise exception) or
> other similar problems that wont allow the database to execute the SQL
> command,the strack trace will bring the complete list of function call.

Uh, doesn't the CONTEXT field of error messages give you that already?

            regards, tom lane

On 07/31/2016 01:27 PM, Edson Richter wrote:

Please reply to list also
Ccing list.

>
>
>> Subject: Re: [GENERAL] Proposal "stack trace" like debugging option in
> PostgreSQL
>> To: edsonrichter@hotmail.com; pgsql-general@postgresql.org
>> From: adrian.klaver@aklaver.com
>> Date: Sat, 30 Jul 2016 15:26:42 -0700
>>
>> On 07/30/2016 10:52 AM, Edson Richter wrote:
>> > Dear community,
>> >
>> >
>> > Sorry if this is not the right place for proposing new features. Also,
>> > sorry if I'm proposing something already existing.
>> >
>> > I do currently use the "debug" extension to better understand the
>> > entrophy of my application regarding database.
>>
>> Can you be more specific about what you mean by debug extension?
>

************
> pgAdmin III debugger:
>
> shared_preload_libraries = 'plugin_debugger'                # (change
> requires restart)
>
>

***************

>>
>> It might help provide folks with an idea of what you are looking for.
>>
>> >
>> > But in production this is not possible, and I would to propose a feature
>> > that has less impact over production then a debug extension: a
>> > stacktrace of calls.
>> >
>> > Simular to Java stack traces, but disabled by default. When enabled, In
>> > case of an event like "duplicate key" (or a function raise exception) or
>> > other similar problems that wont allow the database to execute the SQL
>> > command,the strack trace will bring the complete list of function call.
>>
>> Have you tried cranking up the log level:
>>
>>
> https://www.postgresql.org/docs/9.5/static/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-WHEN
>>
>> to one of the debug levels. Though that will result in a lot of log
>> output if you leave it on for any length of time.
>>
>

*****************

> Yes - I get the statements, but in case of an exception, I don't get the
> stack call showing how deep my function call is, which order has been in
> place. One update, insert or delete can throw a trigger that will
> cascade many levels until the problem is found.
>
> And, in general, is a bad idea (IMHO) to enable higher levels of logging
> in production systems when nothing is wrong. The stack trace is helpful
> when you don't have the logging, but something unexpected happens and
> you need more details. And, also, is unlikely you will be able to
> reproduce the sequence of error without that additional information.

******************






>
>
> Edson Richter

>
>> >
>> > This would help to track down problems that escaped the development and
>> > test environments, and reached the production systems.
>> >
>> >
>> > If this feature already exists, please kindly point me to the docs. If
>> > not, please consider adding this in a future release.
>> >
>> >
>> > Thanks,
>> >
>> >
>>
>>
>> --
>> Adrian Klaver
>> adrian.klaver@aklaver.com


--
Adrian Klaver
adrian.klaver@aklaver.com

Edson Richter <edsonrichter@hotmail.com> writes:
>> From: tgl@sss.pgh.pa.us
>> Uh, doesn't the CONTEXT field of error messages give you that already?

> Would you give me an example where I can get the info you mention above? Do I need to enable some kind of parameter
toget this context field? 

Well, you have not mentioned what sort of client environment you are
using, but the server certainly sends that information.  In psql,
for example, I can do this:

regression=# create table foo (f1 int primary key, f2 text);
CREATE TABLE
regression=# create function ifoo(int, text) returns void as
$$ begin insert into foo values($1,$2); end $$ language plpgsql;
CREATE FUNCTION
regression=# create function ifoo2(int, text) returns void as
$$ begin perform ifoo($1,$2); end $$ language plpgsql;
CREATE FUNCTION
regression=# select ifoo2(1,'foo');
 ifoo2
-------

(1 row)

regression=# select ifoo2(1,'foo');
ERROR:  duplicate key value violates unique constraint "foo_pkey"
DETAIL:  Key (f1)=(1) already exists.
CONTEXT:  SQL statement "insert into foo values($1,$2)"
PL/pgSQL function ifoo(integer,text) line 1 at SQL statement
SQL statement "SELECT ifoo($1,$2)"
PL/pgSQL function ifoo2(integer,text) line 1 at PERFORM

If you're using a misdesigned client that will not show these auxiliary
error fields, you could try looking in the server log --- at default
log verbosity, it will contain that info too.  The above test case
gave me this log entry:

ERROR:  duplicate key value violates unique constraint "foo_pkey"
DETAIL:  Key (f1)=(1) already exists.
CONTEXT:  SQL statement "insert into foo values($1,$2)"
        PL/pgSQL function ifoo(integer,text) line 1 at SQL statement
        SQL statement "SELECT ifoo($1,$2)"
        PL/pgSQL function ifoo2(integer,text) line 1 at PERFORM
STATEMENT:  select ifoo2(1,'foo');

            regards, tom lane

Hello

On 08/01/2016 12:15 AM, Tom Lane wrote:
> Edson Richter <edsonrichter@hotmail.com> writes:
>>> From: tgl@sss.pgh.pa.us
>>> Uh, doesn't the CONTEXT field of error messages give you that already?
>
>> Would you give me an example where I can get the info you mention above? Do I need to enable some kind of parameter
toget this context field? 
>
> Well, you have not mentioned what sort of client environment you are
> using, but the server certainly sends that information.  In psql,
> for example, I can do this:
>
> regression=# create table foo (f1 int primary key, f2 text);
> CREATE TABLE
> regression=# create function ifoo(int, text) returns void as
> $$ begin insert into foo values($1,$2); end $$ language plpgsql;
> CREATE FUNCTION
> regression=# create function ifoo2(int, text) returns void as
> $$ begin perform ifoo($1,$2); end $$ language plpgsql;
> CREATE FUNCTION
> regression=# select ifoo2(1,'foo');
>  ifoo2
> -------
>
> (1 row)
>
> regression=# select ifoo2(1,'foo');
> ERROR:  duplicate key value violates unique constraint "foo_pkey"
> DETAIL:  Key (f1)=(1) already exists.
> CONTEXT:  SQL statement "insert into foo values($1,$2)"
> PL/pgSQL function ifoo(integer,text) line 1 at SQL statement
> SQL statement "SELECT ifoo($1,$2)"
> PL/pgSQL function ifoo2(integer,text) line 1 at PERFORM
>
> If you're using a misdesigned client that will not show these auxiliary
> error fields, you could try looking in the server log --- at default
> log verbosity, it will contain that info too.  The above test case
> gave me this log entry:
>
> ERROR:  duplicate key value violates unique constraint "foo_pkey"
> DETAIL:  Key (f1)=(1) already exists.
> CONTEXT:  SQL statement "insert into foo values($1,$2)"
>         PL/pgSQL function ifoo(integer,text) line 1 at SQL statement
>         SQL statement "SELECT ifoo($1,$2)"
>         PL/pgSQL function ifoo2(integer,text) line 1 at PERFORM
> STATEMENT:  select ifoo2(1,'foo');
>
>             regards, tom lane
>
>

Maybe this could help, too.

In the documentation there is a description of how to get the call stack
of functions:

https://www.postgresql.org/docs/current/static/plpgsql-control-structures.html

40.6.7. Obtaining Current Execution Information

The GET [ CURRENT ] DIAGNOSTICS command retrieves information about
current execution state (whereas the GET STACKED DIAGNOSTICS command
discussed above reports information about the execution state as of a
previous error). This command has the form:

GET [ CURRENT ] DIAGNOSTICS variable { = | := } item [ , ... ];

Currently only one information item is supported. Status item PG_CONTEXT
will return a text string with line(s) of text describing the call
stack. The first line refers to the current function and currently
executing GET DIAGNOSTICS command. The second and any subsequent lines
refer to calling functions further up the call stack. For example:

CREATE OR REPLACE FUNCTION outer_func() RETURNS integer AS $$
BEGIN
   RETURN inner_func();
END;
$$ LANGUAGE plpgsql;

CREATE OR REPLACE FUNCTION inner_func() RETURNS integer AS $$
DECLARE
   stack text;
BEGIN
   GET DIAGNOSTICS stack = PG_CONTEXT;
   RAISE NOTICE E'--- Call Stack ---\n%', stack;
   RETURN 1;
END;
$$ LANGUAGE plpgsql;

SELECT outer_func();

NOTICE:  --- Call Stack ---
PL/pgSQL function inner_func() line 5 at GET DIAGNOSTICS
PL/pgSQL function outer_func() line 3 at RETURN
CONTEXT:  PL/pgSQL function outer_func() line 3 at RETURN
  outer_func
  ------------
            1
(1 row)

Regards
Charles

--
Swiss PostgreSQL Users Group
c/o Charles Clavadetscher
Treasurer
Motorenstrasse 18
CH – 8005 Zürich

http://www.swisspug.org

+-----------------------+
|   ____  ______  ___   |
|  /    )/      \/   \  |
| (     / __    _\    ) |
|  \    (/ o)  ( o)   ) |
|   \_  (_  )   \ ) _/  |
|     \  /\_/    \)/    |
|      \/ <//|  |\\>    |
|           _|  |       |
|           \|_/        |
|                       |
| PostgreSQL 1996-2016  |
|  20 Years of Success  |
|                       |
+-----------------------+