| Bug #23300 | Slow query log on slave does not log slow replicated statements | ||
|---|---|---|---|
| Submitted: | 15 Oct 2006 8:00 | Modified: | 12 Nov 13:27 |
| Reporter: | Morgan Tocker | ||
| Status: | Closed | ||
| Category: | Server: Replication | Severity: | S3 (Non-critical) |
| Version: | 4.1+ | OS: | Any (*) |
| Assigned to: | Luís Soares | Target Version: | 6.0-beta |
| Triage: | Needs Triage: D4 (Minor) / R4 (High) / E3 (Medium) | ||
[15 Oct 2006 20:26]
Shane Bester
verified on 5.0.26
Master: (--long_query_time=5 --log-slow-queries)
# Query_time: 27 Lock_time: 0 Rows_sent: 0 Rows_examined: 0
use test;
UPDATE index_test SET a=REPEAT('A', 50);
Slave: (--long_query_time=5 --log-slow-queries)
Tcp port: 3306 Unix socket: (null)
Time Id Command Argument
[23 Oct 2008 17:20]
Lars Thalmann
See also BUG#27492.
[23 Oct 2008 17:39]
Lars Thalmann
Jon, please document the current behaviour. After doing this, set the bug report back to "verified". We will probably fix this in a later version, but not in 5.1 and below.
[24 Oct 2008 18:44]
Jon Stephens
Thank you for your bug report. This issue has been addressed in the documentation. The updated documentation will appear on our website shortly, and will be included in the next release of the relevant products. Docs update: http://lists.mysql.com/commits/57034
[24 Oct 2008 18:46]
Jon Stephens
Set bug category/status to Replication/Verified following docs fix per comment from Lars.
[10 Feb 18:08]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/65776 3010 Luis Soares 2009-02-10 BUG#23300: Slow query log on slave does not log slow replicated statements When using replication, the slave will not log any slow query logs queries replicated from the master, even if the option "--slow-query-log" is set and these take more than "log_query_time" to execute. In order to log slow queries in replicated thread one needs to set the --log-slow-slave-statements, so that the SQL thread is initialized with the correct switch. Although setting this flag correctly configures the slave thread option to log slow queries, there is an issue with the condition that is used to check whether to log the slow query or not. When replaying binlog events the statement contains the SET TIMESTAMP clause which will force the slow logging condition check to fail. Consequently, the slow query logging does take place. This patch addresses this issue by removing the second condition from the log_slow_statements as it prevents slow queries to be binlogged and seems to be deprecated.
[13 Feb 0:57]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/66106 3010 Luis Soares 2009-02-13 BUG#23300: Slow query log on slave does not log slow replicated statements When using replication, the slave will not log any slow query logs queries replicated from the master, even if the option "--log-slow-slave-statements" is set and these take more than "log_query_time" to execute. In order to log slow queries in replicated thread one needs to set the --log-slow-slave-statements, so that the SQL thread is initialized with the correct switch. Although setting this flag correctly configures the slave thread option to log slow queries, there is an issue with the condition that is used to check whether to log the slow query or not. When replaying binlog events the statement contains the SET TIMESTAMP clause which will force the slow logging condition check to fail. Consequently, the slow query logging will not take place. This patch addresses this issue by removing the second condition from the log_slow_statements as it prevents slow queries to be binlogged and seems to be deprecated.
[19 Feb 9:59]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/66837 2817 Luis Soares 2009-02-19 BUG#23300: Slow query log on slave does not log slow replicated statements When using replication, the slave will not log any slow query logs queries replicated from the master, even if the option "--log-slow-slave-statements" is set and these take more than "log_query_time" to execute. In order to log slow queries in replicated thread one needs to set the --log-slow-slave-statements, so that the SQL thread is initialized with the correct switch. Although setting this flag correctly configures the slave thread option to log slow queries, there is an issue with the condition that is used to check whether to log the slow query or not. When replaying binlog events the statement contains the SET TIMESTAMP clause which will force the slow logging condition check to fail. Consequently, the slow query logging will not take place. This patch addresses this issue by removing the second condition from the log_slow_statements as it prevents slow queries to be binlogged and seems to be deprecated. added: mysql-test/suite/rpl/r/rpl_slow_query_log.result mysql-test/suite/rpl/t/rpl_slow_query_log-slave.opt mysql-test/suite/rpl/t/rpl_slow_query_log.test modified: sql/log.cc sql/sql_parse.cc
[19 Feb 10:04]
Luís Soares
Pushed into 6.0-rpl tree.
[24 Mar 18:20]
Bugs System
Pushed into 6.0.11-alpha (revid:alik@sun.com-20090324171507-s5aac9guj21l0jz6) (version source revid:luis.soares@sun.com-20090219085910-05i23vtboj9gj4fx) (merge vers: 6.0.10-alpha) (pib:6)
[25 Mar 10:55]
Jon Stephens
Documented in the 6.0.11 changelog as follows:
Queries which were written to the slow query log on the master
were not written to the slow query log on the slave.
Also updated sections "The Slow Query Log" and "Replication and the Slow Query Log" in
the 6.0 Manual.
Closed.
[28 May 9:18]
Mats Kindahl
Note that BUG#45136, which is marked as a duplicate, is talking about that this option does not work while this bug report talks about it not being available in the options list. Both issues need to be fixed with this bug. For more information, see: BUG#45136, BUG#23300, and BUG#27492
[28 May 9:20]
Mats Kindahl
Sorry, this comment was intended for BUG#45014.
[29 Sep 14:26]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/84987 3113 Luis Soares 2009-09-29 BUG#23300: Slow query log on slave does not log slow replicated statements NOTE: this is the backport to next-mr. When using replication, the slave will not log any slow query logs queries replicated from the master, even if the option "--log-slow-slave-statements" is set and these take more than "log_query_time" to execute. In order to log slow queries in replicated thread one needs to set the --log-slow-slave-statements, so that the SQL thread is initialized with the correct switch. Although setting this flag correctly configures the slave thread option to log slow queries, there is an issue with the condition that is used to check whether to log the slow query or not. When replaying binlog events the statement contains the SET TIMESTAMP clause which will force the slow logging condition check to fail. Consequently, the slow query logging will not take place. This patch addresses this issue by removing the second condition from the log_slow_statements as it prevents slow queries to be binlogged and seems to be deprecated.
[29 Sep 16:09]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/85026 3114 Luis Soares 2009-09-29 BUG#23300: Slow query log on slave does not log slow replicated statements NOTE: this is the backport to next-mr. When using replication, the slave will not log any slow query logs queries replicated from the master, even if the option "--log-slow-slave-statements" is set and these take more than "log_query_time" to execute. In order to log slow queries in replicated thread one needs to set the --log-slow-slave-statements, so that the SQL thread is initialized with the correct switch. Although setting this flag correctly configures the slave thread option to log slow queries, there is an issue with the condition that is used to check whether to log the slow query or not. When replaying binlog events the statement contains the SET TIMESTAMP clause which will force the slow logging condition check to fail. Consequently, the slow query logging will not take place. This patch addresses this issue by removing the second condition from the log_slow_statements as it prevents slow queries to be binlogged and seems to be deprecated.
[27 Oct 10:48]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091027094604-9p7kplu1vd2cvcju) (version source revid:zhenxing.he@sun.com-20091026140226-uhnqejkyqx1aeilc) (merge vers: 6.0.14-alpha) (pib:13)
[27 Oct 19:16]
Jon Stephens
Already documented in 6.0.11 changelog; closed w/o further action.
[6 Nov 11:03]
Andy Pritchard
I cant find any record of the fix for this bug or its many duplicates being moved into the 5.x releases. Since mysql 6 has been retired has this bug been overlooked.
[9 Nov 10:39]
Andy Pritchard
Have raised Bug #48632 about this fix needing to be ported to the 5.x generation and the slow log documentation.
[9 Nov 13:15]
Valeriy Kravchuk
Bug #48632 was marked as a duplicate of this one. We need fix for 5.x!
[9 Nov 16:35]
Lars Thalmann
This bug is already pushed into the code for the next GA release coming after 5.1 (most likely 5.5 or 5.6). Whether this fix should go into 5.1 or not is handled in BUG#48632. Re-closing this bug.
[12 Nov 9:17]
Bugs System
Pushed into 5.5.0-beta (revid:alik@sun.com-20091110093229-0bh5hix780cyeicl) (version source revid:alik@sun.com-20091027095744-rf45u3x3q5d1f5y0) (merge vers: 5.5.0-beta) (pib:13)
[12 Nov 13:27]
Jon Stephens
Also documented bugfix in the 5.5.0 changelog; closed.
Description: When using replication, the slave will not log any queries replicated from the master (see testcase). This behaviour _could_ be okay, if it were documented in the manual (see suggested fixes). Verified in 4.1, untested so far in 5.0, 5.1. How to repeat: CREATE TABLE index_test (id INT NOT NULL PRIMARY KEY auto_increment, a char(50), b char(50)) ENGINE=MyISAM; Insert some dummy rows: insert into index_test (a,b) values (REPEAT('a', 50), REPEAT('b', 50)); insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; insert into index_test (a,b) SELECT a,b FROM index_test; Add 50 partial indexes on a: ALTER TABLE index_test ADD INDEX idx_1 (a(1)), ADD INDEX idx_2 (a(2)), ADD INDEX idx_3 (a(3)), ADD INDEX idx_4 (a(4)), ADD INDEX idx_5 (a(5)), ADD INDEX idx_6 (a(6)), ADD INDEX idx_7 (a(7)), ADD INDEX idx_8 (a(8)), ADD INDEX idx_9 (a(9)), ADD INDEX idx_10 (a(10)), ADD INDEX idx_11 (a(11)), ADD INDEX idx_12 (a(12)), ADD INDEX idx_13 (a(13)), ADD INDEX idx_14 (a(14)), ADD INDEX idx_15 (a(15)), ADD INDEX idx_16 (a(16)), ADD INDEX idx_17 (a(17)), ADD INDEX idx_18 (a(18)), ADD INDEX idx_19 (a(19)), ADD INDEX idx_20 (a(20)), ADD INDEX idx_21 (a(21)), ADD INDEX idx_22 (a(22)), ADD INDEX idx_23 (a(23)), ADD INDEX idx_24 (a(24)), ADD INDEX idx_25 (a(25)), ADD INDEX idx_26 (a(26)), ADD INDEX idx_27 (a(27)), ADD INDEX idx_28 (a(28)), ADD INDEX idx_29 (a(29)), ADD INDEX idx_30 (a(30)), ADD INDEX idx_31 (a(31)), ADD INDEX idx_32 (a(32)), ADD INDEX idx_33 (a(33)), ADD INDEX idx_34 (a(34)), ADD INDEX idx_35 (a(35)), ADD INDEX idx_36 (a(36)), ADD INDEX idx_37 (a(37)), ADD INDEX idx_38 (a(38)), ADD INDEX idx_39 (a(39)), ADD INDEX idx_40 (a(40)), ADD INDEX idx_41 (a(41)), ADD INDEX idx_42 (a(42)), ADD INDEX idx_43 (a(43)), ADD INDEX idx_44 (a(44)), ADD INDEX idx_45 (a(45)), ADD INDEX idx_46 (a(46)), ADD INDEX idx_47 (a(47)), ADD INDEX idx_48 (a(48)), ADD INDEX idx_49 (a(49)), ADD INDEX idx_50 (a(50)); ** Attempt an update ** mysql> UPDATE index_test SET a=REPEAT('A', 50); This update would take at least 1 second on most systems. In my test it logs to the master's slow query log: # Query_time: 29 Lock_time: 0 Rows_sent: 0 Rows_examined: 0 use test2; UPDATE index_test SET a=REPEAT('B', 50); On the slave, the slow query log is empty: Tcp port: 3307 Unix socket: /tmp/mysql2.sock Time Id Command Argument Suggested fix: Either document in manual here <http://dev.mysql.com/doc/refman/5.0/en/slow-query-log.html>, or change behaviour (I vote change behaviour in next major release!)