0

During daily batch operations (mass delete/upsert operations), regular throughput is sometimes affected, e.g. operations such as a single lookup on a PK or a small range (7 rows examined, 1 row returned) can take many seconds (anywhere between 15 and 90 seconds).

I let a show engine innodb status running for 2 two days in a loop and then aggregated some of the results to try and spot anything strange. (mysqltuner doesn't find anything particularly out of the ordinary in the configuration).

A couple of things stand out. In the FILE I/O section, I see some fairly high Pending normal aio writes values: (sort'ed, uniq'ed and re-sort'ed)

130 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 120
  4 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 119
  4 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 116
  1 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 111
  1 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 108
  1 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 105
  3 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 104
  1 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 101
    ...

Given the number of times the system hits 120 it looks like some sort of bottleneck. (Pending reads, log and checkpoint writes are all negligible).

Similarly (but I think it's just another aspect of the underlying issue), from the BUFFER POOL AND MEMORY section

124 Pending writes: LRU 0, flush list 122, single page 0
 72 Pending writes: LRU 0, flush list 121, single page 0
  6 Pending writes: LRU 0, flush list 120, single page 0
  7 Pending writes: LRU 0, flush list 119, single page 0
  3 Pending writes: LRU 0, flush list 117, single page 0
  8 Pending writes: LRU 0, flush list 116, single page 0
  1 Pending writes: LRU 0, flush list 115, single page 0

Machine specs:

Mysql 5.6.35-80.0-log Percona Server (GPL), Release 80.0
32 CPU
256 GiB RAM (225GiB innodb buffer pool)
SSD disk
innodb_thread_concurrency = 32
innodb_write_io_threads = 4

What should I be looking at to lift the 120 aio writes ceiling? And is this in fact a problem?

edit: additional Innodb status:

mysql> show status like 'Uptime'; +---------------+---------+ | Variable_name | Value | +---------------+---------+ | Uptime | 9723873 | +---------------+---------+

mysql> show global status like 'Innodb%'; +-----------------------------------------+----------------+ | Variable_name | Value | +-----------------------------------------+----------------+ | Innodb_buffer_pool_dump_status | not started | | Innodb_buffer_pool_load_status | not started | | Innodb_background_log_sync | 9703969 | | Innodb_buffer_pool_pages_data | 13162206 | | Innodb_buffer_pool_bytes_data | 215649583104 | | Innodb_buffer_pool_pages_dirty | 92656 | | Innodb_buffer_pool_bytes_dirty | 1518075904 | | Innodb_buffer_pool_pages_flushed | 439442727 | | Innodb_buffer_pool_pages_LRU_flushed | 0 | | Innodb_buffer_pool_pages_free | 8193 | | Innodb_buffer_pool_pages_made_not_young | 2931229194 | | Innodb_buffer_pool_pages_made_young | 159504393 | | Innodb_buffer_pool_pages_misc | 1247513 | | Innodb_buffer_pool_pages_old | 4858541 | | Innodb_buffer_pool_pages_total | 14417912 | | Innodb_buffer_pool_read_ahead_rnd | 0 | | Innodb_buffer_pool_read_ahead | 10426224 | | Innodb_buffer_pool_read_ahead_evicted | 0 | | Innodb_buffer_pool_read_requests | 1570315891758 | | Innodb_buffer_pool_reads | 44141228 | | Innodb_buffer_pool_wait_free | 702963 | | Innodb_buffer_pool_write_requests | 48239522888 | | Innodb_checkpoint_age | 333521469 | | Innodb_checkpoint_max_age | 1737806931 | | Innodb_data_fsyncs | 182882530 | | Innodb_data_pending_fsyncs | 0 | | Innodb_data_pending_reads | 0 | | Innodb_data_pending_writes | 0 | | Innodb_data_read | 918980710912 | | Innodb_data_reads | 56105251 | | Innodb_data_writes | 934762846 | | Innodb_data_written | 16676682864128 | | Innodb_dblwr_pages_written | 439442728 | | Innodb_dblwr_writes | 16936010 | | Innodb_deadlocks | 5069 | | Innodb_have_atomic_builtins | ON | | Innodb_history_list_length | 634 | | Innodb_ibuf_discarded_delete_marks | 0 | | Innodb_ibuf_discarded_deletes | 0 | | Innodb_ibuf_discarded_inserts | 0 | | Innodb_ibuf_free_list | 50877 | | Innodb_ibuf_merged_delete_marks | 22294441 | | Innodb_ibuf_merged_deletes | 3064591 | | Innodb_ibuf_merged_inserts | 8401121 | | Innodb_ibuf_merges | 2848421 | | Innodb_ibuf_segment_size | 50879 | | Innodb_ibuf_size | 1 | | Innodb_log_waits | 2 | | Innodb_log_write_requests | 4217298354 | | Innodb_log_writes | 474832949 | | Innodb_lsn_current | 7308754206409 | | Innodb_lsn_flushed | 7308753971429 | | Innodb_lsn_last_checkpoint | 7308420684940 | | Innodb_master_thread_active_loops | 8640164 | | Innodb_master_thread_idle_loops | 1064269 | | Innodb_max_trx_id | 17940449769 | | Innodb_mem_adaptive_hash | 24179214720 | | Innodb_mem_dictionary | 1018254697 | | Innodb_mem_total | 245912043520 | | Innodb_mutex_os_waits | 12108720 | | Innodb_mutex_spin_rounds | 1059845628 | | Innodb_mutex_spin_waits | 382281971 | | Innodb_oldest_view_low_limit_trx_id | 0 | | Innodb_os_log_fsyncs | 10007215 | | Innodb_os_log_pending_fsyncs | 0 | | Innodb_os_log_pending_writes | 0 | | Innodb_os_log_written | 2276384210944 | | Innodb_page_size | 16384 | | Innodb_pages_created | 12973236 | | Innodb_pages_read | 56090142 | | Innodb_pages_written | 439442728 | | Innodb_purge_trx_id | 17940449769 | | Innodb_purge_undo_no | 0 | | Innodb_row_lock_current_waits | 0 | | Innodb_current_row_locks | 4 | | Innodb_row_lock_time | 1338876761 | | Innodb_row_lock_time_avg | 1173 | | Innodb_row_lock_time_max | 683448 | | Innodb_row_lock_waits | 1141134 | | Innodb_rows_deleted | 1057900435 | | Innodb_rows_inserted | 2669370850 | | Innodb_rows_read | 1006726857724 | | Innodb_rows_updated | 4348142688 | | Innodb_num_open_files | 8440 | | Innodb_read_views_memory | 11792 | | Innodb_descriptors_memory | 8000 | | Innodb_s_lock_os_waits | 11020917 | | Innodb_s_lock_spin_rounds | 495689751 | | Innodb_s_lock_spin_waits | 109330863 | | Innodb_truncated_status_writes | 0 | | Innodb_available_undo_logs | 128 | | Innodb_x_lock_os_waits | 14985092 | | Innodb_x_lock_spin_rounds | 2194261953 | | Innodb_x_lock_spin_waits | 45543353 | +-----------------------------------------+----------------+

mysql> show variables like 'innodb%'; +-------------------------------------------+------------------------+ | Variable_name | Value | +-------------------------------------------+------------------------+ | innodb_adaptive_flushing | ON | | innodb_adaptive_flushing_lwm | 10 | | innodb_adaptive_hash_index | ON | | innodb_adaptive_hash_index_partitions | 1 | | innodb_adaptive_max_sleep_delay | 150000 | | innodb_additional_mem_pool_size | 67108864 | | innodb_api_bk_commit_interval | 5 | | innodb_api_disable_rowlock | OFF | | innodb_api_enable_binlog | OFF | | innodb_api_enable_mdl | OFF | | innodb_api_trx_level | 0 | | innodb_autoextend_increment | 64 | | innodb_autoinc_lock_mode | 1 | | innodb_buffer_pool_dump_at_shutdown | OFF | | innodb_buffer_pool_dump_now | OFF | | innodb_buffer_pool_filename | ib_buffer_pool | | innodb_buffer_pool_instances | 8 | | innodb_buffer_pool_load_abort | OFF | | innodb_buffer_pool_load_at_startup | OFF | | innodb_buffer_pool_load_now | OFF | | innodb_buffer_pool_populate | ON | | innodb_buffer_pool_size | 236223201280 | | innodb_change_buffer_max_size | 25 | | innodb_change_buffering | all | | innodb_checksum_algorithm | innodb | | innodb_checksums | ON | | innodb_cleaner_lsn_age_factor | high_checkpoint | | innodb_cmp_per_index_enabled | OFF | | innodb_commit_concurrency | 0 | | innodb_compressed_columns_threshold | 96 | | innodb_compressed_columns_zip_level | 6 | | innodb_compression_failure_threshold_pct | 5 | | innodb_compression_level | 6 | | innodb_compression_pad_pct_max | 50 | | innodb_concurrency_tickets | 5000 | | innodb_corrupt_table_action | assert | | innodb_data_file_path | ibdata1:64M:autoextend | | innodb_data_home_dir | | | innodb_disable_sort_file_cache | OFF | | innodb_doublewrite | ON | | innodb_empty_free_list_algorithm | backoff | | innodb_fake_changes | 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_timeout | 1 | | innodb_flush_log_at_trx_commit | 2 | | innodb_flush_method | O_DIRECT | | innodb_flush_neighbors | 1 | | innodb_flushing_avg_loops | 30 | | innodb_force_load_corrupted | OFF | | innodb_force_recovery | 0 | | innodb_foreground_preflush | exponential_backoff | | innodb_ft_aux_table | | | innodb_ft_cache_size | 8000000 | | innodb_ft_enable_diag_print | OFF | | innodb_ft_enable_stopword | ON | | innodb_ft_max_token_size | 84 | | innodb_ft_min_token_size | 3 | | innodb_ft_num_word_optimize | 2000 | | innodb_ft_result_cache_limit | 2000000000 | | innodb_ft_server_stopword_table | | | innodb_ft_sort_pll_degree | 2 | | innodb_ft_total_cache_size | 640000000 | | innodb_ft_user_stopword_table | | | innodb_io_capacity | 200 | | innodb_io_capacity_max | 2000 | | innodb_kill_idle_transaction | 0 | | innodb_large_prefix | OFF | | innodb_lock_wait_timeout | 400 | | innodb_locking_fake_changes | ON | | innodb_locks_unsafe_for_binlog | OFF | | innodb_log_arch_dir | ./ | | innodb_log_arch_expire_sec | 0 | | innodb_log_archive | OFF | | innodb_log_block_size | 512 | | innodb_log_buffer_size | 8388608 | | innodb_log_checksum_algorithm | innodb | | innodb_log_compressed_pages | ON | | innodb_log_file_size | 1073741824 | | innodb_log_files_in_group | 2 | | innodb_log_group_home_dir | ./ | | innodb_lru_scan_depth | 1024 | | innodb_max_bitmap_file_size | 104857600 | | innodb_max_changed_pages | 1000000 | | innodb_max_dirty_pages_pct | 75 | | innodb_max_dirty_pages_pct_lwm | 0 | | innodb_max_purge_lag | 0 | | innodb_max_purge_lag_delay | 0 | | innodb_mirrored_log_groups | 1 | | innodb_monitor_disable | | | innodb_monitor_enable | | | innodb_monitor_reset | | | innodb_monitor_reset_all | | | innodb_numa_interleave | ON | | innodb_old_blocks_pct | 37 | | innodb_old_blocks_time | 1000 | | innodb_online_alter_log_max_size | 134217728 | | innodb_open_files | 16384 | | innodb_optimize_fulltext_only | OFF | | innodb_page_size | 16384 | | innodb_print_all_deadlocks | OFF | | innodb_purge_batch_size | 300 | | innodb_purge_threads | 1 | | innodb_random_read_ahead | OFF | | innodb_read_ahead_threshold | 56 | | innodb_read_io_threads | 4 | | innodb_read_only | OFF | | innodb_replication_delay | 0 | | innodb_rollback_on_timeout | OFF | | innodb_rollback_segments | 128 | | innodb_sched_priority_cleaner | 19 | | innodb_show_locks_held | 10 | | innodb_show_verbose_locks | 0 | | innodb_sort_buffer_size | 1048576 | | innodb_spin_wait_delay | 6 | | innodb_stats_auto_recalc | ON | | innodb_stats_include_delete_marked | OFF | | innodb_stats_method | nulls_equal | | innodb_stats_on_metadata | OFF | | innodb_stats_persistent | ON | | innodb_stats_persistent_sample_pages | 20 | | innodb_stats_sample_pages | 8 | | innodb_stats_transient_sample_pages | 8 | | innodb_status_output | OFF | | innodb_status_output_locks | OFF | | innodb_strict_mode | OFF | | innodb_support_xa | ON | | innodb_sync_array_size | 1 | | innodb_sync_spin_loops | 30 | | innodb_table_locks | ON | | innodb_thread_concurrency | 32 | | innodb_thread_sleep_delay | 0 | | innodb_tmpdir | | | innodb_track_changed_pages | OFF | | innodb_undo_directory | . | | innodb_undo_logs | 128 | | innodb_undo_tablespaces | 0 | | innodb_use_atomic_writes | OFF | | innodb_use_global_flush_log_at_trx_commit | ON | | innodb_use_native_aio | ON | | innodb_use_sys_malloc | ON | | innodb_version | 5.6.35-80.0 | | innodb_write_io_threads | 4 | +-------------------------------------------+------------------------+

5
  • SHOW VARIABLES LIKE 'innodb%'; and SHOW GLOBAL STATUS LIKE 'Innodb%'; And SHOW STATUS LIKE 'Uptime';
    – Rick James
    Jan 22, 2018 at 21:46
  • RAM nnn TB/GB/MB on your Host server, indicate DEDICATED or SHARED? For analysis, current complete Text results of: A) SHOW GLOBAL STATUS; B) SHOW GLOBAL VARIABLES; C) complete current text of error log D) SHOW ENGINE INNODB STATUS; Optional very helpful information, if available includes - htop OR top for most active apps ulimit -a for a linux/unix list of limits, iostat -x for a linux/unix for IOPS of hardware extended status which Device(s) has your primary data? MySQLTuner.com entire report. Feb 25, 2018 at 17:25
  • With innodb_deadlocks of 5069, I would guess you had that many rollbacks of one form or another. If you could tell us how much RAM is on the SERVER and provide the other info requested Feb 25, I will do my best to help you with tuning, including turning loose innodb_write_io_threads which is 4 per the above info. Mar 3, 2018 at 17:31
  • 256GiB RAM, dedicated server. mysqltuner doesn't provide any special insights. I've since bumped innodb_write_io_threads to 8, which seems to have helped, but I still see pending AIO capped at 120.
    – dland
    Mar 7, 2018 at 16:45
  • @dland Please post here (or at pastebin.com) For analysis, current complete my.cnf/ini and Text results of: A) SHOW GLOBAL STATUS; B) SHOW GLOBAL VARIABLES; C) complete current text of error log D) SHOW ENGINE INNODB STATUS; Optional very helpful information, if available includes - htop OR top for most active apps ulimit -a for a linux/unix list of limits, iostat -x for a linux/unix for IOPS of hardware extended status which Device(s) has your primary data? MySQLTuner.com entire report. Mar 10, 2018 at 21:16

