Thread: replication commands and log_statements

Hi,

Replication commands like IDENTIFY_COMMAND are not logged even when
log_statements is set to all. Some users who use log_statements to
audit *all* statements might dislike this current situation. So I'm
thinking to change log_statements or add something like log_replication
so that we can log replication commands. Thought?

Regards,

-- 
Fujii Masao

On 2014-06-11 19:34:25 +0900, Fujii Masao wrote:
> Hi,
> 
> Replication commands like IDENTIFY_COMMAND are not logged even when
> log_statements is set to all. Some users who use log_statements to
> audit *all* statements might dislike this current situation. So I'm
> thinking to change log_statements or add something like log_replication
> so that we can log replication commands. Thought?

Yes, I think we should do that. I can't really see it causing too much
volume...

Greetings,

Andres Freund

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

On 2014-06-11 13:42:58 +0200, Magnus Hagander wrote:
> On Wed, Jun 11, 2014 at 12:34 PM, Fujii Masao <masao.fujii@gmail.com> wrote:
> 
> > Hi,
> >
> > Replication commands like IDENTIFY_COMMAND are not logged even when
> > log_statements is set to all. Some users who use log_statements to
> > audit *all* statements might dislike this current situation. So I'm
> > thinking to change log_statements or add something like log_replication
> > so that we can log replication commands. Thought?
> >
> 
> +1. I think adding a separate parameter is the way to go.

Why? I can't really see a case where the log volume by replication
connections is going to be significant in comparison to 'all'?

Greetings,

Andres Freund

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

On 2014-06-11 14:22:43 +0200, Magnus Hagander wrote:
> Yes, but how would you specify for example "i want DDL and all replication
> commands" (which is quite a reasonable thing to log, I believe). If you
> actually require it to be set to "all", most people won't have any use at
> all for it...

That's a reasonable feature request - but imo it's a separate
one. It seems pretty noncontroversial and simple to make
log_statement=all log replication commands. What you want - and you're
sure not alone with that - is something considerably more complex...

Greetings,

Andres Freund

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

On 2014-06-11 14:50:34 +0200, Magnus Hagander wrote:
> On Wed, Jun 11, 2014 at 2:35 PM, Andres Freund <andres@2ndquadrant.com>
> wrote:
> 
> > On 2014-06-11 14:22:43 +0200, Magnus Hagander wrote:
> > > Yes, but how would you specify for example "i want DDL and all
> > replication
> > > commands" (which is quite a reasonable thing to log, I believe). If you
> > > actually require it to be set to "all", most people won't have any use at
> > > all for it...
> >
> > That's a reasonable feature request - but imo it's a separate
> > one. It seems pretty noncontroversial and simple to make
> > log_statement=all log replication commands. What you want - and you're
> > sure not alone with that - is something considerably more complex...
> >
> >

> I'm just saying if we're going to do it, let's do it right from the
> beginning.

Your wish just seems like a separate feature to me. Including
replication commands in 'all' seems correct independent of the desire
for a more granular control.

> Or are you suggesting this would be something we'd backpatch?

Thought about it for a sec, and then decided it doesn't seem warranted.

Greetings,

Andres Freund

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

Andres Freund <andres@2ndquadrant.com> writes:
> Your wish just seems like a separate feature to me. Including
> replication commands in 'all' seems correct independent of the desire
> for a more granular control.

No, I think I've got to vote with the other side on that.

The reason we can have log_statement as a scalar progression
"none < ddl < mod < all" is that there's little visible use-case
for logging DML but not DDL, nor for logging SELECTS but not
INSERT/UPDATE/DELETE.  However, logging replication commands seems
like something people would reasonably want an orthogonal control for.
There's no nice way to squeeze such a behavior into log_statement.

I guess you could say that log_statement treats replication commands
as if they were DDL, but is that really going to satisfy users?

I think we should consider log_statement to control logging of
SQL only, and invent a separate GUC (or, in the future, likely
more than one GUC?) for logging of replication activity.
        regards, tom lane

On Wed, Jun 11, 2014 at 11:55 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Andres Freund <andres@2ndquadrant.com> writes:
>> Your wish just seems like a separate feature to me. Including
>> replication commands in 'all' seems correct independent of the desire
>> for a more granular control.
>
> No, I think I've got to vote with the other side on that.
>
> The reason we can have log_statement as a scalar progression
> "none < ddl < mod < all" is that there's little visible use-case
> for logging DML but not DDL, nor for logging SELECTS but not
> INSERT/UPDATE/DELETE.  However, logging replication commands seems
> like something people would reasonably want an orthogonal control for.
> There's no nice way to squeeze such a behavior into log_statement.
>
> I guess you could say that log_statement treats replication commands
> as if they were DDL, but is that really going to satisfy users?
>
> I think we should consider log_statement to control logging of
> SQL only, and invent a separate GUC (or, in the future, likely
> more than one GUC?) for logging of replication activity.

Seems reasonable. OK. The attached patch adds log_replication_command
parameter which causes replication commands to be logged. I added this to
next CF.

Regards,

--
Fujii Masao

On Wed, Jun 11, 2014 at 7:42 AM, Magnus Hagander <magnus@hagander.net> wrote:
>> Replication commands like IDENTIFY_COMMAND are not logged even when
>> log_statements is set to all. Some users who use log_statements to
>> audit *all* statements might dislike this current situation. So I'm
>> thinking to change log_statements or add something like log_replication
>> so that we can log replication commands. Thought?
>
> +1. I think adding a separate parameter is the way to go.
>
> The other option would be to turn log_statements into a parameter that you
> specify multiple ones

I kind of like this idea, but...

> - so instead of "all" today it would be "ddl,dml,all"
> or something like that, and then you'd also add "replication" as an option.
> But that would cause all sorts of backwards compatibility annoyances.. And
> do you really want to be able to say things like "ddl,all" meanin you'd get
> ddl and select but not dml?

