Thread: [PROPOSAL] Client Log Output Filtering

Currently log messages generated by pgaudit can be made visible to the
client simply by altering client_min_messages.  While this has not been
a showstopper for anyone it's ideal, either.

The client authentication code sets the global variable
ClientAuthInProgress which causes ereport() to filter client output <
ERROR while forcing client output >= ERROR.  This functionality would
also work well for pgaudit.

The patch creates a new counter to separate the log filtering from the
authentication functionality.  This makes it possible to get the same
filtering in other parts of the code (or extensions) without abusing the
ClientAuthInProgress variable or using the log hook.

I also considered a new function for ereport (like errhidecontext()) but
this mechanism would not have worked for authentication and so would not
have been used anywhere in core.

If there are no objections I'll submit it to the next commitfest.

--
-David
david@pgmasters.net

David Steele wrote:
> Currently log messages generated by pgaudit can be made visible to the
> client simply by altering client_min_messages.  While this has not been a
> showstopper for anyone it's ideal, either.
> 
> The client authentication code sets the global variable ClientAuthInProgress
> which causes ereport() to filter client output < ERROR while forcing client
> output >= ERROR.  This functionality would also work well for pgaudit.
> 
> The patch creates a new counter to separate the log filtering from the
> authentication functionality.  This makes it possible to get the same
> filtering in other parts of the code (or extensions) without abusing the
> ClientAuthInProgress variable or using the log hook.

Hmm, okay, but this would need a large blinking comment explaining that
the calling code have better set a PG_TRY block when incrementing, so
that on errors it resets to zero again.  Or maybe some handling in
AbortOutOfAnyTransaction/AbortCurrentTransaction.  or both.

> I also considered a new function for ereport (like errhidecontext()) but
> this mechanism would not have worked for authentication and so would not
> have been used anywhere in core.

But then, you already know that authentication phase is not exactly the
same use case as security auditing, so they don't have to work the same
way necessarily.  I think this needs more discussion.  If the audit code
calls something that throws an error (other than an audit message -- say
"out of memory"), then it would also be hidden, but you may not want it
to be hidden.  I think maybe it's better to have each individual error
message be marked as "don't show to client" rather than a global var.

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

On Mon, Jan 11, 2016 at 6:50 PM, Alvaro Herrera
<alvherre@2ndquadrant.com> wrote:
> I think maybe it's better to have each individual error
> message be marked as "don't show to client" rather than a global var.

+1.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On 1/11/16 6:50 PM, Alvaro Herrera wrote:
> David Steele wrote:
>> The patch creates a new counter to separate the log filtering from the
>> authentication functionality.  This makes it possible to get the same
>> filtering in other parts of the code (or extensions) without abusing the
>> ClientAuthInProgress variable or using the log hook.
>
> Hmm, okay, but this would need a large blinking comment explaining that
> the calling code have better set a PG_TRY block when incrementing, so
> that on errors it resets to zero again.  Or maybe some handling in
> AbortOutOfAnyTransaction/AbortCurrentTransaction.  or both.

In the case of pgaudit only the ereport call is wrapped in the 
LimitClientLogOutput() calls which I thought was safe - am I wrong about 
that?

>> I also considered a new function for ereport (like errhidecontext()) but
>> this mechanism would not have worked for authentication and so would not
>> have been used anywhere in core.

> If the audit code
> calls something that throws an error (other than an audit message -- say
> "out of memory"), then it would also be hidden, but you may not want it
> to be hidden.

This shouldn't happen -- see above.

I think maybe it's better to have each individual error
> message be marked as "don't show to client" rather than a global var.

That's easy enough to do and I already have the code for it since that's 
the first thing I tried.  However, there were two reasons I didn't 
submit that version:

1) Unless pgaudit is committed there wouldn't be any code calling the 
errhidefromclient() function and that seemed like a bad plan.

2) There would be two different ways to suppress client messages but I 
was hoping to only have one.

As you say, authentication is a different beast so maybe #2 is not a big 
deal.  I could combine the alternative ereport patch with the pgaudit 
patch to address #1 but I would like to have the capability in core 
whether pgaudit is committed or not, which is why I submitted it separately.

Any advice would be greatly appreciated.

Thanks,
-- 
-David
david@pgmasters.net

David Steele wrote:
> On 1/11/16 6:50 PM, Alvaro Herrera wrote:
> >David Steele wrote:
> >>The patch creates a new counter to separate the log filtering from the
> >>authentication functionality.  This makes it possible to get the same
> >>filtering in other parts of the code (or extensions) without abusing the
> >>ClientAuthInProgress variable or using the log hook.
> >
> >Hmm, okay, but this would need a large blinking comment explaining that
> >the calling code have better set a PG_TRY block when incrementing, so
> >that on errors it resets to zero again.  Or maybe some handling in
> >AbortOutOfAnyTransaction/AbortCurrentTransaction.  or both.
> 
> In the case of pgaudit only the ereport call is wrapped in the
> LimitClientLogOutput() calls which I thought was safe - am I wrong about
> that?

Yeah, errstart itself could fail.  It's not common but it does happen.

> 1) Unless pgaudit is committed there wouldn't be any code calling the
> errhidefromclient() function and that seemed like a bad plan.

Well, you could add a test module to ensure it continues to work.

> 2) There would be two different ways to suppress client messages but I was
> hoping to only have one.

I think they are two different things actually.

I'm closing this as returned with feedback.

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

On 2/1/16 5:25 PM, Alvaro Herrera wrote:
> David Steele wrote:

>> 2) There would be two different ways to suppress client messages but I was
>> hoping to only have one.
>
> I think they are two different things actually.

Fair enough - that was my initial reaction as well but then I thought
the other way would be better.

> I'm closing this as returned with feedback.

I have attached a patch that adds an ereport() macro to suppress client
output for a single report call (applies cleanly on 1d0c3b3).  I'll also
move it to the next CF.

Thanks!
--
-David
david@pgmasters.net

On Mon, Feb 1, 2016 at 7:24 PM, David Steele <david@pgmasters.net> wrote:
> On 2/1/16 5:25 PM, Alvaro Herrera wrote:
>> David Steele wrote:
>
>>> 2) There would be two different ways to suppress client messages but I was
>>> hoping to only have one.
>>
>> I think they are two different things actually.
>
> Fair enough - that was my initial reaction as well but then I thought
> the other way would be better.
>
>> I'm closing this as returned with feedback.
>
> I have attached a patch that adds an ereport() macro to suppress client
> output for a single report call (applies cleanly on 1d0c3b3).  I'll also
> move it to the next CF.

I don't see any reason not to accept this.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On 03/02/16 05:02, Robert Haas wrote:
> On Mon, Feb 1, 2016 at 7:24 PM, David Steele <david@pgmasters.net> wrote:
>>
>> I have attached a patch that adds an ereport() macro to suppress client
>> output for a single report call (applies cleanly on 1d0c3b3).  I'll also
>> move it to the next CF.
>
> I don't see any reason not to accept this.
>

Yes, the idea seems sane.

Looking at the code, this adds bool hide_from_client to edata which is 
not initialized in errstart so that needs to be fixed.

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

On 3/9/16 7:37 PM, Petr Jelinek wrote:
> On 03/02/16 05:02, Robert Haas wrote:
>> On Mon, Feb 1, 2016 at 7:24 PM, David Steele <david@pgmasters.net> wrote:
>>>
>>> I have attached a patch that adds an ereport() macro to suppress client
>>> output for a single report call (applies cleanly on 1d0c3b3).  I'll also
>>> move it to the next CF.
>>
>> I don't see any reason not to accept this.
>>
>
> Yes, the idea seems sane.
>
> Looking at the code, this adds bool hide_from_client to edata which is
> not initialized in errstart so that needs to be fixed.

I figured this would take care of it:

MemSet(edata, 0, sizeof(ErrorData));

Since I want hide_from_client to default to false.  Am I missing something?

-- 
-David
david@pgmasters.net

David Steele <david@pgmasters.net> writes:
> On 3/9/16 7:37 PM, Petr Jelinek wrote:
>> Looking at the code, this adds bool hide_from_client to edata which is
>> not initialized in errstart so that needs to be fixed.

> I figured this would take care of it:
> MemSet(edata, 0, sizeof(ErrorData));
> Since I want hide_from_client to default to false.  Am I missing something?

The patch is evidently modeled on errhidestmt and errhidectx, which are
making the same assumption for their fields.

I wonder whether, instead of continuing to proliferate random bool fields
in struct ErrorData, we oughta replace them all with an "int flags" field.
That's probably material for a separate patch though.
        regards, tom lane

David Steele <david@pgmasters.net> writes:
> I have attached a patch that adds an ereport() macro to suppress client
> output for a single report call (applies cleanly on 1d0c3b3).  I'll also
> move it to the next CF.

This patch fails to add the necessary documentation (see sources.sgml)
        regards, tom lane

On 10/03/16 15:08, David Steele wrote:
>> Looking at the code, this adds bool hide_from_client to edata which is
>> not initialized in errstart so that needs to be fixed.
>
> I figured this would take care of it:
>
> MemSet(edata, 0, sizeof(ErrorData));
>
> Since I want hide_from_client to default to false.  Am I missing something?
>

Right, missed that, sorry for the noise.

I have another issue though.

The comment above errhidefromclient says "Only log levels below ERROR 
can be hidden from the client." but use of the errhidefromclient(true) 
actually does hide the error message from client, client just gets 
failed query without any message when used with ERROR level.

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

