MySQL High Performance

Syndicate content
Percona's MySQL & InnoDB performance and scalability blog
Updated: 3 hours 11 min ago

Multi-threaded replication with MySQL 5.6: Use GTIDs!

8 hours 11 min ago

MySQL 5.6 allows you to execute replicated events in parallel as long as data is split across several databases. This feature is named “Multi-Threaded Slave” (MTS) and it is easy to enable by setting slave_parallel_workers to a > 1 value. However if you decide to use MTS without GTIDs, you may run into annoying issues. Let’s look at two of them.

Skipping replication errors

When replication stops with an error, a frequent approach is to “ignore now and fix later.” This means you will run SET GLOBAL sql_slave_skip_counter=1 to be able to restart replication as quickly as possible and later use pt-table-checksum/pt-table-sync to resync data on the slave.

Then the day when I hit:

mysql> show slave status; [...] Last_SQL_Error: Worker 0 failed executing transaction '' at master log mysql-bin.000017, end_log_pos 1216451; Error 'Duplicate entry '1001' for key 'PRIMARY'' on query. Default database: 'db1'. Query: 'INSERT INTO sbtest1 (id, k, c, pad) VALUES (0, 5320, '49123511666-22272014664-85739796464-62261637750-57593947547-00947134109-73607171516-11063345053-55659776318-82888369235', '11400300639-05875856680-20973514928-29618434959-69429576205')' Exec_Master_Log_Pos: 1005432

I tried to use the trick:

mysql> set global sql_slave_skip_counter=1; mysql> start slave;

But:

mysql> show slave status; [...] Last_SQL_Error: Worker 0 failed executing transaction '' at master log mysql-bin.000017, end_log_pos 1216451; Error 'Duplicate entry '1001' for key 'PRIMARY'' on query. Default database: 'db1'. Query: 'INSERT INTO sbtest1 (id, k, c, pad) VALUES (0, 5320, '49123511666-22272014664-85739796464-62261637750-57593947547-00947134109-73607171516-11063345053-55659776318-82888369235', '11400300639-05875856680-20973514928-29618434959-69429576205')' Exec_Master_Log_Pos: 1005882

Note that the position reported with Exec_Master_Log_Pos has moved forward, but I still have my duplicate key error. What’s wrong?

The issue is that the positions reported by SHOW SLAVE STATUS are misleading when using MTS. Quoting the documentation about Exec_Master_Log_Pos:

When using a multi-threaded slave (by setting slave_parallel_workers to a nonzero value in MySQL 5.6.3 and later), the value in this column actually represents a “low-water” mark, before which no uncommitted transactions remain. Because the current implementation allows execution of transactions on different databases in a different order on the slave than on the master, this is not necessarily the position of the most recently executed transaction.

So the solution to my problem is first to make sure that there is no execution gap, and only then to skip the offending event. There is a specific statement for the first part:

mysql> start slave until sql_after_mts_gaps;

And now I can finally skip the error and restart replication:

mysql> set global sql_slave_skip_counter=1; mysql> start slave; mysql> show slave statusG Slave_IO_Running: Yes Slave_SQL_Running: Yes

The last thing to do is of course to resync the slave.

Backups

If you cannot trust the output of SHOW SLAVE STATUS to get the current binlog position, it means that taking a backup from a slave with parallel replication is tricky.

For instance, if you run mysqldump --dump-slave=2 to get the binlog position of the master, mysqldump will first run STOP SLAVE and then SHOW SLAVE STATUS. Is stopping the slave sufficient to avoid execution gaps? Actually, no.

The only option then seems to be: run STOP SLAVE followed by START SLAVE UNTIL SQL_AFTER_MTS_GAPS, followed by mysqldump while replication is stopped. Not very handy!

GTIDs to the rescue!

The solution for both issues is to use GTIDs.

They help when you want to skip an event because when using GTIDs, you must explicitly specify the transaction you will be skipping. It doesn’t matter whether there are execution holes.

They also help for backups because mysqldump takes the position from gtid_executed which is updated at each transaction commit (XtraBackup does that too).

Conclusion

If your application uses several databases and if you’re fighting with replication lag, MTS can be a great feature for you. But although GTIDs are not technically necessary, you’ll be exposed to tricky situations if you don’t use them.

Is everything rosy when using both GTIDs and MTS? Not exactly… But that will be the topic for a separate post!

By the way, if you are in the Brussels area this weekend, come see me and other great speakers at the MySQL and friends devroom at FOSDEM!

The post Multi-threaded replication with MySQL 5.6: Use GTIDs! appeared first on MySQL Performance Blog.

Percona University: Back to school Feb. 12 in Raleigh, N.C.

Di, 2015-01-27 19:01

Percona CEO Peter Zaitsev leads a track at the inaugural Percona University event in Raleigh, N.C. on Jan. 29, 2013.

About two years ago we held our first-ever Percona University event in Raleigh, N.C. It was a great success with high attendance and very positive feedback which led us to organize a number of similar educational events in different locations around the world.

And next month we’ll be back where it all started. On February 12, Percona University comes to Raleigh – and this time the full-day educational event will be much more cool. What have we changed? Take a look at the agenda.

First - this is no longer just a MySQL-focused event. While 10 years ago MySQL was the default, dominating choice for modern companies looking to store and process data effectively – this is no longer the case. And as such the event’s theme is “Smart Data.” In addition to MySQL, Percona and MariaDB technologies (which you would expect to be covered), we have talks about Hadoop, MongoDB, Cassandra, Redis, Kafka, SQLLite.

However the “core” data-store technologies is not the only thing successful data architects should know – one should also be well-versed in the modern approaches to the infrastructure and general data management. This is why we also have talks about Ansible and OpenStack, DBaaS and PaaS as well as a number of more talks about big-picture topics around architecture and technology management.

Second – this is our first multi-track Percona University event – we had so many great speakers interested in speaking that we could not fit them all into one track, so we have two tracks now with 25 sessions which makes that quite an educational experience!

Third – while we’re committed to having those events be very affordable, we decided to charge $10 per attendee. The reason for this is to encourage people to register who actually plan on attending – when hosting free events we found out that way too many registered and never showed up, which was causing the venues to rapidly fill past capacity and forcing us to turn away those who could actually be there. It was also causing us to order more food than needed, causing waste. We trust $10 will not prevent you from attending, but if it does cause hardship, just drop me a note and I’ll give you a free pass.

A few other things you need to know:

This is very much a technically focused event. I have encouraged all speakers to make it about technology rather than sales pitches or marketing presentations.

This is low-key educational event. Do not expect it to be very fancy. If you’re looking for the great conference experience consider attending the Percona Live MySQL Conference and Expo this April.

Although it’s a full-day event, you can come for just part of the day. We recognize many of you will not be able to take a full day from work and may be able to attend only in the morning or the afternoon. This is totally fine. The morning registration hours is when most people will register, however, there will be someone on the desk to get you your pass throughout the day.

Thinking of Attending? Take a look at the day’s sessions and then register as space is limited. The event will be held at North Carolina State University’s McKimmon Conference & Training Center. I hope to see you there!

The post Percona University: Back to school Feb. 12 in Raleigh, N.C. appeared first on MySQL Performance Blog.

Percona Toolkit 2.2.13 is now available

Mo, 2015-01-26 16:25

Percona is pleased to announce the availability of Percona Toolkit 2.2.13.  Released January 26, 2015. Percona Toolkit is a collection of advanced command-line tools to perform a variety of MySQL server and system tasks that are too difficult or complex for DBAs to perform manually. Percona Toolkit, like all Percona software, is free and open source.

This release is the current GA (Generally Available) stable release in the 2.2 series. It includes multiple bug fixes for pt-table-checksum with better support for Percona XtraDB Cluster, various other fixes, as well as continued preparation for MySQL 5.7 compatibility. Full details are below. Downloads are available here and from the Percona Software Repositories.

New Features:

  • pt-kill now supports new --query-id option. This option can be used to print a query fingerprint hash after killing a query to enable the cross-referencing with the pt-query-digest output. This option can be used along with --print option as well.

Bugs Fixed:

  • Fixed bug 1408375: Percona Toolkit was vulnerable to MITM attack which could allow exfiltration of MySQL configuration information via --version-check option. This vulnerability was logged as CVE 2015-1027
  • Fixed bug 1019479: pt-table-checksum now works with ONLY_FULL_GROUP_BY SQL mode.
  • Fixed bug 1394934: running pt-table-checksum in debug mode would cause an error.
  • Fixed bug 1396868: regression introduced in Percona Toolkit 2.2.12 caused pt-online-schema-change not to honor --ask-pass option.
  • Fixed bug 1399789: pt-table-checksum would fail to find Percona XtraDB Cluster nodes when variable wsrep_node_incoming_address was set to AUTO.
  • Fixed bug 1321297: pt-table-checksum was reporting differences on timestamp columns with replication from 5.5 to 5.6 server version, although the data was identical.
  • Fixed bug 1388870: pt-table-checksum was showing differences if the master and slave were in different time zone.
  • Fixed bug 1402668: pt-mysql-summary would exit if Percona XtraDB Cluster was in Donor/Desynced state.
  • Fixed bug 1266869: pt-stalk would fail to start if $HOME environment variable was not set.

Details of the release can be found in the release notes and the 2.2.13 milestone at Launchpad. Bugs can be reported on the Percona Toolkit launchpad bug tracker.

The post Percona Toolkit 2.2.13 is now available appeared first on MySQL Performance Blog.

MySQL benchmarks on eXFlash DIMMs

Mo, 2015-01-26 13:00

In this blog post, we will discuss MySQL performance on eXFlash DIMMs. Earlier we measured the IO performance of these storage devices with sysbench fileio.

Environment

The benchmarking environment was the same as the one we did sysbench fileio in.

CPU: 2x Intel Xeon E5-2690 (hyper threading enabled)
FusionIO driver version: 3.2.6 build 1212
Operating system: CentOS 6.5
Kernel version: 2.6.32-431.el6.x86_64

In this case, we used a separate machine for testing which had a 10G ethernet connection to this server. This server executed sysbench. The client was not the bottleneck in this case. The environment is described in greater detail at the end of the blog post.

Sysbench OLTP write workload

The graph shows throughput for sysbench OLTP, we will examine properties only for the dark areas of this graph: which is the read/write case for high concurrency.

Each table in the following sections has the following columns
columnexplanationstorageThe device that was used for the measurement.threadsThe number of sysbench client threads were used in the benchmark.ro_rwRead-only or read-write. In the whitepaper you can find detailed information about read-only data as well.sdThe standard deviation of the metric in question.meanThe mean of the metric in question.95thpctThe 95th percentile of the metric in question (the maximum without the highest 5 percent of the samples).maxThe maximum of the metric in question.

Sysbench OLTP throughputstoragethreadsro_rwsdmean95thpctmaxeXFlash DIMM_4128rw714.096055996.51057172.07257674.87eXFlash DIMM_4256rw470.954106162.42716673.02057467.99eXFlash DIMM_8128rw195.578577140.50387493.47807723.13eXFlash DIMM_8256rw173.513736498.14606736.17107490.95fio128rw588.142821855.43042280.27807179.95fio256rw599.885102187.52712584.19957467.13

Going from 4 to 8 eXFlash DIMMs will mostly mean more consistent throughput. The mean throughput is significantly higher in case of 8 DIMMs used, but the 95th percentile and the maximum values are not much different (the difference in standard deviation also shows this). The reason they are not much different is that these benchmark are CPU bound (check CPU idle time table later in this post or the graphs in the whitepaper). The PCI-E flash drive on the other hand can do less than half of the throughput of the eXFlash DIMMs (the most relevant is comparing the 95th percentile value).

Sysbench OLTP response timestoragethreadsro_rwsdmean95thpctmaxeXFlash DIMM_4128rw4.418778437.93148944.260064.54eXFlash DIMM_4256rw9.664274190.789317109.0450176.45eXFlash DIMM_8128rw2.100408528.79601732.160067.10eXFlash DIMM_8256rw5.593257294.060628101.6300121.92fio128rw51.2343587138.052150203.1160766.11fio256rw72.9901355304.851844392.7660862.00

The 95th percentile response time for the eXFlash DIMM’s case are less than 1/4 compared to the PCI-E flash device.

CPU idle percentagestoragethreadsro_rwsdmean95thpctmaxeXFlash DIMM_4128rw1.628466743.36838576.260022.18eXFlash DIMM_4256rw1.069800952.29306343.917026.37eXFlash DIMM_8128rw0.429876370.85535431.290015.28eXFlash DIMM_8256rw1.323284354.48617956.71009.40fio128rw4.2115699626.127899431.502055.49fio256rw5.4948985219.312363927.671547.34

The percentage of CPU being idle shows that the performance bottleneck in this benchmark was the CPU in case of eXFlash DIMMs (both with 4 and 8 DIMMs, this is why we didn’t see a substantial throughput difference between the 4 and the 8 DIMM setup). However, for the PCI-E flash, the storage device itself was the bottleneck.

If you are interested in more details, download the free white paper which contains the full analysis of sysbench OLTP and linkbench benchmarks.

The post MySQL benchmarks on eXFlash DIMMs appeared first on MySQL Performance Blog.

Using Percona Cloud Tools to solve real-world MySQL problems

Fr, 2015-01-23 19:49

For months when speaking with customers I have been positioning Percona Cloud Tools (PCT) as a valuable tool for the DBA/Developer/SysAdmin but only recently have I truly been able to harness the data and make a technical recommendation to a customer that I feel would have been very difficult to accomplish otherwise.

Let me provide some background: I was tasked with performing a Performance Audit for one of our customers (Performance Audits are extremely popular as they allow you to have a MySQL Expert confirm or reveal challenges within your MySQL environment and make your database run faster!) and as part of our conversation we discussed and agreed to install Percona Cloud Tools. We let the site run for a few days, and then I started my audit. What I noticed was that at regular intervals there was often a CPU spike, along with a corresponding drop in Queries Per Second (QPS), but that lasted only for a few seconds. We decided that further investigation was warranted as the customer was concerned the spikes impacted their users’ experience with the application.

