auto-explain does not work with JSON & csvlog

Josh Berkus <josh@agliodbs.com> writes:

With 9.0, the obvious thing to do with autoexplain is to log JSON or XML
explain plans to a csvlog and then automatically process them.

However, when I attempt to do this, I get the following warning at
PostgreSQL startup time:

Loaded module "auto_explain"
Not safe to send CSV data

I wouldn't be too surprised if that happened on a one-time basis during
postmaster startup ...

And on checking, auto-explain is indeed NOT sending anything to the
csvlog. It's not sending anything to the regular log, either.

... but this part sounds like it's probably a configuration mistake
on your part.

regards, tom lane

Josh Berkus <josh@agliodbs.com> writes:

With 9.0, the obvious thing to do with autoexplain is to log JSON or XML
explain plans to a csvlog and then automatically process them.

BTW, I tried this and it works fine for me.

However, when I attempt to do this, I get the following warning at
PostgreSQL startup time:

Loaded module "auto_explain"
Not safe to send CSV data

FWIW, the reason for that happening is that
process_shared_preload_libraries() executes, and reports what it did,
before we fork off the syslogger process. So there's no way to CSV-ize
the "Loaded module" report. The only way to suppress that would be to
not preload libraries till after we start the syslogger, which seems
like a bad idea --- what if a library wants to be loaded in the
syslogger? Anyway, you'll get the same "not safe" bleat for any message
logged during early postmaster startup.

Maybe we should just drop the "not safe" message. It's not conveying
anything very helpful, I think. The useful bit of the behavior is to
shove the original message out to stderr, which it's doing already.

regards, tom lane

Tom Lane wrote:

Anyway, you'll get the same "not safe" bleat for any message
logged during early postmaster startup.

Maybe we should just drop the "not safe" message. It's not conveying
anything very helpful, I think. The useful bit of the behavior is to
shove the original message out to stderr, which it's doing already.

I thought we agreed back in November to stop the bleating. Maybe you
thought I'd remove it and I thought you would ;-).

cheers

andrew

Andrew Dunstan <andrew@dunslane.net> writes:

Tom Lane wrote:

Anyway, you'll get the same "not safe" bleat for any message
logged during early postmaster startup.

Maybe we should just drop the "not safe" message. It's not conveying
anything very helpful, I think. The useful bit of the behavior is to
shove the original message out to stderr, which it's doing already.

I thought we agreed back in November to stop the bleating.

Did we? I'd forgotten. Anyway, it seems like something that made sense
while CSV logging was under testing, but not any more.

regards, tom lane

Tom Lane <tgl@sss.pgh.pa.us> writes:

Andrew Dunstan <andrew@dunslane.net> writes:

I thought we agreed back in November to stop the bleating.

Did we? I'd forgotten.

You're right ... this conversation seems to be a repeat of the
thread here:
http://archives.postgresql.org/pgsql-hackers/2009-11/msg01260.php

I'll go fix it now before I forget again.

regards, tom lane