...you lost me here.  I mean, I think it could be quite useful to
redefine the existing GUC as a list.  We could continue to have ddl,
dml, and all as tokens that would be in the list, but you wouldn't
write "ddl,dml,all" because "all" would include everything that those
other ones would log.  But then you could have combinations like
"dml,replication" and so on.  And you could do much more fine-grained
things, like allow log_statement=create,alter,drop to log all such
statements but not, for example, cluster.

I think if we go the route of adding a separate GUC for this, we're
going to get tired of adding GUCs way before we've come close to
meeting the actual requirements in this area.  A comma-separated list
of tokens seems to offer a lot more flexibility.

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

On 12/06/14 20:37, Fujii Masao wrote:
> On Wed, Jun 11, 2014 at 11:55 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Andres Freund <andres@2ndquadrant.com> writes:
>>> Your wish just seems like a separate feature to me. Including
>>> replication commands in 'all' seems correct independent of the desire
>>> for a more granular control.
>>
>> No, I think I've got to vote with the other side on that.
>>
>> The reason we can have log_statement as a scalar progression
>> "none < ddl < mod < all" is that there's little visible use-case
>> for logging DML but not DDL, nor for logging SELECTS but not
>> INSERT/UPDATE/DELETE.  However, logging replication commands seems
>> like something people would reasonably want an orthogonal control for.
>> There's no nice way to squeeze such a behavior into log_statement.
>>
>> I guess you could say that log_statement treats replication commands
>> as if they were DDL, but is that really going to satisfy users?
>>
>> I think we should consider log_statement to control logging of
>> SQL only, and invent a separate GUC (or, in the future, likely
>> more than one GUC?) for logging of replication activity.
>
> Seems reasonable. OK. The attached patch adds log_replication_command
> parameter which causes replication commands to be logged. I added this to
> next CF.

A quick review:

- Compiles against HEAD
- Works as advertised
- Code style looks fine


A couple of suggestions:

- minor rewording for the description, mentioning that statements will  still be logged as DEBUG1 even if parameter set
to'off' (might  prevent reports of the kind "I set it to 'off', why am I still seeing  log entries?").
 
       <para>        Causes each replication command to be logged in the server log.        See <xref
linkend="protocol-replication">for more information about        replication commands. The default value is
<literal>off</>.When set to        <literal>off</>, commands will be logged at log level <literal>DEBUG1</literal>.
  Only superusers can change this setting.       </para>
 

- I feel it would be more consistent to use the plural form  for this parameter, i.e. "log_replication_commands", in
linewith  "log_lock_waits", "log_temp_files", "log_disconnections" etc.
 

- It might be an idea to add a cross-reference to this parameter from  the "Streaming Replication Protocol" page:
http://www.postgresql.org/docs/devel/static/protocol-replication.html


Regards


Ian Barwick

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

On Thu, Jun 12, 2014 at 10:55 PM, Robert Haas <robertmhaas@gmail.com> wrote:
> On Wed, Jun 11, 2014 at 7:42 AM, Magnus Hagander <magnus@hagander.net> wrote:
>>> Replication commands like IDENTIFY_COMMAND are not logged even when
>>> log_statements is set to all. Some users who use log_statements to
>>> audit *all* statements might dislike this current situation. So I'm
>>> thinking to change log_statements or add something like log_replication
>>> so that we can log replication commands. Thought?
>>
>> +1. I think adding a separate parameter is the way to go.
>>
>> The other option would be to turn log_statements into a parameter that you
>> specify multiple ones
>
> I kind of like this idea, but...
>
>> - so instead of "all" today it would be "ddl,dml,all"
>> or something like that, and then you'd also add "replication" as an option.
>> But that would cause all sorts of backwards compatibility annoyances.. And
>> do you really want to be able to say things like "ddl,all" meanin you'd get
>> ddl and select but not dml?
>
> ...you lost me here.  I mean, I think it could be quite useful to
> redefine the existing GUC as a list.  We could continue to have ddl,
> dml, and all as tokens that would be in the list, but you wouldn't
> write "ddl,dml,all" because "all" would include everything that those
> other ones would log.  But then you could have combinations like
> "dml,replication" and so on.

Yep, that seems useful, even aside from logging of replication command topic.
OK, I've just implemented the patch (attached) which does this, i.e., redefines
log_statement as a list. Thanks to the patch, log_statement can be set
to "none",
"ddl", "mod", "dml", "all", and any combinations of them. The meanings of
"none", "ddl", "mod" and "all" are the same as they are now. New setting value
"dml" loggs both data modification statements like INSERT and query access
statements like SELECT and COPY TO.

What about applying this patch first?

Regards,

--
Fujii Masao

Fujii Masao <masao.fujii@gmail.com> writes:
> OK, I've just implemented the patch (attached) which does this, i.e., redefines
> log_statement as a list. Thanks to the patch, log_statement can be set
> to "none",
> "ddl", "mod", "dml", "all", and any combinations of them. The meanings of
> "none", "ddl", "mod" and "all" are the same as they are now. New setting value
> "dml" loggs both data modification statements like INSERT and query access
> statements like SELECT and COPY TO.

I still don't like this one bit.  It's turning log_statement from a
reasonably clean design into a complete mess, which will be made even
worse after you add replication control to it.
        regards, tom lane

On Fri, Jun 20, 2014 at 10:48 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Fujii Masao <masao.fujii@gmail.com> writes:
>> OK, I've just implemented the patch (attached) which does this, i.e., redefines
>> log_statement as a list. Thanks to the patch, log_statement can be set
>> to "none",
>> "ddl", "mod", "dml", "all", and any combinations of them. The meanings of
>> "none", "ddl", "mod" and "all" are the same as they are now. New setting value
>> "dml" loggs both data modification statements like INSERT and query access
>> statements like SELECT and COPY TO.
>
> I still don't like this one bit.  It's turning log_statement from a
> reasonably clean design into a complete mess, which will be made even
> worse after you add replication control to it.
Yeah, I'd vote as well to let log_statement as it is (without
mentioning the annoyance it would cause to users), and to have
replication statement logging managed with a separate GUC for clarity.
-- 
Michael

