3

I had my RDS MySQL 5.6.34 server crash under normal load with nothing out of the ordinary today (That I could find). Amazon support pointed me the the error log.

MySQL config: https://gist.github.com/blasto333/9e82b6261681303f7369c3a2652e03f2

You can see full error log at:

https://www.dropbox.com/s/8y10mfok4l6zc1m/mysql-error-running.log.21.txt?dl=0

Most of the error log has:

InnoDB: Warning: a long semaphore wait: --Thread 47504778909440 has waited at dict0dict.cc line 1122 for 241.00 seconds the semaphore: Mutex at 0x2b33b16f34a8 created file dict0dict.cc line 1057, lock var 1 waiters flag 1 InnoDB: Warning: a long semaphore wait:

There is deadlock too

LATEST DETECTED DEADLOCK
------------------------
2018-07-05 23:11:31 2b34c9f8d700
*** (1) TRANSACTION:
TRANSACTION 1056966456, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 22 lock struct(s), heap size 2936, 10 row lock(s), undo log entries 8
MySQL thread id 149979681, OS thread handle 0x2b348aea9700, query id 1268732633 172.31.43.29 phppoint updating
UPDATE `phppos_items` SET `last_modified` = '2018-07-05 18:11:31'
WHERE `item_id` = 9794
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 1273297 n bits 152 index `PRIMARY` of table `phppoint_fatpanda`.`phppos_items` trx id 1056966456 lock_mode X locks rec but not gap waiting
Record lock, heap no 30 PHYSICAL RECORD: n_fields 61; compact format; info bits 0
 0: len 4; hex 80002642; asc   &B;;
 1: len 6; hex 00003f00027d; asc   ?  };;
 2: len 7; hex 1b00013aea2ab2; asc    : * ;;
 3: len 24; hex 4650205468757273646179204368756262792050726f6d6f; asc FP Thursday Chubby Promo;;
 4: len 4; hex 80000041; asc    A;;

Any idea of where I can start looking?

mysql> show global status;
+-----------------------------------------------+--------------+
| Variable_name                                 | Value        |
+-----------------------------------------------+--------------+
| Aborted_clients                               | 75           |
| Aborted_connects                              | 767          |
| Binlog_cache_disk_use                         | 23592        |
| Binlog_cache_use                              | 1910314      |
| Binlog_stmt_cache_disk_use                    | 0            |
| Binlog_stmt_cache_use                         | 9909         |
| Bytes_received                                | 19020005934  |
| Bytes_sent                                    | 450148820308 |
| Com_admin_commands                            | 9            |
| Com_assign_to_keycache                        | 0            |
| Com_alter_db                                  | 0            |
| Com_alter_db_upgrade                          | 0            |
| Com_alter_event                               | 0            |
| Com_alter_function                            | 0            |
| Com_alter_procedure                           | 0            |
| Com_alter_server                              | 0            |
| Com_alter_table                               | 6097         |
| Com_alter_tablespace                          | 0            |
| Com_alter_user                                | 0            |
| Com_analyze                                   | 0            |
| Com_begin                                     | 50002        |
| Com_binlog                                    | 0            |
| Com_call_procedure                            | 66           |
| Com_change_db                                 | 332896       |
| Com_change_master                             | 0            |
| Com_check                                     | 0            |
| Com_checksum                                  | 0            |
| Com_commit                                    | 50169        |
| Com_create_db                                 | 25           |
| Com_create_event                              | 0            |
| Com_create_function                           | 0            |
| Com_create_index                              | 0            |
| Com_create_procedure                          | 0            |
| Com_create_server                             | 0            |
| Com_create_table                              | 2822         |
| Com_create_trigger                            | 0            |
| Com_create_udf                                | 0            |
| Com_create_user                               | 0            |
| Com_create_view                               | 0            |
| Com_dealloc_sql                               | 0            |
| Com_delete                                    | 70492        |
| Com_delete_multi                              | 148          |
| Com_do                                        | 0            |
| Com_drop_db                                   | 1            |
| Com_drop_event                                | 0            |
| Com_drop_function                             | 0            |
| Com_drop_index                                | 0            |
| Com_drop_procedure                            | 0            |
| Com_drop_server                               | 0            |
| Com_drop_table                                | 615          |
| Com_drop_trigger                              | 0            |
| Com_drop_user                                 | 0            |
| Com_drop_view                                 | 0            |
| Com_empty_query                               | 0            |
| Com_execute_sql                               | 0            |
| Com_flush                                     | 2023         |
| Com_get_diagnostics                           | 0            |
| Com_grant                                     | 2            |
| Com_ha_close                                  | 0            |
| Com_ha_open                                   | 0            |
| Com_ha_read                                   | 0            |
| Com_help                                      | 0            |
| Com_insert                                    | 494163       |
| Com_insert_select                             | 0            |
| Com_install_plugin                            | 0            |
| Com_kill                                      | 66           |
| Com_load                                      | 0            |
| Com_lock_tables                               | 2819         |
| Com_optimize                                  | 97           |
| Com_preload_keys                              | 0            |
| Com_prepare_sql                               | 0            |
| Com_purge                                     | 662          |
| Com_purge_before_date                         | 0            |
| Com_release_savepoint                         | 0            |
| Com_rename_table                              | 0            |
| Com_rename_user                               | 0            |
| Com_repair                                    | 0            |
| Com_replace                                   | 47982        |
| Com_replace_select                            | 9            |
| Com_reset                                     | 0            |
| Com_resignal                                  | 0            |
| Com_revoke                                    | 0            |
| Com_revoke_all                                | 0            |
| Com_rollback                                  | 65           |
| Com_rollback_to_savepoint                     | 0            |
| Com_savepoint                                 | 0            |
| Com_select                                    | 14400535     |
| Com_set_option                                | 11497318     |
| Com_signal                                    | 0            |
| Com_show_binlog_events                        | 0            |
| Com_show_binlogs                              | 33           |
| Com_show_charsets                             | 0            |
| Com_show_collations                           | 0            |
| Com_show_create_db                            | 1717         |
| Com_show_create_event                         | 0            |
| Com_show_create_func                          | 0            |
| Com_show_create_proc                          | 208          |
| Com_show_create_table                         | 486369       |
| Com_show_create_trigger                       | 40           |
| Com_show_databases                            | 53           |
| Com_show_engine_logs                          | 0            |
| Com_show_engine_mutex                         | 0            |
| Com_show_engine_status                        | 2            |
| Com_show_events                               | 20           |
| Com_show_errors                               | 0            |
| Com_show_fields                               | 2087822      |
| Com_show_function_code                        | 0            |
| Com_show_function_status                      | 3436         |
| Com_show_grants                               | 10           |
| Com_show_keys                                 | 42           |
| Com_show_master_status                        | 13           |
| Com_show_open_tables                          | 0            |
| Com_show_plugins                              | 0            |
| Com_show_privileges                           | 0            |
| Com_show_procedure_code                       | 0            |
| Com_show_procedure_status                     | 3436         |
| Com_show_processlist                          | 119951       |
| Com_show_profile                              | 0            |
| Com_show_profiles                             | 0            |
| Com_show_relaylog_events                      | 0            |
| Com_show_slave_hosts                          | 0            |
| Com_show_slave_status                         | 10           |
| Com_show_status                               | 1917         |
| Com_show_storage_engines                      | 0            |
| Com_show_table_status                         | 324246       |
| Com_show_tables                               | 1276858      |
| Com_show_triggers                             | 324172       |
| Com_show_variables                            | 2051         |
| Com_show_warnings                             | 4            |
| Com_slave_start                               | 0            |
| Com_slave_stop                                | 0            |
| Com_stmt_close                                | 3            |
| Com_stmt_execute                              | 23           |
| Com_stmt_fetch                                | 10           |
| Com_stmt_prepare                              | 23           |
| Com_stmt_reprepare                            | 0            |
| Com_stmt_reset                                | 0            |
| Com_stmt_send_long_data                       | 0            |
| Com_truncate                                  | 252          |
| Com_uninstall_plugin                          | 0            |
| Com_unlock_tables                             | 4537         |
| Com_update                                    | 1876581      |
| Com_update_multi                              | 0            |
| Com_xa_commit                                 | 0            |
| Com_xa_end                                    | 0            |
| Com_xa_prepare                                | 0            |
| Com_xa_recover                                | 0            |
| Com_xa_rollback                               | 0            |
| Com_xa_start                                  | 0            |
| Compression                                   | OFF          |
| Connection_errors_accept                      | 0            |
| Connection_errors_internal                    | 0            |
| Connection_errors_max_connections             | 0            |
| Connection_errors_peer_address                | 0            |
| Connection_errors_select                      | 0            |
| Connection_errors_tcpwrap                     | 0            |
| Connections                                   | 14109046     |
| Created_tmp_disk_tables                       | 3483968      |
| Created_tmp_files                             | 27074        |
| Created_tmp_tables                            | 5675076      |
| Delayed_errors                                | 0            |
| Delayed_insert_threads                        | 0            |
| Delayed_writes                                | 0            |
| Flush_commands                                | 1            |
| Handler_commit                                | 16730928     |
| Handler_delete                                | 58746        |
| Handler_discover                              | 0            |
| Handler_external_lock                         | 44461222     |
| Handler_mrr_init                              | 0            |
| Handler_prepare                               | 4935298      |
| Handler_read_first                            | 555947737    |
| Handler_read_key                              | 4342441284   |
| Handler_read_last                             | 51021        |
| Handler_read_next                             | 4410037167   |
| Handler_read_prev                             | 1041500      |
| Handler_read_rnd                              | 66317337     |
| Handler_read_rnd_next                         | 4061126421   |
| Handler_rollback                              | 14002        |
| Handler_savepoint                             | 0            |
| Handler_savepoint_rollback                    | 0            |
| Handler_update                                | 6298422      |
| Handler_write                                 | 528228581    |
| Innodb_buffer_pool_dump_status                | not started  |
| Innodb_buffer_pool_load_status                | not started  |
| Innodb_buffer_pool_pages_data                 | 157888       |
| Innodb_buffer_pool_bytes_data                 | 2586836992   |
| Innodb_buffer_pool_pages_dirty                | 1456         |
| Innodb_buffer_pool_bytes_dirty                | 23855104     |
| Innodb_buffer_pool_pages_flushed              | 6097239      |
| Innodb_buffer_pool_pages_free                 | 8192         |
| Innodb_buffer_pool_pages_misc                 | 0            |
| Innodb_buffer_pool_pages_total                | 166080       |
| Innodb_buffer_pool_read_ahead_rnd             | 0            |
| Innodb_buffer_pool_read_ahead                 | 4175098      |
| Innodb_buffer_pool_read_ahead_evicted         | 1998         |
| Innodb_buffer_pool_read_requests              | 20669375353  |
| Innodb_buffer_pool_reads                      | 19725302     |
| Innodb_buffer_pool_wait_free                  | 0            |
| Innodb_buffer_pool_write_requests             | 36813736     |
| Innodb_data_fsyncs                            | 4000141      |
| Innodb_data_pending_fsyncs                    | 0            |
| Innodb_data_pending_reads                     | 0            |
| Innodb_data_pending_writes                    | 0            |
| Innodb_data_read                              | 394739994624 |
| Innodb_data_reads                             | 24092362     |
| Innodb_data_writes                            | 9335083      |
| Innodb_data_written                           | 210941677568 |
| Innodb_dblwr_pages_written                    | 6097239      |
| Innodb_dblwr_writes                           | 577145       |
| Innodb_have_atomic_builtins                   | ON           |
| Innodb_log_waits                              | 0            |
| Innodb_log_write_requests                     | 20665741     |
| Innodb_log_writes                             | 2583719      |
| Innodb_os_log_fsyncs                          | 2659640      |
| Innodb_os_log_pending_fsyncs                  | 0            |
| Innodb_os_log_pending_writes                  | 0            |
| Innodb_os_log_written                         | 11108775936  |
| Innodb_page_size                              | 16384        |
| Innodb_pages_created                          | 323226       |
| Innodb_pages_read                             | 24091712     |
| Innodb_pages_written                          | 6097239      |
| Innodb_row_lock_current_waits                 | 0            |
| Innodb_row_lock_time                          | 658          |
| Innodb_row_lock_time_avg                      | 5            |
| Innodb_row_lock_time_max                      | 19           |
| Innodb_row_lock_waits                         | 123          |
| Innodb_rows_deleted                           | 58747        |
| Innodb_rows_inserted                          | 503434       |
| Innodb_rows_read                              | 9533246024   |
| Innodb_rows_updated                           | 2062321      |
| Innodb_num_open_files                         | 14           |
| Innodb_truncated_status_writes                | 0            |
| Innodb_available_undo_logs                    | 128          |
| Key_blocks_not_flushed                        | 0            |
| Key_blocks_unused                             | 13396        |
| Key_blocks_used                               | 3898         |
| Key_read_requests                             | 968442355    |
| Key_reads                                     | 260          |
| Key_write_requests                            | 314009997    |
| Key_writes                                    | 0            |
| Last_query_cost                               | 0.000000     |
| Last_query_partial_plans                      | 0            |
| Max_used_connections                          | 429          |
| Not_flushed_delayed_rows                      | 0            |
| Open_files                                    | 3            |
| Open_streams                                  | 0            |
| Open_table_definitions                        | 1400         |
| Open_tables                                   | 2000         |
| Opened_files                                  | 15050970     |
| Opened_table_definitions                      | 1057163      |
| Opened_tables                                 | 4565317      |
| Performance_schema_accounts_lost              | 0            |
| Performance_schema_cond_classes_lost          | 0            |
| Performance_schema_cond_instances_lost        | 0            |
| Performance_schema_digest_lost                | 0            |
| Performance_schema_file_classes_lost          | 0            |
| Performance_schema_file_handles_lost          | 0            |
| Performance_schema_file_instances_lost        | 0            |
| Performance_schema_hosts_lost                 | 0            |
| Performance_schema_locker_lost                | 0            |
| Performance_schema_mutex_classes_lost         | 0            |
| Performance_schema_mutex_instances_lost       | 0            |
| Performance_schema_rwlock_classes_lost        | 0            |
| Performance_schema_rwlock_instances_lost      | 0            |
| Performance_schema_session_connect_attrs_lost | 0            |
| Performance_schema_socket_classes_lost        | 0            |
| Performance_schema_socket_instances_lost      | 0            |
| Performance_schema_stage_classes_lost         | 0            |
| Performance_schema_statement_classes_lost     | 0            |
| Performance_schema_table_handles_lost         | 0            |
| Performance_schema_table_instances_lost       | 0            |
| Performance_schema_thread_classes_lost        | 0            |
| Performance_schema_thread_instances_lost      | 0            |
| Performance_schema_users_lost                 | 0            |
| Prepared_stmt_count                           | 0            |
| Qcache_free_blocks                            | 4359         |
| Qcache_free_memory                            | 11838224     |
| Qcache_hits                                   | 53345695     |
| Qcache_inserts                                | 10498816     |
| Qcache_lowmem_prunes                          | 4945792      |
| Qcache_not_cached                             | 3901891      |
| Qcache_queries_in_cache                       | 11254        |
| Qcache_total_blocks                           | 32300        |
| Queries                                       | 100927051    |
| Questions                                     | 100924711    |
| Select_full_join                              | 1119531      |
| Select_full_range_join                        | 1691         |
| Select_range                                  | 976854       |
| Select_range_check                            | 37           |
| Select_scan                                   | 5601093      |
| Slave_heartbeat_period                        | 0.000        |
| Slave_last_heartbeat                          |              |
| Slave_open_temp_tables                        | 0            |
| Slave_received_heartbeats                     | 0            |
| Slave_retried_transactions                    | 0            |
| Slave_running                                 | OFF          |
| Slow_launch_threads                           | 0            |
| Slow_queries                                  | 1045         |
| Sort_merge_passes                             | 7119         |
| Sort_range                                    | 246182       |
| Sort_rows                                     | 66189786     |
| Sort_scan                                     | 1565455      |
| Ssl_accept_renegotiates                       | 0            |
| Ssl_accepts                                   | 0            |
| Ssl_callback_cache_hits                       | 0            |
| Ssl_cipher                                    |              |
| Ssl_cipher_list                               |              |
| Ssl_client_connects                           | 0            |
| Ssl_connect_renegotiates                      | 0            |
| Ssl_ctx_verify_depth                          | 0            |
| Ssl_ctx_verify_mode                           | 0            |
| Ssl_default_timeout                           | 0            |
| Ssl_finished_accepts                          | 0            |
| Ssl_finished_connects                         | 0            |
| Ssl_server_not_after                          |              |
| Ssl_server_not_before                         |              |
| Ssl_session_cache_hits                        | 0            |
| Ssl_session_cache_misses                      | 0            |
| Ssl_session_cache_mode                        | Unknown      |
| Ssl_session_cache_overflows                   | 0            |
| Ssl_session_cache_size                        | 0            |
| Ssl_session_cache_timeouts                    | 0            |
| Ssl_sessions_reused                           | 0            |
| Ssl_used_session_cache_entries                | 0            |
| Ssl_verify_depth                              | 0            |
| Ssl_verify_mode                               | 0            |
| Ssl_version                                   |              |
| Table_locks_immediate                         | 22141644     |
| Table_locks_waited                            | 0            |
| Table_open_cache_hits                         | 20638283     |
| Table_open_cache_misses                       | 4565315      |
| Table_open_cache_overflows                    | 4559458      |
| Tc_log_max_pages_used                         | 0            |
| Tc_log_page_size                              | 0            |
| Tc_log_page_waits                             | 0            |
| Threads_cached                                | 53           |
| Threads_connected                             | 19           |
| Threads_created                               | 31446        |
| Threads_running                               | 2            |
| Uptime                                        | 601636       |
| Uptime_since_flush_status                     | 601636       |
+-----------------------------------------------+--------------+
341 rows in set (0.00 sec)
  • Appears to be a very old (bug)[bugs.mysql.com/bug.php?id=73890] . You can try disabling innodb_adaptive_hash_index and restart the rds instance – Kapil Bhagchandani Sep 10 '18 at 2:31
  • 1
    This is the conclusion I came to also and made that change. Do you think this will solve it? I have be running this RDS instinct for over 1.5 years without this happening. – Chris Muench Sep 10 '18 at 21:18
  • 1
    Also what exactly caused it? – Chris Muench Sep 10 '18 at 21:19
  • @ChrisMuench Additional information requested. A) RAM on your host server? B) Please post TEXT results of SHOW GLOBAL STATUS; to go with previously posted information. Will try to have Suggestions for you before the bounty expries. – Wilson Hauck Sep 11 '18 at 17:43
  • @ChrisMuench MORE Additional information request, please. Post on pastebin.com or here. A) complete (not edited) my.cnf or my.ini Text results of: D) complete MySQLTuner report AND Optional very helpful information, if available includes - htop OR top OR mytop for most active apps, ulimit -a for a linux/unix list of limits, iostat -x when system is busy for an idea of IOPS by device, df -h for a linux/unix free space list by device, for server tuning analysis. – Wilson Hauck Sep 11 '18 at 18:01