Here are the tasks that Percona Cloud Tools made easy while I worked to identify the source of the CPU spike and QPS drop:

  1. Per-second granularity data capture of PCT allowed me to identify how significant the spike and QPS actually were – if I was looking at the 1 minute or higher average values (such as Cacti would provide) I probably wouldn’t have been able to detect the spike or stall as clearly in the first place, it would have been lost in the average. In the case of PCT the current graphs group at the 1 minute range but you have the ability to view the min and max values during this 1 minute range since they are the true highest and lowest observed 1s intervals during the 1 minute group.
  2. Ability for all graphs to maintain the same resolution time allowed me to zero-in on the problematic time period and then quickly look across all graphs for corresponding deflections. This analysis led me to discover a significant spike in InnoDB disk reads.
  3. Ability to use the Query Analytics functionality to zoom-in again on the problematic query. By adjusting Query Analytics to an appropriate time period narrowed down the range of unique queries that could be considered the cause. This task in my opinion is the best part of using PCT.
  4. Query Analytics allowed me to view the Rows Examined in Total for each query based on just this shortened interval. I then tagged those that had higher than 10k Rows Examined (arbitrary but most queries for this customer seemed to fall below this) so that I could then review in real-time with the customer before making a decision on what to do next. We can only view this sort of information by leveraging the slow query log – this data is not available via Performance_Schema or via network sniffing.

Once we were able to identify the problematic queries then the rest was routine query optimization – 10 minutes work using Percona Cloud Tools for what might have been an hour using traditional methods!

For those of you wondering how else this can be done, assuming you detected the CPU spike / QPS drop (perhaps you are using Graphite or other tool that can deliver per-second resolution) then you’d also need to be capturing the slow query log at a good enough resolution level (I prefer long_query_time=0 to just get it all), and then be adept at leveraging pt-query-digest with –since and –until options to narrow down your range of queries.  The significant drawback to this approach is that each time you want to tweak your time range you probably need to stream through a fairly large slow log file multiple times which can be both CPU and disk intensive operations, which means it can take some time (probably minutes, maybe hours) depending on the size of your log file.  Certainly a workable approach but nowhere near as quick as reloading a page in your browser

So what are you waiting for? Start using Percona Cloud Tools today, it’s free! Register for the free beta here.

The post Using Percona Cloud Tools to solve real-world MySQL problems appeared first on MySQL Performance Blog.

Importing big tables with large indexes with Myloader MySQL tool

Mi, 2015-01-21 14:00

Mydumper is known as the faster (much faster) mysqldump alternative. So, if you take a logical backup you will choose Mydumper instead of mysqldump. But what about the restore? Well, who needs to restore a logical backup? It takes ages! Even with Myloader. But this could change just a bit if we are able to take advantage of Fast Index Creation.

As you probably know, Mydumper and mysqldump export the struct of a table, with all the indexes and the constraints, and of course, the data. Then, Myloader and MySQL import the struct of the table and import the data. The most important difference is that you can configure Myloader to import the data using a certain amount of threads. The import steps are:

  1. Create the complete struct of the table
  2. Import the data

When you execute Myloader, internally it first creates the tables executing the “-schema.sql” files and then takes all the filenames without “schema.sql” and puts them in a task queue. Every thread takes a filename from the queue, which actually is a chunk of the table, and executes it.  When finished it takes another chunk from the queue, but if the queue is empty it just ends.

This import procedure works fast for small tables, but with big tables with large indexes the inserts are getting slower caused by the overhead of insert the new values in secondary indexes. Another way to import the data is:

  1. Split the table structure into table creation with primary key, indexes creation and constraint creation
  2. Create tables with primary key
  3. Per table do:
    1. Load the data
    2. Create index
  4. Create constraints

This import procedure is implemented in a branch of Myloader that can be downloaded from here or directly executing bzr with the repository:

bzr branch lp:~david-ducos/mydumper/mydumper

The tool reads the schema files and splits them into three separate statements which create the tables with the primary key, the indexes and the constraints. The primary key is kept in the table creation in order to avoid the recreation of the table when a primary key is added and the “KEY” and “CONSTRAINT” lines are removed. These lines are added to the index and constraint statements, respectively.

It processes tables according to their size starting with the largest because creating the indexes of a big table could take hours and is single-threaded. While we cannot process other indexes at the time, we are potentially able to create other tables with the remaining threads.

It has a new thread (monitor_process) that decides which chunk of data will be put in the task queue and a communication queue which is used by the task processes to tell the monitor_process which chunk has been completed.

I run multiple imports on an AWS m1.xlarge machine with one table comparing Myloader and this branch and I found that with large indexes the times were:

As you can see, when you have less than 150M rows, import the data and then create the indexes is higher than import the table with the indexes all at once. But everything changes after 150M rows, import 200M takes 64 minutes more for Myloader but just 24 minutes for the new branch.

On a table of 200M rows with a integer primary key and 9 integer columns, you will see how the time increases as the index gets larger:

Where:

2-2-0: two 1-column and two 2-column index
2-2-1: two 1-column, two 2-column and one 3-column index
2-3-1: two 1-column, three 2-column and one 3-column index
2-3-2: two 1-column, three 2-column and two 3-column index

Conclusion

This branch can only import all the tables with this same strategy, but with this new logic in Myloader, in a future version it could be able to import each table with the best strategy reducing the time of the restore considerably.

The post Importing big tables with large indexes with Myloader MySQL tool appeared first on MySQL Performance Blog.

Identifying useful info from MySQL row-based binary logs

Di, 2015-01-20 15:34

As a MySQL DBA/consultant, it is part of my job to decode the MySQL binary logs – and there are a number of reasons for doing that. In this post, I’ll explain how you can get the important information about your write workload using MySQL row-based binary logs and a simple awk script.

First, it is important to understand that row-based binary logs contain the actual changes done by a query. For example, if I run a delete query against a table, the binary log will contain the rows that were deleted. MySQL provides the mysqlbinlog utility to decode the events stored in MySQL binary logs. You can read more about mysqlbinlog in detail in the reference manual here.

The following example illustrates how mysqlbinlog displays row events that specify data modifications. These correspond to events with the WRITE_ROWS_EVENT, UPDATE_ROWS_EVENT, and DELETE_ROWS_EVENT type codes.

We will use following options of mysqlbinlog.
–base64-output=decode-rows
–verbose, -v
–start-datetime=”datetime”
–stop-datetime=”datetime”

We have a server running with row based binary logging.

mysql> show variables like '%binlog_format%'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | binlog_format | ROW | +---------------+-------+ 1 row in set (0.00 sec)

We created a test table and executed the following sequence of statements under a transaction.

use test; CREATE TABLE t ( id INT NOT NULL, name VARCHAR(20) NOT NULL, date DATE NULL ) ENGINE = InnoDB; START TRANSACTION; INSERT INTO t VALUES(1, 'apple', NULL); UPDATE t SET name = 'pear', date = '2009-01-01' WHERE id = 1; DELETE FROM t WHERE id = 1; COMMIT;

Now let’s see how it is represented in binary logs.

# mysqlbinlog --base64-output=decode-rows -vv --start-datetime="2015-01-12 21:40:00" --stop-datetime="2015-01-12 21:45:00" mysqld-bin.000023 /*!*/; # at 295 #150112 21:40:14 server id 1 end_log_pos 367 CRC32 0x19ab4f0f Query thread_id=108 exec_time=0 error_code=0 SET TIMESTAMP=1421079014/*!*/; BEGIN /*!*/; # at 367 #150112 21:40:14 server id 1 end_log_pos 415 CRC32 0x6b1f2240 Table_map: `test`.`t` mapped to number 251 # at 415 #150112 21:40:14 server id 1 end_log_pos 461 CRC32 0x7725d174 Write_rows: table id 251 flags: STMT_END_F ### INSERT INTO `test`.`t` ### SET ### @1=1 /* INT meta=0 nullable=0 is_null=0 */ ### @2='apple' /* VARSTRING(20) meta=20 nullable=0 is_null=0 */ ### @3=NULL /* VARSTRING(20) meta=0 nullable=1 is_null=1 */ # at 461 #150112 21:40:14 server id 1 end_log_pos 509 CRC32 0x7e44d741 Table_map: `test`.`t` mapped to number 251 # at 509 #150112 21:40:14 server id 1 end_log_pos 569 CRC32 0x0cd1363a Update_rows: table id 251 flags: STMT_END_F ### UPDATE `test`.`t` ### WHERE ### @1=1 /* INT meta=0 nullable=0 is_null=0 */ ### @2='apple' /* VARSTRING(20) meta=20 nullable=0 is_null=0 */ ### @3=NULL /* VARSTRING(20) meta=0 nullable=1 is_null=1 */ ### SET ### @1=1 /* INT meta=0 nullable=0 is_null=0 */ ### @2='pear' /* VARSTRING(20) meta=20 nullable=0 is_null=0 */ ### @3='2009:01:01' /* DATE meta=0 nullable=1 is_null=0 */ # at 569 #150112 21:40:14 server id 1 end_log_pos 617 CRC32 0xf134ad89 Table_map: `test`.`t` mapped to number 251 # at 617 #150112 21:40:14 server id 1 end_log_pos 665 CRC32 0x87047106 Delete_rows: table id 251 flags: STMT_END_F ### DELETE FROM `test`.`t` ### WHERE ### @1=1 /* INT meta=0 nullable=0 is_null=0 */ ### @2='pear' /* VARSTRING(20) meta=20 nullable=0 is_null=0 */ ### @3='2009:01:01' /* DATE meta=0 nullable=1 is_null=0 */ # at 665 #150112 21:40:15 server id 1 end_log_pos 696 CRC32 0x85ffc9ff Xid = 465 COMMIT/*!*/; DELIMITER ; # End of log file ROLLBACK /* added by mysqlbinlog */; /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

  • Row with “Table_map: test.t” defines the table name used by query.
  • Rows with “Write_rows/Update_rows/Delete_rows” defines the event type.
  • Lines that start with “###” defines the actual row that got changed.
  • Columns are represented as @1, @2 and so on.

Now have a look at our simple awk script that will use the mysqlbinlog output and print a beautiful summary for INSERT/UPDATE/DELETE events from row-based binary logs. Just replace the “mysqld-bin.000023″ with your binary log file. The string “#15″ in third line is for year 2015. If you are decoding a binary log file from 2014, just change it to “#14″. It is also recommended to use “–start-datetime” and ” –stop-datetime” options to decode binary logs of a specific time range instead of decoding a large binary log file.

Script :

mysqlbinlog --base64-output=decode-rows -vv --start-datetime="2015-01-12 21:40:00" --stop-datetime="2015-01-12 21:45:00" mysqld-bin.000023 | awk \ 'BEGIN {s_type=""; s_count=0;count=0;insert_count=0;update_count=0;delete_count=0;flag=0;} \ {if(match($0, /#15.*Table_map:.*mapped to number/)) {printf "Timestamp : " $1 " " $2 " Table : " $(NF-4); flag=1} \ else if (match($0, /(### INSERT INTO .*..*)/)) {count=count+1;insert_count=insert_count+1;s_type="INSERT"; s_count=s_count+1;} \ else if (match($0, /(### UPDATE .*..*)/)) {count=count+1;update_count=update_count+1;s_type="UPDATE"; s_count=s_count+1;} \ else if (match($0, /(### DELETE FROM .*..*)/)) {count=count+1;delete_count=delete_count+1;s_type="DELETE"; s_count=s_count+1;} \ else if (match($0, /^(# at) /) && flag==1 && s_count>0) {print " Query Type : "s_type " " s_count " row(s) affected" ;s_type=""; s_count=0; } \ else if (match($0, /^(COMMIT)/)) {print "[Transaction total : " count " Insert(s) : " insert_count " Update(s) : " update_count " Delete(s) : " \ delete_count "] \n+----------------------+----------------------+----------------------+----------------------+"; \ count=0;insert_count=0;update_count=0; delete_count=0;s_type=""; s_count=0; flag=0} } '

Output :

Timestamp : #150112 21:40:14 Table : `test`.`t` Query Type : INSERT 1 row(s) affected Timestamp : #150112 21:40:14 Table : `test`.`t` Query Type : UPDATE 1 row(s) affected Timestamp : #150112 21:40:14 Table : `test`.`t` Query Type : DELETE 1 row(s) affected [Transaction total : 3 Insert(s) : 1 Update(s) : 1 Delete(s) : 1] +----------------------+----------------------+----------------------+----------------------+

This awk script will return following columns as output for every transaction in binary logs.

Timestamp : timestamp of event as logged in binary log.
Table : database.tablename
Query Type : Type of query executed on table and number of rows affected by query.

[Transaction total : 3 Insert(s) : 1 Update(s) : 1 Delete(s) : 1]
Above line print the summary of transaction, it displays the total number of rows affected by transaction, total number of rows affected by each type of query in transaction.

Let’s execute some more queries in sakila database and then we will summarize them using our script. We assume that we executed these queries between “2015-01-16 13:30:00″ and “2015-01-16 14:00:00″

use sakila; mysql> update city set city="Acua++" where city_id=4; Query OK, 1 row affected (0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0 mysql> delete from country where country_id=4; Query OK, 1 row affected (0.04 sec) mysql> insert into country (country_id,country,last_update) values ('4','Angola',now()); Query OK, 1 row affected (0.03 sec) mysql> create table payment_tmp select * from payment; Query OK, 16049 rows affected (0.80 sec) Records: 16049 Duplicates: 0 Warnings: 0 mysql> delete from payment_tmp where payment_id between 10000 and 15000; Query OK, 5001 rows affected (0.08 sec) mysql> update payment_tmp set amount=9.99 where payment_id between 1 and 7000; Query OK, 6890 rows affected (0.08 sec) Rows matched: 7000 Changed: 6890 Warnings: 0 mysql> start transaction; Query OK, 0 rows affected (0.00 sec) mysql> delete from country where country_id=5; Query OK, 1 row affected (0.00 sec) mysql> delete from city where country_id=5; Query OK, 1 row affected (0.00 sec) mysql> delete from address where city_id=300; Query OK, 2 rows affected (0.00 sec) mysql> commit; Query OK, 0 rows affected (0.01 sec)

We will save our script in a file named “summarize_binlogs.sh” and summarize the queries we just executed.

# vim summarize_binlogs.sh #!/bin/bash BINLOG_FILE="mysqld-bin.000035" START_TIME="2015-01-16 13:30:00" STOP_TIME="2015-01-16 14:00:00" mysqlbinlog --base64-output=decode-rows -vv --start-datetime="${START_TIME}" --stop-datetime="${STOP_TIME}" ${BINLOG_FILE} | awk \ 'BEGIN {s_type=""; s_count=0;count=0;insert_count=0;update_count=0;delete_count=0;flag=0;} \ {if(match($0, /#15.*Table_map:.*mapped to number/)) {printf "Timestamp : " $1 " " $2 " Table : " $(NF-4); flag=1} \ else if (match($0, /(### INSERT INTO .*..*)/)) {count=count+1;insert_count=insert_count+1;s_type="INSERT"; s_count=s_count+1;} \ else if (match($0, /(### UPDATE .*..*)/)) {count=count+1;update_count=update_count+1;s_type="UPDATE"; s_count=s_count+1;} \ else if (match($0, /(### DELETE FROM .*..*)/)) {count=count+1;delete_count=delete_count+1;s_type="DELETE"; s_count=s_count+1;} \ else if (match($0, /^(# at) /) && flag==1 && s_count>0) {print " Query Type : "s_type " " s_count " row(s) affected" ;s_type=""; s_count=0; } \ else if (match($0, /^(COMMIT)/)) {print "[Transaction total : " count " Insert(s) : " insert_count " Update(s) : " update_count " Delete(s) : " \ delete_count "] \n+----------------------+----------------------+----------------------+----------------------+"; \ count=0;insert_count=0;update_count=0; delete_count=0;s_type=""; s_count=0; flag=0} } ' :wq # chmod u+x summarize_binlogs.sh

Now we run our script to get the summary of information logged in binary log.

# ./summarize_binlogs.sh Timestamp : #150116 13:41:09 Table : `sakila`.`city` Query Type : UPDATE 1 row(s) affected [Transaction total : 1 Insert(s) : 0 Update(s) : 1 Delete(s) : 0] +----------------------+----------------------+----------------------+----------------------+ Timestamp : #150116 13:41:59 Table : `sakila`.`country` Query Type : DELETE 1 row(s) affected [Transaction total : 1 Insert(s) : 0 Update(s) : 0 Delete(s) : 1] +----------------------+----------------------+----------------------+----------------------+ Timestamp : #150116 13:42:07 Table : `sakila`.`country` Query Type : INSERT 1 row(s) affected [Transaction total : 1 Insert(s) : 1 Update(s) : 0 Delete(s) : 0] +----------------------+----------------------+----------------------+----------------------+ Timestamp : #150116 13:42:13 Table : `sakila`.`payment_tmp` Query Type : INSERT 16049 row(s) affected [Transaction total : 16049 Insert(s) : 16049 Update(s) : 0 Delete(s) : 0] +----------------------+----------------------+----------------------+----------------------+ Timestamp : #150116 13:42:20 Table : `sakila`.`payment_tmp` Query Type : DELETE 5001 row(s) affected [Transaction total : 5001 Insert(s) : 0 Update(s) : 0 Delete(s) : 5001] +----------------------+----------------------+----------------------+----------------------+ Timestamp : #150116 13:42:28 Table : `sakila`.`payment_tmp` Query Type : UPDATE 6890 row(s) affected [Transaction total : 6890 Insert(s) : 0 Update(s) : 6890 Delete(s) : 0] +----------------------+----------------------+----------------------+----------------------+ Timestamp : #150116 13:42:42 Table : `sakila`.`country` Query Type : DELETE 1 row(s) affected Timestamp : #150116 13:42:48 Table : `sakila`.`city` Query Type : DELETE 1 row(s) affected Timestamp : #150116 13:42:53 Table : `sakila`.`address` Query Type : DELETE 2 row(s) affected [Transaction total : 4 Insert(s) : 0 Update(s) : 0 Delete(s) : 4] +----------------------+----------------------+----------------------+----------------------+

See how nicely our script has summarized the information logged in binary log. For the last transaction, it shows 3 rows that corresponds to each statement executed within transaction and then the final summary of transaction i.e. transaction affected 4 rows in total and all of them were deleted.

This was how we can summarize MySQL row-based binary logs in a more readable format using a simple awk script. This will save you time whenever you need to decode the binary logs for troubleshooting. Now I’ll show you how this summarized information can help answer some basic but important questions.

Q1 : Which tables received highest number of insert/update/delete statements?

./summarize_binlogs.sh | grep Table |cut -d':' -f5| cut -d' ' -f2 | sort | uniq -c | sort -nr 3 `sakila`.`payment_tmp` 3 `sakila`.`country` 2 `sakila`.`city` 1 `sakila`.`address`

Q2 : Which table received the highest number of DELETE queries?

./summarize_binlogs.sh | grep -E 'DELETE' |cut -d':' -f5| cut -d' ' -f2 | sort | uniq -c | sort -nr 2 `sakila`.`country` 1 `sakila`.`payment_tmp` 1 `sakila`.`city` 1 `sakila`.`address`

Q3: How many insert/update/delete queries executed against sakila.country table?

./summarize_binlogs.sh | grep -i '`sakila`.`country`' | awk '{print $7 " " $11}' | sort -k1,2 | uniq -c 2 `sakila`.`country` DELETE 1 `sakila`.`country` INSERT

Q4: Give me the top 3 statements which affected maximum number of rows.

./summarize_binlogs.sh | grep Table | sort -nr -k 12 | head -n 3 Timestamp : #150116 13:42:13 Table : `sakila`.`payment_tmp` Query Type : INSERT 16049 row(s) affected Timestamp : #150116 13:42:28 Table : `sakila`.`payment_tmp` Query Type : UPDATE 6890 row(s) affected Timestamp : #150116 13:42:20 Table : `sakila`.`payment_tmp` Query Type : DELETE 5001 row(s) affected

See how easy it is to identify the large transactions.

Q5 : Find DELETE queries that affected more than 1000 rows.

./summarize_binlogs.sh | grep -E 'DELETE' | awk '{if($12>1000) print $0}' Timestamp : #150116 13:42:20 Table : `sakila`.`payment_tmp` Query Type : DELETE 5001 row(s) affected

If we want to get all queries that affected more than 1000 rows.

./summarize_binlogs.sh | grep -E 'Table' | awk '{if($12>1000) print $0}' Timestamp : #150116 13:42:13 Table : `sakila`.`payment_tmp` Query Type : INSERT 16049 row(s) affected Timestamp : #150116 13:42:20 Table : `sakila`.`payment_tmp` Query Type : DELETE 5001 row(s) affected Timestamp : #150116 13:42:28 Table : `sakila`.`payment_tmp` Query Type : UPDATE 6890 row(s) affected

Conclusion

The information logged in binary logs is really helpful to understand our write workload. We used mysqlbinlog + awk to present the binary log contents in more readable format. Further we used the summarized information to answer some of the important questions.

The post Identifying useful info from MySQL row-based binary logs appeared first on MySQL Performance Blog.

Looking deeper into InnoDB’s problem with many row versions

Mo, 2015-01-19 15:06

A few days ago I wrote about MySQL performance implications of InnoDB isolation modes and I touched briefly upon the bizarre performance regression I found with InnoDB handling a large amount of versions for a single row. Today I wanted to look a bit deeper into the problem, which I also filed as a bug.

First I validated in which conditions the problem happens. It seems to happen only in REPEATABLE-READ isolation mode and only in case there is some hot rows which get many row versions during a benchmark run. For example the problem does NOT happen if I run sysbench with “uniform” distribution.

In terms of concurrent selects it also seems to require some very special conditions – you need to have the connection to let some history accumulate by having read snapshot open and then do it again with high history. The exact queries to do that seems not to be that important.

Contrary to what I expected this problem also does not require multiple connections – I can repeat it with only one read and one write connection, which means it can happen in a lot more workloads.

Here is the simplified case to repeat it:

sysbench --num-threads=1 --report-interval=10 --max-time=0 --max-requests=0 --rand-type=uniform --oltp-table-size=1 --mysql-user=root --mysql-password= --mysql-db=sbinnodb --test=/usr/share/doc/sysbench/tests/db/update_index.lua run

It is repeatable on the table with just 1 row where this row is very hot!

Select query sequence:

begin; select c from sbtest1 limit 1; select sleep(20); commit; begin; select c from sbtest1 limit 1; select sleep(300); commit;

It is interesting though, in this case it does not look like it is enough to open a consistent snapshot – it is only when I run the query on the same table as the update workload is running (I assume touches the same data) when the issue happens.

Let’s look at some graphs:

The transaction rate indeed suffers dramatically – in this case going down more than 100x from close to 15K to around 60 in the lowest point.

It is interesting that CPU consumption is reduced but not as much as the throughput.

This is something I find the most enlightening about what seems to happen. The number of buffer pool read requests increases dramatically where the number of transactions goes down. If we do the math we have 940K buffer pool reads per 14.5K updates in the normal case giving us 65 buffer reads per update, which goes up to 37000 per update when we have regression happening. Which is a dramatic change and it points to something that goes badly wrong.

History size is of interest. We can see it grows quickly first – this is when we have the first transaction and sleep(20) and when it grows very slowly when the second transaction is open as update rate is low. Finally it goes to zero very quickly once the transaction is committed. What is worth noting is the history length here peaks at just 280K which is really quite trivial size.

The InnoDB contention graph is interesting from 2 view points. First it shows that the contention picture changes at the time when the transaction is held open and also right afterward when history is being worked out.

If you look at this graph focused only on the os_wait metrics we can see that mutex_os_waits goes down during the problem while x-locks os waits increases significantly. This means there are some very long exclusive lock os-waits happening which is indicative of the long waits. We can’t actually lock times from status variables – we would need to get data from performance schema for that which unfortunately does not cover key mutexes, and which I unfortunately can’t graph easily yet.

Lets look at some more data.

From the great processlist from sys-schema we can get:

*************************** 4. row *************************** thd_id: 536 conn_id: 516 user: root@localhost db: sbinnodb command: Query state: updating time: 0 current_statement: UPDATE sbtest1 SET k=k+1 WHERE id=1 lock_latency: 36.00 us rows_examined: 1 rows_sent: 0 rows_affected: 0 tmp_tables: 0 tmp_disk_tables: 0 full_scan: NO last_statement: NULL last_statement_latency: NULL last_wait: wait/io/table/sql/handler last_wait_latency: Still Waiting source: handler.cc:7692

Which is unfortunately not very helpful as it does not show the actual lock which is being waited on – just saying that it is waiting somewhere inside storage engine call which is obvious.

We can get some good summary information in the other table:

mysql> select * from waits_global_by_latency; +------------------------------------------------------+-----------+---------------+-------------+-------------+ | events | total | total_latency | avg_latency | max_latency | +------------------------------------------------------+-----------+---------------+-------------+-------------+ | wait/synch/cond/sql/Item_func_sleep::cond | 384 | 00:31:27.18 | 4.91 s | 5.00 s | | wait/synch/rwlock/innodb/index_tree_rw_lock | 239460870 | 00:12:13.82 | 3.06 us | 495.27 ms | | wait/synch/mutex/sql/THD::LOCK_thd_data | 601160083 | 36.48 s | 60.41 ns | 643.18 us | | wait/io/table/sql/handler | 1838 | 29.12 s | 15.84 ms | 211.21 ms | | wait/synch/mutex/mysys/THR_LOCK::mutex | 240456674 | 16.57 s | 68.86 ns | 655.16 us | | wait/synch/cond/sql/MDL_context::COND_wait_status | 15 | 14.11 s | 940.37 ms | 999.36 ms | | wait/synch/mutex/innodb/trx_mutex | 360685304 | 10.52 s | 29.11 ns | 4.01 ms | | wait/synch/mutex/innodb/trx_undo_mutex | 120228229 | 3.87 s | 31.93 ns | 426.16 us | | wait/io/file/innodb/innodb_data_file | 399 | 1.46 s | 3.66 ms | 11.21 ms | | wait/synch/mutex/innodb/buf_pool_flush_state_mutex | 32317 | 587.10 ms | 18.17 us | 11.27 ms | | wait/synch/rwlock/innodb/fil_space_latch | 4154178 | 386.96 ms | 92.96 ns | 74.57 us | | wait/io/file/innodb/innodb_log_file | 987 | 271.76 ms | 275.34 us | 14.23 ms | | wait/synch/rwlock/innodb/hash_table_locks | 8509138 | 255.76 ms | 30.05 ns | 53.41 us | | wait/synch/mutex/innodb/srv_threads_mutex | 11938747 | 249.49 ms | 20.66 ns | 15.06 us | | wait/synch/rwlock/innodb/trx_purge_latch | 8488041 | 181.01 ms | 21.28 ns | 23.51 us | | wait/synch/rwlock/innodb/dict_operation_lock | 232 | 100.48 ms | 433.09 us | 61.88 ms | | wait/synch/rwlock/innodb/checkpoint_lock | 10 | 32.34 ms | 3.23 ms | 8.38 ms | | wait/io/socket/sql/client_connection | 2171 | 30.87 ms | 14.22 us | 3.95 ms | | wait/synch/mutex/innodb/log_sys_mutex | 260485 | 6.57 ms | 25.04 ns | 52.00 us | | wait/synch/rwlock/innodb/btr_search_latch | 4982 | 1.71 ms | 343.05 ns | 17.83 us | | wait/io/file/myisam/kfile | 647 | 1.70 ms | 2.63 us | 39.28 us | | wait/synch/rwlock/innodb/dict_table_stats | 46323 | 1.63 ms | 35.06 ns | 6.55 us | | wait/synch/mutex/innodb/os_mutex | 11410 | 904.63 us | 79.19 ns | 26.67 us | | wait/lock/table/sql/handler | 1838 | 794.21 us | 431.94 ns | 9.70 us | | wait/synch/rwlock/sql/MDL_lock::rwlock | 7056 | 672.34 us | 95.15 ns | 53.29 us | | wait/io/file/myisam/dfile | 139 | 518.50 us | 3.73 us | 31.61 us | | wait/synch/mutex/sql/LOCK_global_system_variables | 11692 | 462.58 us | 39.44 ns | 363.39 ns | | wait/synch/mutex/innodb/rseg_mutex | 7238 | 348.25 us | 47.89 ns | 10.38 us | | wait/synch/mutex/innodb/lock_mutex | 5747 | 222.13 us | 38.50 ns | 9.84 us | | wait/synch/mutex/innodb/trx_sys_mutex | 4601 | 187.43 us | 40.69 ns | 326.15 ns | | wait/synch/mutex/sql/LOCK_table_cache | 2173 | 185.14 us | 85.14 ns | 10.02 us | | wait/synch/mutex/innodb/fil_system_mutex | 3481 | 144.60 us | 41.32 ns | 375.91 ns | | wait/synch/rwlock/sql/LOCK_grant | 1217 | 121.86 us | 99.85 ns | 12.07 us | | wait/synch/mutex/innodb/flush_list_mutex | 3191 | 108.82 us | 33.80 ns | 8.81 us | | wait/synch/mutex/innodb/purge_sys_bh_mutex | 3600 | 83.52 us | 23.16 ns | 123.95 ns | | wait/synch/mutex/sql/MDL_map::mutex | 1456 | 75.02 us | 51.33 ns | 8.78 us | | wait/synch/mutex/myisam/MYISAM_SHARE::intern_lock | 1357 | 55.55 us | 40.69 ns | 320.51 ns | | wait/synch/mutex/innodb/log_flush_order_mutex | 204 | 40.84 us | 200.01 ns | 9.42 us | | wait/io/file/sql/FRM | 16 | 31.16 us | 1.95 us | 16.40 us | | wait/synch/mutex/mysys/BITMAP::mutex | 378 | 30.52 us | 80.44 ns | 9.16 us | | wait/synch/mutex/innodb/dict_sys_mutex | 463 | 24.15 us | 51.96 ns | 146.17 ns | | wait/synch/mutex/innodb/buf_pool_LRU_list_mutex | 293 | 23.37 us | 79.50 ns | 313.94 ns | | wait/synch/mutex/innodb/buf_dblwr_mutex | 398 | 22.60 us | 56.65 ns | 380.61 ns | | wait/synch/rwlock/myisam/MYISAM_SHARE::key_root_lock | 388 | 14.86 us | 38.19 ns | 254.16 ns | | wait/synch/mutex/sql/LOCK_plugin | 250 | 14.30 us | 56.97 ns | 137.41 ns | | wait/io/socket/sql/server_unix_socket | 2 | 9.35 us | 4.67 us | 4.72 us | | wait/synch/mutex/sql/THD::LOCK_temporary_tables | 216 | 8.97 us | 41.32 ns | 465.74 ns | | wait/synch/mutex/sql/hash_filo::lock | 151 | 8.35 us | 55.09 ns | 150.87 ns | | wait/synch/mutex/mysys/THR_LOCK_open | 196 | 7.84 us | 39.75 ns | 110.80 ns | | wait/synch/mutex/sql/TABLE_SHARE::LOCK_ha_data | 159 | 6.23 us | 39.13 ns | 108.92 ns | | wait/synch/mutex/innodb/lock_wait_mutex | 29 | 5.38 us | 185.30 ns | 240.38 ns | | wait/synch/mutex/innodb/ibuf_mutex | 29 | 5.26 us | 181.23 ns | 249.46 ns | | wait/synch/mutex/sql/LOCK_status | 62 | 4.12 us | 66.36 ns | 127.39 ns | | wait/synch/mutex/sql/LOCK_open | 109 | 4.05 us | 36.93 ns | 105.79 ns | | wait/io/file/sql/dbopt | 3 | 3.34 us | 1.11 us | 1.99 us | | wait/synch/mutex/innodb/buf_pool_free_list_mutex | 30 | 1.58 us | 52.58 ns | 106.73 ns | | wait/synch/mutex/innodb/srv_innodb_monitor_mutex | 31 | 1.38 us | 44.45 ns | 89.52 ns | | wait/synch/mutex/sql/LOCK_thread_count | 33 | 1.10 us | 33.18 ns | 50.71 ns | | wait/synch/mutex/sql/LOCK_prepared_stmt_count | 32 | 1.10 us | 34.12 ns | 67.92 ns | | wait/synch/mutex/innodb/srv_sys_mutex | 42 | 1.07 us | 25.35 ns | 49.14 ns | | wait/synch/mutex/mysys/KEY_CACHE::cache_lock | 24 | 1.02 us | 42.26 ns | 103.60 ns | | wait/synch/mutex/sql/MDL_wait::LOCK_wait_status | 18 | 544.62 ns | 30.05 ns | 42.57 ns | | wait/synch/rwlock/sql/CRYPTO_dynlock_value::lock | 2 | 509.25 ns | 254.47 ns | 287.02 ns | | wait/synch/rwlock/sql/LOCK_dboptions | 6 | 262.92 ns | 43.82 ns | 84.82 ns | | wait/synch/rwlock/sql/MDL_context::LOCK_waiting_for | 4 | 262.92 ns | 65.73 ns | 103.60 ns | | wait/synch/mutex/sql/LOCK_connection_count | 4 | 238.51 ns | 59.47 ns | 123.01 ns | | wait/synch/mutex/sql/LOCK_sql_rand | 2 | 172.15 ns | 86.08 ns | 94.84 ns | | wait/synch/rwlock/sql/LOCK_system_variables_hash | 2 | 141.16 ns | 70.43 ns | 78.25 ns | | wait/synch/rwlock/sql/gtid_commit_rollback | 2 | 95.47 ns | 47.58 ns | 51.65 ns | | wait/synch/mutex/innodb/autoinc_mutex | 2 | 90.14 ns | 45.07 ns | 45.07 ns | | wait/synch/mutex/sql/LOCK_thd_remove | 2 | 85.14 ns | 42.57 ns | 52.58 ns | | wait/synch/mutex/innodb/ibuf_bitmap_mutex | 1 | 76.37 ns | 76.37 ns | 76.37 ns | | wait/synch/mutex/sql/LOCK_xid_cache | 2 | 62.91 ns | 31.30 ns | 34.43 ns | +------------------------------------------------------+-----------+---------------+-------------+-------------+ 73 rows in set (0.00 sec)

Which shows a couple of hotspots – the well-known index_tree_rw_lock hotspot which should be gone in MySQL 5.7 as well as trx_mutex and trx_undo_mutexes. It is especially worth noting the almost 500ms which this index tree lw_lock was waited at max (this is the data for a couple of minutes only, so it it is unlikely to be a very rare outlier). This hints to me that in the case of many versions our index_tree_rw_lock might be held for a prolonged period of time.

What is interesting is that the reliable “SHOW ENGINE INNODB STATUS” remains quite handy:

---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 58847289 --Thread 140386357991168 has waited at btr0cur.cc line 304 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fb0bea2ca40 '&block->lock' a writer (thread id 140386454755072) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file buf0flu.cc line 1082 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/row /row0row.cc line 815 --Thread 140386374776576 has waited at btr0cur.cc line 577 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fade8077f98 '&new_index->lock' a writer (thread id 140386357991168) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file btr0cur.cc line 586 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/btr /btr0cur.cc line 577 --Thread 140386324420352 has waited at btr0cur.cc line 577 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fade8077f98 '&new_index->lock' a writer (thread id 140386357991168) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file btr0cur.cc line 586 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/btr /btr0cur.cc line 577 --Thread 140386332813056 has waited at btr0cur.cc line 577 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fade8077f98 '&new_index->lock' a writer (thread id 140386357991168) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file btr0cur.cc line 586 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/btr /btr0cur.cc line 577 --Thread 140386445960960 has waited at btr0cur.cc line 586 for 0.0000 seconds the semaphore: S-lock on RW-latch at 0x7fade8077f98 '&new_index->lock' a writer (thread id 140386357991168) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file btr0cur.cc line 586 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/btr /btr0cur.cc line 577 --Thread 140386366383872 has waited at btr0cur.cc line 577 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fade8077f98 '&new_index->lock' a writer (thread id 140386357991168) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file btr0cur.cc line 586 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/btr /btr0cur.cc line 577 --Thread 140386341205760 has waited at btr0cur.cc line 577 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fade8077f98 '&new_index->lock' a writer (thread id 140386357991168) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file btr0cur.cc line 586 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/btr /btr0cur.cc line 577 --Thread 140386349598464 has waited at btr0cur.cc line 577 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fade8077f98 '&new_index->lock' a writer (thread id 140386357991168) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file btr0cur.cc line 586 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/btr /btr0cur.cc line 577

Another sample….

---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 61753307 --Thread 140386332813056 has waited at row0row.cc line 815 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fb0bea2cd40 '&block->lock' a writer (thread id 140386454755072) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file buf0flu.cc line 1082 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/row/row0row.cc line 815 --Thread 140386366383872 has waited at row0row.cc line 815 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fb0bea2cd40 '&block->lock' a writer (thread id 140386454755072) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file buf0flu.cc line 1082 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/row/row0row.cc line 815 --Thread 140386341205760 has waited at row0row.cc line 815 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fb0bea2cd40 '&block->lock' a writer (thread id 140386454755072) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file buf0flu.cc line 1082 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/row/row0row.cc line 815 --Thread 140386374776576 has waited at row0row.cc line 815 for 0.0000 seconds the semaphore: X-lock on RW-latch at 0x7fb0bea2cd40 '&block->lock' a writer (thread id 140386454755072) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file buf0flu.cc line 1082 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/row/row0row.cc line 815 --Thread 140386445960960 has waited at btr0cur.cc line 257 for 0.0000 seconds the semaphore: X-lock (wait_ex) on RW-latch at 0x7fb0bea2f2c0 '&block->lock' a writer (thread id 140386445960960) has reserved it in mode wait exclusive number of readers 1, waiters flag 0, lock_word: ffffffffffffffff Last time read locked in file btr0cur.cc line 257 Last time write locked in file /mnt/workspace/percona-server-5.6-debian-binary/label_exp/ubuntu-trusty-64bit/percona-server-5.6-5.6.21-70.1/storage/innobase/btr/btr0cur.cc line 257 OS WAIT ARRAY INFO: signal count 45260762 Mutex spin waits 1524575466, rounds 5092199292, OS waits 43431355 RW-shared spins 14500456, rounds 258217222, OS waits 3721069 RW-excl spins 37764438, rounds 730059390, OS waits 12592324 Spin rounds per wait: 3.34 mutex, 17.81 RW-shared, 19.33 RW-excl

The first one shows mostly index lock contention which we have already seen. The second, though, shows a lot of contention on the block lock, which is something that is not covered by performance schema instrumentation in MySQL 5.6.

Now to tell the truth in this 2nd thread test case it is not your typical case of contention – unlike the case with 64 threads we do not see that drastic CPU drop and it still stays above 25%, the single thread fully saturated should show on this system. This is however where DBA level profiling gets tough with MySQL – as I mentioned the only indication of excessive activity going on is a high number of buffer pool requests – there is no instrumentation which I’m aware of that tells us anything around scanning many old row versions in undo space. Perhaps some more metrics around this syssystem need to be added to INNODB_METRICS?

A good tool to see CPU consumption which both developers and DBAs can use is oprofile, which is of low enough overhead to use in production. Note that to get any meaningful information about the CPU usage inside the program you need to have debug systems installed. For Percona Server 5.6 On Ubuntu you can do apt-get install percona-server-5.6-dbg

To profile just the MySQL Process you can do:

root@ts140i:~# operf --pid 8970 operf: Press Ctl-c or 'kill -SIGINT 9113' to stop profiling operf: Profiler started ^C Profiling done.

To get top symbols (functions) called in mysqld I can do:

root@ts140i:~# opreport -l | more Using /root/oprofile_data/samples/ for samples directory. warning: /no-vmlinux could not be found. warning: [vdso] (tgid:8970 range:0x7fffba5fe000-0x7fffba5fffff) could not be found. CPU: Intel Haswell microarchitecture, speed 3.201e+06 MHz (estimated) Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit mask of 0x00 (No unit mask) count 100000 samples % image name symbol name 212162 12.4324 mysqld buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*) 204230 11.9676 mysqld dict_table_copy_types(dtuple_t*, dict_table_t const*) 179783 10.5351 no-vmlinux /no-vmlinux 144335 8.4579 mysqld trx_undo_update_rec_get_update(unsigned char*, dict_index_t*, unsigned long, unsigned long, unsigned long, unsigned long, trx_t*, mem_block_info_t*, upd_t **) 95984 5.6245 mysqld trx_undo_prev_version_build(unsigned char const*, mtr_t*, unsigned char const*, dict_index_t*, unsigned long*, mem_block_info_t*, unsigned char**) 78785 4.6167 mysqld row_build(unsigned long, dict_index_t const*, unsigned char const*, unsigned long const*, dict_table_t const*, dtuple_t const*, unsigned long const*, row_ ext_t**, mem_block_info_t*) 76656 4.4919 libc-2.19.so _int_free 63040 3.6941 mysqld rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**) 52794 3.0937 mysqld mtr_commit(mtr_t*)

Which points to some hot functions – quite as expected we see some functions working with undo space here. In some cases it is also helpful to look at the call graph to understand where functions are being called if it is not clear.

Now in many cases looking at oprofile report it is hard to figure out what is “wrong” without having the baseline. In this case we can look at the oprofile run for sysbench alone:

root@ts140i:~# opreport -l | more Using /root/oprofile_data/samples/ for samples directory. warning: /no-vmlinux could not be found. warning: [vdso] (tgid:8970 range:0x7fffba5fe000-0x7fffba5fffff) could not be found. CPU: Intel Haswell microarchitecture, speed 3.201e+06 MHz (estimated) Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit mask of 0x00 (No unit mask) count 100000 samples % image name symbol name 1331386 28.4544 no-vmlinux /no-vmlinux 603873 12.9060 mysqld ut_delay(unsigned long) 158428 3.3859 mysqld buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*) 88172 1.8844 mysqld my_timer_cycles 75948 1.6232 mysqld srv_worker_thread 74350 1.5890 mysqld MYSQLparse(THD*) 68075 1.4549 mysqld mutex_spin_wait(void*, bool, char const*, unsigned long) 59321 1.2678 mysqld que_run_threads(que_thr_t*) 59152 1.2642 mysqld start_mutex_wait_v1 57495 1.2288 mysqld rw_lock_x_lock_func(rw_lock_t*, unsigned long, char const*, unsigned long, bool, bool) 53133 1.1356 mysqld mtr_commit(mtr_t*) 44404 0.9490 mysqld end_mutex_wait_v1 40226 0.8597 libpthread-2.19.so pthread_mutex_lock 38889 0.8311 mysqld log_block_calc_checksum_innodb(unsigned char const*)

As you see this report is very different in terms of top functions.

Final thoughts: I had 2 purposes with this blog post. First, I hope it will contain some helpful information for developers so this bug can be fixed at least in MySQL 5.7. It is quite a nasty one as it can come out of nowhere if the application unexpectedly develops hot rows. Second, I hope it will show some of the methods you can use to capture and analyze data about MySQL performance.

The post Looking deeper into InnoDB’s problem with many row versions appeared first on MySQL Performance Blog.

FOSDEM 2015: MySQL and Friends Community Dinner!

Fr, 2015-01-16 08:00

As you may already be aware, FOSDEM and its wonderful MySQL and Friends track are once again descending upon the campus of the ULB in Brussels, Belgium. Logically, a traditional MySQL and Friends Community Dinner must follow! Signups for that dinner, on January 31, are now available, so be sure to get your tickets before they run out.

As 2015 heralds the 20th anniversary of MySQL, it stands to reason we would love to mark the occasion with our biggest and best edition yet!

With the help of some wonderful sponsors, your hosts are looking forward to welcoming you for a night to remember. As such, brace yourselves for a feast prepared for the community, by the community. That’s right, we will be firing up the pizza ovens and serve you all with the best pizzas Belgium has to offer.

The listed ticket price includes all-you-can-eat pizza (or until we run out… go ahead, we dare you), as well as a great selection of Belgian specialty beers and other beverages. We’ll make sure that vegetarians have plenty of options, but anyone intending to join us with special dietary requirements, please let us know ahead of time!We’re looking forward to meeting you all again at FOSDEM 2015 and the Community Dinner. See you then!From the Party-Squad – Liz van Dijk, Dimitri Vanoverbeke and Kenny GrypSponsorsOnce again, we want to thank our generous sponsors, whose help makes this affordable at such a great price.On that subject, we would like to point out that we will not be able to get an exact fix on the full cost until we have a full list of attendees, so with that in mind, the price we’ve set is based on the assumption of a certain amount of people attending. If the amount of people ends lower than our target, any remaining funds will be donated to the FOSDEM organization. FOSDEM, by the way, is a free, developer-oriented annual event attracting more than 5,000 geeks from around the world.Community Sponsors:

 

Other Sponsors:

ICAB Brussels – Business and Technology Incubator

Wondering how to get there from FOSDEM?

The venue itself is located very close to the VUB. You can find the route to get there right here.

The total distance from the ULB campus is about 2.3km, so you could walk there, but it might be more comfortable to take the tram.

– Tram 25 departs from the “ULB” stop regularly, and will take you up to “Hansen-Soulie”, where you need to get out, and walk the remaining 200m. The tram ride takes about 11 minutes.

The post FOSDEM 2015: MySQL and Friends Community Dinner! appeared first on MySQL Performance Blog.

Hyper-threading – how does it double CPU throughput?

Do, 2015-01-15 08:00

The other day a customer asked me to do capacity planning for their web server farm. I was looking at the CPU graph for one of the web servers that had Hyper-threading switched ON and thought to myself: “This must be quite a misleading graph – it shows 30% CPU usage. It can’t really be that this server can handle 3 times more work?”

Or can it?

I decided to do what we usually do in such case – I decided to test it and find out the truth. Turns out – there’s more to it than meets the eye.

How Intel Hyper-Threading works

Before we get to my benchmark results, let’s talk a little bit about hyper-threading. According to Intel, Intel® Hyper-Threading Technology (Intel® HT Technology) uses processor resources more efficiently, enabling multiple threads to run on each core. As a performance feature, Intel HT Technology also increases processor throughput, improving overall performance on threaded software.

Sounds almost like magic, but in reality (and correct me if I’m wrong), what HT does essentially is – by presenting one CPU core as two CPUs (threads rather), it allows you to offload task scheduling from kernel to CPU.

So for example if you just had one physical CPU core and two tasks with the same priority running in parallel, the kernel would have to constantly switch the context so that both tasks get a fair amount of CPU time. If, however, you have the CPU presented to you as two CPUs, the kernel can give each task a CPU and take a vacation.

On the hardware level, it will still be one CPU doing the same amount of work, but there maybe some optimization to how that work is going to be executed.

My hypothesis

Here’s the problem that was driving me nuts: if HT does NOT actually give you twice more power and yet the system represents statistics for each CPU thread separately, then at 50% CPU utilization (as per mpstat on Linux), the CPU should be maxed out.

So if I tried to model the scalability of that web server – a 12-core system with HT enabled (represented as 24 CPUs on a system), assuming perfect linear scalability, here’s how it should look:

Throughput (requests per second) | 9 | ,+++++++++++++++ | + | + 6 | + | + | + 3 | + | + | + 0 '-----+----+----+----+---- 1 6 12 18 24

In the example above, single CPU thread could process the request in 1.2s, which is why you see it max out at 9-10 requests/sec (12/1.2).

From the user perspective, this limitation would hit VERY unexpectedly, as one would expect 50% utilization to be… well, exactly that – 50% utilization.

In fact, the CPU utilization graph would look even more frustrating. For example if I were increasing the number of parallel requests linearly from 1 to 24, here’s how that relationship should look:

CPU utilization: 100% | ++++++++++++++ | . | . | . | . 50% | . | + | + | + | + 0% '----+----+----+----+---- 0 6 12 18 24

Hence CPU utilization would skyrocket right at 12 cores from 50% to 100%, because in fact the system CPU would be 100% utilized at this point.

What happens in reality

Naturally, I decided to run a benchmark and see if my assumptions are correct. The benchmark was pretty basic – I wrote a CPU-intensive php script, that took 1.2s to execute on the CPU I was testing this, and bashed it over http (apache) with ab at increasing concurrency. Here’s the result:

Raw data can be found here.

If this does not blow your mind, please go over the facts again and then back at the graph.

Still not sure why do I find this interesting? Let me explain. If you look carefully, initially – at concurrency of 1 through 8 – it scales perfectly. So if you only had data for threads 1-8 (and you knew processes don’t incur coherency delays due to shared data structures), you’d probably predict that it will scale linearly until it reaches ~10 requests/sec at 12 cores, at which point adding more parallel requests would not have any benefits as the CPU would be saturated.

What happens in reality, though, is that past 8 parallel threads (hence, past 33% virtual CPU utilization), execution time starts to increase and maximum performance is only achieved at 24-32 concurrent requests. It looks like at the 33% mark there’s some kind of “throttling” happening.

In other words, to avoid a sharp performance hit past 50% CPU utilization, at 33% virtual thread utilization (i.e. 66% actual CPU utilization), the system gives the illusion of a performance limit – execution slows down so that the system only reaches the saturation point at 24 threads (visually, at 100% CPU utilization).

Naturally then the question is – does it still make sense to run hyper-threading on a multi-core system? I see at least two drawbacks:

1. You don’t see the real picture of how utilized your system really is – if the CPU graph shows 30% utilization, your system may well be 60% utilized already.
2. Past 60% physical utilization, execution speed of your requests will be throttled intentionally in order to provide higher system throughput.

So if you are optimizing for higher throughput – that may be fine. But if you are optimizing for response time, then you may consider running with HT turned off.

Did I miss something?

The post Hyper-threading – how does it double CPU throughput? appeared first on MySQL Performance Blog.

Percona XtraBackup 2.2.8 is now available

Mi, 2015-01-14 14:36

Percona is glad to announce the release of Percona XtraBackup 2.2.8 on January 14, 2015. Downloads are available from our download site or Percona Software Repositories.

Percona XtraBackup enables MySQL backups without blocking user queries, making it ideal for companies with large data sets and mission-critical applications that cannot tolerate long periods of downtime. Offered free as an open source solution, Percona XtraBackup drives down backup costs while providing unique features for MySQL backups.

New Features:

  • Percona XtraBackup has been rebased on MySQL 5.6.22.

Bugs Fixed:

  • Incremental backups would fail if the number of undo tablespaces (innodb_undo_tablespaces) was more than 1. This was caused by innobackupex removing the undo tablespaces during the prepare phase. Bug fixed #1363234.
  • Fixed multiple memory leaks detected by AddressSanitizer. Bug fixed #1395143.
  • innobackupex could fail when preparing backup that was taken from Percona Server 5.5 with log files (innodb_log_file_size) bigger than 4G. The root cause was that the last checkpoint LSN offset in log group is stored at different offsets in ibdata1 for Percona Server 5.5 and MySQL 5.6 when the total size of log files is greater than 4G. Bug fixed #1403237.
  • Percona XtraBackup out-of-source builds failed. Bug fixed #1402450.

Release notes with all the bugfixes for Percona XtraBackup 2.2.8 are available in our online documentation. Bugs can be reported on the launchpad bug tracker. Percona XtraBackup is an open source, free MySQL hot backup software that performs non-blocking backups for InnoDB and XtraDB databases.

The post Percona XtraBackup 2.2.8 is now available appeared first on MySQL Performance Blog.

MySQL performance implications of InnoDB isolation modes

Mi, 2015-01-14 11:00

Over the past few months I’ve written a couple of posts about dangerous debt of InnoDB Transactional History and about the fact MVCC can be the cause of severe MySQL performance issues. In this post I will cover a related topic – InnoDB Transaction Isolation Modes, their relationship with MVCC (multi-version concurrency control) and how they impact MySQL performance.

The MySQL Manual provides a decent description of transaction isolation modes supported by MySQL – I will not repeat it here but rather focus on performance implications.

SERIALIZABLE – This is the strongest isolation mode to the point it essentially defeats Multi-Versioning making all SELECTs locking causing significant overhead both in terms of lock management (setting locks is expensive) and the concurrency you can get. This mode is only used in very special circumstances among MySQL Applications.

REPEATABLE READ – This is default isolation level and generally it is quite nice and convenient for the application. It sees all the data at the time of the first read (assuming using standard non-locking reads). This however comes at high cost – InnoDB needs to maintain transaction history up to the point of transaction start, which can be very expensive. The worse-case scenario being applications with a high level of updates and hot rows – you really do not want InnoDB to deal with rows which have hundreds of thousands of versions.

In terms of performance impact, both reads and writes can be impacted. For select queries traversing multiple row versions is very expensive but so it is also for updates, especially as version control seems to cause severe contention issues in MySQL 5.6

Here is example: I ran sysbench for a completely in-memory data set and when start transaction and run full table scan query couple of times while keeping transaction open:

sysbench --num-threads=64 --report-interval=10 --max-time=0 --max-requests=0 --rand-type=pareto --oltp-table-size=80000000 --mysql-user=root --mysql-password= --mysql-db=sbinnodb --test=/usr/share/doc/sysbench/tests/db/update_index.lua run

As you can see the write throughput drops drastically and stays low at all times when transaction is open, and not only when the query is running. This is perhaps the worse-case scenario I could find which happens when you have select outside of transaction followed by a long transaction in repeatable-read isolation mode. Though you can see regression in other cases, too.

Here is the set of queries I used if someone wants to repeat the test:

select avg(length(c)) from sbtest1; begin; select avg(length(c)) from sbtest1; select sleep(300); commit;

Not only is Repeatable Read the default isolation level, it is also used for logical backups with InnoDB – think mydumper or mysqldump –single-transaction
These results show such backup methods not only can’t be used with large data sets due to long recovery time but also can’t be used with some high write environments due to their performance impact.

READ COMMITTED mode is similar to REPEATABLE READ with the essential difference being what versions are not kept to the start of first read in transaction, but instead to the start of the current statement. As such using this mode allows InnoDB to maintain a lot less versions, especially if you do not have very long running statements. If you have some long running selects – such as reporting queries performance impact can be still severe.

In general I think good practice is to use READ COMITTED isolation mode as default and change to REPEATABLE READ for those applications or transactions which require it.

READ UNCOMMITTED – I think this is the least understood isolation mode (not a surprise as it only has 2 lines of documentation about it) which only describe it from the logical point of view. If you’re using this isolation mode you will see all the changes done in the database as they happen, even those by transactions which have not been yet committed. One nice use case for this isolation mode is what you can “watch” as some large scale UPDATE statements are happening with dirty reads showing which rows have already been changes and which have not.

So this statement shows changes that have not been committed yet and might not ever be committed if the transaction doing them runs into some errors so – this mode should be used with extreme care. There are a number of cases though when we do not need 100% accurate data and in this case this mode becomes very handy.

So how does READ UNCOMMITTED behave from a performance point of view? In theory InnoDB could purge row versions even if they have been created after the start of the statement in READ UNCOMMITTED mode. In practice, due to a bug or some intricate implementation detail it does not do that – row versions still will be kept to the start of the statement. So if you run very long running SELECT in READ UNCOMMITTED statements you will get a large amount of row versions created, just as if you would use READ COMMITTED. No win here.

There is an important win from SELECT side – READ UNCOMMITTED isolation mode means InnoDB never needs to go and examine the older row versions – the last row version is always the correct one which can cause dramatic performance improvement especially if the undo space had spilled over to the disk so finding old row versions can cause a lot of IO.

Perhaps the best illustration I discovered with query select avg(k) from sbtest1; ran in parallel with the same update heavy workload stated above. In READ COMMITTED isolation mode it never completes – I assume because new index entries are inserted faster than they are scanned, in case of READ UNCOMMITTED isolation mode it completes in a minute or so.

Final Thoughts: Using InnoDB Isolation modes correctly can help your application to get the best possible performance. Your mileage may vary and in some cases you will see no difference; in others it will be absolutely dramatic. There also seems to be a lot of work to be done in relationship to InnoDB performance with long version history. I hope it will be tackled in the future MySQL version.

The post MySQL performance implications of InnoDB isolation modes appeared first on MySQL Performance Blog.

Percona Live 2015 conference sessions announced!

Di, 2015-01-13 17:01

Today we announced the full conference sessions schedule for April’s Percona Live MySQL Conference & Expo 2015 and this year’s event, once again at the Hyatt Regency Santa Clara and Santa Clara Convention Center, looks to be the biggest yet with networking and learning opportunities for MySQL professionals and enthusiasts at all levels.

Conference sessions will run April 14-16 following each morning’s keynote addresses (the keynotes have yet to be announced). The 2015 conference features a variety of formal tracks and sessions related to high availability, DevOps, programming, performance optimization, replication and backup. They’ll also cover MySQL in the cloud, MySQL and NoSQL, MySQL case studies, security (a very hot topic), and “what’s new” in MySQL.

The sessions will be delivered by top MySQL practitioners at some of the world’s leading MySQL vendors and users, including Oracle, Facebook, Google, LinkedIn, Twitter, Yelp, Percona and MariaDB.

Sessions will include:

  • “Better DevOps with MySQL and Docker,” Sunny Gleason, Founder, SunnyCloud
  • “Big Transactions on Galera Cluster,” Seppo Jaakola, CEO, Codership
  • “Database Defense in Depth,” Geoffrey Anderson, Database Operations Engineer, Box, Inc.
  • “The Database is Down, Now What?” Jeremy Tinley, Senior MySQL Operations Engineer, Etsy.com
  • “Encrypting MySQL data at Google,” Jeremy Cole, Sr. Systems Engineer, and Jonas Oreland, Software Developer, Google
  • “High-Availability using MySQL Fabric,” Mats Kindahl, Senior Principal Software Developer, MySQL Group, Oracle
  • “High Performance MySQL choices in Amazon Web Services: Beyond RDS,” Andrew Shieh, Director of Operations, SmugMug
  • “How to Analyze and Tune MySQL Queries for Better Performance,” Øystein Grøvlen, Senior Principal Software Engineer, Oracle
  • “InnoDB: A journey to the core III,” Davi Arnaut, Sr. Software Engineer, LinkedIn, and Jeremy Cole, Sr. Systems Engineer, Google, Inc.
  • “Meet MariaDB 10.1,” Sergei Golubchik, Chief Architect, MariaDB
  • “MySQL 5.7 Performance: Scalability & Benchmarks,” Dimitri Kravtchuk, MySQL Performance Architect, Oracle
  • “MySQL at Twitter – 2015,” Calvin Sun, Sr. Engineering Manager, and Inaam Rana, Staff Software Engineer, Twitter
  • “MySQL Automation at Facebook Scale,” Shlomo Priymak, MySQL Database Engineer, Facebook
  • “MySQL Cluster Performance Tuning – The 7.4.x Talk,” Johan Andersson CTO and Alex Yu, Vice President of Products, Severalnines AB
  • “MySQL for Facebook Messenger,” Domas Mituzas, Database Engineer, Facebook
  • “MySQL Indexing, How Does It Really Work?” Tim Callaghan, Vice President of Engineering, Tokutek
  • “MySQL in the Hosted Cloud,” Colin Charles, Chief Evangelist, MariaDB
  • “MySQL Security Essentials,” Ronald Bradford, Founder & CEO, EffectiveMySQL
  • “Scaling MySQL in Amazon Web Services,” Mark Filipi, MySQL Team Lead, Pythian
  • “Online schema changes for maximizing uptime,” David Turner, DBA, Dropbox, and Ben Black, DBA, Tango
  • “Upgrading to MySQL 5.6 @ scale,” Tom Krouper, Staff Database Administrator , Twitter

Of course Percona Live 2015 will also include several hours of hands-on, intensive tutorials – led by some of the top minds in MySQL. We had a post talking about the tutorials in more detail last month. Since then we added two more: “MySQL devops: initiation on how to automate MySQL deployment” and “Deploying MySQL HA with Ansible and Vagrant.” And of course Dimitri Vanoverbeke, Liz van Dijk and Kenny Gryp will once again this year host the ever-popular “Operational DBA in a Nutshell! Hands On Tutorial!

Yahoo, VMWare, Box and Yelp are among the industry leaders sponsoring the event, and additional sponsorship opportunities are still available.

Worldwide interest in Percona Live continues to soar, and this year, for the first time, the conference will run in parallel with OpenStack Live 2015, a new Percona conference scheduled for April 13 and 14. That event will be a unique opportunity for OpenStack users and enthusiasts to learn from leading OpenStack experts in the field about top cloud strategies, improving overall cloud performance, and operational best practices for managing and optimizing OpenStack and its MySQL database core.

Best of all, your full Percona Live ticket gives you access to the OpenStack Live conference! So why not save some $$? Early Bird registration discounts are available through Feb. 1, 2015 at 11:30 p.m. PST.

I hope to see you in April!

The post Percona Live 2015 conference sessions announced! appeared first on MySQL Performance Blog.

Percona Server 5.6.22-71.0 is now available

Mo, 2015-01-12 18:07

Percona is glad to announce the release of Percona Server 5.6.22-71.0 on January 12, 2015. Download the latest version from the Percona web site or from the Percona Software Repositories.

Based on MySQL 5.6.22, including all the bug fixes in it, Percona Server 5.6.22-71.0 is the current GA release in the Percona Server 5.6 series. Percona Server is open-source and free – and this is the latest release of our enhanced, drop-in replacement for MySQL. Complete details of this release can be found in the 5.6.22-71.0 milestone on Launchpad.

New Features:

  • Percona Server has implemented improved slow log reporting for queries in stored procedures.
  • TokuDB storage engine package has been updated to version 7.5.4. Percona Server with an older version of TokuDB could hit an early scaling limit when the binary log was enabled. TokuDB 7.5.4 fixes this problem by using the hints supplied by the binary log group commit algorithm to avoid fsync’ing its recovery log during the commit phase of the 2 phase commit algorithm that MySQL uses for transactions when the binary log is enabled.

Bugs Fixed:

  • Debian and Ubuntu init scripts no longer have a hardcoded server startup timeout. This has been done to accommodate situations where server startup takes a very long time, for example, due to a crash recovery or buffer pool dump restore. Bugs fixed #1072538 and #1328262.
  • A read-write workload on compressed InnoDB tables might have caused an assertion error. Bug fixed #1268656.
  • Selecting from GLOBAL_TEMPORARY_TABLES table while running an online ALTER TABLE in parallel could lead to server crash. Bug fixed #1294190.
  • A wrong stack size calculation could lead to a server crash when Performance Schema tables were storing big amount of data or in case of server being under highly concurrent load. Bug fixed #1351148 (upstream #73979).
  • A query on an empty table with a BLOB column may crash the server. Bug fixed #1384568 (upstream #74644).
  • A read-write workload on compressed InnoDB tables might have caused an assertion error. Bug fixed #1395543.
  • If HandlerSocket was enabled, the server would hang during shutdown. Bug fixed #1397859.
  • The default MySQL configuration file, my.cnf, was not installed during a new installation on CentOS. Bug fixed #1405667.
  • The query optimizer did not pick a covering index for some ORDER BY queries. Bug fixed #1394967 (upstream #57430).
  • SHOW ENGINE INNODB STATUS was displaying two identical TRANSACTIONS sections. Bug fixed #1404565.
  • A race condition in Multiple user level locks per connection implementation could cause a deadlock. Bug fixed #1405076.

Other bugs fixed: #1394357, #1337251, #1399174, #1396330 (upstream #74987), and #1401776 (upstream #75189).

Known Issues:
If you’re upgrading TokuDB package on CentOS 5/6 you’ll need to restart the MySQL service after the upgrade, otherwise TokuDB storage engine won’t be initialized.

Release notes for Percona Server 5.6.22-71.0 are available in the online documentation. Please report any bugs on the launchpad bug tracker

The post Percona Server 5.6.22-71.0 is now available appeared first on MySQL Performance Blog.

Percona Server 5.5.41-37.0 is now available

Mo, 2015-01-12 17:43


Percona is glad to announce the release of Percona Server 5.5.41-37.0 on January 9, 2015. Based on MySQL 5.5.41, including all the bug fixes in it, Percona Server 5.5.41-37.0 is now the current stable release in the 5.5 series.

Percona Server is open-source and free. Details of the release can be found in the 5.5.41-37.0 milestone on Launchpad. Downloads are available here and from the Percona Software Repositories.

New Features:

Bugs Fixed:

  • Debian and Ubuntu init scripts no longer have a hardcoded server startup timeout. This has been done to accommodate situations where server startup takes a very long time, for example, due to a crash recovery or buffer pool dump restore. Bugs fixed #1072538 and #1328262.
  • If HandlerSocket was enabled, the server would hang during shutdown. Bug fixed #1319904.
  • Wrong stack calculation could lead to a server crash when Performance Schema tables were storing big amount of data or in case of server being under highly concurrent load. Bug fixed #1351148 (upstream #73979).
  • Values of IP and DB fields in the Audit Log Plugin were incorrect. Bug fixed #1379023.
  • Percona Server 5.5 would fail to build with GCC 4.9.1 (such as bundled with Ubuntu Utopic) in debug configuration. Bug fixed #1396358 (upstream #75000).
  • Default MySQL configuration file, my.cnf, was not installed during the new installation on CentOS. Bug fixed #1405667.
  • A session on a server in mixed mode binlogging would switch to row-based binlogging whenever a temporary table was created and then queried. This switch would last until the session end or until all temporary tables in the session were dropped. This was unnecessarily restrictive and has been fixed so that only the statements involving temporary tables were logged in the row-based format whereas the rest of the statements would continue to use the statement-based logging. Bug fixed #1313901 (upstream #72475).
  • Purging bitmaps exactly up to the last tracked LSN would abort XtraDB changed page tracking. Bug fixed #1382336.
  • mysql_install_db script would silently ignore any mysqld startup failures. Bug fixed #1382782 (upstream #74440).

Other bugs fixed: #1067103, #1394357, #1282599, #1335590, #1369950, #1401791 (upstream #73281), and #1396330 (upstream #74987).

(Please also note that Percona Server 5.6 series is the latest General Availability series and current GA release is 5.6.22-71.0.)

Release notes for Percona Server 5.5.41-37.0 are available in our online documentation. Bugs can be reported on the launchpad bug tracker.

The post Percona Server 5.5.41-37.0 is now available appeared first on MySQL Performance Blog.

Managing data using open source technologies? Learn what’s hot in 2015!

Do, 2015-01-08 20:17

Whether you’re looking at the overall MySQL ecosystem or the all-data management landscape, the choice of technologies has never been larger than it is in 2015.

Having so many options is great but it also can be very hard to make a selection. I’m going to help narrow the list next week during a Webinar titled, “Open Source Technologies you should evaluate in 2015,” January 14 at 10 a.m. PST.

During the hour I’ll share which technologies I think worthy of consideration in 2015 – open source and proprietary technologies that allow you to manage your data easier, increase development pace, scale better and improve availability and security. I’ll also discuss recent developments in MySQL, NoSQL and NewSQL, Cloud and general advances in hardware.

Specifically, some of the areas I’ll address will include:

  • Cloud-based Database as a Service (DBaaS) such as Amazon RDS for MySQL, Amazon RDS for Aurora, Google Cloud, and OpenStack Trove
  • MySQL 5.7
  • Hybrid database environments with MySQL plus MongoDB or other NoSQL solutions
  • Advanced Monitoring capabilities such as Percona Cloud Tools
  • Other performance enhancements such as solid state devices (SSD) and the TokuDB storage engine

I hope to see you next week! (Register now to reserve your spot!)

The post Managing data using open source technologies? Learn what’s hot in 2015! appeared first on MySQL Performance Blog.

Django with time zone support and MySQL

Mi, 2015-01-07 11:00

This is yet another story of Django web-framework with time zone support and pain dealing with python datetimes and MySQL on the backend. In other words, offset-naive vs offset-aware datetimes.

Shortly, more about the problem. After reading the official documentation about the time zones, it makes clear that in order to reflect python datetime in the necessary time zone you need to make it tz-aware first and than show in that time zone.

Here is the first issue: tz-aware in what time zone? MySQL stores timestamps in UTC and converts for storage/retrieval from/to the current time zone. By default, the current time zone is the server’s time, can be changed on MySQL globally, per connection etc. So it becomes not obvious what was tz of the value initially before stored in UTC. If you change server or session tz further, it will lead to more mess. Unlike MySQL, PostgreSQL has timestamp with time zone data type, so Django can auto-detect tz and make datetimes tz-aware automatically featuring tzinfo attribute.

There are many solutions on the web… for example an extension to detect tz on UI by Javascript and pass back to the backend allowing you to work with tz-aware data, however, I need something simpler but mainly with less changes to the existing code base.

Here is my case. The server and MySQL are on UTC. That’s cool and it cuts off the first barrier. I store python datetimes in MySQL timespamp columns also in UTC per database time. Anyway, it is a best practice to store time in UTC. I have some read-only pages on the web app and want to show datetimes according to user’s tz. Looks to be a simple task but dealing with MySQL on backend, all my data coming from models have a naive datetime type assigned. So I need to find a way to easily make all my DateTimeField fields UTC-aware (add tzinfo attribute) and some convenient method of showing datetimes in user’s tz still having an access to UTC or naive datetimes for calculation on the backned. Therefore, I will be still doing all the calculation in UTC and showing TZ-aware values to users only on UI side.

This is an example of middleware that gets user’s tz from the database and sets in the session, so it can be retrieved anywhere using get_current_timezone():

from django.utils.timezone import activate from myapp.models import UserInfo class TimezoneMiddleware(object):     """Middleware that is run on each request before the view is executed. Activate user's timezone for further retrieval by get_current_timezone() or creating tz-aware datetime objects beforehand.     """     def process_request(self, request):         session_tz = request.session.get('timezone') # If tz has been already set in session, let's activate it # and avoid SQL query to retrieve it on each request.         if session_tz:             activate(session_tz)         else:             try:                 # Get user's tz from the database.                 uinfo = UserInfo.objects.get(user_id=request.user.id, user_id__isnull=False)                 if uinfo.timezone: # If tz is configured by user, let's set it for the session.                     request.session['timezone'] = uinfo.timezone                     activate(uinfo.timezone)             except UserInfo.DoesNotExist:                 pass

This is an excerpt from models.py:

from django.db import models from django.utils.timezone import get_current_timezone, make_aware, utc def localize_datetime(dtime):     """Makes DateTimeField value UTC-aware and returns datetime string localized in user's timezone in ISO format. """   tz_aware = make_aware(dtime, utc).astimezone(get_current_timezone())     return datetime.datetime.strftime(tz_aware, '%Y-%m-%d %H:%M:%S') class Messages(models.Model):     id = models.AutoField(primary_key=True)     body = models.CharField(max_length=160L)     created = models.DateTimeField(auto_now_add=True) @property     def created_tz(self):     return localize_datetime(self.created) ...

“Messages” model has “created” field (timestamp in MySQL) and a property “created_tz”. That property reflects “created” in user’s tz using the function localize_datetime() which makes naive datetimes tz(UTC)-aware, converts into user’s tz set on the session level and returns a string in ISO format. In my case, I don’t prefer the default RFC format that includes +00:00 tz portion of datetime with tzinfo attribute or even need tz-aware datetimes to operate with. Same way I can have similar properties in all needed models knowing they can be accessed by the same name with “_tz” suffix.

Taking into account the above, I reference “created” for calculations in views or controllers and “created_tz” in templaetes or for JSON-output.  This way I don’t need to change all references of “created” to something like “make_aware(created, utc)” or datetime.datetime.utcnow() to datetime.datetime.utcnow().replace(tzinfo=pytz.utc) across the code. The code changes in my app will be minimal by introducing a custom property in the model and continue operating with UTC on the raw level:

# views.py # Operating UTC msgs = Messages.objects.filter(created__gt=datetime.datetime.now() - datetime.datetime.timedelta(hours=24))

<! -- HTML template -- > {% for m in msgs %} {{ m.id }}. {{ m.body }} (added on {{ m.created_tz }}) {% endfor %} * All times in user's tz.

I hope this article may help in your findings.
Happy New Year across all time zones!

The post Django with time zone support and MySQL appeared first on MySQL Performance Blog.

Getting mutex information from MySQL’s performance_schema

Di, 2015-01-06 08:00

We have been using SHOW ENGINE INNODB MUTEX command for years. It shows us mutex and rw-lock information that could be useful during service troubleshooting in case of performance problems. As Morgan Tocker announced in his blog post the command will be removed from MySQL 5.7 and we have to use performance_schema to get that info.

The documentation of MySQL also says that most of the command output has been removed from 5.6 and that we can find similar info in performance_schema. It doesn’t show any examples of how to use performance_schema or what is the query we need to use from now on. It is also important to mention that 5.6 doesn’t show any warning about the feature being deprecated.

This is a short blog post to show how to configure performance_schema and get the info we need. Hoping it will end up in the official documentation in some way.

The instruments we need are not enabled by default. Those are in wait/synch/mutex/% so the config line we need to use is:

performance-schema-instrument='wait/synch/mutex/innodb/%=ON'

Then, just compare the results from an idle Percona Server 5.6. First the output of SHOW ENGINE…

mysql> show engine innodb mutex; +--------+------------------------------+------------+ | Type | Name | Status | +--------+------------------------------+------------+ | InnoDB | &buf_pool->flush_state_mutex | os_waits=1 | | InnoDB | &log_sys->checkpoint_lock | os_waits=2 | +--------+------------------------------+------------+

Now the results from the query that get us the mutex information from performance_schema:

mysql> SELECT EVENT_NAME, SUM_TIMER_WAIT/1000000000 WAIT_MS, COUNT_STAR FROM performance_schema.events_waits_summary_global_by_event_name WHERE SUM_TIMER_WAIT > 0 AND EVENT_NAME LIKE 'wait/synch/mutex/innodb/%' ORDER BY SUM_TIMER_WAIT DESC, COUNT_STAR DESC; +----------------------------------------------------+---------+------------+ | EVENT_NAME | WAIT_MS | COUNT_STAR | +----------------------------------------------------+---------+------------+ | wait/synch/mutex/innodb/log_sys_mutex | 11.1054 | 28279 | | wait/synch/mutex/innodb/buf_pool_flush_state_mutex | 9.7611 | 94095 | | wait/synch/mutex/innodb/os_mutex | 5.3339 | 58515 | | wait/synch/mutex/innodb/dict_sys_mutex | 2.4108 | 4033 | | wait/synch/mutex/innodb/flush_list_mutex | 2.3688 | 8036 | | wait/synch/mutex/innodb/lock_wait_mutex | 2.2412 | 4016 | | wait/synch/mutex/innodb/buf_pool_LRU_list_mutex | 2.1912 | 4182 | | wait/synch/mutex/innodb/fil_system_mutex | 0.9789 | 5060 | | wait/synch/mutex/innodb/mutex_list_mutex | 0.1723 | 8523 | | wait/synch/mutex/innodb/rw_lock_list_mutex | 0.1706 | 8245 | | wait/synch/mutex/innodb/srv_innodb_monitor_mutex | 0.0102 | 65 | | wait/synch/mutex/innodb/recv_sys_mutex | 0.0050 | 146 | | wait/synch/mutex/innodb/buf_pool_free_list_mutex | 0.0048 | 165 | | wait/synch/mutex/innodb/trx_mutex | 0.0020 | 105 | | wait/synch/mutex/innodb/srv_sys_mutex | 0.0012 | 11 | | wait/synch/mutex/innodb/trx_sys_mutex | 0.0010 | 29 | | wait/synch/mutex/innodb/lock_mutex | 0.0008 | 26 | | wait/synch/mutex/innodb/innobase_share_mutex | 0.0004 | 5 | | wait/synch/mutex/innodb/buf_dblwr_mutex | 0.0003 | 4 | | wait/synch/mutex/innodb/file_format_max_mutex | 0.0003 | 6 | | wait/synch/mutex/innodb/rseg_mutex | 0.0002 | 7 | | wait/synch/mutex/innodb/recv_writer_mutex | 0.0001 | 1 | | wait/synch/mutex/innodb/ut_list_mutex | 0.0001 | 1 | | wait/synch/mutex/innodb/ibuf_mutex | 0.0001 | 2 | | wait/synch/mutex/innodb/log_flush_order_mutex | 0.0000 | 1 | +----------------------------------------------------+---------+------------+

The difference is clear. We get much more information from Performance Schema. In my personal opinion, despite the extra resources needed by Performance Schema, the change is for the better.

The post Getting mutex information from MySQL’s performance_schema appeared first on MySQL Performance Blog.

Using YUM to install specific MySQL/Percona Server versions

Mo, 2015-01-05 14:52

Sometimes it is desired to use particular software versions in production, and not necessary the latest ones. There may be several reasons for that, where I think the most common is when a new version should spend some time in testing or a staging environment before getting to production. In theory each new version is supposed to be better as usually it contains a handful of bug fixes and even new or improved functionality. However there is also a risk of some regression or a new bug introduction as a side effect of code changes.

Quite often DBAs want the same MySQL version to be installed on all database instances, regardless of what actually is the latest version available in the software provider’s repository. There are several ways to achieve this:
* download specific version packages manually and then install them,
* have custom local repository mirror where you decide when and which version gets there, and just update from there using yum/apt,
* have database instance images with all software prepared,
* point to a particular version just using default package-management utility.

My idea was to remind about this last method as maybe the least known one.
In this article I will focus on YUM as it seems this is the only one currently offering multiple versions from official repositories of Oracle and Percona MySQL variants. APT theoretically is also able to install older versions, but command “apt-cache madison …” returns only the latest one for me. For example using Oracle repo:

root@ubuntu-14:~# apt-cache madison mysql-community-server mysql-community-server | 5.6.22-2ubuntu14.04 | http://repo.mysql.com/apt/ubuntu/ trusty/mysql-5.6 amd64 Packages mysql-community | 5.6.22-2ubuntu14.04 | http://repo.mysql.com/apt/ubuntu/ trusty/mysql-5.6 Sources

So let’s see how it looks like for YUM repositories. I have installed repositories from Oracle, MariaDB and Percona on Centos 6 test machine. This is what they offer for the main server package versions:

[root@localhost ~]# yum repolist repo id repo name status base CentOS-6 - Base 6,518 extras CentOS-6 - Extras 36 mariadb MariaDB 17 mysql-connectors-community MySQL Connectors Community 12 mysql-tools-community MySQL Tools Community 18 mysql56-community MySQL 5.6 Community Server 112 percona-release-noarch Percona-Release YUM repository - noarch 26 percona-release-x86_64 Percona-Release YUM repository - x86_64 432 updates CentOS-6 - Updates 530 repolist: 7,701 [root@localhost ~]# yum -q list available --showduplicates mysql-community-server.x86_64 Available Packages mysql-community-server.x86_64 5.6.15-1.el6 mysql56-community mysql-community-server.x86_64 5.6.16-1.el6 mysql56-community mysql-community-server.x86_64 5.6.17-4.el6 mysql56-community mysql-community-server.x86_64 5.6.19-2.el6 mysql56-community mysql-community-server.x86_64 5.6.20-4.el6 mysql56-community mysql-community-server.x86_64 5.6.21-2.el6 mysql56-community mysql-community-server.x86_64 5.6.22-2.el6 mysql56-community [root@localhost ~]# [root@localhost ~]# yum -q list available --showduplicates MariaDB-server.x86_64 Available Packages MariaDB-server.x86_64 10.0.15-1.el6 mariadb [root@localhost ~]# [root@localhost ~]# yum -q list available --showduplicates Percona-Server-server-56.x86_64 Available Packages Percona-Server-server-56.x86_64 5.6.13-rel61.0.461.rhel6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.14-rel62.0.483.rhel6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.15-rel63.0.519.rhel6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.16-rel64.0.el6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.16-rel64.1.el6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.16-rel64.2.el6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.17-rel65.0.el6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.17-rel66.0.el6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.19-rel67.0.el6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.20-rel68.0.el6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.21-rel69.0.el6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.21-rel70.0.el6 percona-release-x86_64 Percona-Server-server-56.x86_64 5.6.21-rel70.1.el6 percona-release-x86_64

So at least for both Oracle and Percona packages we can use yum to install several versions back (12 in case of Percona Server 5.6).

How can we do that? Let’s install Percona Server version 5.6.19. To get a full package name with it’s version, we join it’s name with version but the CPU family part needs to be removed or replaced to the end. So Percona-Server-server-56.x86_64 +  5.6.19-rel67.0.el6 -> Percona-Server-server-56-5.6.19-rel67.0.el6 or Percona-Server-server-56-5.6.19-rel67.0.el6.x86_64:

[root@localhost ~]# yum -q install Percona-Server-server-56-5.6.19-rel67.0.el6 Percona-Server-client-56-5.6.19-rel67.0.el6 Percona-Server-shared-56-5.6.19-rel67.0.el6 ============================================================================================================================= Package Arch Version Repository Size ============================================================================================================================= Installing: Percona-Server-client-56 x86_64 5.6.19-rel67.0.el6 percona-release-x86_64 6.8 M Percona-Server-server-56 x86_64 5.6.19-rel67.0.el6 percona-release-x86_64 19 M Percona-Server-shared-56 x86_64 5.6.19-rel67.0.el6 percona-release-x86_64 721 k Transaction Summary ============================================================================================================================= Install 3 Package(s) Is this ok [y/N]: y (...) [root@localhost ~]# rpm -qa|grep Percona Percona-Server-server-56-5.6.19-rel67.0.el6.x86_64 Percona-Server-client-56-5.6.19-rel67.0.el6.x86_64 Percona-Server-shared-56-5.6.19-rel67.0.el6.x86_64

But what if it happens that we have to revert to previous version? We can actually do that with YUM very quickly:

[root@localhost ~]# service mysql status SUCCESS! MySQL (Percona Server) running (1998) [root@localhost ~]# service mysql stop Shutting down MySQL (Percona Server).. SUCCESS! [root@localhost ~]# yum -q downgrade Percona-Server-server-56.x86_64 Percona-Server-client-56.x86_64 Percona-Server-shared-56.x86_64 ================================================================================================================================ Package Arch Version Repository Size ================================================================================================================================ Downgrading: Percona-Server-client-56 x86_64 5.6.17-rel66.0.el6 percona-release-x86_64 6.8 M Percona-Server-server-56 x86_64 5.6.17-rel66.0.el6 percona-release-x86_64 19 M Percona-Server-shared-56 x86_64 5.6.17-rel66.0.el6 percona-release-x86_64 720 k Transaction Summary ================================================================================================================================ Downgrade 3 Package(s) Is this ok [y/N]: y Giving mysqld 5 seconds to exit nicely (...) [root@localhost ~]# rpm -qa|grep Percona Percona-Server-shared-56-5.6.17-rel66.0.el6.x86_64 Percona-Server-server-56-5.6.17-rel66.0.el6.x86_64 Percona-Server-client-56-5.6.17-rel66.0.el6.x86_64

What if we want to downgrade, but let’s say few versions down? It is also possible with a single YUM command. By the way, after the last step we are on Percona Server 5.6.17 rel66.0 version and YUM nicely shows that when listing all available packages, see the screen shot below:

So let’s downgrade to Percona Server 5.6.15 rel63.0 – it’s actually very easy as the “downgrade” option also understands the version attribute:

[root@localhost ~]# yum -q downgrade Percona-Server-server-56-5.6.15-rel63.0.519.rhel6 Percona-Server-client-56-5.6.15-rel63.0.519.rhel6 Percona-Server-shared-56-5.6.15-rel63.0.519.rhel6 ===================================================================================================================================  Package                             Arch              Version                             Repository                         Size =================================================================================================================================== Downgrading:  Percona-Server-client-56            x86_64            5.6.15-rel63.0.519.rhel6            percona-release-x86_64            6.5 M  Percona-Server-server-56            x86_64            5.6.15-rel63.0.519.rhel6            percona-release-x86_64             18 M  Percona-Server-shared-56            x86_64            5.6.15-rel63.0.519.rhel6            percona-release-x86_64            691 k Transaction Summary =================================================================================================================================== Downgrade     3 Package(s) Is this ok [y/N]: y Giving mysqld 5 seconds to exit nicely (...)

We can do the same, or more complicated package operations, using the YUM transaction feature:

[root@localhost ~]# yum shell Loaded plugins: fastestmirror, security Setting up Yum Shell > remove Percona-Server-shared-56 Percona-Server-server-56 Percona-Server-client-56 Setting up Remove Process > install Percona-Server-server-56-5.6.15-rel63.0.519.rhel6 Percona-Server-client-56-5.6.15-rel63.0.519.rhel6 Percona-Server-shared-56-5.6.15-rel63.0.519.rhel6 (...) Setting up Install Process > run --> Running transaction check ---> Package Percona-Server-client-56.x86_64 0:5.6.15-rel63.0.519.rhel6 will be installed ---> Package Percona-Server-client-56.x86_64 0:5.6.17-rel66.0.el6 will be erased ---> Package Percona-Server-server-56.x86_64 0:5.6.15-rel63.0.519.rhel6 will be installed ---> Package Percona-Server-server-56.x86_64 0:5.6.17-rel66.0.el6 will be erased ---> Package Percona-Server-shared-56.x86_64 0:5.6.15-rel63.0.519.rhel6 will be obsoleting ---> Package Percona-Server-shared-56.x86_64 0:5.6.17-rel66.0.el6 will be erased (...) ================================================================================================================================ Package Arch Version Repository Size ================================================================================================================================ Installing: Percona-Server-client-56 x86_64 5.6.15-rel63.0.519.rhel6 percona-release-x86_64 6.5 M Percona-Server-server-56 x86_64 5.6.15-rel63.0.519.rhel6 percona-release-x86_64 18 M Percona-Server-shared-51 x86_64 5.1.73-rel14.12.624.rhel6 percona-release-x86_64 2.1 M replacing mysql-libs.x86_64 5.1.73-3.el6_5 Percona-Server-shared-56 x86_64 5.6.15-rel63.0.519.rhel6 percona-release-x86_64 691 k replacing mysql-libs.x86_64 5.1.73-3.el6_5 Removing: Percona-Server-client-56 x86_64 5.6.17-rel66.0.el6 @percona-release-x86_64 33 M Percona-Server-server-56 x86_64 5.6.17-rel66.0.el6 @percona-release-x86_64 86 M Percona-Server-shared-56 x86_64 5.6.17-rel66.0.el6 @percona-release-x86_64 3.4 M Transaction Summary ================================================================================================================================ Install 4 Package(s) Remove 3 Package(s) Total download size: 27 M Is this ok [y/N]: y (...) Removed: Percona-Server-client-56.x86_64 0:5.6.17-rel66.0.el6 Percona-Server-server-56.x86_64 0:5.6.17-rel66.0.el6 Percona-Server-shared-56.x86_64 0:5.6.17-rel66.0.el6 Installed: Percona-Server-client-56.x86_64 0:5.6.15-rel63.0.519.rhel6 Percona-Server-server-56.x86_64 0:5.6.15-rel63.0.519.rhel6 Percona-Server-shared-51.x86_64 0:5.1.73-rel14.12.624.rhel6 Percona-Server-shared-56.x86_64 0:5.6.15-rel63.0.519.rhel6 Replaced: mysql-libs.x86_64 0:5.1.73-3.el6_5 Finished Transaction > quit Leaving Shell [root@localhost ~]# rpm -qa|grep Percona Percona-Server-shared-56-5.6.15-rel63.0.519.rhel6.x86_64 Percona-Server-client-56-5.6.15-rel63.0.519.rhel6.x86_64 Percona-Server-shared-51-5.1.73-rel14.12.624.rhel6.x86_64 Percona-Server-server-56-5.6.15-rel63.0.519.rhel6.x86_64

The fact that we can use single command or single YUM transaction, instead of a manual rpm download and installation, is not the only advantage of this method. The other very important one is that we don’t have to worry about breaking package dependencies when we uninstall current version manually in order to install different one, as there may be many packages that depend on MySQL.

However, if anyone does “yum update” on this system, our packages will be upgraded to the latest version, which is what we probably don’t want to happen yet, and surely not without our supervision:

[root@localhost ~]# yum -q update =================================================================================================================================== Package Arch Version Repository Size =================================================================================================================================== Updating: Percona-Server-client-56 x86_64 5.6.21-rel70.1.el6 percona-release-x86_64 6.4 M Percona-Server-server-56 x86_64 5.6.21-rel70.1.el6 percona-release-x86_64 19 M Percona-Server-shared-56 x86_64 5.6.21-rel70.1.el6 percona-release-x86_64 721 k Transaction Summary =================================================================================================================================== Upgrade 3 Package(s) Is this ok [y/N]: N Exiting on user Command

To prevent that, we should lock our packages on current version. To achieve that, we need yum-plugin-versionlock package which allows us to do this:

[root@localhost ~]# yum versionlock Percona-Server-server-56 Percona-Server-client-56 Percona-Server-shared-56 Loaded plugins: fastestmirror, security, versionlock Adding versionlock on: 0:Percona-Server-server-56-5.6.15-rel63.0.519.rhel6 Adding versionlock on: 0:Percona-Server-client-56-5.6.15-rel63.0.519.rhel6 Adding versionlock on: 0:Percona-Server-shared-56-5.6.15-rel63.0.519.rhel6 versionlock added: 3 [root@localhost ~]# yum update Loaded plugins: fastestmirror, security, versionlock Setting up Update Process (...) No Packages marked for Update

Now these packages cannot be updated unless you clear the locks with

yum versionlock clear

(clear any locks) or particular locks:

[root@localhost ~]# yum -q versionlock list 0:Percona-Server-server-56-5.6.15-rel63.0.519.rhel6.* 0:Percona-Server-client-56-5.6.15-rel63.0.519.rhel6.* 0:Percona-Server-shared-56-5.6.15-rel63.0.519.rhel6.* [root@localhost ~]# yum versionlock delete '0:Percona-Server-client-56-5.6.15-rel63.0.519.rhel6.*' Loaded plugins: fastestmirror, security, versionlock Deleting versionlock for: 0:Percona-Server-client-56-5.6.15-rel63.0.519.rhel6.* versionlock deleted: 1 [root@localhost ~]# yum -q versionlock list 0:Percona-Server-server-56-5.6.15-rel63.0.519.rhel6.* 0:Percona-Server-shared-56-5.6.15-rel63.0.519.rhel6.* [root@localhost ~]# yum -q update ===================================================================================================================================  Package                              Arch               Version                          Repository                          Size =================================================================================================================================== Updating:  Percona-Server-client-56             x86_64             5.6.21-rel70.1.el6               percona-release-x86_64             6.4 M Transaction Summary =================================================================================================================================== Upgrade       1 Package(s) Is this ok [y/N]:

I think the fact that you can install particular MySQL and Percona Server versions using YUM lets you simplify software management tools recipes, like Chef, Puppet or Ansible. For example, the Chef’s yum_package resource has version attribute, and an example recipe for Percona Server 5.6.20 installation may look like this:

pkgs = ["Percona-Server-client-56","Percona-Server-shared-56","Percona-Server-server-56","Percona-Server-56-debuginfo"] pkgs.each do |pkg| yum_package pkg do version "5.6.20-rel68.0.el6" allow_downgrade true end end

Hopefully we will see similar functionality from APT MySQL repositories eventually.

The post Using YUM to install specific MySQL/Percona Server versions appeared first on MySQL Performance Blog.

The MySQL Query Cache: How it works, plus workload impacts (good and bad)

Fr, 2015-01-02 08:00

Query caching is one of the prominent features in MySQL and a vital part of query optimization. It is important to know how it works as it has the potential to cause significant performance improvements – or a slowdown – of your workload.

The MySQL query cache is a global one shared among the sessions. It caches the select query along with the result set, which enables the identical selects to execute faster as the data fetches from the in memory. It is important to have everything identical, no new comments, spaces, or most significantly differences in the WHERE clause. Basically when you trigger a select query, if it is available in the cache; it fetches from there or it considers the query as a new one and will go to the parser.

Even though it has some nice advantages, the MySQL query cache has its own downsides too. Well, let’s think about this: If you are frequently updating the table, you are then invalidating the query cache for ALL queries cached for that table. So really, anytime you have a “frequently updated table” means you’re probably not going to get any sort of good usage from the query cache. See the below example.

mysql> SHOW STATUS LIKE "qcache%"; +-------------------------+---------+ | Variable_name | Value | +-------------------------+---------+ | Qcache_free_blocks | 1 | | Qcache_free_memory | 1031320 | | Qcache_hits | 0 | | Qcache_inserts | 0 | | Qcache_lowmem_prunes | 0 | | Qcache_not_cached | 1 | | Qcache_queries_in_cache | 0 | | Qcache_total_blocks | 1 | +-------------------------+---------+ 8 rows in set (0.06 sec) mysql> select * from d.t1; 405 rows in set (0.05 sec) mysql> select * from d.t1 where id=88995159; 1 row in set (0.00 sec) mysql> SHOW STATUS LIKE "qcache%"; +-------------------------+---------+ | Variable_name | Value | +-------------------------+---------+ | Qcache_free_blocks | 1 | | Qcache_free_memory | 1020600 | | Qcache_hits | 0 | | Qcache_inserts | 2 | | Qcache_lowmem_prunes | 0 | | Qcache_not_cached | 1 | | Qcache_queries_in_cache | 2 | | Qcache_total_blocks | 6 | +-------------------------+---------+ 8 rows in set (0.00 sec)

From the above  we are sure the queries are cached. Let us try an insert and see the status, it will invalidate the query cache and reclaim the memory.

mysql> insert into d.t1 (data)value('Welcome'); Query OK, 1 row affected (0.05 sec) mysql> SHOW STATUS LIKE "qcache%"; +-------------------------+---------+ | Variable_name | Value | +-------------------------+---------+ | Qcache_free_blocks | 1 | | Qcache_free_memory | 1031320 | | Qcache_hits | 0 | | Qcache_inserts | 2 | | Qcache_lowmem_prunes | 0 | | Qcache_not_cached | 1 | | Qcache_queries_in_cache | 0 | | Qcache_total_blocks | 1 | +-------------------------+---------+ 8 rows in set (0.00 sec)

Now let us think about how to decide the query cache size:

To exemplify:-  I am having a mysql instance with two tables “t” and “t1″. Table “t” is with numerous records and “t1″ is with a fewer records. Let’s restart the mysql and see the query cache details.

mysql> show variables like 'query_cache_size'; +------------------+---------+ | Variable_name | Value | +------------------+---------+ | query_cache_size | 1048576 | +------------------+---------+ 1 row in set (0.00 sec) mysql> SHOW STATUS LIKE "qcache%"; +-------------------------+---------+ | Variable_name | Value | +-------------------------+---------+ | Qcache_free_blocks | 1 | | Qcache_free_memory | 1031320 | | Qcache_hits | 0 | | Qcache_inserts | 0 | | Qcache_lowmem_prunes | 0 | | Qcache_not_cached | 1 | | Qcache_queries_in_cache | 0 | | Qcache_total_blocks | 1 | +-------------------------+---------+ 8 rows in set (0.01 sec)

From the above status note the below four points.

1) There is around 1 MB free space with Qcache.