On Fri, Jun 20, 2014 at 9:48 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Fujii Masao <masao.fujii@gmail.com> writes:
>> OK, I've just implemented the patch (attached) which does this, i.e., redefines
>> log_statement as a list. Thanks to the patch, log_statement can be set
>> to "none",
>> "ddl", "mod", "dml", "all", and any combinations of them. The meanings of
>> "none", "ddl", "mod" and "all" are the same as they are now. New setting value
>> "dml" loggs both data modification statements like INSERT and query access
>> statements like SELECT and COPY TO.
>
> I still don't like this one bit.  It's turning log_statement from a
> reasonably clean design into a complete mess, which will be made even
> worse after you add replication control to it.

Well, I don't object to having a separate GUC for replication command
logging if people prefer that design.  But let's not have any
delusions of adequacy about log_statement.  I've had more than one
conversation with customers about that particular parameter, all of
which involved the customer being unhappy that there were only four
choices and they couldn't log the stuff that they cared about without
logging a lot of other stuff that they didn't care about.  Now,
providing more choices there will, indisputably, add complexity, but
it will also provide utility.

What we're talking about here is not unlike what we went through with
EXPLAIN syntax.  We repeatedly rejected patches that might have added
useful functionality to EXPLAIN on the grounds that (1) we didn't want
to make new keywords and (2) even if we did add new keywords,
extending the EXPLAIN productions would produce grammar conflicts.
Then, we implemented the extensible-options stuff, and suddenly it
became possible for people to write patches adding useful
functionality to EXPLAIN that didn't get sunk before it got out of the
gate, and since then we've gotten a new EXPLAIN option every release
or two, and IMHO all of those options are pretty useful.  Similarly,
building a logging facility that meets the needs of real users is
going to require a configuration method more flexible than a total
order with four choices.  I happen to think a list of comma-separated
tokens is a pretty good choice, but something else could be OK, too.
We need something better than what we've got now, though.

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

* Robert Haas (robertmhaas@gmail.com) wrote:
> Similarly,
> building a logging facility that meets the needs of real users is
> going to require a configuration method more flexible than a total
> order with four choices.  I happen to think a list of comma-separated
> tokens is a pretty good choice, but something else could be OK, too.
> We need something better than what we've got now, though.

Absolutely, and not all of that should be done through postgresql.conf,
imv.  The level of flexibility that is being asked for, from what I've
seen and heard, really needs to be met with new catalog tables or
extending existing ones.  The nearby thread on pg_audit would be a good
example.

I certainly don't want to be specifying specific table names or
providing a list of roles through any GUC (or configuration file of any
kind).  I'm not adverse to improving log_statement to a list with tokens
that indicate various meaning levels but anything done through that
mechanism will be very coarse.
Thanks,
    Stephen

On Mon, Jun 23, 2014 at 11:15 AM, Stephen Frost <sfrost@snowman.net> wrote:
> * Robert Haas (robertmhaas@gmail.com) wrote:
>> Similarly,
>> building a logging facility that meets the needs of real users is
>> going to require a configuration method more flexible than a total
>> order with four choices.  I happen to think a list of comma-separated
>> tokens is a pretty good choice, but something else could be OK, too.
>> We need something better than what we've got now, though.
>
> Absolutely, and not all of that should be done through postgresql.conf,
> imv.  The level of flexibility that is being asked for, from what I've
> seen and heard, really needs to be met with new catalog tables or
> extending existing ones.  The nearby thread on pg_audit would be a good
> example.
>
> I certainly don't want to be specifying specific table names or
> providing a list of roles through any GUC (or configuration file of any
> kind).  I'm not adverse to improving log_statement to a list with tokens
> that indicate various meaning levels but anything done through that
> mechanism will be very coarse.

True, but it would be enough to let you make a list of commands you'd
like to audit, and I think that might be valuable enough to justify
the price of admission.  I certainly agree that logging based on which
object is being accessed needs a different design, tied into the
catalogs.

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

Hi.

Do we have any consensus about what to do with these two patches?

1. Introduce a "log_replication_command" setting.
2. Change log_statement to be a list of tokens.

If I understand correctly, there weren't any strong objections to the
former, but the situation is less clear when it comes to the second.

-- Abhijit

On Wed, Jul 2, 2014 at 4:26 AM, Abhijit Menon-Sen <ams@2ndquadrant.com> wrote:
> Hi.
>
> Do we have any consensus about what to do with these two patches?
>
> 1. Introduce a "log_replication_command" setting.
> 2. Change log_statement to be a list of tokens.
>
> If I understand correctly, there weren't any strong objections to the
> former, but the situation is less clear when it comes to the second.

On second thought, I'd like to propose the third option. This is the same idea
as Andres suggested upthread. That is, we log replication commands only
when log_statement is set to all. Neither new parameter is introduced nor
log_statement is redefined as a list.

Firstly, since log_statement=all means that all statements are logged, it's
basically natural and intuitive to log even replication commands in that
setting. Secondly, any statements except DDL and data-modifying statements,
e.g., VACUUM, CHECKPOINT, BEGIN, ..etc, are logged only when log_statement=all.
So even if some users want to control the logging of DDL and maintenance
commands orthogonally, which is impossible for now. Therefore, even if the
logging of replication commands which are neither DDL nor data-modifying
statements also cannot be controlled orthogonally, I don't think that users
get so surprised. Of course I have no objection to address the issue by, e.g.,
enabling such orthogonal logging control, in the future, though.

Thought? What about introducing that simple but not so confusing change first?

Regards,

-- 
Fujii Masao

At 2014-08-07 23:22:43 +0900, masao.fujii@gmail.com wrote:
>
> That is, we log replication commands only when log_statement is set to
> all. Neither new parameter is introduced nor log_statement is
> redefined as a list.

That sounds good to me.

-- Abhijit