2
+150

Suggestions for your AMAZON RDS Custom DB Parameter Group to influence my.cnf Rate per Second=RPS

read_rnd_buffer_size=256K  # from 512K to reduce CPU busy
innodb_io_capacity_max=20000  # from 2000 to open the SSD door wider
innodb_io_capacity=10000  # from 200 to take advantage of SSD capability
thread_cache_size=100  # from 68 to reduce threads_created CAP=100
innodb_lru_scan_depth=100  # from 1024 to reduce CPU busy see refman
innodb_flushing_avg_loops=10  # from 30 to reduce loop delay
innodb_purge_threads=4  # from 1 to expedite purge cycles
table_open_cache=10000  # from 2000 to reduce opened_tables RPS
table_definition_cache=10000  # from 1400 to reduce opened_table_definitions RPS
innodb_buffer_pool_size=3G  # from ~2.7G to reduce innodb_data_reads RPS
innodb_log_buffer_size=40M  # from 8M to support ~ 30 minutes in RAM
thread_concurrency=20  # from 10 to expedite processing

The last 2 suggestions are NOT Dynamic, the others are DYNamic updates. SET GLOBAL name=nn; K,M,G not available in CLI, *1024 or *1024*1024 or *1024*1024*1024 for K M G respectively.

Remember the ONE A DAY, monitor BEFORE moving to next Suggestion. When in doubt, put back the old value until you can determine side effects.

14,002 handler_rollback count in 7 days does NOT seem reasonable to me. 23 com_stmt_prepare with only 3 com_stmt_close is abnormal, to release resources, the close is needed.

The very BEST to you and your group.

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.