Petr Jelinek <petr@2ndquadrant.com> writes:
> The comment above errhidefromclient says "Only log levels below ERROR 
> can be hidden from the client." but use of the errhidefromclient(true) 
> actually does hide the error message from client, client just gets 
> failed query without any message when used with ERROR level.

Um.  That seems pretty broken --- I think it's a violation of the wire
protocol spec.

I notice though that we allow client_min_messages to be set to FATAL,
which would be a different way of violating the protocol.  Maybe we
should reduce the max setting of that to ERROR?

libpq/psql seem to more or less survive this situation:

regression=# set client_min_messages to fatal;
SET
regression=# select 2/0;
regression=# select 1;?column? 
----------       1
(1 row)

but it doesn't really seem like a great idea.
        regards, tom lane

On 10/03/16 17:07, Tom Lane wrote:
> Petr Jelinek <petr@2ndquadrant.com> writes:
>> The comment above errhidefromclient says "Only log levels below ERROR
>> can be hidden from the client." but use of the errhidefromclient(true)
>> actually does hide the error message from client, client just gets
>> failed query without any message when used with ERROR level.
>
> Um.  That seems pretty broken --- I think it's a violation of the wire
> protocol spec.
>

I was thinking that as well. The doc says that on error the 
ErrorResponse is sent and connection is closed and we clearly fail to 
send the ErrorResponse in this case.

> I notice though that we allow client_min_messages to be set to FATAL,
> which would be a different way of violating the protocol.  Maybe we
> should reduce the max setting of that to ERROR?
>

Hmm yeah that seems to be that way for very long time though so I wonder 
if that's intentional although it's also against protocol spec then. In 
any case I would be in favor of lowering the max setting to ERROR.

For the patch at hand, it should be sufficient for errhidefromclient() 
to check that the edata->elevel is lower than ERROR.

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

On 3/10/16 11:00 AM, Petr Jelinek wrote:

> The comment above errhidefromclient says "Only log levels below ERROR
> can be hidden from the client." but use of the errhidefromclient(true)
> actually does hide the error message from client, client just gets
> failed query without any message when used with ERROR level.

Right you are.  The v3 patch adds this check.

I also added the documentation to sources.sgml that Tom pointed out was
missing.

Thanks,
--
-David
david@pgmasters.net

On 3/10/16 11:07 AM, Tom Lane wrote:
> Petr Jelinek <petr@2ndquadrant.com> writes:
>> The comment above errhidefromclient says "Only log levels below ERROR
>> can be hidden from the client." but use of the errhidefromclient(true)
>> actually does hide the error message from client, client just gets
>> failed query without any message when used with ERROR level.
>
> Um.  That seems pretty broken --- I think it's a violation of the wire
> protocol spec.
>
> I notice though that we allow client_min_messages to be set to FATAL,
> which would be a different way of violating the protocol.  Maybe we
> should reduce the max setting of that to ERROR?

This was the same conclusion I came to for the log_level setting in pgaudit.

I'll submit a proposal to hackers after 9.6 to make this change.

--
-David
david@pgmasters.net

On 3/10/16 9:51 AM, Tom Lane wrote:

> The patch is evidently modeled on errhidestmt and errhidectx, which are
> making the same assumption for their fields.
>
> I wonder whether, instead of continuing to proliferate random bool fields
> in struct ErrorData, we oughta replace them all with an "int flags" field.
> That's probably material for a separate patch though.

There are currently six boolean flags (if you include my new one) that
all relate to visibility in one way or another.  Combining them into a
"flags" field makes sense to me.

I'll submit a proposal to hackers after 9.6 to make this change.

--
-David
david@pgmasters.net

David Steele <david@pgmasters.net> writes:
> On 3/10/16 11:00 AM, Petr Jelinek wrote:
>> The comment above errhidefromclient says "Only log levels below ERROR
>> can be hidden from the client." but use of the errhidefromclient(true)
>> actually does hide the error message from client, client just gets
>> failed query without any message when used with ERROR level.

> Right you are.  The v3 patch adds this check.

> I also added the documentation to sources.sgml that Tom pointed out was
> missing.

I set to work on committing this, but was soon rather dissatisfied with
it, because as-implemented there is no way to short-circuit elog.c's
processing if the message is not to be sent to either the client or the
postmaster log.  Ideally this would be taken into account when errstart()
figures the output_to_client setting to begin with --- but of course we
can't do that with this API, because errhidefromclient() hasn't run yet.

The patch is buggy even without that consideration, because it would
potentially disable client output of messages even after they've been
promoted to FATAL by pg_re_throw.  We could fix that by clearing the flag
in pg_re_throw, but I think that's just another symptom of the shutoff
being done in the wrong place.

