BUG #9186: CONTEXT log line still appears when turned off

Can anyone comment on this? I am able reproduce this in head, and the
behavior does look odd. I am able to see the error by just doing:

SET log_min_error_statement = notice;

in a session before calling the functions; I didn't need to modify
postgresql.conf. I am not sure even where to start in debugging this.

---------------------------------------------------------------------------

On Tue, Feb 11, 2014 at 02:32:10PM +0000, mduyunov@avito.ru wrote:

The following bug has been logged on the website:

Bug reference: 9186
Logged by: Maxim Duyunov
Email address: mduyunov@avito.ru
PostgreSQL version: 9.3.2
Operating system: Debian GNU/Linux
Description:

Hello!

I wanted to call function inside the other one and write some notices.
On purpose to switch off "STATEMENT" and "CONTEXT" log lines I set
log_min_error_statement = 'warning' on function,
but there are still CONTEXT log lines, when I call function via perform or
execute.
It looks like a bug.

Even with setting "log_min_error_statement" set for functions: test_call* it
still shows "statement" and "context".

Please, advice me how to switch off "statement" and "context" log lines only
for "notice".

Sincerely,
Maxim Duyunov.

Server default settings:
select name, setting from pg_settings where name ~ 'log_min|verbo'
"log_error_verbosity";"default"
"log_min_duration_statement";"-1"
"log_min_error_statement";"notice"
"log_min_messages";"notice"

PostgreSQL versions:
"PostgreSQL 9.2.6 on x86_64-unknown-linux-gnu, compiled by gcc (Debian
4.4.5-8) 4.4.5, 64-bit"
"Linux avi-sql09 2.6.32-5-amd64 #1 SMP Sun May 6 04:00:17 UTC 2012 x86_64
GNU/Linux"
"Debian GNU/Linux 6.0"
----
"PostgreSQL 9.3.2 on x86_64-unknown-linux-gnu, compiled by gcc-4.8.real
(Debian 4.8.2-8) 4.8.2, 64-bit"
"Linux seb 3.12-1-amd64 #1 SMP Debian 3.12.6-2 (2013-12-29) x86_64
GNU/Linux"
"Debian GNU/Linux jessie/sid"

----
CREATE OR REPLACE FUNCTION test_func(i_name text) RETURNS void AS
$$
begin
raise notice 'Hello, %', i_name;
end;
$$
language plpgsql
set log_min_error_statement = 'warning';
----
CREATE OR REPLACE FUNCTION test_call() RETURNS void AS
$$
begin
execute 'select test_func(''Maxim'')';
end;
$$
language plpgsql
set log_min_error_statement = 'warning';
----
CREATE OR REPLACE FUNCTION test_call2() RETURNS void AS
$$
begin
perform test_func('Maxim');
end;
$$
language plpgsql
set log_min_error_statement = 'warning';
----
SELECT test_func('Maxim');
SELECT test_call();
SELECT test_call2();
----
2014-02-11 17:58:53 MSK
pid=6601,user=postgres,db=dbname,host=10.7.170.1(61351) NOTICE: Hello,
Maxim
----
2014-02-11 17:58:24 MSK
pid=6601,user=postgres,db=dbname,host=10.7.170.1(61351) NOTICE: Hello,
Maxim
2014-02-11 17:58:24 MSK
pid=6601,user=postgres,db=dbname,host=10.7.170.1(61351) CONTEXT: SQL
statement "select test_func('Maxim')"
PL/pgSQL function test_call() line 3 at EXECUTE statement
----
2014-02-11 18:03:42 MSK
pid=6601,user=postgres,db=dbname,host=10.7.170.1(61351) NOTICE: Hello,
Maxim
2014-02-11 18:03:42 MSK
pid=6601,user=postgres,db=dbname,host=10.7.170.1(61351) CONTEXT: SQL
statement "SELECT test_func('Maxim')"
PL/pgSQL function test_call2() line 3 at PERFORM
----

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ Everyone has their own god. +

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

Hi,

On 2014-04-19 09:27:00 -0400, Bruce Momjian wrote:

Can anyone comment on this? I am able reproduce this in head, and the
behavior does look odd. I am able to see the error by just doing:

SET log_min_error_statement = notice;

in a session before calling the functions; I didn't need to modify
postgresql.conf. I am not sure even where to start in debugging this.

Aren't CONTEXT messages influenced by log_error_verbosity, rather than
log_min_error_statement?

Greetings,

Andres Freund

--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

On Sat, Apr 19, 2014 at 03:35:52PM +0200, Andres Freund wrote:

Hi,

On 2014-04-19 09:27:00 -0400, Bruce Momjian wrote:

Can anyone comment on this? I am able reproduce this in head, and the
behavior does look odd. I am able to see the error by just doing:

SET log_min_error_statement = notice;

in a session before calling the functions; I didn't need to modify
postgresql.conf. I am not sure even where to start in debugging this.

Aren't CONTEXT messages influenced by log_error_verbosity, rather than
log_min_error_statement?

Thanks. I was confused by this, and I can see how the user was confused
because of the way the log message appears in the email, though that
might be just cut/past wrapping:

2014-02-11 18:03:42 MSK
pid=6601,user=postgres,db=dbname,host=10.7.170.1(61351) NOTICE: Hello,
Maxim
2014-02-11 18:03:42 MSK
pid=6601,user=postgres,db=dbname,host=10.7.170.1(61351) CONTEXT: SQL
statement "SELECT test_func('Maxim')"
PL/pgSQL function test_call2() line 3 at PERFORM

That "statement" is not generated by log_min_error_statement, but rather
is part of the CONTEXT line.

Using log_error_verbosity=terse does allow the notice to appear in the
logs without the context.

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ Everyone has their own god. +

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

Bruce Momjian <bruce@momjian.us> writes:

Can anyone comment on this? I am able reproduce this in head, and the
behavior does look odd. I am able to see the error by just doing:
SET log_min_error_statement = notice;
in a session before calling the functions; I didn't need to modify
postgresql.conf. I am not sure even where to start in debugging this.

That's because it's not a bug. The CONTEXT is attached to the NOTICE
lines. log_min_error_statement has got nothing whatsoever to do with
the verbosity of individual log entries, so there is no way to use it
to "turn off CONTEXT lines".

There might be a feature request in here somewhere, but it's not
a bug.

regards, tom lane

--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs