MySQL: Very slow update/insert/delete queries hanging on "query end" step

Question

I have a large and heavy loaded mysql database which performs quite fast at times, but some times get terribly slow. All tables are InnoDB, server has 32GB of RAM and database size is about 40GB.

Top 20 queries in my slow_query_log are update, insert and delete queries and I cannot understand why they are so slow (up to 120 seconds sometimes!)

Here is the most frequent query:

UPDATE comment_fallows set comment_cnt_new = 0 WHERE user_id = 1; 

Profiling results:

mysql> set profiling = 1; Query OK, 0 rows affected (0.00 sec)  mysql> update comment_fallows set comment_cnt_new = 0 where user_id = 1; Query OK, 0 rows affected (2.77 sec) Rows matched: 18  Changed: 0  Warnings: 0  mysql> show profile for query 1; +---------------------------+----------+ | Status                    | Duration | +---------------------------+----------+ | starting                  | 0.000021 | | checking permissions      | 0.000004 | | Opening tables            | 0.000010 | | System lock               | 0.000004 | | init                      | 0.000041 | | Searching rows for update | 0.000084 | | Updating                  | 0.000055 | | end                       | 0.000010 | | query end                 | 2.766245 | | closing tables            | 0.000007 | | freeing items             | 0.000013 | | logging slow query        | 0.000003 | | cleaning up               | 0.000002 | +---------------------------+----------+ 13 rows in set (0.00 sec) 

I am using master/server replication, so the binary log is enabled. I've fallowed one advice I've found on the internet and set flush_log_at_trx_commit to 0 but it did not make any difference:

mysql> show variables like '%trx%'; +-------------------------------------------+-------+ | Variable_name                             | Value | +-------------------------------------------+-------+ | innodb_flush_log_at_trx_commit            | 0     | | innodb_use_global_flush_log_at_trx_commit | ON    | +-------------------------------------------+-------+ 

The table structure:

CREATE TABLE `comment_fallows` (   `id` int(11) NOT NULL AUTO_INCREMENT,   `user_id` int(11) NOT NULL,   `part_id` int(11) DEFAULT NULL,   `article_id` int(11) DEFAULT NULL,   `request_id` int(11) DEFAULT NULL,   `comment_cnt` int(10) unsigned NOT NULL,   `comment_cnt_new` int(10) unsigned NOT NULL DEFAULT '0',   `last_comment_date` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,   PRIMARY KEY (`id`),   KEY `user_id` (`user_id`,`last_comment_date`),   KEY `part_id` (`part_id`),   KEY `last_comment_date` (`last_comment_date`),   KEY `request_id` (`request_id`),   CONSTRAINT `comment_fallows_ibfk_1` FOREIGN KEY (`user_id`) REFERENCES `users` (`id`) ON DELETE CASCADE,   CONSTRAINT `comment_fallows_ibfk_2` FOREIGN KEY (`part_id`) REFERENCES `fanfic_parts` (`id`) ON DELETE CASCADE,   CONSTRAINT `comment_fallows_ibfk_3` FOREIGN KEY (`request_id`) REFERENCES `requests` (`id`) ON DELETE CASCADE ) ENGINE=InnoDB AUTO_INCREMENT=2239419 DEFAULT CHARSET=utf8 

And all the innodb settings (server has 32 GB of RAM):

mysql> show variables like '%innodb%'; +-------------------------------------------+------------------------+ | Variable_name                             | Value                  | +-------------------------------------------+------------------------+ | have_innodb                               | YES                    | | ignore_builtin_innodb                     | OFF                    | | innodb_adaptive_flushing                  | ON                     | | innodb_adaptive_flushing_method           | estimate               | | innodb_adaptive_hash_index                | ON                     | | innodb_adaptive_hash_index_partitions     | 1                      | | innodb_additional_mem_pool_size           | 16777216               | | innodb_autoextend_increment               | 8                      | | innodb_autoinc_lock_mode                  | 1                      | | innodb_blocking_buffer_pool_restore       | OFF                    | | innodb_buffer_pool_instances              | 1                      | | innodb_buffer_pool_restore_at_startup     | 0                      | | innodb_buffer_pool_shm_checksum           | ON                     | | innodb_buffer_pool_shm_key                | 0                      | | innodb_buffer_pool_size                   | 21474836480            | | innodb_change_buffering                   | all                    | | innodb_checkpoint_age_target              | 0                      | | innodb_checksums                          | ON                     | | innodb_commit_concurrency                 | 0                      | | innodb_concurrency_tickets                | 500                    | | innodb_corrupt_table_action               | assert                 | | innodb_data_file_path                     | ibdata1:10M:autoextend | | innodb_data_home_dir                      |                        | | innodb_dict_size_limit                    | 0                      | | innodb_doublewrite                        | ON                     | | innodb_doublewrite_file                   |                        | | innodb_fake_changes                       | OFF                    | | innodb_fast_checksum                      | OFF                    | | innodb_fast_shutdown                      | 1                      | | innodb_file_format                        | Antelope               | | innodb_file_format_check                  | ON                     | | innodb_file_format_max                    | Antelope               | | innodb_file_per_table                     | ON                     | | innodb_flush_log_at_trx_commit            | 0                      | | innodb_flush_method                       |                        | | innodb_flush_neighbor_pages               | area                   | | innodb_force_load_corrupted               | OFF                    | | innodb_force_recovery                     | 0                      | | innodb_ibuf_accel_rate                    | 100                    | | innodb_ibuf_active_contract               | 1                      | | innodb_ibuf_max_size                      | 10737401856            | | innodb_import_table_from_xtrabackup       | 0                      | | innodb_io_capacity                        | 10000                  | | innodb_kill_idle_transaction              | 0                      | | innodb_large_prefix                       | OFF                    | | innodb_lazy_drop_table                    | 0                      | | innodb_lock_wait_timeout                  | 120                    | | innodb_locks_unsafe_for_binlog            | OFF                    | | innodb_log_block_size                     | 512                    | | innodb_log_buffer_size                    | 8388608                | | innodb_log_file_size                      | 268435456              | | innodb_log_files_in_group                 | 3                      | | innodb_log_group_home_dir                 | ./                     | | innodb_max_dirty_pages_pct                | 90                     | | innodb_max_purge_lag                      | 0                      | | innodb_mirrored_log_groups                | 1                      | | innodb_old_blocks_pct                     | 37                     | | innodb_old_blocks_time                    | 0                      | | innodb_open_files                         | 300                    | | innodb_page_size                          | 16384                  | | innodb_purge_batch_size                   | 20                     | | innodb_purge_threads                      | 1                      | | innodb_random_read_ahead                  | OFF                    | | innodb_read_ahead                         | linear                 | | innodb_read_ahead_threshold               | 56                     | | innodb_read_io_threads                    | 8                      | | innodb_recovery_stats                     | OFF                    | | innodb_recovery_update_relay_log          | OFF                    | | innodb_replication_delay                  | 0                      | | innodb_rollback_on_timeout                | OFF                    | | innodb_rollback_segments                  | 128                    | | innodb_show_locks_held                    | 10                     | | innodb_show_verbose_locks                 | 0                      | | innodb_spin_wait_delay                    | 6                      | | innodb_stats_auto_update                  | 1                      | | innodb_stats_method                       | nulls_equal            | | innodb_stats_on_metadata                  | ON                     | | innodb_stats_sample_pages                 | 8                      | | innodb_stats_update_need_lock             | 1                      | | innodb_strict_mode                        | OFF                    | | innodb_support_xa                         | ON                     | | innodb_sync_spin_loops                    | 30                     | | innodb_table_locks                        | ON                     | | innodb_thread_concurrency                 | 16                     | | innodb_thread_concurrency_timer_based     | OFF                    | | innodb_thread_sleep_delay                 | 10000                  | | innodb_use_global_flush_log_at_trx_commit | ON                     | | innodb_use_native_aio                     | ON                     | | innodb_use_sys_malloc                     | ON                     | | innodb_use_sys_stats_table                | OFF                    | | innodb_version                            | 1.1.8-rel25.1          | | innodb_write_io_threads                   | 8                      | +-------------------------------------------+------------------------+ 92 rows in set (0.00 sec) 

I've been struggling with this problem for weeks and would be very greatfull for any advice on how to solve this problem.

Why could my update, insert and delete queries be so slow on query end step?

update

I have disabled query cache, but update, insert and delete queries are still very very slow (nothing changed)

show variables like '%cache%'; +------------------------------+----------------------+ | Variable_name                | Value                | +------------------------------+----------------------+ | binlog_cache_size            | 4194304              | | binlog_stmt_cache_size       | 32768                | | have_query_cache             | YES                  | | key_cache_age_threshold      | 300                  | | key_cache_block_size         | 1024                 | | key_cache_division_limit     | 100                  | | max_binlog_cache_size        | 18446744073709547520 | | max_binlog_stmt_cache_size   | 18446744073709547520 | | metadata_locks_cache_size    | 1024                 | | query_cache_limit            | 16777216             | | query_cache_min_res_unit     | 4096                 | | query_cache_size             | 0                    | | query_cache_strip_comments   | OFF                  | | query_cache_type             | ON                   | | query_cache_wlock_invalidate | OFF                  | | stored_program_cache         | 256                  | | table_definition_cache       | 400                  | | table_open_cache             | 2048                 | | thread_cache_size            | 8                    | +------------------------------+----------------------+ 

Answer 1

Try setting values:

innodb_flush_log_at_trx_commit=2 innodb_flush_method=O_DIRECT (for non-windows machine) innodb_buffer_pool_size=25GB (currently it is close to 21GB) innodb_doublewrite=0 innodb_support_xa=0 innodb_thread_concurrency=0...1000 (try different values, beginning with 200) 

References:

MySQL docs for description of different variables.

MySQL Server Setting Tuning

MySQL Performance Optimization basics

Hope it helps...

Answer 2

There appears to be a bug with how MySQL handles the query cache which causes similar behaviour (see http://bugs.mysql.com/bug.php?id=28382).

What is basically happening is that the cache needs to be updated following any query that modifies data (INSERT, UPDATE, DELETE). With a large cache it is taking a long time to do this, if the cache is smaller then its faster.

So the work-around until the engine is fixed is to decrease the cache size.