Tuesday, January 28, 2014

Important MySQL settings to tune after installation

We usually run MySQL with default setting in production environment without analyzing the hardware configuration, database size, load on database and nature of application. That is big mistake we made!!! And any point of time MySQL will face performance issue. 
Lets make it easier. The goal of this post is to give a list of critical setting which should be configured after first MySQL installation.

Basic Setting

innodb_buffer_pool_size : The buffer pool cached all data and indexes so keeping it as large as possible will ensure mysql use memory rather than disk for read operation. Recommended value is 80% of your system memory.

key_buffer_size : this parameter cache the MYISAM table data and enhance the read performance. Examine how much data is on MyISAM tables and configure it accordingly.

innodb_log_file_size: this is size of redo log. the redo logs ensure writes are fast and recovery at the time of crash. In latest MySQL 5.6 redo logs can be configured up to 4 GB. Configuring it 1 GB is ideal value for write performance and fast recovery. If your database is write intensive then increase it to 4 GB but recovery would be slow in case of crash.

max_connections: define how many connection can be made to database at any point of time, what could be the feasible value? high values might consume all resource and hang your database ( a single connection use some memory ) and lower value might unstable your application. Better is to monitor your application for some time and come to a final value. In case application doesnt kill connection after it complete it operation then handle it at application level.

InnoDB Setting

innodb_file_per_table : this setting will tell InnoDB if it stores data and indexes in shared tables space ( ibdata1) or in individual .ibd files. Setting this value ON will benefit you in reclaim space when dropping, truncating or rebuilding a table.

innodb_flush_log_at_trx_commit : setting of 1 means that InnoDB is fully ACID compliant. 

innodb_flush_method: this setting controls how data and logs are flushed to disk. Popular values are O_DIRECT when you have a hardware RAID controller with a battery-protected write-back cache and fdatasync (default value) for most other scenarios. sysbench is a good tool to help you choose between the 2 values.

innodb_log_buffer_size: this is the size of the buffer for transactions that have not been committed yet. The default value (1MB) is usually fine but as soon as you have transactions with large blob/text fields, the buffer can fill up very quickly and trigger extra I/O load. Look at the Innodb_log_waits status variable and if it is not 0, increase innodb_log_buffer_size.

Monday, October 21, 2013

why index refuse to work??

We never thought primary key refuse to work in a query even if the key included in where clause. yes, it happens. I got a a mail from developer team saying a very simple query is taking minutes to fetch the records although it should take milliseconds. initially i execute the query and check with explain.

mysql> explain select * from ad_detail where ad_id=5029;
+----+-------------+------------+------+---------------+------+---------+------+---------+-------------+
| id | select_type | table      | type | possible_keys | key  | key_len | ref  | rows    | Extra       |
+----+-------------+------------+------+---------------+------+---------+------+---------+-------------+
|  1 | SIMPLE      | ad_details | ALL  | PRIMARY       | NULL | NULL    | NULL | 3926237 | Using where |
+----+-------------+------------+------+---------------+------+---------+------+---------+-------------+
1 row in set (0.00 sec)

ad_id is primary key, query should use this key. however, it not happening here. where is the problem?

lets check the table structure.

mysql> desc ad_details;
+------------------+----------------+------+-----+-------------------+-----------------------------+
| Field            | Type           | Null | Key | Default           | Extra                       |
+------------------+----------------+------+-----+-------------------+-----------------------------+
| AD_ID            | varchar(50)    | NO   | PRI | NULL              |                             |
| SA_ID           | varchar(50)    | YES  | MUL | NULL              |                             |
| BOOKING_C   | varchar(20)    | YES  | MUL | INT               |                             |
| CT_ID           | varchar(10)    | YES  |     | NULL              |                             |
| SB_CT_ID       | varchar(10)    | YES  |     | NULL              |                             |
| AD_TITLE         | varchar(110)   | YES  |     | NULL              |                             |
| AD_DESCRIPTION   | varchar(10100) | YES  |     | NULL              |                             |
| EMAIL            | varchar(50)    | YES  |     | NULL              |                             |
| MOBILE           | varchar(15)    | YES  |     | NULL              |                             |
| LAND_LINE        | varchar(20)    | YES  |     | NULL              |                             |
| AD_POST_DATE     | date           | YES  |     | NULL              |                             |
| AD_EXPIRY_DATE   | date           | YES  |     | NULL              |                             |
-----------------------------------------------------------------------------------------------

