A case in MySQL for troubleshooting library delay conditions

  • 2020-11-03 22:37:44
  • OfStack

One core of mysqld's cpu occupies 100% under the condition that there is no business in the slave library under the condition of one customer's inspection today. Lookup slow queries also have no SQL on write.
It can be said that the single process copy of the Canon caused by 1 cpu occupied. Once you know why, it's easy to analyze.
Analyze what is written in binlog 1 to see where you can optimize or accelerate. Use tools: pasrebinlog
Using show slave status\G; Look up the currently synchronized to the node and parse the day value.


git clone https://github.com/wubx/mysql-binlog-statistic.git
cd mysql-binlog-statistic/bin/
parsebinlog /u1/mysql/logs/mysql-bin.000806

...
====================================
Table xx_db.xxtable:
Type DELETE opt :  101246
Type INSERT opt :  103265
================================
...


In order of the largest number, locate to: xx_db.xxtable. For one day value, more than 100,000 can be deleted, and more than 100,000 can be written. Is this table writing slower?
View innodb from the library:


MySQL> show engine innodb status\G;
...
---TRANSACTION 1C0C2DFDF, ACTIVE 3 sec fetching rows
mysql tables in use 1, locked 1
3361 lock struct(s), heap size 407992, 477888 row lock(s), undo log entries 42
MySQL thread id 43, OS thread handle 0x7fc1800c4700, query id 1908504 Reading event from the relay log
TABLE LOCK table xx_db.xxtable trx id 1C0C2DFDF lock mode IX
RECORD LOCKS space id 1002 page no 1975 n bits 1120 index `AK_movieid` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap
RECORD LOCKS space id 1002 page no 6965 n bits 264 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap
RECORD LOCKS space id 1002 page no 6967 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap
RECORD LOCKS space id 1002 page no 6973 n bits 264 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap
RECORD LOCKS space id 1002 page no 6982 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap
RECORD LOCKS space id 1002 page no 6983 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap
RECORD LOCKS space id 1002 page no 6987 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap
RECORD LOCKS space id 1002 page no 6999 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap
RECORD LOCKS space id 1002 page no 7000 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap
TOO MANY LOCKS PRINTED FOR THIS TRX: SUPPRESSING FURTHER PRINTS
----------------------------
END OF INNODB MONITOR OUTPUT

...


You can also see from Innodb's monitor output that es34EN_ES35en.xxtable is already a table level table, causing low concurrency and a large number of: GEN_CLUST_INDEX and belonging to one transaction. GEN_CLUST_INDEX means that there is no master build and one master build is generated internally. For the master build generated internally, it is very easy to cause page split operation.

Here is the solution to the problem:
Add 1 master to xx_db.xxtable. To es50EN_db.xxtable, an idint add-on with no business meaning has been added. In this way, it can be seen immediately that the cpu single core occupied by mysqld is reduced to about 3%. Meanwhile, the subsequent synchronization 1 cut is normal, and there is no synchronization delay in observation for one day.


Related articles: