Mysql – Mariadb tuning – slow writes

galerainnodbjoomlamariadbMySQL

Background:
I have a a website I am migrating from a stand alone MariaDB server to a MariaDB galera cluster. Part of this had me convert the tables from a large number of MyISAM to InnoDB. For what it is worth, the website is a large joomla installation.

The front end end side of the website is performing fine. No issues there. The admin section is painfully slow to save anything – 25-30 seconds from the time you hit save until it finishes.

Setup
3 node galera setup – 12 core Intel(R) Xeon(R) CPU E5-1650 v4 @ 3.60GHz
64GB w SSD on Raid

HA Proxy for load balancing

/etc/my.cnf

[mysqld]
innodb_buffer_pool_siz=32Gb
innodb_log_file_size = 2Gb
innodb_flush_method=O_DIRECT
max_connections=750
innodb_flush_log_at_trx_commit=2
innodb_log_buffer_size=2Mb
query_cache_size=0
skip_name_resolve
sync-binlog=0

Right now I have only a single development site hooked up so I can measure what's going on reliably. Here is what I noticed with waits when a single save was performed:

Prior to save:

MariaDB [(none)]> show global status like "%waits%";
+-------------------------------+-------+
| Variable_name                 | Value |
+-------------------------------+-------+
| Innodb_log_waits              | 0     |
| Innodb_mutex_os_waits         | 4     |
| Innodb_mutex_spin_waits       | 4     |
| Innodb_row_lock_current_waits | 0     |
| Innodb_row_lock_waits         | 0     |
| Innodb_s_lock_os_waits        | 9     |
| Innodb_s_lock_spin_waits      | 11    |
| Innodb_x_lock_os_waits        | 1     |
| Innodb_x_lock_spin_waits      | 0     |
| Tc_log_page_waits             | 0     |
+-------------------------------+-------+
10 rows in set (0.01 sec)

After Save:

MariaDB [(none)]> show global status like "%waits%";
+-------------------------------+-------+
| Variable_name                 | Value |
+-------------------------------+-------+
| Innodb_log_waits              | 0     |
| Innodb_mutex_os_waits         | 177   |
| Innodb_mutex_spin_waits       | 1580  |
| Innodb_row_lock_current_waits | 0     |
| Innodb_row_lock_waits         | 0     |
| Innodb_s_lock_os_waits        | 164   |
| Innodb_s_lock_spin_waits      | 687   |
| Innodb_x_lock_os_waits        | 656   |
| Innodb_x_lock_spin_waits      | 905   |
| Tc_log_page_waits             | 0     |
+-------------------------------+-------+

I know there is more overhead with innodb than myisam but I thought disabling sync-binlog and setting innodb_flush_log_at_trx_commit to 2 would help but what I am actually seeing is about a 1000% degradation in write performance.

Just looking for some guidance on what to check, what might be wrong. I am not sure if that os_waits count is high on a single save in an application, it seems like it is to me, but I don't really follow what would cause it or how to fix it.

After setting the slow query log to 2s, this is the only thing it caught while trying to save:

# Time: 180126 18:03:38
# User@Host: dev[dev] @  [192.168.10.200]
# Thread_id: 136  Schema: dev  QC_hit: No
# Query_time: 6.306918  Lock_time: 0.000000  Rows_sent: 0  Rows_examined: 109438
# Rows_affected: 82677
use dev;
SET timestamp=1517007818;
UPDATE jos_assets
SET lft = lft + 2
WHERE lft > 337711;
# Time: 180126 18:03:48
# User@Host: dev[dev] @  [192.168.10.200]
# Thread_id: 136  Schema: dev  QC_hit: No
# Query_time: 9.985669  Lock_time: 0.000000  Rows_sent: 0  Rows_examined: 109438
# Rows_affected: 82683
SET timestamp=1517007828;
UPDATE jos_assets
SET rgt = rgt + 2
WHERE rgt >= 337711;

Thx in advance.

Best Answer

This problem turned out to be very Joomla specific and has to do with inefficiencies with the _assets table. I guess I should have checked the slow query log earlier, but as you can see in the original post there were 2 queries that were updating the table in one "save" when posting a new article causing 82677 rows to be updated. Even in the speediest deployment this will take time.

Why Joomla needs to do this every time a post is saved I am not entirely sure, but some research suggested it was safe to remove all article related entries in that table which knocked it down to a total of about 4000 rows. Much faster now.

For reference if you have a Joomla site that is slow after converting to Innodb, this is the page I found some info on the asset table:

https://www.itoctopus.com/creating-new-articles-on-your-joomla-website-is-taking-a-long-time-clean-your-assets-table

OBSERVATION #1

The very first thing that catches my eye is the table structure

CREATE TABLE IF NOT EXISTS `productsCategories` (
  `categoriesId` int(11) NOT NULL,
  `productsId` int(11) NOT NULL,
  PRIMARY KEY (`categoriesId`,`productsId`),
  KEY `categoriesId` (`categoriesId`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;

Please notice that the categoriesId index and the PRIMARY KEY start with the same column. It is a redundant index. Since this table is InnoDB, the categoriesId index is redundant for another reason: All secondary indexes contains keys into gen_clust_index (aka Clustered Index; See what is gen_clust_index used for in mysql?)

If you remove the categoriesId index with

ALTER TABLE productsCategories DROP INDEX categoriesId;

this will improve INSERTs dramatically because of not having to do extra Secondary and Clustered index maintenance.

OBSERVATION #2

If you are doing any bulk insert operations, you need a large bulk insert buffer.

Please see my past posts on this:

OBSERVATION #3

Your log file size is way too small !!! It should be 25% of the InnoDB Buffer Pool, which in your case should be 1G. See my post on how to resize InnoDB Log Files.

OBSERVATION #4

Please, do not set innodb_thread_concurrency !!! I learned firsthand at Percona Live NYC to leave that setting alone. It is disabled by default in MySQL 5.5, MySQL 5.1 InnoDB Plugin, and Percona Server 5.1+.

OBSERVATION #5

You need to use innodb_file_per_table. If this is disabled, I make file maintenance on ibdata1 a nightmare. Please read my post on how to cleanup InnoDB to implement this.

OBSERVATION #6

If you are using MySQL 5.5 or Percona Server, you have to set certain options to make InnoDB use mutiple CPUs/multiple cores. Please see my post on those settings.

OBSERVATION #7

You have innodb_log_buffer_size=4M. The default is 8M. That will cause twice as much flushing to the redo logs. That will also counteract your innodb_flush_log_at_trx_commit=2setting. Please set it to 32M. Also, please see MySQL Documentation on innodb_log_buffer_size.

In light of these observations, please add or replace the following settings:

[mysqld]
innodb_thread_concurrency = 0
innodb_read_io_threads = 64
innodb_write_io_threads = 64
innodb_io_capacity = 5000
innodb_file_per_table
innodb_log_file_size=1G
innodb_log_buffer_size=1G
bulk_insert_buffer_size = 256M

MySQL – Slow query – wp_options table. Website unable to handle traffic

Query_time: 49.248039 Lock_time: 0.000180 Rows_sent: 485 Rows_examined: 538

This, from your slow query log, implies that it took 49 seconds to execute this query. Try running

CREATE INDEX wp_options_autoload ON wp_options (autoload);

And then try loading your pages again.

Though with only 538 rows in the table, that's an extremely long time for that query to run.