debugsqlMinor
MySQL 5.6.34 RDS Warning: a long semaphore wait causes crash -- log included
Viewed 0 times
waitloglongsemaphoremysqlincludedwarningrdscrashcauses
Problem
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
Any idea of where I can start looking?
```
mysql> show global status;
+-----------------------------------------------+--------------+
| Variable_name | Value |
+-----------------------------------------------+--------------+
| Aborted_client
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_client
Solution
Suggestions for your AMAZON RDS Custom DB Parameter Group to influence my.cnf Rate per Second=RPS
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 10241024 or 102410241024 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.
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 processingThe last 2 suggestions are NOT Dynamic, the others are DYNamic updates.
SET GLOBAL name=nn; K,M,G not available in CLI,
1024 or 10241024 or 102410241024 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.
Code Snippets
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 processingContext
StackExchange Database Administrators Q#216728, answer score: 2
Revisions (0)
No revisions yet.