I wonder just what the expected usage scenario is for this function, and
whether it would not be better addressed by inventing some other API
rather than modeling it on errhidestmt(), which is by no means the same
kind of thing.

One idea is to invent a new elevel which is never sent to the client ---
analogously to COMMERROR, though probably much higher priority than that,
maybe the same priority as LOG.  If there actually is a use for a range of
elevels on errhidefromclient'd messages, that wouldn't work very well of
course.  Or we could consider having a flag bit that is OR'd into the
elevel, along the lines of
ereport(LOG | ERR_HIDE_FROM_CLIENT, (errmsg(....)));

so that the information is available at errstart time.
        regards, tom lane

On 3/28/16 2:00 PM, Tom Lane wrote:

> I set to work on committing this, but was soon rather dissatisfied with
> it, because as-implemented there is no way to short-circuit elog.c's
> processing if the message is not to be sent to either the client or the
> postmaster log.  Ideally this would be taken into account when errstart()
> figures the output_to_client setting to begin with --- but of course we
> can't do that with this API, because errhidefromclient() hasn't run yet.

That's a weakness of this approach but I'm not sure it's a big deal 
since there will generally still be output on the server.  If both are 
suppressed I think that would be a sign of misconfiguration.

> The patch is buggy even without that consideration, because it would
> potentially disable client output of messages even after they've been
> promoted to FATAL by pg_re_throw.  We could fix that by clearing the flag
> in pg_re_throw, but I think that's just another symptom of the shutoff
> being done in the wrong place.

Or elevel could be checked in EmitErrorReport():
if (edata->output_to_client &&            !(edata->hide_from_client && edata->elevel < ERROR))
send_message_to_frontend(edata);

> I wonder just what the expected usage scenario is for this function, and
> whether it would not be better addressed by inventing some other API
> rather than modeling it on errhidestmt(), which is by no means the same
> kind of thing.

The particular use case I have in mind is to suppress client output in 
pgaudit.  The original patch took a different approach by trying to 
merge with the logic to suppress messages in auth.  Maybe you should 
take a look at that patch and see what you think:

http://www.postgresql.org/message-id/5655B621.3080906@pgmasters.net

> One idea is to invent a new elevel which is never sent to the client ---
> analogously to COMMERROR, though probably much higher priority than that,
> maybe the same priority as LOG.  If there actually is a use for a range of
> elevels on errhidefromclient'd messages, that wouldn't work very well of
> course.  Or we could consider having a flag bit that is OR'd into the
> elevel <...>

I think a flag would be more flexible than introducing a new log level.

-- 
-David
david@pgmasters.net

David Steele <david@pgmasters.net> writes:
> On 3/28/16 2:00 PM, Tom Lane wrote:
>> One idea is to invent a new elevel which is never sent to the client ---
>> analogously to COMMERROR, though probably much higher priority than that,
>> maybe the same priority as LOG.  If there actually is a use for a range of
>> elevels on errhidefromclient'd messages, that wouldn't work very well of
>> course.  Or we could consider having a flag bit that is OR'd into the
>> elevel <...>

> I think a flag would be more flexible than introducing a new log level.

I thought about this some more, and while the flag-bit approach definitely
has some attraction, it also has a big problem: there are lots of places
with code like "if (elevel >= ERROR)" which would be at risk of getting
confused, and I'm not confident we'd find them all.  We could possibly
dodge that by shifting the elevel constants up a couple of bits and
putting the flag in the LSB rather than a high-order bit; but that's a
bit icky/risky too.

Repurposing COMMERROR is definitely starting to seem like a low-impact
solution compared to these others.  Under what circumstances would you
be wanting hide-from-client with an elevel different from LOG, anyway?
        regards, tom lane

On 3/29/16 10:18 AM, Tom Lane wrote:
> David Steele <david@pgmasters.net> writes:
>> On 3/28/16 2:00 PM, Tom Lane wrote:
>>> One idea is to invent a new elevel which is never sent to the client ---
>>> analogously to COMMERROR, though probably much higher priority than that,
>>> maybe the same priority as LOG.  If there actually is a use for a range of
>>> elevels on errhidefromclient'd messages, that wouldn't work very well of
>>> course.  Or we could consider having a flag bit that is OR'd into the
>>> elevel <...>
>
>> I think a flag would be more flexible than introducing a new log level.
>
> I thought about this some more, and while the flag-bit approach definitely
> has some attraction, it also has a big problem: there are lots of places
> with code like "if (elevel >= ERROR)" which would be at risk of getting
> confused, and I'm not confident we'd find them all.  We could possibly
> dodge that by shifting the elevel constants up a couple of bits and
> putting the flag in the LSB rather than a high-order bit; but that's a
> bit icky/risky too.
>
> Repurposing COMMERROR is definitely starting to seem like a low-impact
> solution compared to these others.  Under what circumstances would you
> be wanting hide-from-client with an elevel different from LOG, anyway?