On Thu, Aug 7, 2014 at 12:07 PM, Abhijit Menon-Sen <ams@2ndquadrant.com> wrote:
> At 2014-08-07 23:22:43 +0900, masao.fujii@gmail.com wrote:
>> That is, we log replication commands only when log_statement is set to
>> all. Neither new parameter is introduced nor log_statement is
>> redefined as a list.
>
> That sounds good to me.

It sounds fairly unprincipled to me.  I liked the idea of making
log_statement a list, but if we aren't gonna do that, I think this
should be a separate parameter.

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

On Fri, Aug  8, 2014 at 08:51:13AM -0400, Robert Haas wrote:
> On Thu, Aug 7, 2014 at 12:07 PM, Abhijit Menon-Sen <ams@2ndquadrant.com> wrote:
> > At 2014-08-07 23:22:43 +0900, masao.fujii@gmail.com wrote:
> >> That is, we log replication commands only when log_statement is set to
> >> all. Neither new parameter is introduced nor log_statement is
> >> redefined as a list.
> >
> > That sounds good to me.
> 
> It sounds fairly unprincipled to me.  I liked the idea of making
> log_statement a list, but if we aren't gonna do that, I think this
> should be a separate parameter.

I am unclear there is enough demand for a separate replication logging
parameter --- using log_statement=all made sense to me.

--  Bruce Momjian  <bruce@momjian.us>        http://momjian.us EnterpriseDB
http://enterprisedb.com
 + Everyone has their own god. +

On Fri, Aug 8, 2014 at 11:00 AM, Bruce Momjian <bruce@momjian.us> wrote:
> On Fri, Aug  8, 2014 at 08:51:13AM -0400, Robert Haas wrote:
>> On Thu, Aug 7, 2014 at 12:07 PM, Abhijit Menon-Sen <ams@2ndquadrant.com> wrote:
>> > At 2014-08-07 23:22:43 +0900, masao.fujii@gmail.com wrote:
>> >> That is, we log replication commands only when log_statement is set to
>> >> all. Neither new parameter is introduced nor log_statement is
>> >> redefined as a list.
>> >
>> > That sounds good to me.
>>
>> It sounds fairly unprincipled to me.  I liked the idea of making
>> log_statement a list, but if we aren't gonna do that, I think this
>> should be a separate parameter.
>
> I am unclear there is enough demand for a separate replication logging
> parameter --- using log_statement=all made sense to me.

Most people don't want to turn on log_statement=all because it
produces too much log volume.

See, for example:
http://bonesmoses.org/2014/08/05/on-postgresql-logging-verbosity/

But logging replication commands is quite low-volume, so it is not
hard to imagine someone wanting to log all replication commands but
not all SQL statements.

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

On Sat, Aug 9, 2014 at 12:29 AM, Robert Haas <robertmhaas@gmail.com> wrote:
> On Fri, Aug 8, 2014 at 11:00 AM, Bruce Momjian <bruce@momjian.us> wrote:
>> On Fri, Aug  8, 2014 at 08:51:13AM -0400, Robert Haas wrote:
>>> On Thu, Aug 7, 2014 at 12:07 PM, Abhijit Menon-Sen <ams@2ndquadrant.com> wrote:
>>> > At 2014-08-07 23:22:43 +0900, masao.fujii@gmail.com wrote:
>>> >> That is, we log replication commands only when log_statement is set to
>>> >> all. Neither new parameter is introduced nor log_statement is
>>> >> redefined as a list.
>>> >
>>> > That sounds good to me.
>>>
>>> It sounds fairly unprincipled to me.  I liked the idea of making
>>> log_statement a list, but if we aren't gonna do that, I think this
>>> should be a separate parameter.
>>
>> I am unclear there is enough demand for a separate replication logging
>> parameter --- using log_statement=all made sense to me.
>
> Most people don't want to turn on log_statement=all because it
> produces too much log volume.
>
> See, for example:
> http://bonesmoses.org/2014/08/05/on-postgresql-logging-verbosity/
>
> But logging replication commands is quite low-volume, so it is not
> hard to imagine someone wanting to log all replication commands but
> not all SQL statements.

You can do that by executing
"ALTER ROLE <replication user> SET log_statement TO 'all'".
If you don't use the replication user to execute SQL statements,
no SQL statements are logged in that setting.

Regards,

-- 
Fujii Masao

On Fri, Aug 8, 2014 at 1:04 PM, Fujii Masao <masao.fujii@gmail.com> wrote:
> On Sat, Aug 9, 2014 at 12:29 AM, Robert Haas <robertmhaas@gmail.com> wrote:
>> On Fri, Aug 8, 2014 at 11:00 AM, Bruce Momjian <bruce@momjian.us> wrote:
>>> On Fri, Aug  8, 2014 at 08:51:13AM -0400, Robert Haas wrote:
>>>> On Thu, Aug 7, 2014 at 12:07 PM, Abhijit Menon-Sen <ams@2ndquadrant.com> wrote:
>>>> > At 2014-08-07 23:22:43 +0900, masao.fujii@gmail.com wrote:
>>>> >> That is, we log replication commands only when log_statement is set to
>>>> >> all. Neither new parameter is introduced nor log_statement is
>>>> >> redefined as a list.
>>>> >
>>>> > That sounds good to me.
>>>>
>>>> It sounds fairly unprincipled to me.  I liked the idea of making
>>>> log_statement a list, but if we aren't gonna do that, I think this
>>>> should be a separate parameter.
>>>
>>> I am unclear there is enough demand for a separate replication logging
>>> parameter --- using log_statement=all made sense to me.
>>
>> Most people don't want to turn on log_statement=all because it
>> produces too much log volume.
>>
>> See, for example:
>> http://bonesmoses.org/2014/08/05/on-postgresql-logging-verbosity/
>>
>> But logging replication commands is quite low-volume, so it is not
>> hard to imagine someone wanting to log all replication commands but
>> not all SQL statements.
>
> You can do that by executing
> "ALTER ROLE <replication user> SET log_statement TO 'all'".
> If you don't use the replication user to execute SQL statements,
> no SQL statements are logged in that setting.