wow!!! here is the problem, ad_id is varchar. comparing string/varchar to integer not going to use the index ad_id. put the ad_id value in " "

change the query to select * from ad_detail where ad_id="5029";

lets the explain output again

mysql> explain select * from ad_detail where ad_id="5029";
+----+-------------+------------+-------+---------------+---------+---------+-------+------+-------+
| id | select_type | table      | type  | possible_keys | key     | key_len | ref   | rows | Extra |
+----+-------------+------------+-------+---------------+---------+---------+-------+------+-------+
|  1 | SIMPLE      | ad_details | const | PRIMARY       | PRIMARY | 52      | const |    1 |       |
+----+-------------+------------+-------+---------------+---------+---------+-------+------+----

Now we can see the query is using PRIMARY as key and just scanning 1 record to execute it.
This is very simple mistake we sometimes do referring a varchar to integer value in code/application.

I think for better utilization of index we should keep primary key as integer rather than a varchar.



Wednesday, April 3, 2013

Is MySQL 5.6 slower than 5.5?

Since MySQL 5.6 released there are so many benchmarks reports posted using the sysbench OLTP workload. Most of the benchmarks are surprising and totally disagree with the claim MySQL posted about performance gain of more than 200% with MySQL 5.6. So I did sysbench OLTP benchmark on old system which show MySQL 5.5 has performance edge over MySQL 5.6. Its very early now to make any assumptions on performance because the new version just starting in production use or in QA/Staging. So after 5-6 month we might have real time performance benchmark.
One important point we should remember that MySQL 5.6 has performance schema enabled by default and the latest version has lots of improvement in performance schema which reduced overhead so i have added benchmark with and without performance schema feature.
My Hardware configuration is:
Red Hat Enterprise Linux Server release 5.2 2.6.18-92.el5
Dual-Core AMD Opteron(tm) Processor 2216 4 CPU
8 GB RAM
Without any mysql tuning parameter.

sysbench --test=oltp --mysql-user=root --mysql-password=root --oltp-table-size=1000000 --mysql-db=test --max-time=60 --max-requests=0 --num-threads=? run

                                                          Read Only Benchmark

The graphs are clearly showing better MySQL 5.5 performance over 5.6, also we could see 5.6 without performance schema is better than using performance schema, i think performance schema has little overhead.

The Read Write benchmark also showing MySQL 5.5 performance is better than 5.6, however 5.6 with out performance schema is performing better than MySQL 5.5

                                       Read Write Benchmark

Lets tweak some parameters on MySQL 5.6 and see the graph. I think Buffer Pool might make a difference in performance so i did another benchmark with Buffer Pool 4 GB, again results are not encouraging.
There are two more important parameters which affect performances suddenly if configured properly according to hardware and OS configuration. These are : innodb_adaptive_hash_index and innodb_spin_wait_delay. I see some performance gain if  innodb_spin_wait_delay is disabled but still performance is below MySQL 5.5. No performance impact can be seen if innodb_adaptive_hash_index is OFF.

See the cumulative graph for Read Only Benchmark.


Monday, March 25, 2013

Intrepreting MySQL Binary Logs using mysqlbinlog

MySQL Database Server logs each change data statement in binary logs. Binary logs generally used for replicating all changes on master database server to slave database server. These logs can be used for disaster recovery, to perform some specific database maintenance activities or for database incremental backup. Binary logging can be enabled using log-bin parameter in my.cnf ( the MySQL configuration  file ). So to analyze and process logs in binary format mysqlbinlog utility is used. This tools convert the binary logs into plain text or human readable format depending upon the binlog format set in my.cnf.
There are three binary log format STATEMENT : queries logged in plain text format, ROW : queries logged on binary format and MIXED. Default binary log format is STATEMENT.

To start with binary logs lets execute some data change queries on mysql :

create table test ( id int );
insert into test values (1);
insert into test values (2);
alter table test add column( id2 int);