In pgaudit the log level for audit messages is user configurable but 
this was mostly added for testing purposes on the client side.  I don't 
think it would be a big deal to force the level to LOG when client 
output is suppressed.

The advantage of this approach is that it will also work on older 
versions of PG so I don't have to wait to introduce the feature.  I'll 
try it out and see how it goes.

Thanks,
-- 
-David
david@pgmasters.net

David Steele wrote:
> On 3/29/16 10:18 AM, Tom Lane wrote:

> >Repurposing COMMERROR is definitely starting to seem like a low-impact
> >solution compared to these others.  Under what circumstances would you
> >be wanting hide-from-client with an elevel different from LOG, anyway?
> 
> In pgaudit the log level for audit messages is user configurable but this
> was mostly added for testing purposes on the client side.  I don't think it
> would be a big deal to force the level to LOG when client output is
> suppressed.

So audit records would use COMMERROR?  That sounds really bad to me.

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

On 3/29/16 11:37 AM, Alvaro Herrera wrote:
> David Steele wrote:
>> On 3/29/16 10:18 AM, Tom Lane wrote:
>
>>> Repurposing COMMERROR is definitely starting to seem like a low-impact
>>> solution compared to these others.  Under what circumstances would you
>>> be wanting hide-from-client with an elevel different from LOG, anyway?
>>
>> In pgaudit the log level for audit messages is user configurable but this
>> was mostly added for testing purposes on the client side.  I don't think it
>> would be a big deal to force the level to LOG when client output is
>> suppressed.
>
> So audit records would use COMMERROR?  That sounds really bad to me.

I'm not a big fan of it myself but my ideas don't seem to be getting any 
traction...

-- 
-David
david@pgmasters.net

Alvaro Herrera <alvherre@2ndquadrant.com> writes:
> David Steele wrote:
>> On 3/29/16 10:18 AM, Tom Lane wrote:
>>> Repurposing COMMERROR is definitely starting to seem like a low-impact
>>> solution compared to these others.  Under what circumstances would you
>>> be wanting hide-from-client with an elevel different from LOG, anyway?

> So audit records would use COMMERROR?  That sounds really bad to me.

My proposal would be to invent a new elevel macro, maybe LOG_ONLY,
for this purpose.  But under the hood it'd be the same as COMMERROR.
        regards, tom lane

On 3/29/16 12:28 PM, Tom Lane wrote:
> Alvaro Herrera <alvherre@2ndquadrant.com> writes:
>> David Steele wrote:
>>> On 3/29/16 10:18 AM, Tom Lane wrote:
>>>> Repurposing COMMERROR is definitely starting to seem like a low-impact
>>>> solution compared to these others.  Under what circumstances would you
>>>> be wanting hide-from-client with an elevel different from LOG, anyway?
>
>> So audit records would use COMMERROR?  That sounds really bad to me.
>
> My proposal would be to invent a new elevel macro, maybe LOG_ONLY,
> for this purpose.  But under the hood it'd be the same as COMMERROR.

My mistake, I see what you are getting at now.

-- 
-David
david@pgmasters.net

On 2016-03-29 12:28:40 -0400, Tom Lane wrote:
> Alvaro Herrera <alvherre@2ndquadrant.com> writes:
> > David Steele wrote:
> >> On 3/29/16 10:18 AM, Tom Lane wrote:
> >>> Repurposing COMMERROR is definitely starting to seem like a low-impact
> >>> solution compared to these others.  Under what circumstances would you
> >>> be wanting hide-from-client with an elevel different from LOG, anyway?
> 
> > So audit records would use COMMERROR?  That sounds really bad to me.
> 
> My proposal would be to invent a new elevel macro, maybe LOG_ONLY,
> for this purpose.  But under the hood it'd be the same as COMMERROR.

A couple years back I proposed making thinks like COMERROR into flags |
ed into elevel, rather than distinct levels.  I still think that's a
better approach; and it doesn't force us to forgo using distinct log
levels.

Andres

On 2016-03-29 18:33:19 +0200, Andres Freund wrote:
> A couple years back I proposed making thinks like COMERROR into flags |
> ed into elevel, rather than distinct levels.  I still think that's a
> better approach; and it doesn't force us to forgo using distinct log
> levels.

http://archives.postgresql.org/message-id/201002132237.43930.andres%40anarazel.de

Andres Freund <andres@anarazel.de> writes:
> On 2016-03-29 12:28:40 -0400, Tom Lane wrote:
>> My proposal would be to invent a new elevel macro, maybe LOG_ONLY,
>> for this purpose.  But under the hood it'd be the same as COMMERROR.

> A couple years back I proposed making thinks like COMERROR into flags |
> ed into elevel, rather than distinct levels.  I still think that's a
> better approach; and it doesn't force us to forgo using distinct log
> levels.