If you have a user devoted to it, I suppose that's true.  I still
think it shouldn't get munged together like that.

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

* Robert Haas (robertmhaas@gmail.com) wrote:
> On Fri, Aug 8, 2014 at 1:04 PM, Fujii Masao <masao.fujii@gmail.com> wrote:
> > You can do that by executing
> > "ALTER ROLE <replication user> SET log_statement TO 'all'".
> > If you don't use the replication user to execute SQL statements,
> > no SQL statements are logged in that setting.
>
> If you have a user devoted to it, I suppose that's true.  I still
> think it shouldn't get munged together like that.

Folks *should* have a dedicated replication user, imv.  That said, I
agree with Robert in that I don't particularly like this recommendation
for how to enable logging of replication commands.  For one thing, it
means having to remember to set the per-role GUC for every replication
user which is created and that's the kind of trivially-missed step that
can get people into trouble.
Thanks,
    Stephen

On Tue, Aug 12, 2014 at 2:34 AM, Robert Haas <robertmhaas@gmail.com> wrote:
> On Fri, Aug 8, 2014 at 1:04 PM, Fujii Masao <masao.fujii@gmail.com> wrote:
>> On Sat, Aug 9, 2014 at 12:29 AM, Robert Haas <robertmhaas@gmail.com> wrote:
>>> On Fri, Aug 8, 2014 at 11:00 AM, Bruce Momjian <bruce@momjian.us> wrote:
>>>> On Fri, Aug  8, 2014 at 08:51:13AM -0400, Robert Haas wrote:
>>>>> On Thu, Aug 7, 2014 at 12:07 PM, Abhijit Menon-Sen <ams@2ndquadrant.com> wrote:
>>>>> > At 2014-08-07 23:22:43 +0900, masao.fujii@gmail.com wrote:
>>>>> >> That is, we log replication commands only when log_statement is set to
>>>>> >> all. Neither new parameter is introduced nor log_statement is
>>>>> >> redefined as a list.
>>>>> >
>>>>> > That sounds good to me.
>>>>>
>>>>> It sounds fairly unprincipled to me.  I liked the idea of making
>>>>> log_statement a list, but if we aren't gonna do that, I think this
>>>>> should be a separate parameter.
>>>>
>>>> I am unclear there is enough demand for a separate replication logging
>>>> parameter --- using log_statement=all made sense to me.
>>>
>>> Most people don't want to turn on log_statement=all because it
>>> produces too much log volume.
>>>
>>> See, for example:
>>> http://bonesmoses.org/2014/08/05/on-postgresql-logging-verbosity/
>>>
>>> But logging replication commands is quite low-volume, so it is not
>>> hard to imagine someone wanting to log all replication commands but
>>> not all SQL statements.
>>
>> You can do that by executing
>> "ALTER ROLE <replication user> SET log_statement TO 'all'".
>> If you don't use the replication user to execute SQL statements,
>> no SQL statements are logged in that setting.
>
> If you have a user devoted to it, I suppose that's true.  I still
> think it shouldn't get munged together like that.

Why do we need to treat only replication commands as special ones and
add new parameter to display them? I agree to add new parameter like
log_replication to log the replication activity instead of the command
itself, like checkpoint activity which can be enabled by log_checkpoints.
But I'm not sure why logging of replication commands also needs to be
controlled by separate parameter.

And, I still think that those who set log_statement to all expect that all
the commands including replication commands are logged. I'm afraid
that separating only parameter for replication commands might confuse
the users.

Regards,

-- 
Fujii Masao

On Tue, Aug 12, 2014 at 10:07:34AM +0530, Amit Kapila wrote:
> On Tue, Aug 12, 2014 at 9:29 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
> > On Tue, Aug 12, 2014 at 2:34 AM, Robert Haas <robertmhaas@gmail.com> wrote:
> > >
> > > If you have a user devoted to it, I suppose that's true.  I still
> > > think it shouldn't get munged together like that.
> >
> > Why do we need to treat only replication commands as special ones and
> > add new parameter to display them?
> 
> One difference is that replication commands are internally generated
> commands. Do we anywhere else log such internally generated
> commands with log_statement = all?

Good point --- we do not.  In fact, this is similar to how we don't log
SPI queries, e.g. SQL queries inside functions.  We might want to enable
that someday too.  Could we enable logging of both with a single GUC?

--  Bruce Momjian  <bruce@momjian.us>        http://momjian.us EnterpriseDB
http://enterprisedb.com
 + Everyone has their own god. +

* Bruce Momjian (bruce@momjian.us) wrote:
> On Tue, Aug 12, 2014 at 10:07:34AM +0530, Amit Kapila wrote:
> > On Tue, Aug 12, 2014 at 9:29 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
> > > On Tue, Aug 12, 2014 at 2:34 AM, Robert Haas <robertmhaas@gmail.com> wrote:
> > > >
> > > > If you have a user devoted to it, I suppose that's true.  I still
> > > > think it shouldn't get munged together like that.
> > >
> > > Why do we need to treat only replication commands as special ones and
> > > add new parameter to display them?
> >
> > One difference is that replication commands are internally generated
> > commands. Do we anywhere else log such internally generated
> > commands with log_statement = all?

Not entirely sure what you're referring to as 'internally generated'
here..  While they can come from another backend, they don't have to.

> Good point --- we do not.  In fact, this is similar to how we don't log
> SPI queries, e.g. SQL queries inside functions.  We might want to enable
> that someday too.  Could we enable logging of both with a single GUC?

I don't see those as the same at all.  I'd like to see improved
flexibility in this area, certainly, but don't want two independent
considerations like these tied to one GUC..
Thanks,
    Stephen

