Percona Server with XtraDB

lp:~stewart/percona-server/5.6-slow-query-plugin-prototype

Created by Stewart Smith on 2012-09-21 and last modified on 2012-09-21
Get this branch:
bzr branch lp:~stewart/percona-server/5.6-slow-query-plugin-prototype
Only Stewart Smith can upload to this branch. If you are Stewart Smith please log in for upload directions.

Branch merges

Related bugs

Related blueprints

Branch information

Owner:
Stewart Smith
Project:
Percona Server
Status:
Development

Recent revisions

306. By Stewart Smith on 2012-09-21

Prototype slow query log audit plugin.

This plugin (named extended_slow_query_log) implements the MySQL
Slow Query log.

The built-in slow query log holds LOCK_log for an awfully long time, and
I thought I could do it better.

This plugin uses a lock-free algorithm to write to the log file: call write(2)
with the complete log entry and let the OS kernel take care of the rest.
While this MAY not work for NFS (at least certain versions), this will work
for the most common case of local disk.

I had to extend the plugin API slightly to get all the same information as
the MySQL slow query log.

The main challenge is log file rotation, as if you just close(2) a file
descriptor that others may be write(2)ing to then bad things may happen
(namely that the file descriptor gets reused for something else.. say an
innodb data file, and writing part of your slow query log as an innodb
page will not end in hugs and puppies).

My solution to log file rotation is to basically count how many people
may be using it and waiting until this drops to zero before closing the
file descriptor. This avoids taking any locks around calling write(),
which is the most time consuming part of writing the log.

I know of one more possible improvement to this: reduce the number of
malloc() calls (we should be able to cache this for each thd).

I ran two benchmarks on my laptop (Intel(R) Core(TM) i7-2620M CPU @
2.70GHz) - 2 cores, 4 threads total.

1) Using existing slow query log code

eatmydata ./mysql-test-run.pl --start-and-exit --mysqld=--slow-query-log \
--mysqld=--long-query-time=0

../client/mysqlslap -u root test -S var/tmp/mysqld.1.sock -q 'select 1;'
--number-of-queries=1000000 --concurrency=64 --create-schema=test
Benchmark
 Average number of seconds to run all queries: 18.293 seconds
 Minimum number of seconds to run all queries: 18.293 seconds
 Maximum number of seconds to run all queries: 18.293 seconds
 Number of clients running queries: 64
 Average number of queries per client: 15625

2) Using my audit plugin
eatmydata ./mysql-test-run.pl extended_slow_query_log --start-and-exit

mysql> INSTALL PLUGIN extended_slow_query_log SONAME
'extended_slow_query_log.so';
Query OK, 0 rows affected (0.00 sec)

mysql> SET GLOBAL extended_slow_query_log_enable=1;
Query OK, 0 rows affected (0.00 sec)

../client/mysqlslap -u root test -S var/tmp/mysqld.1.sock -q 'select 1;'
--number-of-queries=1000000 --concurrency=64 --create-schema=test
Benchmark
 Average number of seconds to run all queries: 15.812 seconds
 Minimum number of seconds to run all queries: 15.812 seconds
 Maximum number of seconds to run all queries: 15.812 seconds
 Number of clients running queries: 64
 Average number of queries per client: 15625

(these numbers have been pretty stable over sevaral runs)

 and a third, without any slow query log enabled:

 ./client/mysqlslap -u root test -S var/tmp/mysqld.1.sock -q 'select 1;'
 --number-of-queries=1000000 --concurrency=64 --create-schema=test
 Benchmark
  Average number of seconds to run all queries: 13.006 seconds
  Minimum number of seconds to run all queries: 13.006 seconds
  Maximum number of seconds to run all queries: 13.006 seconds
  Number of clients running queries: 64
  Average number of queries per client: 15625

305. By Stewart Smith on 2012-09-18

merge null-merge of show-lock-name patch

304. By Stewart Smith on 2012-09-18

merge show temp tables test fixes

303. By Stewart Smith on 2012-09-12

null merge innodb_admin_command_base.patch as it was only used for manual LRU dump/restore and this is now native in MySQL 5.6

302. By Stewart Smith on 2012-09-12

null merge innodb_recovery_patches.patch - two bug fixes have been broken out into separate commits and we aren't bringing innodb_recovery_stats forward to PS 5.6

301. By Stewart Smith on 2012-09-12

Extract fix for http://bugs.mysql.com/bug.php?id=44140 from innodb_recovery_patches.patch

Description from original bug report:
Description:
Sometimes (it is really rare), We meet the error message during crash recovery of InnoDB.

090405 4:29:47 InnoDB: ERROR: We were only able to scan the log up to 1319 813701532
InnoDB: but a database page a had an lsn 1319 814039859. It is possible that the
InnoDB: database is now corrupt!

I accept the message as,,
"There have been some logged modification to certain page before the last recv_recover_page() for the page"

And I have caught the modification.
#0 0x00000000004a5b60 in log_close ()
#1 0x00000000004d93b9 in mtr_commit ()
#2 0x000000000042e572 in ibuf_delete_rec ()
#3 0x000000000042f314 in ibuf_merge_or_delete_for_page ()
#4 0x000000000049724e in buf_page_io_complete ()
#5 0x00000000004cbdd7 in fil_aio_wait ()
#6 0x000000000040c678 in io_handler_thread ()

I suspect ibuf_merge_or_delete_for_page() from buf_page_io_complete() (triggered by recv_read_in_area()) and recv_recover_page() from recv_apply_hashed_log_recs() can conflict.

300. By Stewart Smith on 2012-09-12

Extract fix for http://bugs.mysql.com/bug.php?id=43948 from innodb_recovery_patches.patch

Original Description of bug (from above URL) by Yasufumi:
Description:
Sometimes, the recovery from crash hang up at recv_apply_hashed_log_recs() with waiting (recv_sys->n_addrs == 0).

If buf_page_init_for_read() from buf_read_page_low() results error, recv_recover_page() is not called and recv_sys->n_addrs is not decremented.

How to repeat:
It may be rare case.
But, crash with high load may cause more.

299. By Stewart Smith on 2012-09-12

document replacement of XtraDB SYS_STATS with InnoDB implementation

298. By Stewart Smith on 2012-09-12

null merge innodb_stats.patch from PS5.5 - this functionality is replaced by MySQL 5.6 InnoDB persistent statistics

297. By Stewart Smith on 2012-09-12

null merge innodb_show_sys_tables.patch into PS5.6, it's replaced by MySQL 5.6 functionality

Branch metadata

Branch format:
Branch format 7
Repository format:
Bazaar repository format 2a (needs bzr 1.16 or later)
Stacked on:
lp:percona-server/5.5
This branch contains Public information 
Everyone can see this information.

Subscribers