If we invent LOG_ONLY (feel free to bikeshed the name), we could later
redefine it as (LOG | ERR_HIDE_FROM_CLIENT), if we ever upgrade the
underlying implementation to allow that.  But I remain concerned about
dealing with logic like "if (elevel < ERROR)", and I am unconvinced that
there's a near-term use-case here that's compelling enough to justify
finding all the places that do that.
        regards, tom lane

On 2016-03-29 12:38:48 -0400, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> > On 2016-03-29 12:28:40 -0400, Tom Lane wrote:
> If we invent LOG_ONLY (feel free to bikeshed the name), we could later
> redefine it as (LOG | ERR_HIDE_FROM_CLIENT), if we ever upgrade the
> underlying implementation to allow that.  But I remain concerned about
> dealing with logic like "if (elevel < ERROR)", and I am unconvinced that
> there's a near-term use-case here that's compelling enough to justify
> finding all the places that do that.

Hm. Putting the distinct levels in the upper bits, and the flags in the
lower bits should deal with that concern?   We already have a bunch of
pretty ugly bits about errors that shouldn't go to clients, I'd rather
have something that allows addressing those as well.

On Tue, Mar 29, 2016 at 12:38 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Andres Freund <andres@anarazel.de> writes:
>> On 2016-03-29 12:28:40 -0400, Tom Lane wrote:
>>> My proposal would be to invent a new elevel macro, maybe LOG_ONLY,
>>> for this purpose.  But under the hood it'd be the same as COMMERROR.
>
>> A couple years back I proposed making thinks like COMERROR into flags |
>> ed into elevel, rather than distinct levels.  I still think that's a
>> better approach; and it doesn't force us to forgo using distinct log
>> levels.
>
> If we invent LOG_ONLY (feel free to bikeshed the name), we could later
> redefine it as (LOG | ERR_HIDE_FROM_CLIENT), if we ever upgrade the
> underlying implementation to allow that.  But I remain concerned about
> dealing with logic like "if (elevel < ERROR)", and I am unconvinced that
> there's a near-term use-case here that's compelling enough to justify
> finding all the places that do that.

Yeah, I think it's dead certain that such code exists, and, ahem, not
only in our tree.  I suspect that EDB is not the only organization
that has written code that involves comparing error levels.  Putting
the flags in the low-order bits seems like it might be workable, but I
think using a high-order bit is right out.

I don't agree that there is no compelling use case for log-only
output.  I think there's a lot of use case for that, either for
general auditing (like pgaudit) or for any specific case where you
want to log sensitive information that shouldn't ever be allowed to
leak to the client.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Robert Haas wrote:

> Yeah, I think it's dead certain that such code exists, and, ahem, not
> only in our tree.  I suspect that EDB is not the only organization
> that has written code that involves comparing error levels.  Putting
> the flags in the low-order bits seems like it might be workable, but I
> think using a high-order bit is right out.

We could redefine elevel as a struct when assertions are enabled, and
provide functions to do the < comparisons in that case; they would
reduce to regular integers when assertions are disabled.  That would
raise compile-time errors in all places that need to be updated.

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

Robert Haas <robertmhaas@gmail.com> writes:
> On Tue, Mar 29, 2016 at 12:38 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> If we invent LOG_ONLY (feel free to bikeshed the name), we could later
>> redefine it as (LOG | ERR_HIDE_FROM_CLIENT), if we ever upgrade the
>> underlying implementation to allow that.  But I remain concerned about
>> dealing with logic like "if (elevel < ERROR)", and I am unconvinced that
>> there's a near-term use-case here that's compelling enough to justify
>> finding all the places that do that.

> Yeah, I think it's dead certain that such code exists, and, ahem, not
> only in our tree.  I suspect that EDB is not the only organization
> that has written code that involves comparing error levels.

Yeah, that's exactly my concern: it'd likely break third-party code
not only our own.

> Putting
> the flags in the low-order bits seems like it might be workable, but I
> think using a high-order bit is right out.

We'd need a bit more investigation.  I'm not exactly sure that we can
renumber the existing elevel codes at all without breaking things
(guc.c's management of client_min_messages et al would be a place
to look at, for instance).  But if someone wants to pursue it,
the general concept seems somewhat sane.

Looking back at the earlier thread Andres mentioned, I see that he was
specifically on about being able to do ereport(ERROR | LOG_NO_CLIENT),
which I've got a problem with because of the point about not breaking
wire-protocol expectations.  You could maybe define such a case as
substituting a text like "error message is hidden" when sending the
error to the client?  But the draft patch he had didn't address that
point, and it doesn't look like he thought about the elevel-comparisons
issue either.