* Amit Kapila (amit.kapila16@gmail.com) wrote:
> On Wed, Aug 13, 2014 at 4:24 AM, Stephen Frost <sfrost@snowman.net> wrote:
> > Not entirely sure what you're referring to as 'internally generated'
> > here..
>
> Here 'internally generated' means that user doesn't execute those
> statements, rather the replication/backup code form these statements
> (IDENTIFY_SYSTEM, TIMELINE_HISTORY, BASE_BACKUP, ...)
> and send to server to get the appropriate results.

You could argue the same about pg_dump..  I'd not thought of it before,
but it might be kind of neat to have psql support "connect in
replication mode" and then allow the user to run replication commands.
Still, this isn't the same.

> Yes, few days back I have seen one of the user expects
> such functionality. Refer below mail:
> http://www.postgresql.org/message-id/CAA4eK1LVuirQnMjV1vTMrG_F+1F9e9-8RDGnwiDsCqVTps1ptQ@mail.gmail.com

Oh, to be clear- I agree that logging of queries executed through SPI is
desirable; I'd certainly like to have that capability without having to
go through the auto-explain module or write my own module.  That doesn't
mean we should consider them either "internal" (which I don't really
agree with- consider anonymous DO blocks...) or somehow related to
replication logging.

> >Could we enable logging of both with a single GUC?
> >
> > I don't see those as the same at all.  I'd like to see improved
> > flexibility in this area, certainly, but don't want two independent
> > considerations like these tied to one GUC..
>
> Agreed, I also think both are different and shouldn't be logged
> with one GUC.  Here the important thing to decide is which is
> the better way to proceed for allowing logging of replication
> commands such that it can allow us to extend it for more
> things.  We have discussed below options:
>
> a. Make log_statement a list of comma separated options
> b. Have a separate parameter something like log_replication*
> c. Log it when user has mentioned option 'all' in log_statement.

Regarding this, I'm generally in the camp that says to just include it
in 'all' and be done with it- for now.  This is just another example
of where we really need a much more granular and configurable framework
for auditing and we're not going to get through GUCs, so let's keep the
GUC based approach simple and familiar to our users and build a proper
auditing system.
Thanks,
    Stephen

On Thu, Aug 14, 2014 at 9:26 AM, Stephen Frost <sfrost@snowman.net> wrote:
> * Amit Kapila (amit.kapila16@gmail.com) wrote:
>> On Wed, Aug 13, 2014 at 4:24 AM, Stephen Frost <sfrost@snowman.net> wrote:
>> > Not entirely sure what you're referring to as 'internally generated'
>> > here..
>>
>> Here 'internally generated' means that user doesn't execute those
>> statements, rather the replication/backup code form these statements
>> (IDENTIFY_SYSTEM, TIMELINE_HISTORY, BASE_BACKUP, ...)
>> and send to server to get the appropriate results.
>
> You could argue the same about pg_dump..  I'd not thought of it before,
> but it might be kind of neat to have psql support "connect in
> replication mode" and then allow the user to run replication commands.

You can do that by specifying "replication=1" as the conninfo when
exexcuting psql. For example,

$ psql -d "replication=1"
psql (9.5devel)
Type "help" for help.

postgres=# IDENTIFY_SYSTEM;     systemid       | timeline |  xlogpos  | dbname
---------------------+----------+-----------+--------6047222920639525794 |        1 | 0/1711678 |
(1 row)


>> Agreed, I also think both are different and shouldn't be logged
>> with one GUC.  Here the important thing to decide is which is
>> the better way to proceed for allowing logging of replication
>> commands such that it can allow us to extend it for more
>> things.  We have discussed below options:
>>
>> a. Make log_statement a list of comma separated options
>> b. Have a separate parameter something like log_replication*
>> c. Log it when user has mentioned option 'all' in log_statement.
>
> Regarding this, I'm generally in the camp that says to just include it
> in 'all' and be done with it- for now.  This is just another example
> of where we really need a much more granular and configurable framework
> for auditing and we're not going to get through GUCs, so let's keep the
> GUC based approach simple and familiar to our users and build a proper
> auditing system.

+1

Regards,

-- 
Fujii Masao

On Thu, Aug 14, 2014 at 10:40 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
> On Thu, Aug 14, 2014 at 9:26 AM, Stephen Frost <sfrost@snowman.net> wrote:
>> * Amit Kapila (amit.kapila16@gmail.com) wrote:
>>> On Wed, Aug 13, 2014 at 4:24 AM, Stephen Frost <sfrost@snowman.net> wrote:
>>> > Not entirely sure what you're referring to as 'internally generated'
>>> > here..
>>>
>>> Here 'internally generated' means that user doesn't execute those
>>> statements, rather the replication/backup code form these statements
>>> (IDENTIFY_SYSTEM, TIMELINE_HISTORY, BASE_BACKUP, ...)
>>> and send to server to get the appropriate results.
>>
>> You could argue the same about pg_dump..  I'd not thought of it before,
>> but it might be kind of neat to have psql support "connect in
>> replication mode" and then allow the user to run replication commands.
>
> You can do that by specifying "replication=1" as the conninfo when
> exexcuting psql. For example,
>
> $ psql -d "replication=1"
> psql (9.5devel)
> Type "help" for help.
>
> postgres=# IDENTIFY_SYSTEM;
>       systemid       | timeline |  xlogpos  | dbname
> ---------------------+----------+-----------+--------
>  6047222920639525794 |        1 | 0/1711678 |
> (1 row)
More details here:
http://www.postgresql.org/docs/9.4/static/protocol-replication.html

Note as well that not all the commands work though:
=# START_REPLICATION PHYSICAL 0/0;
unexpected PQresultStatus: 8
=# START_REPLICATION PHYSICAL 0/0;
PQexec not allowed during COPY BOTH
We may do something to improve about that but I am not sure it is worth it.
Regards,
-- 
Michael

Amit,