$ mysqlbinlog mysql-bin.000004

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#130325 16:20:55 server id 1  end_log_pos 107   Start: binlog v 4, server v 5.5.30-log created 130325 16:20:55 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
DyxQUQ8BAAAAZwAAAGsAAAABAAQANS41LjMwLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAPLFBREzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 107
#130325 16:21:08 server id 1  end_log_pos 198   Query   thread_id=1     exec_time=0     error_code=0
use `test`/*!*/;
SET TIMESTAMP=1364208668/*!*/;
SET @@session.pseudo_thread_id=1/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create table test ( id int )
/*!*/;
# at 198
#130325 16:21:17 server id 1  end_log_pos 266   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364208677/*!*/;
BEGIN
/*!*/;
# at 266
#130325 16:21:17 server id 1  end_log_pos 356   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364208677/*!*/;
insert into test values (1)
/*!*/;
# at 356
#130325 16:21:17 server id 1  end_log_pos 383   Xid = 8
COMMIT/*!*/;
# at 383
#130325 16:21:18 server id 1  end_log_pos 451   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364208678/*!*/;
BEGIN
/*!*/;
# at 451
#130325 16:21:18 server id 1  end_log_pos 541   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364208678/*!*/;
insert into test values (2)
/*!*/;
# at 541
#130325 16:21:18 server id 1  end_log_pos 568   Xid = 9
COMMIT/*!*/;
# at 568
#130325 16:21:26 server id 1  end_log_pos 668   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364208686/*!*/;
alter table test add column( id2 int)
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;


We could see all queries in plain text from above mysqlbinlog output when binary log format is STATEMENT.

mysqlbinlog displays row events encoded as base-64 string which is not human readable.
Here is mysqlbinlog output with ROW format:

$ mysqlbinlog mysql-bin.000004 

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#130325 16:42:34 server id 1  end_log_pos 107   Start: binlog v 4, server v 5.5.30-log created 130325 16:42:34 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
IjFQUQ8BAAAAZwAAAGsAAAABAAQANS41LjMwLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAiMVBREzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 107
#130325 16:42:52 server id 1  end_log_pos 198   Query   thread_id=1     exec_time=0     error_code=0
use `test`/*!*/;
SET TIMESTAMP=1364209972/*!*/;
SET @@session.pseudo_thread_id=1/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create table test ( id int )
/*!*/;
# at 198
#130325 16:42:57 server id 1  end_log_pos 266   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364209977/*!*/;
BEGIN
/*!*/;
# at 266
#130325 16:42:57 server id 1  end_log_pos 309   Table_map: `test`.`test` mapped to number 34
# at 309
#130325 16:42:57 server id 1  end_log_pos 343   Write_rows: table id 34 flags: STMT_END_F

BINLOG '
OTFQURMBAAAAKwAAADUBAAAAACIAAAAAAAEABHRlc3QABHRlc3QAAQMAAQ==
OTFQURcBAAAAIgAAAFcBAAAAACIAAAAAAAEAAf/+AQAAAA==
'/*!*/;
# at 343
#130325 16:42:57 server id 1  end_log_pos 370   Xid = 8
COMMIT/*!*/;
# at 370
#130325 16:43:00 server id 1  end_log_pos 438   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364209980/*!*/;
BEGIN
/*!*/;
# at 438
#130325 16:43:00 server id 1  end_log_pos 481   Table_map: `test`.`test` mapped to number 34
# at 481
#130325 16:43:00 server id 1  end_log_pos 515   Write_rows: table id 34 flags: STMT_END_F

BINLOG '
PDFQURMBAAAAKwAAAOEBAAAAACIAAAAAAAEABHRlc3QABHRlc3QAAQMAAQ==
PDFQURcBAAAAIgAAAAMCAAAAACIAAAAAAAEAAf/+AgAAAA==
'/*!*/;
# at 515
#130325 16:43:00 server id 1  end_log_pos 542   Xid = 9
COMMIT/*!*/;
# at 542
#130325 16:43:03 server id 1  end_log_pos 642   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364209983/*!*/;
alter table test add column( id2 int)
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;


 To display row events as comments run mysqlbinlog with -v option:

