BUG #6168: db_link may generate additional unformatted log entries in stderr

The following bug has been logged online:

Bug reference: 6168
Logged by: Marc Mamin
Email address: marc(at)intershop(dot)de
PostgreSQL version: 9.1 Beta 3
Operating system: Linux
Description: db_link may generate additional unformatted log entries
in stderr
Details:

Hello,

The problem occures with 9.1 Beta 3 on Linux, but I suspect this to be an
older issue in db_link

here my logging configuration:
log_destination = 'stderr,csvlog'
logging_collector = on
log_line_prefix = '%t|%c|%p|%u|'
log_min_messages = warning

I've stumbled on a few entries in my stderr log where the line prefix where
missing. e.g.:

2011-08-08 13:12:16 CEST|4e3fc490.17bc|6076|foo|DETAIL: Returned type
character ...
2011-08-08 13:12:16 CEST|4e3fc490.17bc|6076|foo|CONTEXT: PL/pgSQL
function "bm_ ...
2011-08-08 13:12:16 CEST|4e3fc490.17bc|6076|foo|STATEMENT: Select
coalesce(colu ...
=> NOTICE: table "sessions_summary_raw_20110815" does not exist, skipping
=> NOTICE: ALTER TABLE / ADD PRIMARY KEY will create implicit index
"pk_sessions_s ...
=> NOTICE: table "sessions_site_summary_raw_20110815" does not exist,
skipping

NOTICE entries should moreover not be logged !

Those entries are coming from db_link.

Here is a small test case to repeat:

CREATE FUNCTION my_warn (msg varchar) returns int AS
$$
BEGIN
raise WARNING '%', msg;
return 0;
END;
$$
language 'PLPGSQL';

cic_db=# SELECT dblink_connect_u('1', 'hostaddr=127.0.0.1 port=5432
dbname=cic_db user=isdb1 password=foo');
dblink_connect_u
------------------
OK
(1 row)

cic_db=# SELECT dblink_send_query ('1', $$select my_warn ('my_warn
test')$$);
dblink_send_query
-------------------
1
(1 row)

cic_db=# SELECT * FROM dblink_get_result('1') AS t1(f1 int);
f1
----
0
(1 row)

cic_db=# SELECT dblink_disconnect('1');
dblink_disconnect
-------------------
OK
(1 row)

DROP FUNCTION my_warn(msg varchar);

stderr log: the correct warning entry is followed by a repetiton of the
message:
(In my real case I only see the unformated NOTICE, probably because of the
log_min_messages set to warning)
;

2011-08-19 12:44:11 CEST|4e4e3e7b.529d|21149|isdb1|WARNING: my_warn
test
=> WARNING: my_warn test

the csvlog is clean. It does not contains these extra entries:

2011-08-19 12:44:11.799
CEST,"isdb1","cic_db",21149,"127.0.0.1:42769",4e4e3e7b.529d,1,"SELECT",2011-
08-19 12:44:11 CEST,4/116414,0,WARNING,01000,"my_warn test",,,,,,,,,""

As far as I see, this is just a cosmetic issue, but might be problmatic for
third party applications that parse the stderr log.

HTH,

Marc Mamin