* Amit Kapila (amit.kapila16@gmail.com) wrote:
> On Thu, Aug 14, 2014 at 5:56 AM, Stephen Frost <sfrost@snowman.net> wrote:
> > Regarding this, I'm generally in the camp that says to just include it
> > in 'all' and be done with it- for now.
>
> Okay, but tomorrow if someone wants to implement a patch to log
> statements executed through SPI (statements inside functions), then
> what will be your suggestion, does those also can be allowed to log
> with 'all' option or you would like to suggest him to wait for a proper
> auditing system?

No, I'd suggest having a different option for it as that would be a huge
change for people who are already doing 'all', potentially.  Adding the
replication commands is extremely unlikely to cause individuals who are
already logging 'all' any problems, as far as I can tell.

> Wouldn't allowing to log everything under 'all' option can start
> confusing some users without having individual
> (ddl, mod, replication, ...) options for different kind of statements.

I don't see logging replication commands under 'all' as confusing, no.
Thanks,
    Stephen

On Sat, Aug 16, 2014 at 10:27 AM, Amit Kapila <amit.kapila16@gmail.com> wrote:
> I think ideally it would have been better if we could have logged
> replication commands under separate log_level, but as still there
> is no consensus on extending log_statement and nobody is even
> willing to pursue, it seems okay to go ahead and log these under
> 'all' level.

I think the consensus is clearly for a separate GUC.

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

On Wed, Aug 20, 2014 at 1:14 PM, Michael Paquier
<michael.paquier@gmail.com> wrote:
>
>
>
> On Wed, Aug 20, 2014 at 2:06 AM, Robert Haas <robertmhaas@gmail.com> wrote:
>>
>> On Sat, Aug 16, 2014 at 10:27 AM, Amit Kapila <amit.kapila16@gmail.com>
>> wrote:
>> > I think ideally it would have been better if we could have logged
>> > replication commands under separate log_level, but as still there
>> > is no consensus on extending log_statement and nobody is even
>> > willing to pursue, it seems okay to go ahead and log these under
>> > 'all' level.
>>
>> I think the consensus is clearly for a separate GUC.
>
> +1.

Okay. Attached is the updated version of the patch which I posted before.
This patch follows the consensus and adds separate parameter
"log_replication_command".

Regards,

--
Fujii Masao

On Tue, Aug 26, 2014 at 7:17 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
> On Wed, Aug 20, 2014 at 1:14 PM, Michael Paquier
> <michael.paquier@gmail.com> wrote:
>> On Wed, Aug 20, 2014 at 2:06 AM, Robert Haas <robertmhaas@gmail.com> wrote:
>>>
>>> On Sat, Aug 16, 2014 at 10:27 AM, Amit Kapila <amit.kapila16@gmail.com>
>>> wrote:
>>> > I think ideally it would have been better if we could have logged
>>> > replication commands under separate log_level, but as still there
>>> > is no consensus on extending log_statement and nobody is even
>>> > willing to pursue, it seems okay to go ahead and log these under
>>> > 'all' level.
>>>
>>> I think the consensus is clearly for a separate GUC.
>>
>> +1.
>
> Okay. Attached is the updated version of the patch which I posted before.
> This patch follows the consensus and adds separate parameter
> "log_replication_command".

Looks fine to me.

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

On Thu, Jun 19, 2014 at 5:29 PM, Ian Barwick <ian@2ndquadrant.com> wrote:
> On 12/06/14 20:37, Fujii Masao wrote:
>>
>> On Wed, Jun 11, 2014 at 11:55 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>>>
>>> Andres Freund <andres@2ndquadrant.com> writes:
>>>>
>>>> Your wish just seems like a separate feature to me. Including
>>>> replication commands in 'all' seems correct independent of the desire
>>>> for a more granular control.
>>>
>>>
>>> No, I think I've got to vote with the other side on that.
>>>
>>> The reason we can have log_statement as a scalar progression
>>> "none < ddl < mod < all" is that there's little visible use-case
>>> for logging DML but not DDL, nor for logging SELECTS but not
>>> INSERT/UPDATE/DELETE.  However, logging replication commands seems
>>> like something people would reasonably want an orthogonal control for.
>>> There's no nice way to squeeze such a behavior into log_statement.
>>>
>>> I guess you could say that log_statement treats replication commands
>>> as if they were DDL, but is that really going to satisfy users?
>>>
>>> I think we should consider log_statement to control logging of
>>> SQL only, and invent a separate GUC (or, in the future, likely
>>> more than one GUC?) for logging of replication activity.
>>
>>
>> Seems reasonable. OK. The attached patch adds log_replication_command
>> parameter which causes replication commands to be logged. I added this to
>> next CF.
>
>
> A quick review:

Sorry, I've noticed this email right now. Thanks for reviewing the patch!