$mysqlbinlog SM-Couple1-bin.000004 -v
 

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#130325 16:42:34 server id 1  end_log_pos 107   Start: binlog v 4, server v 5.5.30-log created 130325 16:42:34 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
IjFQUQ8BAAAAZwAAAGsAAAABAAQANS41LjMwLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAiMVBREzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 107
#130325 16:42:52 server id 1  end_log_pos 198   Query   thread_id=1     exec_time=0     error_code=0
use `test`/*!*/;
SET TIMESTAMP=1364209972/*!*/;
SET @@session.pseudo_thread_id=1/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create table test ( id int )
/*!*/;
# at 198
#130325 16:42:57 server id 1  end_log_pos 266   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364209977/*!*/;
BEGIN
/*!*/;
# at 266
#130325 16:42:57 server id 1  end_log_pos 309   Table_map: `test`.`test` mapped to number 34
# at 309
#130325 16:42:57 server id 1  end_log_pos 343   Write_rows: table id 34 flags: STMT_END_F

BINLOG '
OTFQURMBAAAAKwAAADUBAAAAACIAAAAAAAEABHRlc3QABHRlc3QAAQMAAQ==
OTFQURcBAAAAIgAAAFcBAAAAACIAAAAAAAEAAf/+AQAAAA==
'/*!*/;
### INSERT INTO `test`.`test`
### SET
###   @1=1
# at 343
#130325 16:42:57 server id 1  end_log_pos 370   Xid = 8
COMMIT/*!*/;
# at 370
#130325 16:43:00 server id 1  end_log_pos 438   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364209980/*!*/;
BEGIN
/*!*/;
# at 438
#130325 16:43:00 server id 1  end_log_pos 481   Table_map: `test`.`test` mapped to number 34
# at 481
#130325 16:43:00 server id 1  end_log_pos 515   Write_rows: table id 34 flags: STMT_END_F

BINLOG '
PDFQURMBAAAAKwAAAOEBAAAAACIAAAAAAAEABHRlc3QABHRlc3QAAQMAAQ==
PDFQURcBAAAAIgAAAAMCAAAAACIAAAAAAAEAAf/+AgAAAA==
'/*!*/;
### INSERT INTO `test`.`test`
### SET
###   @1=2
# at 515
#130325 16:43:00 server id 1  end_log_pos 542   Xid = 9
COMMIT/*!*/;
# at 542
#130325 16:43:03 server id 1  end_log_pos 642   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364209983/*!*/;
alter table test add column( id2 int)
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;


We can suppress BINLOG for row events using

$  mysqlbinlog SM-Couple1-bin.000005 -v --base64-output=DECODE-ROWS

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#130325 16:42:34 server id 1  end_log_pos 107   Start: binlog v 4, server v 5.5.30-log created 130325 16:42:34 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
# at 107
#130325 16:42:52 server id 1  end_log_pos 198   Query   thread_id=1     exec_time=0     error_code=0
use `test`/*!*/;
SET TIMESTAMP=1364209972/*!*/;
SET @@session.pseudo_thread_id=1/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create table test ( id int )
/*!*/;
# at 198
#130325 16:42:57 server id 1  end_log_pos 266   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364209977/*!*/;
BEGIN
/*!*/;
# at 266
#130325 16:42:57 server id 1  end_log_pos 309   Table_map: `test`.`test` mapped to number 34
# at 309
#130325 16:42:57 server id 1  end_log_pos 343   Write_rows: table id 34 flags: STMT_END_F
### INSERT INTO `test`.`test`
### SET
###   @1=1
# at 343
#130325 16:42:57 server id 1  end_log_pos 370   Xid = 8
COMMIT/*!*/;
# at 370
#130325 16:43:00 server id 1  end_log_pos 438   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364209980/*!*/;
BEGIN
/*!*/;
# at 438
#130325 16:43:00 server id 1  end_log_pos 481   Table_map: `test`.`test` mapped to number 34
# at 481
#130325 16:43:00 server id 1  end_log_pos 515   Write_rows: table id 34 flags: STMT_END_F
### INSERT INTO `test`.`test`
### SET
###   @1=2
# at 515
#130325 16:43:00 server id 1  end_log_pos 542   Xid = 9
COMMIT/*!*/;
# at 542
#130325 16:43:03 server id 1  end_log_pos 642   Query   thread_id=1     exec_time=0     error_code=0
SET TIMESTAMP=1364209983/*!*/;
alter table test add column( id2 int)
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;


You should not suppress BINLOG statements if you intend to re-execute mysqlbinlog output.