> I don't agree that there is no compelling use case for log-only
> output.  I think there's a lot of use case for that, either for
> general auditing (like pgaudit) or for any specific case where you
> want to log sensitive information that shouldn't ever be allowed to
> leak to the client.

Oh, I agree that there's a compelling use-case for LOG |
ERR_HIDE_FROM_CLIENT.  I'm less certain that there's a use-case
for supporting such a flag across all elevels that is strong enough
to justify all the work we'd have to do to make it happen.  Basically,
my point is that LOG_ONLY achieves 95% of the benefit for probably
0.01% of the work.
        regards, tom lane

On Tue, Mar 29, 2016 at 12:58 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Robert Haas <robertmhaas@gmail.com> writes:
>> On Tue, Mar 29, 2016 at 12:38 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>>> If we invent LOG_ONLY (feel free to bikeshed the name), we could later
>>> redefine it as (LOG | ERR_HIDE_FROM_CLIENT), if we ever upgrade the
>>> underlying implementation to allow that.  But I remain concerned about
>>> dealing with logic like "if (elevel < ERROR)", and I am unconvinced that
>>> there's a near-term use-case here that's compelling enough to justify
>>> finding all the places that do that.
>
>> Yeah, I think it's dead certain that such code exists, and, ahem, not
>> only in our tree.  I suspect that EDB is not the only organization
>> that has written code that involves comparing error levels.
>
> Yeah, that's exactly my concern: it'd likely break third-party code
> not only our own.
>
>> Putting
>> the flags in the low-order bits seems like it might be workable, but I
>> think using a high-order bit is right out.
>
> We'd need a bit more investigation.  I'm not exactly sure that we can
> renumber the existing elevel codes at all without breaking things
> (guc.c's management of client_min_messages et al would be a place
> to look at, for instance).  But if someone wants to pursue it,
> the general concept seems somewhat sane.
>
> Looking back at the earlier thread Andres mentioned, I see that he was
> specifically on about being able to do ereport(ERROR | LOG_NO_CLIENT),
> which I've got a problem with because of the point about not breaking
> wire-protocol expectations.  You could maybe define such a case as
> substituting a text like "error message is hidden" when sending the
> error to the client?  But the draft patch he had didn't address that
> point, and it doesn't look like he thought about the elevel-comparisons
> issue either.
>
>> I don't agree that there is no compelling use case for log-only
>> output.  I think there's a lot of use case for that, either for
>> general auditing (like pgaudit) or for any specific case where you
>> want to log sensitive information that shouldn't ever be allowed to
>> leak to the client.
>
> Oh, I agree that there's a compelling use-case for LOG |
> ERR_HIDE_FROM_CLIENT.  I'm less certain that there's a use-case
> for supporting such a flag across all elevels that is strong enough
> to justify all the work we'd have to do to make it happen.  Basically,
> my point is that LOG_ONLY achieves 95% of the benefit for probably
> 0.01% of the work.

If LOG_ONLY is what we can get right now, I'm happy to take the money and run.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On 2016-03-29 12:58:22 -0400, Tom Lane wrote:
> Looking back at the earlier thread Andres mentioned, I see that he was
> specifically on about being able to do ereport(ERROR | LOG_NO_CLIENT),
> which I've got a problem with because of the point about not breaking
> wire-protocol expectations.

Yes.  The reason for doing it in that case is that we weren't allowed to
send errors to the client in that specific case - by the protocol state.

There's a number of cases during early startup/auth where we really
don't want client to get messages.


> and it doesn't look like he thought about the elevel-comparisons
> issue either.

Nope, I didn't. That's a long while ago ;)

Greetings,

Andres Freund

Andres Freund <andres@anarazel.de> writes:
> There's a number of cases during early startup/auth where we really
> don't want client to get messages.

Right, which we handle at present with ClientAuthInProgress.  But
I think it's worth drawing a distinction between "don't send message
to client because of the state we're in" and "don't send this message
to client because it's security-sensitive".  The latter is better
handled by annotations attached to specific ereport sites, the former
not.
        regards, tom lane

Hi Tom,

On 3/29/16 12:58 PM, Tom Lane wrote:

> Oh, I agree that there's a compelling use-case for LOG |
> ERR_HIDE_FROM_CLIENT.  I'm less certain that there's a use-case
> for supporting such a flag across all elevels that is strong enough
> to justify all the work we'd have to do to make it happen.  Basically,
> my point is that LOG_ONLY achieves 95% of the benefit for probably
> 0.01% of the work.

Attached is a patch that re-purposes COMMERROR as LOG_SERVER_ONLY.  I
went ahead and replaced all instances of COMMERROR with LOG_SERVER_ONLY.

I left the COMMERROR #define but it is no longer used by any server,
client, or included contrib code (I also noted that it was DEPRECATED in
the comment).  I'll leave it up to the committer to remove if deemed
appropriate.

