log_slow_slave_statements should have global scope only

[Oleg Tsarev]

log_slow_slave_statements as noticed in documentation:
http://www.percona.com/docs/wiki/percona-server:features:slow_extended#system_variables
work only after restart SLAVE.

i.e. "- When I do set global log_slow_slave_statements=1 I need to do "SLAVE STOP/SLAVE START" for it to pick up"

I think this behavior useless and we can provide ability to work without restart slave

[Oleg Tsarev (tsarev)]

Vadim, please decide important this or not

[Peter Zaitsev (pz-percona)]

Oleg,

Can you please provide more verbose and clear description for the bug you're
reporting.

I can read current bug report at least 3 different ways:

- When I do set global log_slow_slave_statements=1 I need to do "SLAVE
STOP/SLAVE START" for it to pick up
- I need to restart whole MySQL Server (on the slave) and set this option in
my.cnf so it picks up
- If I set option in my.cnf (even) the statements will not be logged until I
do SLAVE STOP/SLAVE START

On Thu, Feb 3, 2011 at 3:45 AM, Oleg Tsarev <email address hidden> wrote:

> Public bug reported:
>
> log_slow_slave_statements as noticed in documentation:
>
> http://www.percona.com/docs/wiki/percona-server:features:slow_extended#system_variables
> work only after restart SLAVE.
>
> I think this behavior useless and we can provide ability to work without
> restart slave
>
> ** Affects: percona-server
> Importance: Undecided
> Assignee: Vadim Tkachenko (vadim-tk)
> Status: New
>
> ** Changed in: percona-server
> Assignee: (unassigned) => Vadim Tkachenko (vadim-tk)
>
> --
> You received this bug notification because you are a member of Percona
> developers, which is the registrant for Percona Server.
> https://bugs.launchpad.net/bugs/712396
>
> Title:
> log_slow_slave_statements not work on replication threads without
> RESTART
>
> Status in Percona Server with XtraDB:
> New
>
> Bug description:
> log_slow_slave_statements as noticed in documentation:
>
> http://www.percona.com/docs/wiki/percona-server:features:slow_extended#system_variables
> work only after restart SLAVE.
>
> I think this behavior useless and we can provide ability to work
> without restart slave
>
>
>

--
Peter Zaitsev, CEO, Percona Inc.
Tel: [phone] ext 501 Skype: peter_zaitsev
24/7 Emergency Line [phone] ext 911

Percona Training Workshops
http://www.percona.com/training/

[Oleg Tsarev (tsarev)]

Peter,

In this bug I mean this:
"- When I do set global log_slow_slave_statements=1 I need to do "SLAVE
STOP/SLAVE START" for it to pick up"

[Vadim Tkachenko (vadim-tk)]

I do not think current behavior is useless, it just has to be documented.
I put this as documentation bug and no fixed needed.

[Peter Zaitsev (pz-percona)]

Vadim,

Agreed. Though frankly I think it should have been global variable to begin
with, I do not see
a good use case why to set it for current thread only, unlike with
long_query_time where
I might prefer to log slow queries from current thread only.

On Mon, Feb 7, 2011 at 3:12 PM, Vadim Tkachenko <email address hidden> wrote:

> I do not think current behavior is useless, it just has to be documented.
> I put this as documentation bug and no fixed needed.
>
> --
> You received this bug notification because you are a member of Percona
> developers, which is the registrant for Percona Server.
> https://bugs.launchpad.net/bugs/712396
>
> Title:
> log_slow_slave_statements not work on replication threads without
> RESTART
>
> Status in Percona Server with XtraDB:
> New
>
> Bug description:
> log_slow_slave_statements as noticed in documentation:
>
> http://www.percona.com/docs/wiki/percona-server:features:slow_extended#system_variables
> work only after restart SLAVE.
>
> I think this behavior useless and we can provide ability to work
> without restart slave
>
>
>

--
Peter Zaitsev, CEO, Percona Inc.
Tel: [phone] ext 501 Skype: peter_zaitsev
24/7 Emergency Line [phone] ext 911

Join us for Percona Live Event, San Francisco, Feb 16
http://www.percona.com/events/percona-live-san-francisco-2011/

[Stewart Smith (stewart)]

Look like two part fix:
1) should be global not thread variable.
2) fix docs.

[Raghavendra D Prabhu (raghavendra-prabhu)]

opt_log_slow_slave_statements is global, however, its value is copied to two THD variables - thd->write_to_slow_log and thd->enable_slow_log, former being used for rate limiting and latter used to weed out admin statements, both of which don't apply to slave thread.

These checks are not required since LOGGER::slow_log_print checks for that option anyways.
in LOGGER::slow_log_print:

    if (thd->slave_thread && !opt_log_slow_slave_statements)
      return 0;

=== modified file 'Percona-Server/sql/sql_parse.cc'
--- Percona-Server/sql/sql_parse.cc 2012-08-13 13:42:13 +0000
+++ Percona-Server/sql/sql_parse.cc 2012-09-04 08:42:00 +0000
@@ -1568,8 +1568,9 @@
                          &g.min_examined_row_limit);

   /* Do not log this thread's queries due to rate limiting. */
- if (!thd->write_to_slow_log && (thd->variables.long_query_time >= 1000000
- || (ulong) query_exec_time < 1000000))
+ if (!thd->slave_thread && (!thd->write_to_slow_log &&
+ (thd->variables.long_query_time >= 1000000
+ || (ulong) query_exec_time < 1000000)))
     DBUG_VOID_RETURN;

@@ -1577,7 +1578,7 @@
     Do not log administrative statements unless the appropriate option is
     set.
   */
- if (thd->enable_slow_log)
+ if (thd->enable_slow_log || thd->slave_thread)
   {
     thd_proc_info(thd, "logging slow query");

[Laurynas Biveinis (laurynas-biveinis)]

It already is global scope only in both 5.1 and 5.5.

[Laurynas Biveinis (laurynas-biveinis)]

Back on the original topic of this bug, i.e. why a slave thread restart required for the variable change to take effect.

After a (needlessly prolonged) 5.5 analysis I think that this is purely a side effect of rate limit implementation (!).

In 5.5 there are two THD flag fields to show whether the query should be slow-logged: enable_slow_log and write_to_slow_log. The latter is added by patch, apparently to control rate limiting. But it's also set at the slave SQL thread initialization, which makes it to require thread restart for its changes to take effect. This is completely arbitrary. Slave thread goes through slow log checks always anyway and there is no reason it cannot check the global variable value there. In fact, naive 5.6 port just gets this feature automatically.

I also also wonder if sanity can be made easier to preserve by getting rid of write_to_slow_log and just doing its check at log_slow_statement (5.5-) or log_slow_applicable (5.6).

I will file separate bug(s) for these items.

[Laurynas Biveinis (laurynas-biveinis)]

Bug 1091712.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1187