2 Answers 2

0

From the docs

A potential disadvantage of native AIO for heavily I/O-bound systems is lack of control over the number of I/O write requests dispatched to the operating system at once. Too many I/O write requests dispatched to the operating system for parallel processing could, in some cases, result in I/O read starvation, depending on the amount of I/O activity and system capabilities.

The docs only mention the conversion for reads threads, though I think it's the same,

InnoDB also attempts to allocate read requests from the same extent to the same thread, to increase the chances of coalescing the requests. If you have a high end I/O subsystem and you see more than 64 × innodb_read_io_threads pending read requests in SHOW ENGINE INNODB STATUS output, you might improve performance by increasing the value of innodb_read_io_threads.

So having more than 64 reads waiting, the advice is to raise it. But you're likely at some point to overwhelm the IO devices themselves and when you do that, holy hell will rain down upon you.

2
  • reads are fine, it's the writes that are piling up.
    – dland
    Jan 23, 2018 at 17:13
  • @dland Use SELECT @@innodb_io_capacity_max; and SELECT @@innodb_io_capacity; to verify you have enough basic throughput capacity to accomplish your goals. Post your current results, please. Jul 5, 2019 at 11:46
0

Suggestions for your my.cfg/ini after reviewing V8 refman

innodb_lru_scan_depth=128  # from 1024 to avoid overloading page_cleaneers
innodb_purge_threads=8  # from 1 to reduce innodb_buffer_pool_bytes_dirty

in a more timely manner.

when you get to newer version supporting this variable,

innodb_page_cleaners=64  # will autolimit to be = innodb_buffer_pool_instances

at startup will be automatic as you grow innodb_buffer_pool_size.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.