- developers - lists.mariadb.org

[Maria-developers] Updated (by Knielsen): Efficient group commit for binary log (116)
by worklog-noreply＠askmonty.org 25 May '10

25 May '10

----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: Efficient group commit for binary log CREATION DATE..: Mon, 26 Apr 2010, 13:28 SUPERVISOR.....: Knielsen IMPLEMENTOR....: COPIES TO......: Serg CATEGORY.......: Server-RawIdeaBin TASK ID........: 116 (http://askmonty.org/worklog/?tid=116) VERSION........: Server-9.x STATUS.........: Un-Assigned PRIORITY.......: 60 WORKED HOURS...: 49 ESTIMATE.......: 0 (hours remain) ORIG. ESTIMATE.: 0 PROGRESS NOTES: -=-=(Knielsen - Tue, 25 May 2010, 13:18)=-=- High Level Description modified. --- /tmp/wklog.116.old.14234 2010-05-25 13:18:07.000000000 +0000 +++ /tmp/wklog.116.new.14234 2010-05-25 13:18:07.000000000 +0000 @@ -21,3 +21,69 @@ http://kristiannielsen.livejournal.com/12408.html http://kristiannielsen.livejournal.com/12553.html +---- + +Implementing group commit in MySQL faces some challenges from the handler +plugin architecture: + +1. Because storage engine handlers have separate transaction log from the +mysql binlog (and from each other), there are multiple fsync() calls per +commit that need the group commit optimisation (2 per participating storage +engine + 1 for binlog). + +2. The code handling commit is split in several places, in main server code +and in storage engine code. With pluggable binlog it will be split even +more. This requires a good abstract yet powerful API to be able to implement +group commit simply and efficiently in plugins without the different parts +having to rely on iternals of the others. + +3. We want the order of commits to be the same in all engines participating in +multiple transactions. This requirement is the reason that InnoDB currently +breaks group commit with the infamous prepare_commit_mutex. + +While currently there is no server guarantee to get same commit order in +engines an binlog (except for the InnoDB prepare_commit_mutex hack), there are +several reasons why this could be desirable: + + - InnoDB hot backup needs to be able to extract a binlog position that is + consistent with the hot backup to be able to provision a new slave, and + this is impossible without imposing at least partial consistent ordering + between InnoDB and binlog. + + - Other backup methods could have similar needs, eg. XtraBackup or + `mysqldump --single-transaction`, to have consistent commit order between + binlog and storage engines without having to do FLUSH TABLES WITH READ LOCK + or similar expensive blocking operation. (other backup methods, like LVM + snapshot, don't need consistent commit order, as they can restore + out-of-order commits during crash recovery using XA). + + - If we have consistent commit order, we can think about optimising commit to + need only one fsync (for binlog); lost commits in storage engines can then + be recovered from the binlog at crash recovery by re-playing against the + engine from a particular point in the binlog. + + - With consistent commit order, we can get better semantics for START + TRANSACTION WITH CONSISTENT SNAPSHOT with multi-engine transactions (and we + could even get it to return also a matching binlog position). Currently, + this "CONSISTENT SNAPSHOT" can be inconsistent among multiple storage + engines. + + - In InnoDB, the performance in the presense of hotspots can be improved if + we can release row locks early in the commit phase, but this requires that we +release them in + the same order as commits in the binlog to ensure consistency between + master and slaves. + + - There was some discussions around Galera [1] synchroneous replication and + global transaction ID that it needed consistent commit order among + participating engines. + + - I believe there could be other applications for guaranteed consistent + commit order, and that the architecture described in this worklog can + implement such guarantee with reasonable overhead. + + +References: + +[1] Galera: http://www.codership.com/products/galera_replication + -=-=(Knielsen - Tue, 25 May 2010, 08:28)=-=- More thoughts on and changes to the archtecture. Got to something now that I am satisfied with and that seems to be able to handle all issues. Implement new prepare_ordered and commit_ordered handler methods and the logic in ha_commit_trans(). Implement TC_LOG::group_log_xid() method and logic in ha_commit_trans(). Implement XtraDB part, using commit_ordered() rather than prepare_commit_mutex. Fix test suite failures. Proof-of-concept patch series complete now. Do initial benchmark, getting good results. With 64 threads, see 26x improvement in queries-per-sec. Next step: write up the architecture description. Worked 21 hours and estimate 0 hours remain (original estimate increased by 21 hours). -=-=(Knielsen - Wed, 12 May 2010, 06:41)=-=- Started work on a Quilt patch series, refactoring the binlog code to prepare for implementing the group commit, and working on the design of group commit in parallel. Found and fixed several problems in error handling when writing to binlog. Removed redundant table map version locking. Split binlog writing into two parts in preparations for group commit. When ready to write to the binlog, threads enter a queue, and the first thread in the queue handles the binlog writing for everyone. When it obtains the LOCK_log, it first loops over all threads, executing the first part of binlog writing (the write(2) syscall essentially). It then runs the second part (fsync(2) essentially) only once, and then wakes up the remaining threads in the queue. Still to be done: Finish the proof-of-concept group commit patch, by 1) implementing the prepare_fast() and commit_fast() callbacks in handler.cc 2) move the binlog thread enqueue from log_xid() to binlog_prepare_fast(), 3) move fast part of InnoDB commit to innobase_commit_fast(), removing the prepare_commit_mutex(). Write up the final design in this worklog. Evaluate the design to see if we can do better/different. Think about possible next steps, such as releasing innodb row locks early (in innobase_prepare_fast), and doing crash recovery by replaying transactions from the binlog (removing the need for engine durability and 2 of 3 fsync() in commit). Worked 28 hours and estimate 0 hours remain (original estimate increased by 28 hours). -=-=(Serg - Mon, 26 Apr 2010, 14:10)=-=- Observers changed: Serg DESCRIPTION: Currently, in order to ensure that the server can recover after a crash to a state in which storage engines and binary log are consistent with each other, it is necessary to use XA with durable commits for both storage engines (innodb_flush_log_at_trx_commit=1) and binary log (sync_binlog=1). This is _very_ expensive, since the server needs to do three fsync() operations for every commit, as there is no working group commit when the binary log is enabled. The idea is to - Implement/fix group commit to work properly with the binary log enabled. - (Optionally) avoid the need to fsync() in the engine, and instead rely on replaying any lost transactions from the binary log against the engine during crash recovery. For background see these articles: http://kristiannielsen.livejournal.com/12254.html http://kristiannielsen.livejournal.com/12408.html http://kristiannielsen.livejournal.com/12553.html ---- Implementing group commit in MySQL faces some challenges from the handler plugin architecture: 1. Because storage engine handlers have separate transaction log from the mysql binlog (and from each other), there are multiple fsync() calls per commit that need the group commit optimisation (2 per participating storage engine + 1 for binlog). 2. The code handling commit is split in several places, in main server code and in storage engine code. With pluggable binlog it will be split even more. This requires a good abstract yet powerful API to be able to implement group commit simply and efficiently in plugins without the different parts having to rely on iternals of the others. 3. We want the order of commits to be the same in all engines participating in multiple transactions. This requirement is the reason that InnoDB currently breaks group commit with the infamous prepare_commit_mutex. While currently there is no server guarantee to get same commit order in engines an binlog (except for the InnoDB prepare_commit_mutex hack), there are several reasons why this could be desirable: - InnoDB hot backup needs to be able to extract a binlog position that is consistent with the hot backup to be able to provision a new slave, and this is impossible without imposing at least partial consistent ordering between InnoDB and binlog. - Other backup methods could have similar needs, eg. XtraBackup or `mysqldump --single-transaction`, to have consistent commit order between binlog and storage engines without having to do FLUSH TABLES WITH READ LOCK or similar expensive blocking operation. (other backup methods, like LVM snapshot, don't need consistent commit order, as they can restore out-of-order commits during crash recovery using XA). - If we have consistent commit order, we can think about optimising commit to need only one fsync (for binlog); lost commits in storage engines can then be recovered from the binlog at crash recovery by re-playing against the engine from a particular point in the binlog. - With consistent commit order, we can get better semantics for START TRANSACTION WITH CONSISTENT SNAPSHOT with multi-engine transactions (and we could even get it to return also a matching binlog position). Currently, this "CONSISTENT SNAPSHOT" can be inconsistent among multiple storage engines. - In InnoDB, the performance in the presense of hotspots can be improved if we can release row locks early in the commit phase, but this requires that we release them in the same order as commits in the binlog to ensure consistency between master and slaves. - There was some discussions around Galera [1] synchroneous replication and global transaction ID that it needed consistent commit order among participating engines. - I believe there could be other applications for guaranteed consistent commit order, and that the architecture described in this worklog can implement such guarantee with reasonable overhead. References: [1] Galera: http://www.codership.com/products/galera_replication ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v3.5.9)

1 0

[Maria-developers] Updated (by Knielsen): Efficient group commit for binary log (116)
by worklog-noreply＠askmonty.org 25 May '10

25 May '10

----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: Efficient group commit for binary log CREATION DATE..: Mon, 26 Apr 2010, 13:28 SUPERVISOR.....: Knielsen IMPLEMENTOR....: COPIES TO......: Serg CATEGORY.......: Server-RawIdeaBin TASK ID........: 116 (http://askmonty.org/worklog/?tid=116) VERSION........: Server-9.x STATUS.........: Un-Assigned PRIORITY.......: 60 WORKED HOURS...: 49 ESTIMATE.......: 0 (hours remain) ORIG. ESTIMATE.: 0 PROGRESS NOTES: -=-=(Knielsen - Tue, 25 May 2010, 13:18)=-=- High Level Description modified. --- /tmp/wklog.116.old.14234 2010-05-25 13:18:07.000000000 +0000 +++ /tmp/wklog.116.new.14234 2010-05-25 13:18:07.000000000 +0000 @@ -21,3 +21,69 @@ http://kristiannielsen.livejournal.com/12408.html http://kristiannielsen.livejournal.com/12553.html +---- + +Implementing group commit in MySQL faces some challenges from the handler +plugin architecture: + +1. Because storage engine handlers have separate transaction log from the +mysql binlog (and from each other), there are multiple fsync() calls per +commit that need the group commit optimisation (2 per participating storage +engine + 1 for binlog). + +2. The code handling commit is split in several places, in main server code +and in storage engine code. With pluggable binlog it will be split even +more. This requires a good abstract yet powerful API to be able to implement +group commit simply and efficiently in plugins without the different parts +having to rely on iternals of the others. + +3. We want the order of commits to be the same in all engines participating in +multiple transactions. This requirement is the reason that InnoDB currently +breaks group commit with the infamous prepare_commit_mutex. + +While currently there is no server guarantee to get same commit order in +engines an binlog (except for the InnoDB prepare_commit_mutex hack), there are +several reasons why this could be desirable: + + - InnoDB hot backup needs to be able to extract a binlog position that is + consistent with the hot backup to be able to provision a new slave, and + this is impossible without imposing at least partial consistent ordering + between InnoDB and binlog. + + - Other backup methods could have similar needs, eg. XtraBackup or + `mysqldump --single-transaction`, to have consistent commit order between + binlog and storage engines without having to do FLUSH TABLES WITH READ LOCK + or similar expensive blocking operation. (other backup methods, like LVM + snapshot, don't need consistent commit order, as they can restore + out-of-order commits during crash recovery using XA). + + - If we have consistent commit order, we can think about optimising commit to + need only one fsync (for binlog); lost commits in storage engines can then + be recovered from the binlog at crash recovery by re-playing against the + engine from a particular point in the binlog. + + - With consistent commit order, we can get better semantics for START + TRANSACTION WITH CONSISTENT SNAPSHOT with multi-engine transactions (and we + could even get it to return also a matching binlog position). Currently, + this "CONSISTENT SNAPSHOT" can be inconsistent among multiple storage + engines. + + - In InnoDB, the performance in the presense of hotspots can be improved if + we can release row locks early in the commit phase, but this requires that we +release them in + the same order as commits in the binlog to ensure consistency between + master and slaves. + + - There was some discussions around Galera [1] synchroneous replication and + global transaction ID that it needed consistent commit order among + participating engines. + + - I believe there could be other applications for guaranteed consistent + commit order, and that the architecture described in this worklog can + implement such guarantee with reasonable overhead. + + +References: + +[1] Galera: http://www.codership.com/products/galera_replication + -=-=(Knielsen - Tue, 25 May 2010, 08:28)=-=- More thoughts on and changes to the archtecture. Got to something now that I am satisfied with and that seems to be able to handle all issues. Implement new prepare_ordered and commit_ordered handler methods and the logic in ha_commit_trans(). Implement TC_LOG::group_log_xid() method and logic in ha_commit_trans(). Implement XtraDB part, using commit_ordered() rather than prepare_commit_mutex. Fix test suite failures. Proof-of-concept patch series complete now. Do initial benchmark, getting good results. With 64 threads, see 26x improvement in queries-per-sec. Next step: write up the architecture description. Worked 21 hours and estimate 0 hours remain (original estimate increased by 21 hours). -=-=(Knielsen - Wed, 12 May 2010, 06:41)=-=- Started work on a Quilt patch series, refactoring the binlog code to prepare for implementing the group commit, and working on the design of group commit in parallel. Found and fixed several problems in error handling when writing to binlog. Removed redundant table map version locking. Split binlog writing into two parts in preparations for group commit. When ready to write to the binlog, threads enter a queue, and the first thread in the queue handles the binlog writing for everyone. When it obtains the LOCK_log, it first loops over all threads, executing the first part of binlog writing (the write(2) syscall essentially). It then runs the second part (fsync(2) essentially) only once, and then wakes up the remaining threads in the queue. Still to be done: Finish the proof-of-concept group commit patch, by 1) implementing the prepare_fast() and commit_fast() callbacks in handler.cc 2) move the binlog thread enqueue from log_xid() to binlog_prepare_fast(), 3) move fast part of InnoDB commit to innobase_commit_fast(), removing the prepare_commit_mutex(). Write up the final design in this worklog. Evaluate the design to see if we can do better/different. Think about possible next steps, such as releasing innodb row locks early (in innobase_prepare_fast), and doing crash recovery by replaying transactions from the binlog (removing the need for engine durability and 2 of 3 fsync() in commit). Worked 28 hours and estimate 0 hours remain (original estimate increased by 28 hours). -=-=(Serg - Mon, 26 Apr 2010, 14:10)=-=- Observers changed: Serg DESCRIPTION: Currently, in order to ensure that the server can recover after a crash to a state in which storage engines and binary log are consistent with each other, it is necessary to use XA with durable commits for both storage engines (innodb_flush_log_at_trx_commit=1) and binary log (sync_binlog=1). This is _very_ expensive, since the server needs to do three fsync() operations for every commit, as there is no working group commit when the binary log is enabled. The idea is to - Implement/fix group commit to work properly with the binary log enabled. - (Optionally) avoid the need to fsync() in the engine, and instead rely on replaying any lost transactions from the binary log against the engine during crash recovery. For background see these articles: http://kristiannielsen.livejournal.com/12254.html http://kristiannielsen.livejournal.com/12408.html http://kristiannielsen.livejournal.com/12553.html ---- Implementing group commit in MySQL faces some challenges from the handler plugin architecture: 1. Because storage engine handlers have separate transaction log from the mysql binlog (and from each other), there are multiple fsync() calls per commit that need the group commit optimisation (2 per participating storage engine + 1 for binlog). 2. The code handling commit is split in several places, in main server code and in storage engine code. With pluggable binlog it will be split even more. This requires a good abstract yet powerful API to be able to implement group commit simply and efficiently in plugins without the different parts having to rely on iternals of the others. 3. We want the order of commits to be the same in all engines participating in multiple transactions. This requirement is the reason that InnoDB currently breaks group commit with the infamous prepare_commit_mutex. While currently there is no server guarantee to get same commit order in engines an binlog (except for the InnoDB prepare_commit_mutex hack), there are several reasons why this could be desirable: - InnoDB hot backup needs to be able to extract a binlog position that is consistent with the hot backup to be able to provision a new slave, and this is impossible without imposing at least partial consistent ordering between InnoDB and binlog. - Other backup methods could have similar needs, eg. XtraBackup or `mysqldump --single-transaction`, to have consistent commit order between binlog and storage engines without having to do FLUSH TABLES WITH READ LOCK or similar expensive blocking operation. (other backup methods, like LVM snapshot, don't need consistent commit order, as they can restore out-of-order commits during crash recovery using XA). - If we have consistent commit order, we can think about optimising commit to need only one fsync (for binlog); lost commits in storage engines can then be recovered from the binlog at crash recovery by re-playing against the engine from a particular point in the binlog. - With consistent commit order, we can get better semantics for START TRANSACTION WITH CONSISTENT SNAPSHOT with multi-engine transactions (and we could even get it to return also a matching binlog position). Currently, this "CONSISTENT SNAPSHOT" can be inconsistent among multiple storage engines. - In InnoDB, the performance in the presense of hotspots can be improved if we can release row locks early in the commit phase, but this requires that we release them in the same order as commits in the binlog to ensure consistency between master and slaves. - There was some discussions around Galera [1] synchroneous replication and global transaction ID that it needed consistent commit order among participating engines. - I believe there could be other applications for guaranteed consistent commit order, and that the architecture described in this worklog can implement such guarantee with reasonable overhead. References: [1] Galera: http://www.codership.com/products/galera_replication ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v3.5.9)

1 0

[Maria-developers] Rev 2791: Prevent cacheing subqueries with random parameters and side effect functions. in file:///home/bell/maria/bzr/work-maria-5.3-scache/
by sanja＠askmonty.org 25 May '10

25 May '10

At file:///home/bell/maria/bzr/work-maria-5.3-scache/ ------------------------------------------------------------ revno: 2791 revision-id: sanja(a)askmonty.org-20100525125457-5rwbiihh0vtghdrj parent: sanja(a)askmonty.org-20100525104536-zw06otfk8ut7fias committer: sanja(a)askmonty.org branch nick: work-maria-5.3-scache timestamp: Tue 2010-05-25 15:54:57 +0300 message: Prevent cacheing subqueries with random parameters and side effect functions. === modified file 'mysql-test/r/subquery_cache.result' --- a/mysql-test/r/subquery_cache.result 2010-05-25 10:45:36 +0000 +++ b/mysql-test/r/subquery_cache.result 2010-05-25 12:54:57 +0000 @@ -1,4 +1,5 @@ set optimizer_switch='subquery_cache=on'; +flush status; create table t1 (a int, b int); insert into t1 values (1,2),(3,4),(1,2),(3,4),(3,4),(4,5),(4,5),(5,6),(5,6),(4,5); create table t2 (c int, d int); @@ -552,4 +553,38 @@ POINT(1 1) POINT(3 3) DROP TABLE t1; +#uncacheable queries test (random and side effect) +flush status; +CREATE TABLE t1 (a int); +INSERT INTO t1 VALUES (2), (4), (1), (3); +select a, a in (select a from t1) from t1 as ext; +a a in (select a from t1) +2 1 +4 1 +1 1 +3 1 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 0 +Subquery_cache_miss 4 +select a, a in (select a from t1 where -1 < rand()) from t1 as ext; +a a in (select a from t1 where -1 < rand()) +2 1 +4 1 +1 1 +3 1 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 0 +Subquery_cache_miss 4 +select a, a in (select a from t1 where -1 < benchmark(a,100)) from t1 as ext; +a a in (select a from t1 where -1 < benchmark(a,100)) +2 1 +4 1 +1 1 +3 1 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 0 +Subquery_cache_miss 4 set optimizer_switch='subquery_cache=default'; === modified file 'mysql-test/t/subquery_cache.test' --- a/mysql-test/t/subquery_cache.test 2010-05-25 10:45:36 +0000 +++ b/mysql-test/t/subquery_cache.test 2010-05-25 12:54:57 +0000 @@ -1,5 +1,6 @@ set optimizer_switch='subquery_cache=on'; +flush status; create table t1 (a int, b int); insert into t1 values (1,2),(3,4),(1,2),(3,4),(3,4),(4,5),(4,5),(5,6),(5,6),(4,5); @@ -188,4 +189,15 @@ DROP TABLE t1; +--echo #uncacheable queries test (random and side effect) +flush status; +CREATE TABLE t1 (a int); +INSERT INTO t1 VALUES (2), (4), (1), (3); +select a, a in (select a from t1) from t1 as ext; +show status like "subquery_cache%"; +select a, a in (select a from t1 where -1 < rand()) from t1 as ext; +show status like "subquery_cache%"; +select a, a in (select a from t1 where -1 < benchmark(a,100)) from t1 as ext; +show status like "subquery_cache%"; + set optimizer_switch='subquery_cache=default'; === modified file 'sql/item_cmpfunc.cc' --- a/sql/item_cmpfunc.cc 2010-05-24 17:29:56 +0000 +++ b/sql/item_cmpfunc.cc 2010-05-25 12:54:57 +0000 @@ -1738,7 +1738,9 @@ const_item_cache&= args[1]->const_item(); DBUG_ASSERT(scache == NULL); if (args[0]->cols() ==1 && - thd->variables.optimizer_switch & OPTIMIZER_SWITCH_SUBQUERY_CACHE) + thd->variables.optimizer_switch & OPTIMIZER_SWITCH_SUBQUERY_CACHE && + !(sub->engine->uncacheable() & (UNCACHEABLE_RAND | + UNCACHEABLE_SIDEEFFECT))) { sub->depends_on.push_front((Item**)&cache); scache= new Subquery_cache_tmptable(thd, sub->depends_on, &result); === modified file 'sql/item_subselect.cc' --- a/sql/item_subselect.cc 2010-05-24 17:29:56 +0000 +++ b/sql/item_subselect.cc 2010-05-25 12:54:57 +0000 @@ -760,7 +760,10 @@ (uint)depends_on.elements, (uint)test(thd->variables.optimizer_switch & OPTIMIZER_SWITCH_SUBQUERY_CACHE))); engine->fix_length_and_dec(row= &value); - if (depends_on.elements && optimizer_flag(thd, OPTIMIZER_SWITCH_SUBQUERY_CACHE)) + if (depends_on.elements && + optimizer_flag(thd, OPTIMIZER_SWITCH_SUBQUERY_CACHE) && + !(engine->uncacheable() & (UNCACHEABLE_RAND | + UNCACHEABLE_SIDEEFFECT))) { DBUG_ASSERT(scache == NULL); scache= new Subquery_cache_tmptable(thd, depends_on, value); @@ -1100,7 +1103,9 @@ /* We need only 1 row to determine existence */ unit->global_parameters->select_limit= new Item_int((int32) 1); if (substype() == EXISTS_SUBS && depends_on.elements && - optimizer_flag(thd, OPTIMIZER_SWITCH_SUBQUERY_CACHE)) + optimizer_flag(thd, OPTIMIZER_SWITCH_SUBQUERY_CACHE) && + !(engine->uncacheable() & (UNCACHEABLE_RAND | + UNCACHEABLE_SIDEEFFECT))) { DBUG_ASSERT(scache == NULL); scache= new Subquery_cache_tmptable(thd, depends_on, &result);

1 0

[Maria-developers] Rev 2790: Fixed sum functions dependency for subqueries in file:///home/bell/maria/bzr/work-maria-5.3-scache/
by sanja＠askmonty.org 25 May '10

25 May '10

At file:///home/bell/maria/bzr/work-maria-5.3-scache/ ------------------------------------------------------------ revno: 2790 revision-id: sanja(a)askmonty.org-20100525104536-zw06otfk8ut7fias parent: sanja(a)askmonty.org-20100524172956-7b14x01aodizr3sq committer: sanja(a)askmonty.org branch nick: work-maria-5.3-scache timestamp: Tue 2010-05-25 13:45:36 +0300 message: Fixed sum functions dependency for subqueries Forgoten files added. === added file 'mysql-test/r/subquery_cache.result' --- a/mysql-test/r/subquery_cache.result 1970-01-01 00:00:00 +0000 +++ b/mysql-test/r/subquery_cache.result 2010-05-25 10:45:36 +0000 @@ -0,0 +1,555 @@ +set optimizer_switch='subquery_cache=on'; +create table t1 (a int, b int); +insert into t1 values (1,2),(3,4),(1,2),(3,4),(3,4),(4,5),(4,5),(5,6),(5,6),(4,5); +create table t2 (c int, d int); +insert into t2 values (2,3),(3,4),(5,6); +#single value subquery test +select a, (select d from t2 where b=c) + 1 from t1; +a (select d from t2 where b=c) + 1 +1 4 +3 NULL +1 4 +3 NULL +3 NULL +4 7 +4 7 +5 NULL +5 NULL +4 7 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 6 +Subquery_cache_miss 4 +#single value subquery test (PS) +prepare stmt1 from 'select a, (select d from t2 where b=c) + 1 from t1'; +execute stmt1; +a (select d from t2 where b=c) + 1 +1 4 +3 NULL +1 4 +3 NULL +3 NULL +4 7 +4 7 +5 NULL +5 NULL +4 7 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 12 +Subquery_cache_miss 8 +execute stmt1; +a (select d from t2 where b=c) + 1 +1 4 +3 NULL +1 4 +3 NULL +3 NULL +4 7 +4 7 +5 NULL +5 NULL +4 7 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 18 +Subquery_cache_miss 12 +deallocate prepare stmt1; +#single value subquery test (SP) +CREATE PROCEDURE p1() select a, (select d from t2 where b=c) + 1 from t1; +call p1; +a (select d from t2 where b=c) + 1 +1 4 +3 NULL +1 4 +3 NULL +3 NULL +4 7 +4 7 +5 NULL +5 NULL +4 7 +call p1; +a (select d from t2 where b=c) + 1 +1 4 +3 NULL +1 4 +3 NULL +3 NULL +4 7 +4 7 +5 NULL +5 NULL +4 7 +drop procedure p1; +#IN subquery test +flush status; +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 0 +Subquery_cache_miss 0 +select a, b , b in (select d from t2) as SUBS from t1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 6 +Subquery_cache_miss 4 +insert into t1 values (7,8),(9,NULL); +select a, b , b in (select d from t2) as SUBS from t1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +7 8 0 +9 NULL NULL +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 12 +Subquery_cache_miss 10 +insert into t2 values (8,NULL); +select a, b , b in (select d from t2) as SUBS from t1; +a b SUBS +1 2 NULL +3 4 1 +1 2 NULL +3 4 1 +3 4 1 +4 5 NULL +4 5 NULL +5 6 1 +5 6 1 +4 5 NULL +7 8 NULL +9 NULL NULL +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 18 +Subquery_cache_miss 16 +#IN subquery tesy (PS) +delete from t1 where a > 6; +delete from t2 where c > 6; +prepare stmt1 from 'select a, b , b in (select d from t2) as SUBS from t1'; +execute stmt1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 24 +Subquery_cache_miss 20 +execute stmt1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 30 +Subquery_cache_miss 24 +insert into t1 values (7,8),(9,NULL); +execute stmt1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +9 NULL NULL +7 8 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 36 +Subquery_cache_miss 30 +execute stmt1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +9 NULL NULL +7 8 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 42 +Subquery_cache_miss 36 +insert into t2 values (8,NULL); +execute stmt1; +a b SUBS +1 2 NULL +3 4 1 +1 2 NULL +3 4 1 +3 4 1 +4 5 NULL +4 5 NULL +5 6 1 +5 6 1 +4 5 NULL +9 NULL NULL +7 8 NULL +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 48 +Subquery_cache_miss 42 +execute stmt1; +a b SUBS +1 2 NULL +3 4 1 +1 2 NULL +3 4 1 +3 4 1 +4 5 NULL +4 5 NULL +5 6 1 +5 6 1 +4 5 NULL +9 NULL NULL +7 8 NULL +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 54 +Subquery_cache_miss 48 +deallocate prepare stmt1; +#IN subquery tesy (SP) +delete from t1 where a > 6; +delete from t2 where c > 6; +CREATE PROCEDURE p1() select a, b , b in (select d from t2) as SUBS from t1; +call p1(); +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 60 +Subquery_cache_miss 52 +call p1(); +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 66 +Subquery_cache_miss 56 +insert into t1 values (7,8),(9,NULL); +call p1(); +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +9 NULL NULL +7 8 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 72 +Subquery_cache_miss 62 +call p1(); +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +9 NULL NULL +7 8 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 78 +Subquery_cache_miss 68 +insert into t2 values (8,NULL); +call p1(); +a b SUBS +1 2 NULL +3 4 1 +1 2 NULL +3 4 1 +3 4 1 +4 5 NULL +4 5 NULL +5 6 1 +5 6 1 +4 5 NULL +9 NULL NULL +7 8 NULL +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 84 +Subquery_cache_miss 74 +call p1(); +a b SUBS +1 2 NULL +3 4 1 +1 2 NULL +3 4 1 +3 4 1 +4 5 NULL +4 5 NULL +5 6 1 +5 6 1 +4 5 NULL +9 NULL NULL +7 8 NULL +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 90 +Subquery_cache_miss 80 +drop procedure p1; +# test of simple exists +select a, b , exists (select * from t2 where b=d) as SUBS from t1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +9 NULL 0 +7 8 0 +# test of prepared statement exists +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 96 +Subquery_cache_miss 86 +prepare stmt1 from 'select a, b , exists (select * from t2 where b=d) as SUBS from t1'; +execute stmt1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +9 NULL 0 +7 8 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 102 +Subquery_cache_miss 92 +execute stmt1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +9 NULL 0 +7 8 0 +show status like "subquery_cache%"; +Variable_name Value +Subquery_cache_hit 108 +Subquery_cache_miss 98 +deallocate prepare stmt1; +# test of stored procedure exists +CREATE PROCEDURE p1() select a, b , exists (select * from t2 where b=d) as SUBS from t1; +call p1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +9 NULL 0 +7 8 0 +call p1; +a b SUBS +1 2 0 +3 4 1 +1 2 0 +3 4 1 +3 4 1 +4 5 0 +4 5 0 +5 6 1 +5 6 1 +4 5 0 +9 NULL 0 +7 8 0 +drop procedure p1; +#clean up +drop table t1,t2; +test different types +#int +CREATE TABLE t1 ( a int, b int); +INSERT INTO t1 VALUES(1,1),(2,2),(3,3); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = 2); +a +1 +3 +DROP TABLE t1; +#char +CREATE TABLE t1 ( a char(1), b char (1)); +INSERT INTO t1 VALUES('1','1'),('2','2'),('3','3'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2'); +a +1 +3 +DROP TABLE t1; +#decimal +CREATE TABLE t1 ( a decimal(3,1), b decimal(3,1)); +INSERT INTO t1 VALUES(1,1),(2,2),(3,3); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = 2); +a +1.0 +3.0 +DROP TABLE t1; +#date +CREATE TABLE t1 ( a date, b date); +INSERT INTO t1 VALUES('1000-01-01','1000-01-01'),('2000-02-01','2000-02-01'),('3000-03-03','3000-03-03'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2000-02-01'); +a +1000-01-01 +3000-03-03 +DROP TABLE t1; +#datetime +CREATE TABLE t1 ( a datetime, b datetime); +INSERT INTO t1 VALUES('1000-01-01 01:01:01','1000-01-01 01:01:01'),('2000-02-02 02:02:02','2000-02-02 02:02:02'),('3000-03-03 03:03:03','3000-03-03 03:03:03'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2000-02-02 02:02:02'); +a +1000-01-01 01:01:01 +3000-03-03 03:03:03 +DROP TABLE t1; +#time +CREATE TABLE t1 ( a time, b time); +INSERT INTO t1 VALUES('01:01:01','01:01:01'),('02:02:02','02:02:02'),('03:03:03','03:03:03'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '02:02:02'); +a +01:01:01 +03:03:03 +DROP TABLE t1; +#timestamp +CREATE TABLE t1 ( a timestamp, b timestamp); +INSERT INTO t1 VALUES('2000-02-02 01:01:01','2000-02-02 01:01:01'),('2000-02-02 02:02:02','2000-02-02 02:02:02'),('2000-02-02 03:03:03','2000-02-02 03:03:03'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2000-02-02 02:02:02'); +a +2000-02-02 01:01:01 +2000-02-02 03:03:03 +DROP TABLE t1; +#bit +CREATE TABLE t1 ( a bit(20), b bit(20)); +INSERT INTO t1 VALUES(1,1),(2,2),(3,3); +SELECT a+0 FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = 2); +a+0 +1 +3 +DROP TABLE t1; +#enum +CREATE TABLE t1 ( a enum('1','2','3'), b enum('1','2','3')); +INSERT INTO t1 VALUES('1','1'),('2','2'),('3','3'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2'); +a +1 +3 +DROP TABLE t1; +#set +CREATE TABLE t1 ( a set('1','2','3'), b set('1','2','3')); +INSERT INTO t1 VALUES('1','1'),('2','2'),('3','3'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2'); +a +1 +3 +DROP TABLE t1; +#blob +CREATE TABLE t1 ( a blob, b blob); +INSERT INTO t1 VALUES('1','1'),('2','2'),('3','3'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2'); +a +1 +3 +DROP TABLE t1; +#geometry +CREATE TABLE t1 ( a geometry, b geometry); +INSERT INTO t1 VALUES(POINT(1,1),POINT(1,1)),(POINT(2,2),POINT(2,2)),(POINT(3,3),POINT(3,3)); +SELECT astext(a) FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = POINT(2,2)); +astext(a) +POINT(1 1) +POINT(3 3) +DROP TABLE t1; +set optimizer_switch='subquery_cache=default'; === added file 'mysql-test/t/subquery_cache.test' --- a/mysql-test/t/subquery_cache.test 1970-01-01 00:00:00 +0000 +++ b/mysql-test/t/subquery_cache.test 2010-05-25 10:45:36 +0000 @@ -0,0 +1,191 @@ + +set optimizer_switch='subquery_cache=on'; + +create table t1 (a int, b int); +insert into t1 values (1,2),(3,4),(1,2),(3,4),(3,4),(4,5),(4,5),(5,6),(5,6),(4,5); +create table t2 (c int, d int); +insert into t2 values (2,3),(3,4),(5,6); + +--echo #single value subquery test +select a, (select d from t2 where b=c) + 1 from t1; + +show status like "subquery_cache%"; + +--echo #single value subquery test (PS) +prepare stmt1 from 'select a, (select d from t2 where b=c) + 1 from t1'; +execute stmt1; +show status like "subquery_cache%"; +execute stmt1; +show status like "subquery_cache%"; +deallocate prepare stmt1; + +--echo #single value subquery test (SP) +CREATE PROCEDURE p1() select a, (select d from t2 where b=c) + 1 from t1; + +call p1; +call p1; + +drop procedure p1; + +--echo #IN subquery test +flush status; + +show status like "subquery_cache%"; +select a, b , b in (select d from t2) as SUBS from t1; +show status like "subquery_cache%"; + +insert into t1 values (7,8),(9,NULL); +select a, b , b in (select d from t2) as SUBS from t1; +show status like "subquery_cache%"; + +insert into t2 values (8,NULL); +select a, b , b in (select d from t2) as SUBS from t1; +show status like "subquery_cache%"; + +--echo #IN subquery tesy (PS) +delete from t1 where a > 6; +delete from t2 where c > 6; + +prepare stmt1 from 'select a, b , b in (select d from t2) as SUBS from t1'; +execute stmt1; +show status like "subquery_cache%"; +execute stmt1; +show status like "subquery_cache%"; + +insert into t1 values (7,8),(9,NULL); +execute stmt1; +show status like "subquery_cache%"; +execute stmt1; +show status like "subquery_cache%"; + +insert into t2 values (8,NULL); +execute stmt1; +show status like "subquery_cache%"; +execute stmt1; +show status like "subquery_cache%"; + +deallocate prepare stmt1; + + +--echo #IN subquery tesy (SP) +delete from t1 where a > 6; +delete from t2 where c > 6; + +CREATE PROCEDURE p1() select a, b , b in (select d from t2) as SUBS from t1; + +call p1(); +show status like "subquery_cache%"; +call p1(); +show status like "subquery_cache%"; + +insert into t1 values (7,8),(9,NULL); +call p1(); +show status like "subquery_cache%"; +call p1(); +show status like "subquery_cache%"; + +insert into t2 values (8,NULL); +call p1(); +show status like "subquery_cache%"; +call p1(); +show status like "subquery_cache%"; + +drop procedure p1; + + +--echo # test of simple exists +select a, b , exists (select * from t2 where b=d) as SUBS from t1; + +--echo # test of prepared statement exists +show status like "subquery_cache%"; +prepare stmt1 from 'select a, b , exists (select * from t2 where b=d) as SUBS from t1'; +execute stmt1; +show status like "subquery_cache%"; +execute stmt1; +show status like "subquery_cache%"; +deallocate prepare stmt1; + +--echo # test of stored procedure exists +CREATE PROCEDURE p1() select a, b , exists (select * from t2 where b=d) as SUBS from t1; +call p1; +call p1; +drop procedure p1; + +--echo #clean up +drop table t1,t2; + +--echo test different types +--echo #int +CREATE TABLE t1 ( a int, b int); +INSERT INTO t1 VALUES(1,1),(2,2),(3,3); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = 2); +DROP TABLE t1; + +--echo #char +CREATE TABLE t1 ( a char(1), b char (1)); +INSERT INTO t1 VALUES('1','1'),('2','2'),('3','3'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2'); +DROP TABLE t1; + +--echo #decimal +CREATE TABLE t1 ( a decimal(3,1), b decimal(3,1)); +INSERT INTO t1 VALUES(1,1),(2,2),(3,3); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = 2); +DROP TABLE t1; + +--echo #date +CREATE TABLE t1 ( a date, b date); +INSERT INTO t1 VALUES('1000-01-01','1000-01-01'),('2000-02-01','2000-02-01'),('3000-03-03','3000-03-03'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2000-02-01'); +DROP TABLE t1; + +--echo #datetime +CREATE TABLE t1 ( a datetime, b datetime); +INSERT INTO t1 VALUES('1000-01-01 01:01:01','1000-01-01 01:01:01'),('2000-02-02 02:02:02','2000-02-02 02:02:02'),('3000-03-03 03:03:03','3000-03-03 03:03:03'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2000-02-02 02:02:02'); +DROP TABLE t1; + +--echo #time +CREATE TABLE t1 ( a time, b time); +INSERT INTO t1 VALUES('01:01:01','01:01:01'),('02:02:02','02:02:02'),('03:03:03','03:03:03'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '02:02:02'); +DROP TABLE t1; + +--echo #timestamp +CREATE TABLE t1 ( a timestamp, b timestamp); +INSERT INTO t1 VALUES('2000-02-02 01:01:01','2000-02-02 01:01:01'),('2000-02-02 02:02:02','2000-02-02 02:02:02'),('2000-02-02 03:03:03','2000-02-02 03:03:03'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2000-02-02 02:02:02'); +DROP TABLE t1; + +--echo #bit +CREATE TABLE t1 ( a bit(20), b bit(20)); +INSERT INTO t1 VALUES(1,1),(2,2),(3,3); +SELECT a+0 FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = 2); +DROP TABLE t1; + +--echo #enum +CREATE TABLE t1 ( a enum('1','2','3'), b enum('1','2','3')); +INSERT INTO t1 VALUES('1','1'),('2','2'),('3','3'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2'); +DROP TABLE t1; + +--echo #set +CREATE TABLE t1 ( a set('1','2','3'), b set('1','2','3')); +INSERT INTO t1 VALUES('1','1'),('2','2'),('3','3'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2'); +DROP TABLE t1; + +--echo #blob +CREATE TABLE t1 ( a blob, b blob); +INSERT INTO t1 VALUES('1','1'),('2','2'),('3','3'); +SELECT a FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = '2'); +DROP TABLE t1; + +--echo #geometry +CREATE TABLE t1 ( a geometry, b geometry); +INSERT INTO t1 VALUES(POINT(1,1),POINT(1,1)),(POINT(2,2),POINT(2,2)),(POINT(3,3),POINT(3,3)); +SELECT astext(a) FROM t1 WHERE NOT a IN (SELECT a FROM t1 WHERE b = POINT(2,2)); +DROP TABLE t1; + + +set optimizer_switch='subquery_cache=default'; === modified file 'sql/item_sum.cc' --- a/sql/item_sum.cc 2010-03-20 12:01:47 +0000 +++ b/sql/item_sum.cc 2010-05-25 10:45:36 +0000 @@ -319,6 +319,7 @@ if (aggr_level >= 0) { ref_by= ref; + thd->lex->current_select->register_dependency_item(aggr_sel, ref); /* Add the object to the list of registered objects assigned to aggr_sel */ if (!aggr_sel->inner_sum_func_list) next= this; === added file 'sql/sql_subquery_cache.cc' --- a/sql/sql_subquery_cache.cc 1970-01-01 00:00:00 +0000 +++ b/sql/sql_subquery_cache.cc 2010-05-25 10:45:36 +0000 @@ -0,0 +1,319 @@ + +#include "mysql_priv.h" +#include "sql_select.h" + +ulonglong subquery_cache_miss, subquery_cache_hit; + +/** + Creates structures which we need for index look up + + @retval FALSE OK + @retval TRUE Error +*/ + +static my_bool createtmp_table_search_structures(THD *thd, + TABLE *table, + List_iterator_fast<Item> &li, + TABLE_REF **ref) +{ + /* + Create/initialize everything we will need to index lookups into the + temptable. + */ + TABLE_REF *tab_ref; + KEY *tmp_key; /* The only index on the temporary table. */ + Item *item; + uint tmp_key_parts; /* Number of keyparts in tmp_key. */ + uint i; + + DBUG_ENTER("createtmp_table_search_structures"); + + tmp_key= table->key_info; + tmp_key_parts= tmp_key->key_parts; + + if (!(tab_ref= (TABLE_REF*) thd->alloc(sizeof(TABLE_REF)))) + DBUG_RETURN(TRUE); + + tab_ref->key= 0; /* The only temp table index. */ + tab_ref->key_length= tmp_key->key_length; + if (!(tab_ref->key_buff= + (uchar*) thd->calloc(ALIGN_SIZE(tmp_key->key_length) * 2)) || + !(tab_ref->key_copy= + (store_key**) thd->alloc((sizeof(store_key*) * + (tmp_key_parts + 1)))) || + !(tab_ref->items= + (Item**) thd->alloc(sizeof(Item*) * tmp_key_parts))) + DBUG_RETURN(TRUE); /* purecov: inspected */ + + tab_ref->key_buff2=tab_ref->key_buff+ALIGN_SIZE(tmp_key->key_length); + tab_ref->key_err=1; + tab_ref->null_rejecting= 1; + tab_ref->disable_cache= FALSE; + tab_ref->has_record= 0; + + KEY_PART_INFO *cur_key_part= tmp_key->key_part; + store_key **ref_key= tab_ref->key_copy; + uchar *cur_ref_buff= tab_ref->key_buff; + + for (i= 0; i < tmp_key_parts; i++, cur_key_part++, ref_key++) + { + item= li++; + DBUG_ASSERT(item); + tab_ref->items[i]= item; + int null_count= test(cur_key_part->field->real_maybe_null()); + *ref_key= new store_key_item(thd, cur_key_part->field, + /* TODO: + the NULL byte is taken into account in + cur_key_part->store_length, so instead of + cur_ref_buff + test(maybe_null), we could + use that information instead. + */ + cur_ref_buff + null_count, + null_count ? tab_ref->key_buff : 0, + cur_key_part->length, tab_ref->items[i]); + cur_ref_buff+= cur_key_part->store_length; + } + *ref_key= NULL; /* End marker. */ + tab_ref->key_err= 1; + tab_ref->key_parts= tmp_key_parts; + *ref= tab_ref; + + DBUG_RETURN(FALSE); +} + + +Subquery_cache_tmptable::Subquery_cache_tmptable(THD *thd, + List<Item*> &dependance, + Item *value) + :cache_table(NULL), table_thd(thd), list(&dependance), val(value), + equalities(NULL), inited (0) +{ + DBUG_ENTER("Subquery_cache_tmptable::Subquery_cache_tmptable"); + DBUG_VOID_RETURN; +}; + + +/** + Creates equalities expression. + + @retval FALSE OK + @retval TRUE Error +*/ + +bool Subquery_cache_tmptable::make_equalities() +{ + List<Item> args; + List_iterator_fast<Item*> li(*list); + Item **ref; + Name_resolution_context *cn= NULL; + DBUG_ENTER("Subquery_cache_tmptable::make_equalities"); + + for (uint i= 1 /* skip result filed */; (ref= li++); i++) + { + Field *fld= cache_table->field[i]; + if (fld->type() == MYSQL_TYPE_VARCHAR || + fld->type() == MYSQL_TYPE_TINY_BLOB || + fld->type() == MYSQL_TYPE_MEDIUM_BLOB || + fld->type() == MYSQL_TYPE_LONG_BLOB || + fld->type() == MYSQL_TYPE_BLOB || + fld->type() == MYSQL_TYPE_VAR_STRING || + fld->type() == MYSQL_TYPE_STRING || + fld->type() == MYSQL_TYPE_NEWDECIMAL || + fld->type() == MYSQL_TYPE_DECIMAL) + { + if (!cn) + { + // dummy resolution context + cn= new Name_resolution_context(); + cn->init(); + } + args.push_front(new Item_func_eq(new Item_ref(cn, ref, "", "", FALSE), + new Item_field(fld))); + } + } + if (args.elements == 1) + equalities= args.head(); + else + equalities= new Item_cond_and(args); + + DBUG_RETURN(equalities->fix_fields(table_thd, &equalities)); +} + +void Subquery_cache_tmptable::init() +{ + ulonglong keymap; + List_iterator_fast<Item*> li(*list); + List_iterator_fast<Item> li_items(items); + Item **item; + DBUG_ENTER("Subquery_cache_tmptable::init"); + DBUG_ASSERT(!inited); + inited= TRUE; + + if (!(ULONGLONG_MAX >> (list->elements + 1))) + { + DBUG_PRINT("info", ("Too many dependencies")); + DBUG_VOID_RETURN; + } + + cache_table= NULL; + while ((item= li++)) + { + DBUG_ASSERT(item); + DBUG_ASSERT(*item); + DBUG_ASSERT((*item)->fixed); + items.push_back((*item)); + } + + cache_table_param.init(); + /* dependance items and result */ + cache_table_param.field_count= list->elements + 1; + /* postpone table creation to index description */ + cache_table_param.skip_create_table= 1; + + + items.push_front(val); + if (!(cache_table= create_tmp_table(table_thd, &cache_table_param, + items, (ORDER*) NULL, + FALSE, FALSE, + (table_thd->options | + TMP_TABLE_ALL_COLUMNS), + HA_POS_ERROR, + (char *)"subquery-cache-table"))) + { + DBUG_PRINT("error", ("create_tmp_table failed, caching switched off")); + DBUG_VOID_RETURN; + } + + if (cache_table->s->blob_fields) + { + DBUG_PRINT("error", ("we do not need blobs")); + goto error; + } + + /* makes all bits set for keys */ + keymap= 1 << (items.elements); /* + 1 - 1 */ + if (!keymap) + keymap= ULONGLONG_MAX; + else + keymap--; + keymap&=~1; + + li_items++; + if (cache_table->alloc_keys(1) || + (cache_table->add_tmp_key(keymap, "cache-table-key") < 0) || + createtmp_table_search_structures(table_thd, cache_table, li_items, + &tab_ref) || + !(tab= create_index_lookup_join_tab(cache_table))) + { + DBUG_PRINT("error", ("creating index failed")); + goto error; + } + cache_table->s->keys= 1; + cache_table->s->uniques= 1; + + if (open_tmp_table(cache_table)) + { + DBUG_PRINT("error", ("Opening (creating) temporary table failed")); + goto error; + } + + if (!(chached_result= new Item_field(cache_table->field[0]))) + { + DBUG_PRINT("error", ("Creating Item_field failed")); + goto error; + } + if (make_equalities()) + { + DBUG_PRINT("error", ("Creating equalities failed")); + goto error; + } + + DBUG_VOID_RETURN; + +error: + /* switch off cache */ + free_tmp_table(table_thd, cache_table); + cache_table= NULL; + DBUG_VOID_RETURN; +} + + +Subquery_cache_tmptable::~Subquery_cache_tmptable() +{ + if (cache_table) + free_tmp_table(table_thd, cache_table); +} + + +Subquery_cache::result Subquery_cache_tmptable::check_value(Item **value) +{ + int res; + DBUG_ENTER("Subquery_cache_tmptable::check_value"); + + if (!inited) + init(); + + if (cache_table) + { + DBUG_PRINT("info", ("status: %u has_record %u", + (uint)cache_table->status, (uint)tab_ref->has_record)); + if ((res= join_read_key2(table_thd, tab, cache_table, tab_ref)) == 1) + DBUG_RETURN(ERROR); + if (res || (equalities && !equalities->val_int())) + { + subquery_cache_miss++; + DBUG_RETURN(MISS); + } + + subquery_cache_hit++; + *value= chached_result; + DBUG_RETURN(Subquery_cache::HIT); + } + DBUG_RETURN(Subquery_cache::MISS); +} + + +my_bool Subquery_cache_tmptable::put_value(Item *value) +{ + int error; + DBUG_ENTER("Subquery_cache_tmptable::put_value"); + DBUG_ASSERT(inited); + + if (!cache_table) + { + DBUG_PRINT("info", ("No table so behave as we successfully put value")); + DBUG_RETURN(FALSE); + } + + *(items.head_ref())= value; + fill_record(table_thd, cache_table->field, items, 1); + if (table_thd->is_error()) + goto err;; + + if ((error= cache_table->file->ha_write_row(cache_table->record[0]))) + { + /* create_myisam_from_heap will generate error if needed */ + if (cache_table->file->is_fatal_error(error, HA_CHECK_DUP) && + create_internal_tmp_table_from_heap(table_thd, cache_table, + cache_table_param.start_recinfo, + &cache_table_param.recinfo, + error, 1)) + goto err; + } + cache_table->status= 0; /* cache_table->record contains an existed record */ + tab_ref->has_record= TRUE; /* the same as above */ + DBUG_PRINT("info", ("has_record: TRUE status: 0")); + + DBUG_RETURN(FALSE); + +err: + free_tmp_table(table_thd, cache_table); + cache_table= NULL; + DBUG_RETURN(TRUE); +} + + +void Subquery_cache_tmptable::cleanup() +{ + cache_table->file->ha_delete_all_rows(); +} === added file 'sql/sql_subquery_cache.h' --- a/sql/sql_subquery_cache.h 1970-01-01 00:00:00 +0000 +++ b/sql/sql_subquery_cache.h 2010-05-25 10:45:36 +0000 @@ -0,0 +1,79 @@ +#ifndef _SQL_SUBQUERY_CACHE_H_ +#define _SQL_SUBQUERY_CACHE_H_ + +/** + Interface for subquery cache +*/ + +extern ulonglong subquery_cache_miss, subquery_cache_hit; + +class Subquery_cache :public Sql_alloc +{ +public: + enum result {ERROR, HIT, MISS}; + + Subquery_cache(){}; + virtual ~Subquery_cache() {}; + /** + Checks presence of the key (taken from cache owner) and if found return + it via value parameter + */ + virtual result check_value(Item **value)= 0; + /** + Puts value into this cache (key should be taken from cache owner) + */ + virtual my_bool put_value(Item *value)= 0; + /** + Cleans up and reset cache before reusing + */ + virtual void cleanup()= 0; +}; + +struct st_table_ref; +struct st_join_table; +//class Item_cache; +class Item_field; + +/** + Implementation of subquery cache over temporary table +*/ + +class Subquery_cache_tmptable :public Subquery_cache +{ +public: + Subquery_cache_tmptable(THD *thd, List<Item*> &dependance, Item *value); + virtual ~Subquery_cache_tmptable(); + virtual result check_value(Item **value); + virtual my_bool put_value(Item *value); + virtual void cleanup(); + void init(); + +private: + bool make_equalities(); + + /* tmp table parameters */ + TMP_TABLE_PARAM cache_table_param; + /* temporary table to store this cache */ + TABLE *cache_table; + /* Thread handler for the temporary table */ + THD *table_thd; + /* tab_ref for index search */ + struct st_table_ref *tab_ref; + /* cache of subquery value to avoid evaluating it twice */ + //Item_cache *value_cache; + /* JOIN_TAB for index lookup */ + st_join_table *tab; + /* Chached result */ + Item_field *chached_result; + /* List of references to items */ + List<Item*> *list; + /* List of items */ + List<Item> items; + /* Value Item example */ + Item *val; + /* Expression to check after index lookup */ + Item *equalities; + /* set if structures are inited */ + bool inited; +}; +#endif

1 0

[Maria-developers] Progress (by Knielsen): Store in binlog text of statements that caused RBR events (47)
by worklog-noreply＠askmonty.org 25 May '10

25 May '10

----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: Store in binlog text of statements that caused RBR events CREATION DATE..: Sat, 15 Aug 2009, 23:48 SUPERVISOR.....: Monty IMPLEMENTOR....: COPIES TO......: Knielsen, Serg CATEGORY.......: Server-Sprint TASK ID........: 47 (http://askmonty.org/worklog/?tid=47) VERSION........: Server-9.x STATUS.........: Code-Review PRIORITY.......: 60 WORKED HOURS...: 31 ESTIMATE.......: 4 (hours remain) ORIG. ESTIMATE.: 35 PROGRESS NOTES: -=-=(Knielsen - Tue, 25 May 2010, 08:29)=-=- Help debug strange problem in mysqlbinlog.test. Worked 1 hour and estimate 4 hours remain (original estimate unchanged). -=-=(Knielsen - Mon, 17 May 2010, 08:45)=-=- Merge with latest trunk and run Buildbot tests. Worked 1 hour and estimate 5 hours remain (original estimate unchanged). -=-=(Knielsen - Wed, 05 May 2010, 13:53)=-=- Review of fixes to first review done. No new issues found. Worked 2 hours and estimate 6 hours remain (original estimate unchanged). -=-=(Knielsen - Fri, 23 Apr 2010, 12:51)=-=- Status updated. --- /tmp/wklog.47.old.28747 2010-04-23 12:51:36.000000000 +0000 +++ /tmp/wklog.47.new.28747 2010-04-23 12:51:36.000000000 +0000 @@ -1 +1 @@ -In-Progress +Code-Review -=-=(Knielsen - Tue, 06 Apr 2010, 15:26)=-=- Code review (mailed to maria-developers@). Worked 7 hours and estimate 8 hours remain (original estimate unchanged). -=-=(Knielsen - Tue, 06 Apr 2010, 15:25)=-=- Status updated. --- /tmp/wklog.47.old.12734 2010-04-06 15:25:54.000000000 +0000 +++ /tmp/wklog.47.new.12734 2010-04-06 15:25:54.000000000 +0000 @@ -1 +1 @@ -Code-Review +In-Progress -=-=(Knielsen - Mon, 29 Mar 2010, 10:59)=-=- Status updated. --- /tmp/wklog.47.old.27790 2010-03-29 10:59:53.000000000 +0000 +++ /tmp/wklog.47.new.27790 2010-03-29 10:59:53.000000000 +0000 @@ -1 +1 @@ -In-Progress +Code-Review -=-=(Alexi - Thu, 18 Feb 2010, 19:29)=-=- Worked 20 hours (alexi) Worked 20 hours and estimate 15 hours remain (original estimate unchanged). -=-=(Serg - Fri, 05 Feb 2010, 14:04)=-=- Observers changed: Knielsen,Serg -=-=(Guest - Fri, 05 Feb 2010, 13:40)=-=- Category updated. --- /tmp/wklog.47.old.9197 2010-02-05 13:40:36.000000000 +0200 +++ /tmp/wklog.47.new.9197 2010-02-05 13:40:36.000000000 +0200 @@ -1 +1 @@ -Server-RawIdeaBin +Server-Sprint ------------------------------------------------------------ -=-=(View All Progress Notes, 31 total)=-=- http://askmonty.org/worklog/index.pl?tid=47&nolimit=1 DESCRIPTION: Store in binlog (and show in mysqlbinlog output) texts of statements that caused RBR events This is needed for (list from Monty): - Easier to understand why updates happened - Would make it easier to find out where in application things went wrong (as you can search for exact strings) - Allow one to filter things based on comments in the statement. The cost of this can be that the binlog will be approximately 2x in size (especially insert of big blob's would be a bit painful), so this should be an optional feature. HIGH-LEVEL SPECIFICATION: Content ~~~~~~~ 1. Annotate_rows_log_event 2. Server option: --binlog-annotate-rows-events 3. Server option: --replicate-annotate-rows-events 4. mysqlbinlog option: --print-annotate-rows-events 5. mysqlbinlog output 1. Annotate_rows_log_event [ ANNOTATE_ROWS_EVENT ] ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Describes the query which caused the corresponding rows events. Has empty post-header and contains the query text in its data part. Example: ************************ ANNOTATE_ROWS_EVENT ************************ 00000220 | B6 A0 2C 4B | time_when = 1261215926 00000224 | 33 | event_type = 51 00000225 | 64 00 00 00 | server_id = 100 00000229 | 36 00 00 00 | event_len = 54 0000022D | 56 02 00 00 | log_pos = 00000256 00000231 | 00 00 | flags = <none> ------------------------ 00000233 | 49 4E 53 45 | query = "INSERT INTO t1 VALUES (1), (2), (3)" 00000237 | 52 54 20 49 | 0000023B | 4E 54 4F 20 | 0000023F | 74 31 20 56 | 00000243 | 41 4C 55 45 | 00000247 | 53 20 28 31 | 0000024B | 29 2C 20 28 | 0000024F | 32 29 2C 20 | 00000253 | 28 33 29 | ************************ In binary log, Annotate_rows event follows the (possible) 'BEGIN' Query event and precedes the first of Table map events which accompany the corresponding rows events. (See example in the "mysqlbinlog output" section below.) 2. Server option: --binlog-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Tells the master to write Annotate_rows events to the binary log. * Variable Name: binlog_annotate_rows_events * Scope: Global & Session * Access Type: Dynamic * Data Type: bool * Default Value: OFF NOTE. Session values allows to annotate only some selected statements: ... SET SESSION binlog_annotate_rows_events=ON; ... statements to be annotated ... SET SESSION binlog_annotate_rows_events=OFF; ... statements not to be annotated ... 3. Server option: --replicate-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Tells the slave to reproduce Annotate_rows events recieved from the master in its own binary log (sensible only in pair with log-slave-updates option). * Variable Name: replicate_annotate_rows_events * Scope: Global * Access Type: Read only * Data Type: bool * Default Value: OFF NOTE. Why do we additionally need this 'replicate' option? Why not to make the slave to reproduce this events when its binlog-annotate-rows-events global value is ON? Well, because, for example, we may want to configure the slave which should reproduce Annotate_rows events but has global binlog-annotate-rows-events = OFF meaning this to be the default value for the client threads (see also "How slave treats replicate-annotate-rows-events option" in LLD part). 4. mysqlbinlog option: --print-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ With this option, mysqlbinlog prints the content of Annotate_rows events (if the binary log does contain them). Without this option (i.e. by default), mysqlbinlog skips Annotate_rows events. 5. mysqlbinlog output ~~~~~~~~~~~~~~~~~~~~~ With --print-annotate-rows-events, mysqlbinlog outputs Annotate_rows events in a form like this: ... # at 1646 #091219 12:45:26 server id 100 end_log_pos 1714 Query thread_id=1 exec_time=0 error_code=0 SET TIMESTAMP=1261215926/*!*/; BEGIN /*!*/; # at 1714 # at 1812 # at 1853 # at 1894 # at 1938 #091219 12:45:26 server id 100 end_log_pos 1812 Query: `DELETE t1, t2 FROM t1 INNER JOIN t2 INNER JOIN t3 WHERE t1.a=t2.a AND t2.a=t3.a` #091219 12:45:26 server id 100 end_log_pos 1853 Table_map: `test`.`t1` mapped to number 16 #091219 12:45:26 server id 100 end_log_pos 1894 Table_map: `test`.`t2` mapped to number 17 #091219 12:45:26 server id 100 end_log_pos 1938 Delete_rows: table id 16 #091219 12:45:26 server id 100 end_log_pos 1982 Delete_rows: table id 17 flags: STMT_END_F ... LOW-LEVEL DESIGN: Content ~~~~~~~ 1. Annotate_rows event number 2. Outline of Annotate_rows event behavior 3. How Master writes Annotate_rows events to the binary log 4. How slave treats replicate-annotate-rows-events option 5. How slave IO thread requests Annotate_rows events 6. How master executes the request 7. How slave SQL thread processes Annotate_rows events 8. General remarks 1. Annotate_rows event number ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ To avoid possible event numbers conflict with MySQL/Sun, we leave a gap between the last MySQL event number and the Annotate_rows event number: enum Log_event_type { ... INCIDENT_EVENT= 26, // New MySQL event numbers are to be added here MYSQL_EVENTS_END, MARIA_EVENTS_BEGIN= 51, // New Maria event numbers start from here ANNOTATE_ROWS_EVENT= 51, ENUM_END_EVENT }; together with the corresponding extension of 'post_header_len' array in the Format description event. (This extension does not affect the compatibility of the binary log). Here is how Format description event looks like with this extension: ************************ FORMAT_DESCRIPTION_EVENT ************************ 00000004 | A1 A0 2C 4B | time_when = 1261215905 00000008 | 0F | event_type = 15 00000009 | 64 00 00 00 | server_id = 100 0000000D | 7F 00 00 00 | event_len = 127 00000011 | 83 00 00 00 | log_pos = 00000083 00000015 | 01 00 | flags = LOG_EVENT_BINLOG_IN_USE_F ------------------------ 00000017 | 04 00 | binlog_ver = 4 00000019 | 35 2E 32 2E | server_ver = 5.2.0-MariaDB-alpha-debug-log ..... ... 0000004B | A1 A0 2C 4B | time_created = 1261215905 0000004F | 13 | common_header_len = 19 ------------------------ post_header_len ------------------------ 00000050 | 38 | 56 - START_EVENT_V3 [1] ..... ... 00000069 | 02 | 2 - INCIDENT_EVENT [26] 0000006A | 00 | 0 - RESERVED [27] ..... ... 00000081 | 00 | 0 - RESERVED [50] 00000082 | 00 | 0 - ANNOTATE_ROWS_EVENT [51] ************************ 2. Outline of Annotate_rows event behavior ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Each Annotate_rows_log_event object has two private members describing the corresponding query: char *m_query_txt; uint m_query_len; When the object is created for writing to a binary log, this query is taken from 'thd' (for short, below we omit the 'Annotate_rows_log_event::' prefix as well as other implementation details): Annotate_rows_log_event(THD *thd) { m_query_txt = thd->query(); m_query_len = thd->query_length(); } When the object is read from a binary log, the query is taken from the buffer containing the binary log representation of the event (this buffer is allocated in Log_event object from which all Log events are derived): Annotate_rows_log_event(char *buf, uint event_len, Format_description_log_event *desc) { m_query_len = event_len - desc->common_header_len; m_query_txt = buf + desc->common_header_len; } The events are written to the binary log by the Log_event::write() member which calls virtual write_data_header() and write_data_body() members ("data header" and "post header" are synonym in replication terminology). In our case, data header is empty and data body is just the query: bool write_data_body(IO_CACHE *file) { return my_b_safe_write(file, (uchar*) m_query_txt, m_query_len); } Printing the event is just printing the query: void Annotate_rows_log_event::print(FILE *file, PRINT_EVENT_INFO *pinfo) { my_b_printf(&pinfo->head_cache, "\tQuery: `%s`\n", m_query_txt); } 3. How Master writes Annotate_rows events to the binary log ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The event is written to the binary log just before the group of Table_map events which precede corresponding Rows events (one query may generate several Table map events in the binary log, but the corresponding Annotate_rows event must be written only once before the first Table map event; hence the boolean variable 'with_annotate' below): int write_locked_table_maps(THD *thd) { ... bool with_annotate= thd->variables.binlog_annotate_rows_events; ... for (uint i= 0; i < ... <number of tables> ...; ++i) { ... thd->binlog_write_table_map(table, ..., with_annotate); with_annotate= 0; // write Annotate_event not more than once ... } ... } int THD::binlog_write_table_map(TABLE *table, ..., bool with_annotate) { ... Table_map_log_event the_event(...); ... if (with_annotate) { Annotate_rows_log_event anno(this); mysql_bin_log.write(&anno); } mysql_bin_log.write(&the_event); ... } 4. How slave treats replicate-annotate-rows-events option ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The replicate-annotate-rows-events option is treated just as the session value of the binlog_annotate_rows_events variable for the slave IO and SQL threads. This setting is done during initialization of these threads: pthread_handler_t handle_slave_io(void *arg) { THD *thd= new THD; ... init_slave_thread(thd, SLAVE_THD_IO); ... } pthread_handler_t handle_slave_sql(void *arg) { THD *thd= new THD; ... init_slave_thread(thd, SLAVE_THD_SQL); ... } int init_slave_thread(THD* thd, SLAVE_THD_TYPE thd_type) { ... thd->variables.binlog_annotate_rows_events= opt_replicate_annotate_rows_events; ... } 5. How slave IO thread requests Annotate_rows events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ If the replicate-annotate-rows-events option is not set on a slave, there is no need for master to send Annotate_rows events to this slave. The slave (or mysqlbinlog in remote case), before requesting binlog dump via the COM_BINLOG_DUMP command, informs the master whether it should send these events by executing the newly added COM_BINLOG_DUMP_OPTIONS_EXT server command: case COM_BINLOG_DUMP_OPTIONS_EXT: thd->binlog_dump_flags_ext= packet[0]; my_ok(thd); break; Note. We add this new command and don't use COM_BINLOG_DUMP to avoid possible conflicts with MySQL/Sun. 6. How master executes the request ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ case COM_BINLOG_DUMP: { ... flags= uint2korr(packet + 4); ... mysql_binlog_send(thd, ..., flags); ... } void mysql_binlog_send(THD* thd, ..., ushort flags) { ... Log_event::read_log_event(&log, packet, ...); ... if ((*packet)[EVENT_TYPE_OFFSET + 1] != ANNOTATE_ROWS_EVENT || flags & BINLOG_SEND_ANNOTATE_ROWS_EVENT) { my_net_write(net, packet->ptr(), packet->length()); } ... } 7. How slave SQL thread processes Annotate_rows events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The slave processes each recieved event by "applying" it, i.e. by calling the Log_event::apply_event() function which in turn calls the virtual do_apply_event() member specific for each type of the event. int exec_relay_log_event(THD* thd, Relay_log_info* rli) { ... Log_event *ev = next_event(rli); ... apply_event_and_update_pos(ev, ...); if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT) delete ev; ... } int apply_event_and_update_pos(Log_event *ev, ...) { ... ev->apply_event(...); ... } int Log_event::apply_event(...) { return do_apply_event(...); } What does it mean to "apply" an Annotate_rows event? It means to set current thd query to that of the described by the event, i.e. to the query which caused the subsequent Rows events (see "How Master writes Annotate_rows events to the binary log" to follow what happens further when the subsequent Rows events are applied): int Annotate_rows_log_event::do_apply_event(...) { thd->set_query(m_query_txt, m_query_len); } NOTE. I am not sure, but possibly current values of thd->query and thd->query_length should be saved before calling set_query() and to be restored on the Annotate_rows_log_event object deletion. Is it really needed ? After calling this do_apply_event() function we may not delete the Annotate_rows_log_event object immediatedly (see exec_relay_log_event() above) because thd->query now points to the string inside this object. We may keep the pointer to this object in the Relay_log_info: class Relay_log_info { public: ... void set_annotate_event(Annotate_rows_log_event*); Annotate_rows_log_event* get_annotate_event(); void free_annotate_event(); ... private: Annotate_rows_log_event* m_annotate_event; }; The saved Annotate_rows object should be deleted when all corresponding Rows events will be processed: int exec_relay_log_event(THD* thd, Relay_log_info* rli) { ... Log_event *ev= next_event(rli); ... apply_event_and_update_pos(ev, ...); if (rli->get_annotate_event() && is_last_rows_event(ev)) rli->free_annotate_event(); else if (ev->get_type_code() == ANNOTATE_ROWS_EVENT) rli->set_annotate_event((Annotate_rows_log_event*) ev); else if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT) delete ev; ... } where bool is_last_rows_event(Log_event* ev) { Log_event_type type= ev->get_type_code(); if (IS_ROWS_EVENT_TYPE(type)) { Rows_log_event* rows= (Rows_log_event*)ev; return rows->get_flags(Rows_log_event::STMT_END_F); } return 0; } #define IS_ROWS_EVENT_TYPE(type) ((type) == WRITE_ROWS_EVENT || \ (type) == UPDATE_ROWS_EVENT || \ (type) == DELETE_ROWS_EVENT) 8. General remarks ~~~~~~~~~~~~~~~~~~ Kristian noticed that introducing new log event type should be coordinated somehow with MySQL/Sun: Kristian: The numeric code for this event must be assigned carefully. It should be coordinated with MySQL/Sun, otherwise we can get into a situation where MySQL uses the same numeric code for one event that MariaDB uses for ANNOTATE_ROWS_EVENT, which would make merging the two impossible. Alex: I reserved about 20 numbers not to have possible conflicts with MySQL. Kristian: Still, I think it would be appropriate to send a polite email to internals(a)lists.mysql.com about this and suggesting to reserve the event number. ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v3.5.9)

1 0

[Maria-developers] Progress (by Knielsen): Store in binlog text of statements that caused RBR events (47)
by worklog-noreply＠askmonty.org 25 May '10

25 May '10

----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: Store in binlog text of statements that caused RBR events CREATION DATE..: Sat, 15 Aug 2009, 23:48 SUPERVISOR.....: Monty IMPLEMENTOR....: COPIES TO......: Knielsen, Serg CATEGORY.......: Server-Sprint TASK ID........: 47 (http://askmonty.org/worklog/?tid=47) VERSION........: Server-9.x STATUS.........: Code-Review PRIORITY.......: 60 WORKED HOURS...: 31 ESTIMATE.......: 4 (hours remain) ORIG. ESTIMATE.: 35 PROGRESS NOTES: -=-=(Knielsen - Tue, 25 May 2010, 08:29)=-=- Help debug strange problem in mysqlbinlog.test. Worked 1 hour and estimate 4 hours remain (original estimate unchanged). -=-=(Knielsen - Mon, 17 May 2010, 08:45)=-=- Merge with latest trunk and run Buildbot tests. Worked 1 hour and estimate 5 hours remain (original estimate unchanged). -=-=(Knielsen - Wed, 05 May 2010, 13:53)=-=- Review of fixes to first review done. No new issues found. Worked 2 hours and estimate 6 hours remain (original estimate unchanged). -=-=(Knielsen - Fri, 23 Apr 2010, 12:51)=-=- Status updated. --- /tmp/wklog.47.old.28747 2010-04-23 12:51:36.000000000 +0000 +++ /tmp/wklog.47.new.28747 2010-04-23 12:51:36.000000000 +0000 @@ -1 +1 @@ -In-Progress +Code-Review -=-=(Knielsen - Tue, 06 Apr 2010, 15:26)=-=- Code review (mailed to maria-developers@). Worked 7 hours and estimate 8 hours remain (original estimate unchanged). -=-=(Knielsen - Tue, 06 Apr 2010, 15:25)=-=- Status updated. --- /tmp/wklog.47.old.12734 2010-04-06 15:25:54.000000000 +0000 +++ /tmp/wklog.47.new.12734 2010-04-06 15:25:54.000000000 +0000 @@ -1 +1 @@ -Code-Review +In-Progress -=-=(Knielsen - Mon, 29 Mar 2010, 10:59)=-=- Status updated. --- /tmp/wklog.47.old.27790 2010-03-29 10:59:53.000000000 +0000 +++ /tmp/wklog.47.new.27790 2010-03-29 10:59:53.000000000 +0000 @@ -1 +1 @@ -In-Progress +Code-Review -=-=(Alexi - Thu, 18 Feb 2010, 19:29)=-=- Worked 20 hours (alexi) Worked 20 hours and estimate 15 hours remain (original estimate unchanged). -=-=(Serg - Fri, 05 Feb 2010, 14:04)=-=- Observers changed: Knielsen,Serg -=-=(Guest - Fri, 05 Feb 2010, 13:40)=-=- Category updated. --- /tmp/wklog.47.old.9197 2010-02-05 13:40:36.000000000 +0200 +++ /tmp/wklog.47.new.9197 2010-02-05 13:40:36.000000000 +0200 @@ -1 +1 @@ -Server-RawIdeaBin +Server-Sprint ------------------------------------------------------------ -=-=(View All Progress Notes, 31 total)=-=- http://askmonty.org/worklog/index.pl?tid=47&nolimit=1 DESCRIPTION: Store in binlog (and show in mysqlbinlog output) texts of statements that caused RBR events This is needed for (list from Monty): - Easier to understand why updates happened - Would make it easier to find out where in application things went wrong (as you can search for exact strings) - Allow one to filter things based on comments in the statement. The cost of this can be that the binlog will be approximately 2x in size (especially insert of big blob's would be a bit painful), so this should be an optional feature. HIGH-LEVEL SPECIFICATION: Content ~~~~~~~ 1. Annotate_rows_log_event 2. Server option: --binlog-annotate-rows-events 3. Server option: --replicate-annotate-rows-events 4. mysqlbinlog option: --print-annotate-rows-events 5. mysqlbinlog output 1. Annotate_rows_log_event [ ANNOTATE_ROWS_EVENT ] ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Describes the query which caused the corresponding rows events. Has empty post-header and contains the query text in its data part. Example: ************************ ANNOTATE_ROWS_EVENT ************************ 00000220 | B6 A0 2C 4B | time_when = 1261215926 00000224 | 33 | event_type = 51 00000225 | 64 00 00 00 | server_id = 100 00000229 | 36 00 00 00 | event_len = 54 0000022D | 56 02 00 00 | log_pos = 00000256 00000231 | 00 00 | flags = <none> ------------------------ 00000233 | 49 4E 53 45 | query = "INSERT INTO t1 VALUES (1), (2), (3)" 00000237 | 52 54 20 49 | 0000023B | 4E 54 4F 20 | 0000023F | 74 31 20 56 | 00000243 | 41 4C 55 45 | 00000247 | 53 20 28 31 | 0000024B | 29 2C 20 28 | 0000024F | 32 29 2C 20 | 00000253 | 28 33 29 | ************************ In binary log, Annotate_rows event follows the (possible) 'BEGIN' Query event and precedes the first of Table map events which accompany the corresponding rows events. (See example in the "mysqlbinlog output" section below.) 2. Server option: --binlog-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Tells the master to write Annotate_rows events to the binary log. * Variable Name: binlog_annotate_rows_events * Scope: Global & Session * Access Type: Dynamic * Data Type: bool * Default Value: OFF NOTE. Session values allows to annotate only some selected statements: ... SET SESSION binlog_annotate_rows_events=ON; ... statements to be annotated ... SET SESSION binlog_annotate_rows_events=OFF; ... statements not to be annotated ... 3. Server option: --replicate-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Tells the slave to reproduce Annotate_rows events recieved from the master in its own binary log (sensible only in pair with log-slave-updates option). * Variable Name: replicate_annotate_rows_events * Scope: Global * Access Type: Read only * Data Type: bool * Default Value: OFF NOTE. Why do we additionally need this 'replicate' option? Why not to make the slave to reproduce this events when its binlog-annotate-rows-events global value is ON? Well, because, for example, we may want to configure the slave which should reproduce Annotate_rows events but has global binlog-annotate-rows-events = OFF meaning this to be the default value for the client threads (see also "How slave treats replicate-annotate-rows-events option" in LLD part). 4. mysqlbinlog option: --print-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ With this option, mysqlbinlog prints the content of Annotate_rows events (if the binary log does contain them). Without this option (i.e. by default), mysqlbinlog skips Annotate_rows events. 5. mysqlbinlog output ~~~~~~~~~~~~~~~~~~~~~ With --print-annotate-rows-events, mysqlbinlog outputs Annotate_rows events in a form like this: ... # at 1646 #091219 12:45:26 server id 100 end_log_pos 1714 Query thread_id=1 exec_time=0 error_code=0 SET TIMESTAMP=1261215926/*!*/; BEGIN /*!*/; # at 1714 # at 1812 # at 1853 # at 1894 # at 1938 #091219 12:45:26 server id 100 end_log_pos 1812 Query: `DELETE t1, t2 FROM t1 INNER JOIN t2 INNER JOIN t3 WHERE t1.a=t2.a AND t2.a=t3.a` #091219 12:45:26 server id 100 end_log_pos 1853 Table_map: `test`.`t1` mapped to number 16 #091219 12:45:26 server id 100 end_log_pos 1894 Table_map: `test`.`t2` mapped to number 17 #091219 12:45:26 server id 100 end_log_pos 1938 Delete_rows: table id 16 #091219 12:45:26 server id 100 end_log_pos 1982 Delete_rows: table id 17 flags: STMT_END_F ... LOW-LEVEL DESIGN: Content ~~~~~~~ 1. Annotate_rows event number 2. Outline of Annotate_rows event behavior 3. How Master writes Annotate_rows events to the binary log 4. How slave treats replicate-annotate-rows-events option 5. How slave IO thread requests Annotate_rows events 6. How master executes the request 7. How slave SQL thread processes Annotate_rows events 8. General remarks 1. Annotate_rows event number ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ To avoid possible event numbers conflict with MySQL/Sun, we leave a gap between the last MySQL event number and the Annotate_rows event number: enum Log_event_type { ... INCIDENT_EVENT= 26, // New MySQL event numbers are to be added here MYSQL_EVENTS_END, MARIA_EVENTS_BEGIN= 51, // New Maria event numbers start from here ANNOTATE_ROWS_EVENT= 51, ENUM_END_EVENT }; together with the corresponding extension of 'post_header_len' array in the Format description event. (This extension does not affect the compatibility of the binary log). Here is how Format description event looks like with this extension: ************************ FORMAT_DESCRIPTION_EVENT ************************ 00000004 | A1 A0 2C 4B | time_when = 1261215905 00000008 | 0F | event_type = 15 00000009 | 64 00 00 00 | server_id = 100 0000000D | 7F 00 00 00 | event_len = 127 00000011 | 83 00 00 00 | log_pos = 00000083 00000015 | 01 00 | flags = LOG_EVENT_BINLOG_IN_USE_F ------------------------ 00000017 | 04 00 | binlog_ver = 4 00000019 | 35 2E 32 2E | server_ver = 5.2.0-MariaDB-alpha-debug-log ..... ... 0000004B | A1 A0 2C 4B | time_created = 1261215905 0000004F | 13 | common_header_len = 19 ------------------------ post_header_len ------------------------ 00000050 | 38 | 56 - START_EVENT_V3 [1] ..... ... 00000069 | 02 | 2 - INCIDENT_EVENT [26] 0000006A | 00 | 0 - RESERVED [27] ..... ... 00000081 | 00 | 0 - RESERVED [50] 00000082 | 00 | 0 - ANNOTATE_ROWS_EVENT [51] ************************ 2. Outline of Annotate_rows event behavior ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Each Annotate_rows_log_event object has two private members describing the corresponding query: char *m_query_txt; uint m_query_len; When the object is created for writing to a binary log, this query is taken from 'thd' (for short, below we omit the 'Annotate_rows_log_event::' prefix as well as other implementation details): Annotate_rows_log_event(THD *thd) { m_query_txt = thd->query(); m_query_len = thd->query_length(); } When the object is read from a binary log, the query is taken from the buffer containing the binary log representation of the event (this buffer is allocated in Log_event object from which all Log events are derived): Annotate_rows_log_event(char *buf, uint event_len, Format_description_log_event *desc) { m_query_len = event_len - desc->common_header_len; m_query_txt = buf + desc->common_header_len; } The events are written to the binary log by the Log_event::write() member which calls virtual write_data_header() and write_data_body() members ("data header" and "post header" are synonym in replication terminology). In our case, data header is empty and data body is just the query: bool write_data_body(IO_CACHE *file) { return my_b_safe_write(file, (uchar*) m_query_txt, m_query_len); } Printing the event is just printing the query: void Annotate_rows_log_event::print(FILE *file, PRINT_EVENT_INFO *pinfo) { my_b_printf(&pinfo->head_cache, "\tQuery: `%s`\n", m_query_txt); } 3. How Master writes Annotate_rows events to the binary log ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The event is written to the binary log just before the group of Table_map events which precede corresponding Rows events (one query may generate several Table map events in the binary log, but the corresponding Annotate_rows event must be written only once before the first Table map event; hence the boolean variable 'with_annotate' below): int write_locked_table_maps(THD *thd) { ... bool with_annotate= thd->variables.binlog_annotate_rows_events; ... for (uint i= 0; i < ... <number of tables> ...; ++i) { ... thd->binlog_write_table_map(table, ..., with_annotate); with_annotate= 0; // write Annotate_event not more than once ... } ... } int THD::binlog_write_table_map(TABLE *table, ..., bool with_annotate) { ... Table_map_log_event the_event(...); ... if (with_annotate) { Annotate_rows_log_event anno(this); mysql_bin_log.write(&anno); } mysql_bin_log.write(&the_event); ... } 4. How slave treats replicate-annotate-rows-events option ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The replicate-annotate-rows-events option is treated just as the session value of the binlog_annotate_rows_events variable for the slave IO and SQL threads. This setting is done during initialization of these threads: pthread_handler_t handle_slave_io(void *arg) { THD *thd= new THD; ... init_slave_thread(thd, SLAVE_THD_IO); ... } pthread_handler_t handle_slave_sql(void *arg) { THD *thd= new THD; ... init_slave_thread(thd, SLAVE_THD_SQL); ... } int init_slave_thread(THD* thd, SLAVE_THD_TYPE thd_type) { ... thd->variables.binlog_annotate_rows_events= opt_replicate_annotate_rows_events; ... } 5. How slave IO thread requests Annotate_rows events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ If the replicate-annotate-rows-events option is not set on a slave, there is no need for master to send Annotate_rows events to this slave. The slave (or mysqlbinlog in remote case), before requesting binlog dump via the COM_BINLOG_DUMP command, informs the master whether it should send these events by executing the newly added COM_BINLOG_DUMP_OPTIONS_EXT server command: case COM_BINLOG_DUMP_OPTIONS_EXT: thd->binlog_dump_flags_ext= packet[0]; my_ok(thd); break; Note. We add this new command and don't use COM_BINLOG_DUMP to avoid possible conflicts with MySQL/Sun. 6. How master executes the request ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ case COM_BINLOG_DUMP: { ... flags= uint2korr(packet + 4); ... mysql_binlog_send(thd, ..., flags); ... } void mysql_binlog_send(THD* thd, ..., ushort flags) { ... Log_event::read_log_event(&log, packet, ...); ... if ((*packet)[EVENT_TYPE_OFFSET + 1] != ANNOTATE_ROWS_EVENT || flags & BINLOG_SEND_ANNOTATE_ROWS_EVENT) { my_net_write(net, packet->ptr(), packet->length()); } ... } 7. How slave SQL thread processes Annotate_rows events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The slave processes each recieved event by "applying" it, i.e. by calling the Log_event::apply_event() function which in turn calls the virtual do_apply_event() member specific for each type of the event. int exec_relay_log_event(THD* thd, Relay_log_info* rli) { ... Log_event *ev = next_event(rli); ... apply_event_and_update_pos(ev, ...); if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT) delete ev; ... } int apply_event_and_update_pos(Log_event *ev, ...) { ... ev->apply_event(...); ... } int Log_event::apply_event(...) { return do_apply_event(...); } What does it mean to "apply" an Annotate_rows event? It means to set current thd query to that of the described by the event, i.e. to the query which caused the subsequent Rows events (see "How Master writes Annotate_rows events to the binary log" to follow what happens further when the subsequent Rows events are applied): int Annotate_rows_log_event::do_apply_event(...) { thd->set_query(m_query_txt, m_query_len); } NOTE. I am not sure, but possibly current values of thd->query and thd->query_length should be saved before calling set_query() and to be restored on the Annotate_rows_log_event object deletion. Is it really needed ? After calling this do_apply_event() function we may not delete the Annotate_rows_log_event object immediatedly (see exec_relay_log_event() above) because thd->query now points to the string inside this object. We may keep the pointer to this object in the Relay_log_info: class Relay_log_info { public: ... void set_annotate_event(Annotate_rows_log_event*); Annotate_rows_log_event* get_annotate_event(); void free_annotate_event(); ... private: Annotate_rows_log_event* m_annotate_event; }; The saved Annotate_rows object should be deleted when all corresponding Rows events will be processed: int exec_relay_log_event(THD* thd, Relay_log_info* rli) { ... Log_event *ev= next_event(rli); ... apply_event_and_update_pos(ev, ...); if (rli->get_annotate_event() && is_last_rows_event(ev)) rli->free_annotate_event(); else if (ev->get_type_code() == ANNOTATE_ROWS_EVENT) rli->set_annotate_event((Annotate_rows_log_event*) ev); else if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT) delete ev; ... } where bool is_last_rows_event(Log_event* ev) { Log_event_type type= ev->get_type_code(); if (IS_ROWS_EVENT_TYPE(type)) { Rows_log_event* rows= (Rows_log_event*)ev; return rows->get_flags(Rows_log_event::STMT_END_F); } return 0; } #define IS_ROWS_EVENT_TYPE(type) ((type) == WRITE_ROWS_EVENT || \ (type) == UPDATE_ROWS_EVENT || \ (type) == DELETE_ROWS_EVENT) 8. General remarks ~~~~~~~~~~~~~~~~~~ Kristian noticed that introducing new log event type should be coordinated somehow with MySQL/Sun: Kristian: The numeric code for this event must be assigned carefully. It should be coordinated with MySQL/Sun, otherwise we can get into a situation where MySQL uses the same numeric code for one event that MariaDB uses for ANNOTATE_ROWS_EVENT, which would make merging the two impossible. Alex: I reserved about 20 numbers not to have possible conflicts with MySQL. Kristian: Still, I think it would be appropriate to send a polite email to internals(a)lists.mysql.com about this and suggesting to reserve the event number. ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v3.5.9)

1 0

[Maria-developers] Progress (by Knielsen): Store in binlog text of statements that caused RBR events (47)
by worklog-noreply＠askmonty.org 25 May '10

25 May '10

----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: Store in binlog text of statements that caused RBR events CREATION DATE..: Sat, 15 Aug 2009, 23:48 SUPERVISOR.....: Monty IMPLEMENTOR....: COPIES TO......: Knielsen, Serg CATEGORY.......: Server-Sprint TASK ID........: 47 (http://askmonty.org/worklog/?tid=47) VERSION........: Server-9.x STATUS.........: Code-Review PRIORITY.......: 60 WORKED HOURS...: 31 ESTIMATE.......: 4 (hours remain) ORIG. ESTIMATE.: 35 PROGRESS NOTES: -=-=(Knielsen - Tue, 25 May 2010, 08:29)=-=- Help debug strange problem in mysqlbinlog.test. Worked 1 hour and estimate 4 hours remain (original estimate unchanged). -=-=(Knielsen - Mon, 17 May 2010, 08:45)=-=- Merge with latest trunk and run Buildbot tests. Worked 1 hour and estimate 5 hours remain (original estimate unchanged). -=-=(Knielsen - Wed, 05 May 2010, 13:53)=-=- Review of fixes to first review done. No new issues found. Worked 2 hours and estimate 6 hours remain (original estimate unchanged). -=-=(Knielsen - Fri, 23 Apr 2010, 12:51)=-=- Status updated. --- /tmp/wklog.47.old.28747 2010-04-23 12:51:36.000000000 +0000 +++ /tmp/wklog.47.new.28747 2010-04-23 12:51:36.000000000 +0000 @@ -1 +1 @@ -In-Progress +Code-Review -=-=(Knielsen - Tue, 06 Apr 2010, 15:26)=-=- Code review (mailed to maria-developers@). Worked 7 hours and estimate 8 hours remain (original estimate unchanged). -=-=(Knielsen - Tue, 06 Apr 2010, 15:25)=-=- Status updated. --- /tmp/wklog.47.old.12734 2010-04-06 15:25:54.000000000 +0000 +++ /tmp/wklog.47.new.12734 2010-04-06 15:25:54.000000000 +0000 @@ -1 +1 @@ -Code-Review +In-Progress -=-=(Knielsen - Mon, 29 Mar 2010, 10:59)=-=- Status updated. --- /tmp/wklog.47.old.27790 2010-03-29 10:59:53.000000000 +0000 +++ /tmp/wklog.47.new.27790 2010-03-29 10:59:53.000000000 +0000 @@ -1 +1 @@ -In-Progress +Code-Review -=-=(Alexi - Thu, 18 Feb 2010, 19:29)=-=- Worked 20 hours (alexi) Worked 20 hours and estimate 15 hours remain (original estimate unchanged). -=-=(Serg - Fri, 05 Feb 2010, 14:04)=-=- Observers changed: Knielsen,Serg -=-=(Guest - Fri, 05 Feb 2010, 13:40)=-=- Category updated. --- /tmp/wklog.47.old.9197 2010-02-05 13:40:36.000000000 +0200 +++ /tmp/wklog.47.new.9197 2010-02-05 13:40:36.000000000 +0200 @@ -1 +1 @@ -Server-RawIdeaBin +Server-Sprint ------------------------------------------------------------ -=-=(View All Progress Notes, 31 total)=-=- http://askmonty.org/worklog/index.pl?tid=47&nolimit=1 DESCRIPTION: Store in binlog (and show in mysqlbinlog output) texts of statements that caused RBR events This is needed for (list from Monty): - Easier to understand why updates happened - Would make it easier to find out where in application things went wrong (as you can search for exact strings) - Allow one to filter things based on comments in the statement. The cost of this can be that the binlog will be approximately 2x in size (especially insert of big blob's would be a bit painful), so this should be an optional feature. HIGH-LEVEL SPECIFICATION: Content ~~~~~~~ 1. Annotate_rows_log_event 2. Server option: --binlog-annotate-rows-events 3. Server option: --replicate-annotate-rows-events 4. mysqlbinlog option: --print-annotate-rows-events 5. mysqlbinlog output 1. Annotate_rows_log_event [ ANNOTATE_ROWS_EVENT ] ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Describes the query which caused the corresponding rows events. Has empty post-header and contains the query text in its data part. Example: ************************ ANNOTATE_ROWS_EVENT ************************ 00000220 | B6 A0 2C 4B | time_when = 1261215926 00000224 | 33 | event_type = 51 00000225 | 64 00 00 00 | server_id = 100 00000229 | 36 00 00 00 | event_len = 54 0000022D | 56 02 00 00 | log_pos = 00000256 00000231 | 00 00 | flags = <none> ------------------------ 00000233 | 49 4E 53 45 | query = "INSERT INTO t1 VALUES (1), (2), (3)" 00000237 | 52 54 20 49 | 0000023B | 4E 54 4F 20 | 0000023F | 74 31 20 56 | 00000243 | 41 4C 55 45 | 00000247 | 53 20 28 31 | 0000024B | 29 2C 20 28 | 0000024F | 32 29 2C 20 | 00000253 | 28 33 29 | ************************ In binary log, Annotate_rows event follows the (possible) 'BEGIN' Query event and precedes the first of Table map events which accompany the corresponding rows events. (See example in the "mysqlbinlog output" section below.) 2. Server option: --binlog-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Tells the master to write Annotate_rows events to the binary log. * Variable Name: binlog_annotate_rows_events * Scope: Global & Session * Access Type: Dynamic * Data Type: bool * Default Value: OFF NOTE. Session values allows to annotate only some selected statements: ... SET SESSION binlog_annotate_rows_events=ON; ... statements to be annotated ... SET SESSION binlog_annotate_rows_events=OFF; ... statements not to be annotated ... 3. Server option: --replicate-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Tells the slave to reproduce Annotate_rows events recieved from the master in its own binary log (sensible only in pair with log-slave-updates option). * Variable Name: replicate_annotate_rows_events * Scope: Global * Access Type: Read only * Data Type: bool * Default Value: OFF NOTE. Why do we additionally need this 'replicate' option? Why not to make the slave to reproduce this events when its binlog-annotate-rows-events global value is ON? Well, because, for example, we may want to configure the slave which should reproduce Annotate_rows events but has global binlog-annotate-rows-events = OFF meaning this to be the default value for the client threads (see also "How slave treats replicate-annotate-rows-events option" in LLD part). 4. mysqlbinlog option: --print-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ With this option, mysqlbinlog prints the content of Annotate_rows events (if the binary log does contain them). Without this option (i.e. by default), mysqlbinlog skips Annotate_rows events. 5. mysqlbinlog output ~~~~~~~~~~~~~~~~~~~~~ With --print-annotate-rows-events, mysqlbinlog outputs Annotate_rows events in a form like this: ... # at 1646 #091219 12:45:26 server id 100 end_log_pos 1714 Query thread_id=1 exec_time=0 error_code=0 SET TIMESTAMP=1261215926/*!*/; BEGIN /*!*/; # at 1714 # at 1812 # at 1853 # at 1894 # at 1938 #091219 12:45:26 server id 100 end_log_pos 1812 Query: `DELETE t1, t2 FROM t1 INNER JOIN t2 INNER JOIN t3 WHERE t1.a=t2.a AND t2.a=t3.a` #091219 12:45:26 server id 100 end_log_pos 1853 Table_map: `test`.`t1` mapped to number 16 #091219 12:45:26 server id 100 end_log_pos 1894 Table_map: `test`.`t2` mapped to number 17 #091219 12:45:26 server id 100 end_log_pos 1938 Delete_rows: table id 16 #091219 12:45:26 server id 100 end_log_pos 1982 Delete_rows: table id 17 flags: STMT_END_F ... LOW-LEVEL DESIGN: Content ~~~~~~~ 1. Annotate_rows event number 2. Outline of Annotate_rows event behavior 3. How Master writes Annotate_rows events to the binary log 4. How slave treats replicate-annotate-rows-events option 5. How slave IO thread requests Annotate_rows events 6. How master executes the request 7. How slave SQL thread processes Annotate_rows events 8. General remarks 1. Annotate_rows event number ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ To avoid possible event numbers conflict with MySQL/Sun, we leave a gap between the last MySQL event number and the Annotate_rows event number: enum Log_event_type { ... INCIDENT_EVENT= 26, // New MySQL event numbers are to be added here MYSQL_EVENTS_END, MARIA_EVENTS_BEGIN= 51, // New Maria event numbers start from here ANNOTATE_ROWS_EVENT= 51, ENUM_END_EVENT }; together with the corresponding extension of 'post_header_len' array in the Format description event. (This extension does not affect the compatibility of the binary log). Here is how Format description event looks like with this extension: ************************ FORMAT_DESCRIPTION_EVENT ************************ 00000004 | A1 A0 2C 4B | time_when = 1261215905 00000008 | 0F | event_type = 15 00000009 | 64 00 00 00 | server_id = 100 0000000D | 7F 00 00 00 | event_len = 127 00000011 | 83 00 00 00 | log_pos = 00000083 00000015 | 01 00 | flags = LOG_EVENT_BINLOG_IN_USE_F ------------------------ 00000017 | 04 00 | binlog_ver = 4 00000019 | 35 2E 32 2E | server_ver = 5.2.0-MariaDB-alpha-debug-log ..... ... 0000004B | A1 A0 2C 4B | time_created = 1261215905 0000004F | 13 | common_header_len = 19 ------------------------ post_header_len ------------------------ 00000050 | 38 | 56 - START_EVENT_V3 [1] ..... ... 00000069 | 02 | 2 - INCIDENT_EVENT [26] 0000006A | 00 | 0 - RESERVED [27] ..... ... 00000081 | 00 | 0 - RESERVED [50] 00000082 | 00 | 0 - ANNOTATE_ROWS_EVENT [51] ************************ 2. Outline of Annotate_rows event behavior ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Each Annotate_rows_log_event object has two private members describing the corresponding query: char *m_query_txt; uint m_query_len; When the object is created for writing to a binary log, this query is taken from 'thd' (for short, below we omit the 'Annotate_rows_log_event::' prefix as well as other implementation details): Annotate_rows_log_event(THD *thd) { m_query_txt = thd->query(); m_query_len = thd->query_length(); } When the object is read from a binary log, the query is taken from the buffer containing the binary log representation of the event (this buffer is allocated in Log_event object from which all Log events are derived): Annotate_rows_log_event(char *buf, uint event_len, Format_description_log_event *desc) { m_query_len = event_len - desc->common_header_len; m_query_txt = buf + desc->common_header_len; } The events are written to the binary log by the Log_event::write() member which calls virtual write_data_header() and write_data_body() members ("data header" and "post header" are synonym in replication terminology). In our case, data header is empty and data body is just the query: bool write_data_body(IO_CACHE *file) { return my_b_safe_write(file, (uchar*) m_query_txt, m_query_len); } Printing the event is just printing the query: void Annotate_rows_log_event::print(FILE *file, PRINT_EVENT_INFO *pinfo) { my_b_printf(&pinfo->head_cache, "\tQuery: `%s`\n", m_query_txt); } 3. How Master writes Annotate_rows events to the binary log ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The event is written to the binary log just before the group of Table_map events which precede corresponding Rows events (one query may generate several Table map events in the binary log, but the corresponding Annotate_rows event must be written only once before the first Table map event; hence the boolean variable 'with_annotate' below): int write_locked_table_maps(THD *thd) { ... bool with_annotate= thd->variables.binlog_annotate_rows_events; ... for (uint i= 0; i < ... <number of tables> ...; ++i) { ... thd->binlog_write_table_map(table, ..., with_annotate); with_annotate= 0; // write Annotate_event not more than once ... } ... } int THD::binlog_write_table_map(TABLE *table, ..., bool with_annotate) { ... Table_map_log_event the_event(...); ... if (with_annotate) { Annotate_rows_log_event anno(this); mysql_bin_log.write(&anno); } mysql_bin_log.write(&the_event); ... } 4. How slave treats replicate-annotate-rows-events option ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The replicate-annotate-rows-events option is treated just as the session value of the binlog_annotate_rows_events variable for the slave IO and SQL threads. This setting is done during initialization of these threads: pthread_handler_t handle_slave_io(void *arg) { THD *thd= new THD; ... init_slave_thread(thd, SLAVE_THD_IO); ... } pthread_handler_t handle_slave_sql(void *arg) { THD *thd= new THD; ... init_slave_thread(thd, SLAVE_THD_SQL); ... } int init_slave_thread(THD* thd, SLAVE_THD_TYPE thd_type) { ... thd->variables.binlog_annotate_rows_events= opt_replicate_annotate_rows_events; ... } 5. How slave IO thread requests Annotate_rows events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ If the replicate-annotate-rows-events option is not set on a slave, there is no need for master to send Annotate_rows events to this slave. The slave (or mysqlbinlog in remote case), before requesting binlog dump via the COM_BINLOG_DUMP command, informs the master whether it should send these events by executing the newly added COM_BINLOG_DUMP_OPTIONS_EXT server command: case COM_BINLOG_DUMP_OPTIONS_EXT: thd->binlog_dump_flags_ext= packet[0]; my_ok(thd); break; Note. We add this new command and don't use COM_BINLOG_DUMP to avoid possible conflicts with MySQL/Sun. 6. How master executes the request ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ case COM_BINLOG_DUMP: { ... flags= uint2korr(packet + 4); ... mysql_binlog_send(thd, ..., flags); ... } void mysql_binlog_send(THD* thd, ..., ushort flags) { ... Log_event::read_log_event(&log, packet, ...); ... if ((*packet)[EVENT_TYPE_OFFSET + 1] != ANNOTATE_ROWS_EVENT || flags & BINLOG_SEND_ANNOTATE_ROWS_EVENT) { my_net_write(net, packet->ptr(), packet->length()); } ... } 7. How slave SQL thread processes Annotate_rows events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The slave processes each recieved event by "applying" it, i.e. by calling the Log_event::apply_event() function which in turn calls the virtual do_apply_event() member specific for each type of the event. int exec_relay_log_event(THD* thd, Relay_log_info* rli) { ... Log_event *ev = next_event(rli); ... apply_event_and_update_pos(ev, ...); if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT) delete ev; ... } int apply_event_and_update_pos(Log_event *ev, ...) { ... ev->apply_event(...); ... } int Log_event::apply_event(...) { return do_apply_event(...); } What does it mean to "apply" an Annotate_rows event? It means to set current thd query to that of the described by the event, i.e. to the query which caused the subsequent Rows events (see "How Master writes Annotate_rows events to the binary log" to follow what happens further when the subsequent Rows events are applied): int Annotate_rows_log_event::do_apply_event(...) { thd->set_query(m_query_txt, m_query_len); } NOTE. I am not sure, but possibly current values of thd->query and thd->query_length should be saved before calling set_query() and to be restored on the Annotate_rows_log_event object deletion. Is it really needed ? After calling this do_apply_event() function we may not delete the Annotate_rows_log_event object immediatedly (see exec_relay_log_event() above) because thd->query now points to the string inside this object. We may keep the pointer to this object in the Relay_log_info: class Relay_log_info { public: ... void set_annotate_event(Annotate_rows_log_event*); Annotate_rows_log_event* get_annotate_event(); void free_annotate_event(); ... private: Annotate_rows_log_event* m_annotate_event; }; The saved Annotate_rows object should be deleted when all corresponding Rows events will be processed: int exec_relay_log_event(THD* thd, Relay_log_info* rli) { ... Log_event *ev= next_event(rli); ... apply_event_and_update_pos(ev, ...); if (rli->get_annotate_event() && is_last_rows_event(ev)) rli->free_annotate_event(); else if (ev->get_type_code() == ANNOTATE_ROWS_EVENT) rli->set_annotate_event((Annotate_rows_log_event*) ev); else if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT) delete ev; ... } where bool is_last_rows_event(Log_event* ev) { Log_event_type type= ev->get_type_code(); if (IS_ROWS_EVENT_TYPE(type)) { Rows_log_event* rows= (Rows_log_event*)ev; return rows->get_flags(Rows_log_event::STMT_END_F); } return 0; } #define IS_ROWS_EVENT_TYPE(type) ((type) == WRITE_ROWS_EVENT || \ (type) == UPDATE_ROWS_EVENT || \ (type) == DELETE_ROWS_EVENT) 8. General remarks ~~~~~~~~~~~~~~~~~~ Kristian noticed that introducing new log event type should be coordinated somehow with MySQL/Sun: Kristian: The numeric code for this event must be assigned carefully. It should be coordinated with MySQL/Sun, otherwise we can get into a situation where MySQL uses the same numeric code for one event that MariaDB uses for ANNOTATE_ROWS_EVENT, which would make merging the two impossible. Alex: I reserved about 20 numbers not to have possible conflicts with MySQL. Kristian: Still, I think it would be appropriate to send a polite email to internals(a)lists.mysql.com about this and suggesting to reserve the event number. ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v3.5.9)

1 0

[Maria-developers] Progress (by Knielsen): Store in binlog text of statements that caused RBR events (47)
by worklog-noreply＠askmonty.org 25 May '10

25 May '10

----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: Store in binlog text of statements that caused RBR events CREATION DATE..: Sat, 15 Aug 2009, 23:48 SUPERVISOR.....: Monty IMPLEMENTOR....: COPIES TO......: Knielsen, Serg CATEGORY.......: Server-Sprint TASK ID........: 47 (http://askmonty.org/worklog/?tid=47) VERSION........: Server-9.x STATUS.........: Code-Review PRIORITY.......: 60 WORKED HOURS...: 31 ESTIMATE.......: 4 (hours remain) ORIG. ESTIMATE.: 35 PROGRESS NOTES: -=-=(Knielsen - Tue, 25 May 2010, 08:29)=-=- Help debug strange problem in mysqlbinlog.test. Worked 1 hour and estimate 4 hours remain (original estimate unchanged). -=-=(Knielsen - Mon, 17 May 2010, 08:45)=-=- Merge with latest trunk and run Buildbot tests. Worked 1 hour and estimate 5 hours remain (original estimate unchanged). -=-=(Knielsen - Wed, 05 May 2010, 13:53)=-=- Review of fixes to first review done. No new issues found. Worked 2 hours and estimate 6 hours remain (original estimate unchanged). -=-=(Knielsen - Fri, 23 Apr 2010, 12:51)=-=- Status updated. --- /tmp/wklog.47.old.28747 2010-04-23 12:51:36.000000000 +0000 +++ /tmp/wklog.47.new.28747 2010-04-23 12:51:36.000000000 +0000 @@ -1 +1 @@ -In-Progress +Code-Review -=-=(Knielsen - Tue, 06 Apr 2010, 15:26)=-=- Code review (mailed to maria-developers@). Worked 7 hours and estimate 8 hours remain (original estimate unchanged). -=-=(Knielsen - Tue, 06 Apr 2010, 15:25)=-=- Status updated. --- /tmp/wklog.47.old.12734 2010-04-06 15:25:54.000000000 +0000 +++ /tmp/wklog.47.new.12734 2010-04-06 15:25:54.000000000 +0000 @@ -1 +1 @@ -Code-Review +In-Progress -=-=(Knielsen - Mon, 29 Mar 2010, 10:59)=-=- Status updated. --- /tmp/wklog.47.old.27790 2010-03-29 10:59:53.000000000 +0000 +++ /tmp/wklog.47.new.27790 2010-03-29 10:59:53.000000000 +0000 @@ -1 +1 @@ -In-Progress +Code-Review -=-=(Alexi - Thu, 18 Feb 2010, 19:29)=-=- Worked 20 hours (alexi) Worked 20 hours and estimate 15 hours remain (original estimate unchanged). -=-=(Serg - Fri, 05 Feb 2010, 14:04)=-=- Observers changed: Knielsen,Serg -=-=(Guest - Fri, 05 Feb 2010, 13:40)=-=- Category updated. --- /tmp/wklog.47.old.9197 2010-02-05 13:40:36.000000000 +0200 +++ /tmp/wklog.47.new.9197 2010-02-05 13:40:36.000000000 +0200 @@ -1 +1 @@ -Server-RawIdeaBin +Server-Sprint ------------------------------------------------------------ -=-=(View All Progress Notes, 31 total)=-=- http://askmonty.org/worklog/index.pl?tid=47&nolimit=1 DESCRIPTION: Store in binlog (and show in mysqlbinlog output) texts of statements that caused RBR events This is needed for (list from Monty): - Easier to understand why updates happened - Would make it easier to find out where in application things went wrong (as you can search for exact strings) - Allow one to filter things based on comments in the statement. The cost of this can be that the binlog will be approximately 2x in size (especially insert of big blob's would be a bit painful), so this should be an optional feature. HIGH-LEVEL SPECIFICATION: Content ~~~~~~~ 1. Annotate_rows_log_event 2. Server option: --binlog-annotate-rows-events 3. Server option: --replicate-annotate-rows-events 4. mysqlbinlog option: --print-annotate-rows-events 5. mysqlbinlog output 1. Annotate_rows_log_event [ ANNOTATE_ROWS_EVENT ] ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Describes the query which caused the corresponding rows events. Has empty post-header and contains the query text in its data part. Example: ************************ ANNOTATE_ROWS_EVENT ************************ 00000220 | B6 A0 2C 4B | time_when = 1261215926 00000224 | 33 | event_type = 51 00000225 | 64 00 00 00 | server_id = 100 00000229 | 36 00 00 00 | event_len = 54 0000022D | 56 02 00 00 | log_pos = 00000256 00000231 | 00 00 | flags = <none> ------------------------ 00000233 | 49 4E 53 45 | query = "INSERT INTO t1 VALUES (1), (2), (3)" 00000237 | 52 54 20 49 | 0000023B | 4E 54 4F 20 | 0000023F | 74 31 20 56 | 00000243 | 41 4C 55 45 | 00000247 | 53 20 28 31 | 0000024B | 29 2C 20 28 | 0000024F | 32 29 2C 20 | 00000253 | 28 33 29 | ************************ In binary log, Annotate_rows event follows the (possible) 'BEGIN' Query event and precedes the first of Table map events which accompany the corresponding rows events. (See example in the "mysqlbinlog output" section below.) 2. Server option: --binlog-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Tells the master to write Annotate_rows events to the binary log. * Variable Name: binlog_annotate_rows_events * Scope: Global & Session * Access Type: Dynamic * Data Type: bool * Default Value: OFF NOTE. Session values allows to annotate only some selected statements: ... SET SESSION binlog_annotate_rows_events=ON; ... statements to be annotated ... SET SESSION binlog_annotate_rows_events=OFF; ... statements not to be annotated ... 3. Server option: --replicate-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Tells the slave to reproduce Annotate_rows events recieved from the master in its own binary log (sensible only in pair with log-slave-updates option). * Variable Name: replicate_annotate_rows_events * Scope: Global * Access Type: Read only * Data Type: bool * Default Value: OFF NOTE. Why do we additionally need this 'replicate' option? Why not to make the slave to reproduce this events when its binlog-annotate-rows-events global value is ON? Well, because, for example, we may want to configure the slave which should reproduce Annotate_rows events but has global binlog-annotate-rows-events = OFF meaning this to be the default value for the client threads (see also "How slave treats replicate-annotate-rows-events option" in LLD part). 4. mysqlbinlog option: --print-annotate-rows-events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ With this option, mysqlbinlog prints the content of Annotate_rows events (if the binary log does contain them). Without this option (i.e. by default), mysqlbinlog skips Annotate_rows events. 5. mysqlbinlog output ~~~~~~~~~~~~~~~~~~~~~ With --print-annotate-rows-events, mysqlbinlog outputs Annotate_rows events in a form like this: ... # at 1646 #091219 12:45:26 server id 100 end_log_pos 1714 Query thread_id=1 exec_time=0 error_code=0 SET TIMESTAMP=1261215926/*!*/; BEGIN /*!*/; # at 1714 # at 1812 # at 1853 # at 1894 # at 1938 #091219 12:45:26 server id 100 end_log_pos 1812 Query: `DELETE t1, t2 FROM t1 INNER JOIN t2 INNER JOIN t3 WHERE t1.a=t2.a AND t2.a=t3.a` #091219 12:45:26 server id 100 end_log_pos 1853 Table_map: `test`.`t1` mapped to number 16 #091219 12:45:26 server id 100 end_log_pos 1894 Table_map: `test`.`t2` mapped to number 17 #091219 12:45:26 server id 100 end_log_pos 1938 Delete_rows: table id 16 #091219 12:45:26 server id 100 end_log_pos 1982 Delete_rows: table id 17 flags: STMT_END_F ... LOW-LEVEL DESIGN: Content ~~~~~~~ 1. Annotate_rows event number 2. Outline of Annotate_rows event behavior 3. How Master writes Annotate_rows events to the binary log 4. How slave treats replicate-annotate-rows-events option 5. How slave IO thread requests Annotate_rows events 6. How master executes the request 7. How slave SQL thread processes Annotate_rows events 8. General remarks 1. Annotate_rows event number ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ To avoid possible event numbers conflict with MySQL/Sun, we leave a gap between the last MySQL event number and the Annotate_rows event number: enum Log_event_type { ... INCIDENT_EVENT= 26, // New MySQL event numbers are to be added here MYSQL_EVENTS_END, MARIA_EVENTS_BEGIN= 51, // New Maria event numbers start from here ANNOTATE_ROWS_EVENT= 51, ENUM_END_EVENT }; together with the corresponding extension of 'post_header_len' array in the Format description event. (This extension does not affect the compatibility of the binary log). Here is how Format description event looks like with this extension: ************************ FORMAT_DESCRIPTION_EVENT ************************ 00000004 | A1 A0 2C 4B | time_when = 1261215905 00000008 | 0F | event_type = 15 00000009 | 64 00 00 00 | server_id = 100 0000000D | 7F 00 00 00 | event_len = 127 00000011 | 83 00 00 00 | log_pos = 00000083 00000015 | 01 00 | flags = LOG_EVENT_BINLOG_IN_USE_F ------------------------ 00000017 | 04 00 | binlog_ver = 4 00000019 | 35 2E 32 2E | server_ver = 5.2.0-MariaDB-alpha-debug-log ..... ... 0000004B | A1 A0 2C 4B | time_created = 1261215905 0000004F | 13 | common_header_len = 19 ------------------------ post_header_len ------------------------ 00000050 | 38 | 56 - START_EVENT_V3 [1] ..... ... 00000069 | 02 | 2 - INCIDENT_EVENT [26] 0000006A | 00 | 0 - RESERVED [27] ..... ... 00000081 | 00 | 0 - RESERVED [50] 00000082 | 00 | 0 - ANNOTATE_ROWS_EVENT [51] ************************ 2. Outline of Annotate_rows event behavior ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Each Annotate_rows_log_event object has two private members describing the corresponding query: char *m_query_txt; uint m_query_len; When the object is created for writing to a binary log, this query is taken from 'thd' (for short, below we omit the 'Annotate_rows_log_event::' prefix as well as other implementation details): Annotate_rows_log_event(THD *thd) { m_query_txt = thd->query(); m_query_len = thd->query_length(); } When the object is read from a binary log, the query is taken from the buffer containing the binary log representation of the event (this buffer is allocated in Log_event object from which all Log events are derived): Annotate_rows_log_event(char *buf, uint event_len, Format_description_log_event *desc) { m_query_len = event_len - desc->common_header_len; m_query_txt = buf + desc->common_header_len; } The events are written to the binary log by the Log_event::write() member which calls virtual write_data_header() and write_data_body() members ("data header" and "post header" are synonym in replication terminology). In our case, data header is empty and data body is just the query: bool write_data_body(IO_CACHE *file) { return my_b_safe_write(file, (uchar*) m_query_txt, m_query_len); } Printing the event is just printing the query: void Annotate_rows_log_event::print(FILE *file, PRINT_EVENT_INFO *pinfo) { my_b_printf(&pinfo->head_cache, "\tQuery: `%s`\n", m_query_txt); } 3. How Master writes Annotate_rows events to the binary log ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The event is written to the binary log just before the group of Table_map events which precede corresponding Rows events (one query may generate several Table map events in the binary log, but the corresponding Annotate_rows event must be written only once before the first Table map event; hence the boolean variable 'with_annotate' below): int write_locked_table_maps(THD *thd) { ... bool with_annotate= thd->variables.binlog_annotate_rows_events; ... for (uint i= 0; i < ... <number of tables> ...; ++i) { ... thd->binlog_write_table_map(table, ..., with_annotate); with_annotate= 0; // write Annotate_event not more than once ... } ... } int THD::binlog_write_table_map(TABLE *table, ..., bool with_annotate) { ... Table_map_log_event the_event(...); ... if (with_annotate) { Annotate_rows_log_event anno(this); mysql_bin_log.write(&anno); } mysql_bin_log.write(&the_event); ... } 4. How slave treats replicate-annotate-rows-events option ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The replicate-annotate-rows-events option is treated just as the session value of the binlog_annotate_rows_events variable for the slave IO and SQL threads. This setting is done during initialization of these threads: pthread_handler_t handle_slave_io(void *arg) { THD *thd= new THD; ... init_slave_thread(thd, SLAVE_THD_IO); ... } pthread_handler_t handle_slave_sql(void *arg) { THD *thd= new THD; ... init_slave_thread(thd, SLAVE_THD_SQL); ... } int init_slave_thread(THD* thd, SLAVE_THD_TYPE thd_type) { ... thd->variables.binlog_annotate_rows_events= opt_replicate_annotate_rows_events; ... } 5. How slave IO thread requests Annotate_rows events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ If the replicate-annotate-rows-events option is not set on a slave, there is no need for master to send Annotate_rows events to this slave. The slave (or mysqlbinlog in remote case), before requesting binlog dump via the COM_BINLOG_DUMP command, informs the master whether it should send these events by executing the newly added COM_BINLOG_DUMP_OPTIONS_EXT server command: case COM_BINLOG_DUMP_OPTIONS_EXT: thd->binlog_dump_flags_ext= packet[0]; my_ok(thd); break; Note. We add this new command and don't use COM_BINLOG_DUMP to avoid possible conflicts with MySQL/Sun. 6. How master executes the request ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ case COM_BINLOG_DUMP: { ... flags= uint2korr(packet + 4); ... mysql_binlog_send(thd, ..., flags); ... } void mysql_binlog_send(THD* thd, ..., ushort flags) { ... Log_event::read_log_event(&log, packet, ...); ... if ((*packet)[EVENT_TYPE_OFFSET + 1] != ANNOTATE_ROWS_EVENT || flags & BINLOG_SEND_ANNOTATE_ROWS_EVENT) { my_net_write(net, packet->ptr(), packet->length()); } ... } 7. How slave SQL thread processes Annotate_rows events ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ The slave processes each recieved event by "applying" it, i.e. by calling the Log_event::apply_event() function which in turn calls the virtual do_apply_event() member specific for each type of the event. int exec_relay_log_event(THD* thd, Relay_log_info* rli) { ... Log_event *ev = next_event(rli); ... apply_event_and_update_pos(ev, ...); if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT) delete ev; ... } int apply_event_and_update_pos(Log_event *ev, ...) { ... ev->apply_event(...); ... } int Log_event::apply_event(...) { return do_apply_event(...); } What does it mean to "apply" an Annotate_rows event? It means to set current thd query to that of the described by the event, i.e. to the query which caused the subsequent Rows events (see "How Master writes Annotate_rows events to the binary log" to follow what happens further when the subsequent Rows events are applied): int Annotate_rows_log_event::do_apply_event(...) { thd->set_query(m_query_txt, m_query_len); } NOTE. I am not sure, but possibly current values of thd->query and thd->query_length should be saved before calling set_query() and to be restored on the Annotate_rows_log_event object deletion. Is it really needed ? After calling this do_apply_event() function we may not delete the Annotate_rows_log_event object immediatedly (see exec_relay_log_event() above) because thd->query now points to the string inside this object. We may keep the pointer to this object in the Relay_log_info: class Relay_log_info { public: ... void set_annotate_event(Annotate_rows_log_event*); Annotate_rows_log_event* get_annotate_event(); void free_annotate_event(); ... private: Annotate_rows_log_event* m_annotate_event; }; The saved Annotate_rows object should be deleted when all corresponding Rows events will be processed: int exec_relay_log_event(THD* thd, Relay_log_info* rli) { ... Log_event *ev= next_event(rli); ... apply_event_and_update_pos(ev, ...); if (rli->get_annotate_event() && is_last_rows_event(ev)) rli->free_annotate_event(); else if (ev->get_type_code() == ANNOTATE_ROWS_EVENT) rli->set_annotate_event((Annotate_rows_log_event*) ev); else if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT) delete ev; ... } where bool is_last_rows_event(Log_event* ev) { Log_event_type type= ev->get_type_code(); if (IS_ROWS_EVENT_TYPE(type)) { Rows_log_event* rows= (Rows_log_event*)ev; return rows->get_flags(Rows_log_event::STMT_END_F); } return 0; } #define IS_ROWS_EVENT_TYPE(type) ((type) == WRITE_ROWS_EVENT || \ (type) == UPDATE_ROWS_EVENT || \ (type) == DELETE_ROWS_EVENT) 8. General remarks ~~~~~~~~~~~~~~~~~~ Kristian noticed that introducing new log event type should be coordinated somehow with MySQL/Sun: Kristian: The numeric code for this event must be assigned carefully. It should be coordinated with MySQL/Sun, otherwise we can get into a situation where MySQL uses the same numeric code for one event that MariaDB uses for ANNOTATE_ROWS_EVENT, which would make merging the two impossible. Alex: I reserved about 20 numbers not to have possible conflicts with MySQL. Kristian: Still, I think it would be appropriate to send a polite email to internals(a)lists.mysql.com about this and suggesting to reserve the event number. ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v3.5.9)

1 0

[Maria-developers] Progress (by Knielsen): Efficient group commit for binary log (116)
by worklog-noreply＠askmonty.org 25 May '10

25 May '10

----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: Efficient group commit for binary log CREATION DATE..: Mon, 26 Apr 2010, 13:28 SUPERVISOR.....: Knielsen IMPLEMENTOR....: COPIES TO......: Serg CATEGORY.......: Server-RawIdeaBin TASK ID........: 116 (http://askmonty.org/worklog/?tid=116) VERSION........: Server-9.x STATUS.........: Un-Assigned PRIORITY.......: 60 WORKED HOURS...: 49 ESTIMATE.......: 0 (hours remain) ORIG. ESTIMATE.: 0 PROGRESS NOTES: -=-=(Knielsen - Tue, 25 May 2010, 08:28)=-=- More thoughts on and changes to the archtecture. Got to something now that I am satisfied with and that seems to be able to handle all issues. Implement new prepare_ordered and commit_ordered handler methods and the logic in ha_commit_trans(). Implement TC_LOG::group_log_xid() method and logic in ha_commit_trans(). Implement XtraDB part, using commit_ordered() rather than prepare_commit_mutex. Fix test suite failures. Proof-of-concept patch series complete now. Do initial benchmark, getting good results. With 64 threads, see 26x improvement in queries-per-sec. Next step: write up the architecture description. Worked 21 hours and estimate 0 hours remain (original estimate increased by 21 hours). -=-=(Knielsen - Wed, 12 May 2010, 06:41)=-=- Started work on a Quilt patch series, refactoring the binlog code to prepare for implementing the group commit, and working on the design of group commit in parallel. Found and fixed several problems in error handling when writing to binlog. Removed redundant table map version locking. Split binlog writing into two parts in preparations for group commit. When ready to write to the binlog, threads enter a queue, and the first thread in the queue handles the binlog writing for everyone. When it obtains the LOCK_log, it first loops over all threads, executing the first part of binlog writing (the write(2) syscall essentially). It then runs the second part (fsync(2) essentially) only once, and then wakes up the remaining threads in the queue. Still to be done: Finish the proof-of-concept group commit patch, by 1) implementing the prepare_fast() and commit_fast() callbacks in handler.cc 2) move the binlog thread enqueue from log_xid() to binlog_prepare_fast(), 3) move fast part of InnoDB commit to innobase_commit_fast(), removing the prepare_commit_mutex(). Write up the final design in this worklog. Evaluate the design to see if we can do better/different. Think about possible next steps, such as releasing innodb row locks early (in innobase_prepare_fast), and doing crash recovery by replaying transactions from the binlog (removing the need for engine durability and 2 of 3 fsync() in commit). Worked 28 hours and estimate 0 hours remain (original estimate increased by 28 hours). -=-=(Serg - Mon, 26 Apr 2010, 14:10)=-=- Observers changed: Serg DESCRIPTION: Currently, in order to ensure that the server can recover after a crash to a state in which storage engines and binary log are consistent with each other, it is necessary to use XA with durable commits for both storage engines (innodb_flush_log_at_trx_commit=1) and binary log (sync_binlog=1). This is _very_ expensive, since the server needs to do three fsync() operations for every commit, as there is no working group commit when the binary log is enabled. The idea is to - Implement/fix group commit to work properly with the binary log enabled. - (Optionally) avoid the need to fsync() in the engine, and instead rely on replaying any lost transactions from the binary log against the engine during crash recovery. For background see these articles: http://kristiannielsen.livejournal.com/12254.html http://kristiannielsen.livejournal.com/12408.html http://kristiannielsen.livejournal.com/12553.html ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v3.5.9)

1 0

[Maria-developers] Progress (by Knielsen): Efficient group commit for binary log (116)
by worklog-noreply＠askmonty.org 25 May '10

25 May '10

----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: Efficient group commit for binary log CREATION DATE..: Mon, 26 Apr 2010, 13:28 SUPERVISOR.....: Knielsen IMPLEMENTOR....: COPIES TO......: Serg CATEGORY.......: Server-RawIdeaBin TASK ID........: 116 (http://askmonty.org/worklog/?tid=116) VERSION........: Server-9.x STATUS.........: Un-Assigned PRIORITY.......: 60 WORKED HOURS...: 49 ESTIMATE.......: 0 (hours remain) ORIG. ESTIMATE.: 0 PROGRESS NOTES: -=-=(Knielsen - Tue, 25 May 2010, 08:28)=-=- More thoughts on and changes to the archtecture. Got to something now that I am satisfied with and that seems to be able to handle all issues. Implement new prepare_ordered and commit_ordered handler methods and the logic in ha_commit_trans(). Implement TC_LOG::group_log_xid() method and logic in ha_commit_trans(). Implement XtraDB part, using commit_ordered() rather than prepare_commit_mutex. Fix test suite failures. Proof-of-concept patch series complete now. Do initial benchmark, getting good results. With 64 threads, see 26x improvement in queries-per-sec. Next step: write up the architecture description. Worked 21 hours and estimate 0 hours remain (original estimate increased by 21 hours). -=-=(Knielsen - Wed, 12 May 2010, 06:41)=-=- Started work on a Quilt patch series, refactoring the binlog code to prepare for implementing the group commit, and working on the design of group commit in parallel. Found and fixed several problems in error handling when writing to binlog. Removed redundant table map version locking. Split binlog writing into two parts in preparations for group commit. When ready to write to the binlog, threads enter a queue, and the first thread in the queue handles the binlog writing for everyone. When it obtains the LOCK_log, it first loops over all threads, executing the first part of binlog writing (the write(2) syscall essentially). It then runs the second part (fsync(2) essentially) only once, and then wakes up the remaining threads in the queue. Still to be done: Finish the proof-of-concept group commit patch, by 1) implementing the prepare_fast() and commit_fast() callbacks in handler.cc 2) move the binlog thread enqueue from log_xid() to binlog_prepare_fast(), 3) move fast part of InnoDB commit to innobase_commit_fast(), removing the prepare_commit_mutex(). Write up the final design in this worklog. Evaluate the design to see if we can do better/different. Think about possible next steps, such as releasing innodb row locks early (in innobase_prepare_fast), and doing crash recovery by replaying transactions from the binlog (removing the need for engine durability and 2 of 3 fsync() in commit). Worked 28 hours and estimate 0 hours remain (original estimate increased by 28 hours). -=-=(Serg - Mon, 26 Apr 2010, 14:10)=-=- Observers changed: Serg DESCRIPTION: Currently, in order to ensure that the server can recover after a crash to a state in which storage engines and binary log are consistent with each other, it is necessary to use XA with durable commits for both storage engines (innodb_flush_log_at_trx_commit=1) and binary log (sync_binlog=1). This is _very_ expensive, since the server needs to do three fsync() operations for every commit, as there is no working group commit when the binary log is enabled. The idea is to - Implement/fix group commit to work properly with the binary log enabled. - (Optionally) avoid the need to fsync() in the engine, and instead rely on replaying any lost transactions from the binary log against the engine during crash recovery. For background see these articles: http://kristiannielsen.livejournal.com/12254.html http://kristiannielsen.livejournal.com/12408.html http://kristiannielsen.livejournal.com/12553.html ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v3.5.9)

1 0