2) The queries in Qcache are zero.

3) There is no Qcache hits.

4) Qcache lowmem prunes is zero.

mysql> select * from d.t1; 405 rows in set (0.03 sec) mysql> SHOW STATUS LIKE "qcache%"; +-------------------------+---------+ | Variable_name | Value | +-------------------------+---------+ | Qcache_free_blocks | 1 | | Qcache_free_memory | 1021624 | | Qcache_hits | 0 | | Qcache_inserts | 1 | | Qcache_lowmem_prunes | 0 | | Qcache_not_cached | 1 | | Qcache_queries_in_cache | 1 | | Qcache_total_blocks | 4 | +-------------------------+---------+ 8 rows in set (0.01 sec)

From the aforesaid status it is clear the query has been cached and it should execute much faster in the next try and increase the Qcache hits status variable by one.

mysql> select * from d.t1; 405 rows in set (0.00 sec). mysql> SHOW STATUS LIKE "%Qcache_hits%"; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Qcache_hits | 1 | +---------------+-------+ 1 row in set (0.00 sec)

Now let us see how the data is getting pruned from the Qcache. For this I will execute a select on table “t” which is having massive records.

mysql> select * from d.t where id > 78995159; mysql> SHOW STATUS LIKE "Qcache_lowmem_prunes"; +----------------------+-------+ | Variable_name | Value | +----------------------+-------+ | Qcache_lowmem_prunes | 1 | +----------------------+-------+ 1 row in set (0.00 sec) mysql> select * from d.t1; 405 rows in set (0.02 sec) mysql> SHOW STATUS LIKE "qcache%"; +-------------------------+---------+ | Variable_name | Value | +-------------------------+---------+ | Qcache_free_blocks | 1 | | Qcache_free_memory | 1021624 | | Qcache_hits | 1 | | Qcache_inserts | 2 | | Qcache_lowmem_prunes | 1 | | Qcache_not_cached | 6 | | Qcache_queries_in_cache | 1 | | Qcache_total_blocks | 4 | +-------------------------+---------+ 8 rows in set (0.01 sec)