> - minor rewording for the description, mentioning that statements will
>   still be logged as DEBUG1 even if parameter set to 'off' (might
>   prevent reports of the kind "I set it to 'off', why am I still seeing
>   log entries?").
>
>        <para>
>         Causes each replication command to be logged in the server log.
>         See <xref linkend="protocol-replication"> for more information about
>         replication commands. The default value is <literal>off</>. When set
> to
>         <literal>off</>, commands will be logged at log level
> <literal>DEBUG1</literal>.
>         Only superusers can change this setting.
>        </para>

Yep, fixed. Attached is the updated version of the patch.

>
> - I feel it would be more consistent to use the plural form
>   for this parameter, i.e. "log_replication_commands", in line with
>   "log_lock_waits", "log_temp_files", "log_disconnections" etc.

But log_statement is in the singular form. So I just used
log_replication_command. For the consistency, maybe we need to
change both parameters in the plural form? I don't have strong
opinion about this.

> - It might be an idea to add a cross-reference to this parameter from
>   the "Streaming Replication Protocol" page:
>   http://www.postgresql.org/docs/devel/static/protocol-replication.html

Yes. I added that.

Regards,

--
Fujii Masao

On 08/28/2014 11:38 AM, Fujii Masao wrote:
> On Thu, Jun 19, 2014 at 5:29 PM, Ian Barwick <ian@2ndquadrant.com> wrote:
>> - minor rewording for the description, mentioning that statements will
>>    still be logged as DEBUG1 even if parameter set to 'off' (might
>>    prevent reports of the kind "I set it to 'off', why am I still seeing
>>    log entries?").
>>
>>         <para>
>>          Causes each replication command to be logged in the server log.
>>          See <xref linkend="protocol-replication"> for more information about
>>          replication commands. The default value is <literal>off</>. When set
>> to
>>          <literal>off</>, commands will be logged at log level
>> <literal>DEBUG1</literal>.
>>          Only superusers can change this setting.
>>         </para>
>
> Yep, fixed. Attached is the updated version of the patch.

I don't think it's necessary to mention that the commands will still be 
logged at DEBUG1 level. We log all kinds of crap at the various DEBUG 
levels, and they're not supposed to be used in normal operation.

>> - I feel it would be more consistent to use the plural form
>>    for this parameter, i.e. "log_replication_commands", in line with
>>    "log_lock_waits", "log_temp_files", "log_disconnections" etc.
>
> But log_statement is in the singular form. So I just used
> log_replication_command. For the consistency, maybe we need to
> change both parameters in the plural form? I don't have strong
> opinion about this.

Yeah, we seem to be inconsistent. log_replication_commands would sound 
better to me in isolation, but then there is log_statement..

I'll mark this as Ready for Committer in the commitfest app (I assume 
you'll take care of committing this yourself when ready).

- Heikki

Thanks for reviewing the patch!

On Wed, Sep 10, 2014 at 4:57 PM, Heikki Linnakangas
<hlinnakangas@vmware.com> wrote:
> On 08/28/2014 11:38 AM, Fujii Masao wrote:
>>
>> On Thu, Jun 19, 2014 at 5:29 PM, Ian Barwick <ian@2ndquadrant.com> wrote:
>>>
>>> - minor rewording for the description, mentioning that statements will
>>>    still be logged as DEBUG1 even if parameter set to 'off' (might
>>>    prevent reports of the kind "I set it to 'off', why am I still seeing
>>>    log entries?").
>>>
>>>         <para>
>>>          Causes each replication command to be logged in the server log.
>>>          See <xref linkend="protocol-replication"> for more information
>>> about
>>>          replication commands. The default value is <literal>off</>. When
>>> set
>>> to
>>>          <literal>off</>, commands will be logged at log level
>>> <literal>DEBUG1</literal>.
>>>          Only superusers can change this setting.
>>>         </para>
>>
>>
>> Yep, fixed. Attached is the updated version of the patch.
>
>
> I don't think it's necessary to mention that the commands will still be
> logged at DEBUG1 level. We log all kinds of crap at the various DEBUG
> levels, and they're not supposed to be used in normal operation.

Agreed. I removed that mention from the document.

>
>>> - I feel it would be more consistent to use the plural form
>>>    for this parameter, i.e. "log_replication_commands", in line with
>>>    "log_lock_waits", "log_temp_files", "log_disconnections" etc.
>>
>>
>> But log_statement is in the singular form. So I just used
>> log_replication_command. For the consistency, maybe we need to
>> change both parameters in the plural form? I don't have strong
>> opinion about this.
>
>
> Yeah, we seem to be inconsistent. log_replication_commands would sound
> better to me in isolation, but then there is log_statement..

Agreed. I changed the GUC name to log_replication_commands.

>
> I'll mark this as Ready for Committer in the commitfest app (I assume you'll
> take care of committing this yourself when ready).

Attached is the updated version of the patch. After at least one day
I will commit the patch.

Regards,

--
Fujii Masao

On Wed, Sep 10, 2014 at 7:39 PM, Fujii Masao <masao.fujii@gmail.com> wrote:
> Thanks for reviewing the patch!
>
> On Wed, Sep 10, 2014 at 4:57 PM, Heikki Linnakangas
> <hlinnakangas@vmware.com> wrote:
>> On 08/28/2014 11:38 AM, Fujii Masao wrote:
>>>
>>> On Thu, Jun 19, 2014 at 5:29 PM, Ian Barwick <ian@2ndquadrant.com> wrote:
>>>>
>>>> - minor rewording for the description, mentioning that statements will
>>>>    still be logged as DEBUG1 even if parameter set to 'off' (might
>>>>    prevent reports of the kind "I set it to 'off', why am I still seeing
>>>>    log entries?").
>>>>
>>>>         <para>
>>>>          Causes each replication command to be logged in the server log.
>>>>          See <xref linkend="protocol-replication"> for more information
>>>> about
>>>>          replication commands. The default value is <literal>off</>. When
>>>> set
>>>> to
>>>>          <literal>off</>, commands will be logged at log level
>>>> <literal>DEBUG1</literal>.
>>>>          Only superusers can change this setting.
>>>>         </para>
>>>
>>>
>>> Yep, fixed. Attached is the updated version of the patch.
>>
>>
>> I don't think it's necessary to mention that the commands will still be
>> logged at DEBUG1 level. We log all kinds of crap at the various DEBUG
>> levels, and they're not supposed to be used in normal operation.
>
> Agreed. I removed that mention from the document.
>
>>
>>>> - I feel it would be more consistent to use the plural form
>>>>    for this parameter, i.e. "log_replication_commands", in line with
>>>>    "log_lock_waits", "log_temp_files", "log_disconnections" etc.
>>>
>>>
>>> But log_statement is in the singular form. So I just used
>>> log_replication_command. For the consistency, maybe we need to
>>> change both parameters in the plural form? I don't have strong
>>> opinion about this.
>>
>>
>> Yeah, we seem to be inconsistent. log_replication_commands would sound
>> better to me in isolation, but then there is log_statement..
>
> Agreed. I changed the GUC name to log_replication_commands.
>
>>
>> I'll mark this as Ready for Committer in the commitfest app (I assume you'll
>> take care of committing this yourself when ready).
>
> Attached is the updated version of the patch. After at least one day
> I will commit the patch.

Applied. Thanks all!

Regards,

-- 
Fujii Masao