I realize there's no agreement on how this should work ideally, but this
patch answers the current need without introducing anything new and
shouldn't cause regressions.  It does address confusion that would arise
from using COMMERROR in ereports that clearly are not.

Thanks,
--
-David
david@pgmasters.net

David Steele <david@pgmasters.net> writes:
> On 3/29/16 12:58 PM, Tom Lane wrote:
>> ...  Basically,
>> my point is that LOG_ONLY achieves 95% of the benefit for probably
>> 0.01% of the work.

> Attached is a patch that re-purposes COMMERROR as LOG_SERVER_ONLY.  I 
> went ahead and replaced all instances of COMMERROR with LOG_SERVER_ONLY.

Uh, what?  COMMERROR is a distinct concept in my opinion.  It might happen
to share the same implementation today, but that doesn't make it the
same thing.

I had in mind a patch that simply added LOG_SERVER_ONLY as another define
and did whatever seemed appropriate documentation-wise.  I see no reason
to touch the places that are currently dealing with client communication
failures.
        regards, tom lane

On 4/4/16 11:21 AM, Tom Lane wrote:
> David Steele <david@pgmasters.net> writes:
>> On 3/29/16 12:58 PM, Tom Lane wrote:
>>> ...  Basically,
>>> my point is that LOG_ONLY achieves 95% of the benefit for probably
>>> 0.01% of the work.
>
>> Attached is a patch that re-purposes COMMERROR as LOG_SERVER_ONLY.  I
>> went ahead and replaced all instances of COMMERROR with LOG_SERVER_ONLY.
>
> Uh, what?  COMMERROR is a distinct concept in my opinion.  It might happen
> to share the same implementation today, but that doesn't make it the
> same thing.

Fair enough.

> I had in mind a patch that simply added LOG_SERVER_ONLY as another define
> and did whatever seemed appropriate documentation-wise.  I see no reason
> to touch the places that are currently dealing with client communication
> failures.

I still prefer to collapse them into a single value for the current
implementation.  Otherwise there are several places that need to check
for both in elog.c and their behavior is identical (for now).  For my 2c
it makes more sense to collapse COMMERROR into LOG_SERVER_ONLY since
that more accurately describes what it actually does in the elog code.

What do you think of the attached?

COMMERROR was not documented in sources.sgml so LOG_SERVER_ONLY wasn't
either.  I'm happy to do that that though it's not clear to me where it
would go.  I could just put it in the general description.

Thanks,
--
-David
david@pgmasters.net

David Steele <david@pgmasters.net> writes:
> On 4/4/16 11:21 AM, Tom Lane wrote:
>> I had in mind a patch that simply added LOG_SERVER_ONLY as another define
>> and did whatever seemed appropriate documentation-wise.  I see no reason
>> to touch the places that are currently dealing with client communication
>> failures.

> I still prefer to collapse them into a single value for the current 
> implementation.

Right, that's what I had in mind, sorry if I was unclear.  I agree that
considering LOG_SERVER_ONLY as the main name and COMMERROR as an alias
is reasonable.

> COMMERROR was not documented in sources.sgml so LOG_SERVER_ONLY wasn't 
> either.  I'm happy to do that that though it's not clear to me where it 
> would go.  I could just put it in the general description.

Ah, I thought I remembered that the specific elevels were documented
there, but I see they're only documented in elog.h.  Doesn't seem like
it's incumbent on this patch to improve that.

Committed with a quick pgindent fixup.
        regards, tom lane

On 4/4/16 12:36 PM, Tom Lane wrote:
> David Steele <david@pgmasters.net> writes:
>> On 4/4/16 11:21 AM, Tom Lane wrote:
>>> I had in mind a patch that simply added LOG_SERVER_ONLY as another define
>>> and did whatever seemed appropriate documentation-wise.  I see no reason
>>> to touch the places that are currently dealing with client communication
>>> failures.
>
>> I still prefer to collapse them into a single value for the current
>> implementation.
>
> Right, that's what I had in mind, sorry if I was unclear.  I agree that
> considering LOG_SERVER_ONLY as the main name and COMMERROR as an alias
> is reasonable.
>
>> COMMERROR was not documented in sources.sgml so LOG_SERVER_ONLY wasn't
>> either.  I'm happy to do that that though it's not clear to me where it
>> would go.  I could just put it in the general description.
>
> Ah, I thought I remembered that the specific elevels were documented
> there, but I see they're only documented in elog.h.  Doesn't seem like
> it's incumbent on this patch to improve that.
>
> Committed with a quick pgindent fixup.

Thank you, and I appreciate you suggesting this simple solution.

The advantage of this over the other possible solutions is that I can 
easily port the feature back to 9.5 by defining LOG_SERVER_ONLY when 
building pgaudit for that version.  That's a big win in my mind.

-- 
-David
david@pgmasters.net