The Qcache_lowmem_prunes is the status variable which indicates how many times MySQL had to clear/prune some data from the Qcache to make space for the outputs of other queries. We need to observe the Qcache_lowmem_prunes  status variable and try to increase/adjust the size of the cache till we get a very low value ratio for the variable.

It is also undesirable to keep the query cache relatively high value at 256 MB as the Qcache invalidation becomes costly. For details, Peter Zaitsev wrote about this a few years ago in a post that’s still relevant today titled, “Beware large Query_Cache sizes.”

Contention often makes query cache the bottleneck instead of help when you have many CPU cores. Generally, query cache should be off unless proven useful for your workload. So it is important to know your environment well to enable the query cache and to decide what the query cache size should be.

There will also be circumstances where there is no chance of identical selects and in this case it is important to set the query_cache_size and query_cache_type variable to zero. The query_cache_type variable controls the query cache and  setting the query_cache_type to zero will reduce the significant overhead in query execution. On a highly concurrent environment there are chances of query cache mutex, which may become the source of a bottleneck. Setting the query_cache_type to zero will avoid the query cache mutex, as the query cache cannot be enabled at runtime which reduces the overhead in query execution. Please go through the details of QUERY CACHE ENHANCEMENTS with Percona Server.

The post The MySQL Query Cache: How it works, plus workload impacts (good and bad) appeared first on MySQL Performance Blog.