MySQL信号量等待日志阅读
Posted 老叶茶馆_
tags:
篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了MySQL信号量等待日志阅读相关的知识，希望对你有一定的参考价值。
mysql中偶尔会遇到Hang住问题，show engine innodb status 中会显示大量的如下信息:
--Thread 140477271320320 has waited at ibuf0ibuf.cc line 3439 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x7fc5a5faa520 created in file buf0buf.cc line 1460
a writer (thread id 140477635114752) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: fffffffff0000000
Last time read locked in file ibuf0ibuf.cc line 4552
Last time write locked in file /dba/app/mysql_home/5.7.19/storage/innobase/ibuf/ibuf0ibuf.cc line 406
2020-11-25T09:33:15.302783+08:00 0 [Warning] InnoDB: A long semaphore wait:
--Thread 140477265372928 has waited at btr0cur.cc line 976 for 241.00 seconds the semaphore:
SX-lock on RW-latch at 0x7fc3189b57b0 created in file dict0dict.cc line 2687
a writer (thread id 140477291595520) has reserved it in mode SX
number of readers 0, waiters flag 1, lock_word: 10000000
Last time read locked in file btr0cur.cc line 1008
Last time write locked in file /dba/app/mysql_home/5.7.19/storage/innobase/btr/btr0cur.cc line 976这种信息比较难以让人理解，此文将分析如何阅读这些信息
信息解读
从上面内容可以得到如下信息:
Thread 140477271320320 在 ibuf0ibuf.cc line 343 添加锁时发生了等待，等待时间是241 s
这个RW-latch 创建在 buf0buf.cc line 1460
a writer (thread id 140477635114752) has reserved it in mode exclusive ， 140477635114752这个线程，作为写者已经获取到了这个RW-latch的锁，并且是独占方式
lock_word: fffffffff0000000 最重要的信息
关于lock_word 需要特殊说明其含义:
MySQL中系统层面的锁，有RW-latch，mutex，等，这里提到的都是RW-latch。lock_word代表了这个latch上的持有锁情况。RW-LOCK的加锁都是通过对lock_word减去某些值来实现加锁，解锁与其相反。MySQL中定义了两个宏:
/* We decrement lock_word by X_LOCK_DECR for each x_lock. It is also the
start value for the lock_word, meaning that it limits the maximum number
of concurrent read locks before the rw_lock breaks. */
/* We decrement lock_word by X_LOCK_HALF_DECR for sx_lock. */
#define X_LOCK_DECR 0x20000000
#define X_LOCK_HALF_DECR 0x10000000lock_word的初始值为X_LOCK_DECR，每次添加x锁时原子递减X_LOCK_DECR，每次添加S锁时原子递减1。每次添加SX锁时递减X_LOCK_HALF_DECR。如果读写锁支持递归写，那么第一个递归写锁加锁成功时，lock_word 依然原子递减X_LOCK_DECR，而后续的递归写锁加锁成功时，lock_word 只是原子递减1。
The status of a rw_lock is held in lock_word. The initial value of lock_word is
X_LOCK_DECR. lock_word is decremented by 1 for each s-lock and by X_LOCK_DECR
or 1 for each x-lock
lock_word对应不同的取值状态就代表了加锁情况:
这里需要结合加锁函数去看:
rw_lock_x_lock_low(rw_lock_t* lock, ulint pass, const char* file_name, ulint line)
// 如果lock_word>X_LOCK_HALF_DECR，尝试将lock_word减少X_LOCK_DECR，代表了X锁只能添加一次
// 如果成功，则至少预定自己为下一个写锁的持有者，返回true，否则返回false
if (rw_lock_lock_word_decr(lock, X_LOCK_DECR, X_LOCK_HALF_DECR))
// 预定自己为下一个写锁持有者，此时lock_word<=0，last_x_file_name:last_x_line 为上一个写锁持有者的上锁位置
// 将自己的线程标识写入writer_thread，
rw_lock_set_writer_id_and_recursion_flag(lock, !pass);)
// 如果lock_word<0，说明有线程持有读锁，必须等待读锁释放
// 阻塞直到 lock_word==0,
rw_lock_x_lock_wait(lock, pass, 0, file_name, line);
else
......
// 成功获得写锁，last_x_file_name:last_x_line指向加锁的位置
lock->last_x_file_name = file_name;
lock->last_x_line = (unsigned int) line;
return true;
rw_lock_lock_word_decr(
/*===================*/
rw_lock_t* lock, /*!< in/out: rw-lock */
ulint amount, /*!< in: amount to decrement */
lint threshold) /*!< in: threshold of judgement */
#ifdef INNODB_RW_LOCKS_USE_ATOMICS
lint local_lock_word;
os_rmb;
local_lock_word = lock->lock_word;
while (local_lock_word > threshold)
if (os_compare_and_swap_lint(&lock->lock_word,
local_lock_word,
local_lock_word - amount))
return(true);
local_lock_word = lock->lock_word;
return(false);
#else /* INNODB_RW_LOCKS_USE_ATOMICS */
bool success = false;
mutex_enter(&(lock->mutex));
if (lock->lock_word > threshold)
lock->lock_word -= amount;
success = true;
mutex_exit(&(lock->mutex));
return(success);
#endif /* INNODB_RW_LOCKS_USE_ATOMICS */
施加不同的锁时，传入的amount和threshold均不同:
| 加锁类型 | amount | threshold | 判断条件及加锁动作 If (lock_word > threshold) lock_word -= amount |
|---|---|---|---|
| s | 1 | 0 | |
| x | X_LOCK_DECR | X_LOCK_HALF_DECR | |
| sx | X_LOCK_HALF_DECR | X_LOCK_HALF_DECR |
举个例子:
lock_word 为初始值X_LOCK_DECR，添加x锁时:
while (local_lock_word > threshold)
if (os_compare_and_swap_lint(&lock->lock_word,
local_lock_word,
local_lock_word - amount))
return(true);
local_lock_word = lock->lock_word;
经过上面运算后lock_word = 0 即代表加X锁成功此问题中lock_word: fffffffff0000000 = - 268435456即- X_LOCK_HALF_DECR，代表添加了X和SX锁，
线程140477271320320再次申请S锁时就发生了等待。
Last time read locked in file ibuf0ibuf.cc line 4552 最后读取锁的位置
Last time write locked in file /dba/app/mysql_home/5.7.19/storage/innobase/ibuf/ibuf0ibuf.cc line 406 最后写入锁的位置
但是这两个并一定就是a writer (thread id xxx)持有的，需要配合lock_word或者根据状态:
has reserved it in mode exclusive
has reserved it in mode wait exclusive
来判断
RW-LATCH INFO
Total number of rw-locks 393385
OS WAIT ARRAY INFO: reservation count 585479
OS WAIT ARRAY INFO: signal count 112559
RW-shared spins 0, rounds 530324, OS waits 385606
RW-excl spins 0, rounds 1265658, OS waits 41898
RW-sx spins 67610, rounds 2015448, OS waits 66228
Spin rounds per wait: 530324.00 RW-shared, 1265658.00 RW-excl, 29.81 RW-sx关于spin lock流程如下:
尝试获得rw-lock锁:
成功 ， 直接返回
不成功，进入循环
开始循环
开始旋转N轮。（这里N由innodb_sync_spin_loops定义和控制）。默认值为30发。
步骤3a：每回合将调用PAUSE逻辑，这将导致CPU在X周期内进入PAUSE。
步骤3b：在每个回合后发布一次软检查，以确认是否有上述锁可用（busy-wait）。
如果可用，则旋转周期退出。
步骤3c：再次尝试获取所需的锁。
如果成功，则返回。（spins=1, rounds=M (M <= N), os-waits=0）
如果失败，并且有一些待处理的回合（max = innodb_sync_spin_loops），则继续旋转。（如何中断循环并导致锁定失败。注意：并行由多个线程查看该锁。虽然在尝试获取该锁时，多个线程已收到有关锁可用性的信号，但其他线程却接过了该锁因此，该线程现在返回重试）。
步骤3d：说一个线程现在完成了它的旋转等待轮，甚至现在它也没有获得锁。进一步旋转和浪费CPU周期没有任何意义。更好地放弃待处理的CPU周期，将其返回给OS，让OS调度做必要的事情。而且，由于所述线程现在要进入睡眠状态，因此应该在一些通用基础结构中注册自己，这将在有可用所述锁定时帮助其发回活动状态。
步骤3e：将线程基础结构通过信号发回到Innodb活动状态的同步阵列基础结构中
所述线程通过在所述阵列中保留插槽来注册自身。
在开始等待之前，请再次尝试查看该锁是否可用。（因为预订可能很耗时，并且锁可能同时可用）。
如果仍然没有锁，则等待同步阵列基础结构发信号通知该线程。
此等待称为OS等待，进入此循环现在将导致OS等待计数增加。
步骤3f：说该线程由同步阵列基础结构发信号通知等待事件。重试以获得所需的锁。
如果成功，则返回。（spins=1, rounds=N, os-waits=1）
如果失败，则整个循环从旋转逻辑重新启动（返回到第3步，并将回合计数重新初始化为0）。注意：spin次数不会重新增加。
PAUSE 逻辑
K = random value from between (0 - innodb_spin_wait_delay) * innodb_spin_wait_pause_multiplier
调用底层 PAUSE 指令 K 次.
Use Case 1
RW-shared spins 338969, rounds 20447615, OS waits 592941
RW-excl spins 50582, rounds 1502625, OS waits 56124
RW-sx spins 12583, rounds 360973, OS waits 10484
Spin rounds per wait: 60.32 RW-shared, 29.71 RW-excl, 28.69 RW-sx让我们分析一下共享自旋的情况:
RW-shared spins 338969, rounds 20447615, OS waits 592941
在头一次尝试中，用了338K 次仍未获取到锁，迫使线程进入自旋锁状态(spin-lock)。
在每个自旋周期内，执行了60轮PAUSE周期（因此，所述自旋周期执行了2次）。
OS-waits/spins = 592/338 = 1.75表明大部分被分流进入了OS-wait（PAUSE的延迟不够）。表明对于大多数自旋周期，单一的操OS-wait是不够的，因此这种操作是在重复进行的。
Conclusion: 该Use-case是高竞争情况。而且，诸如PAUSE循环无法产生所需的延迟来获得锁，导致每个自旋周期产生如此之多的PAUSE循环。
Use Case 2
RW-shared spins 35943, rounds 777178, OS waits 19051
RW-excl spins 4269, rounds 121796, OS waits 4164
RW-sx spins 13407, rounds 321954, OS waits 7346
Spin rounds per wait: 21.62 RW-shared, 28.53 RW-excl, 24.01 RW-sx让我们分析一下共享自旋的情况:
RW-shared spins 35943, rounds 777178, OS waits 19051
流程中，自旋循环35K次。
只有19K次(大约是自旋循环的一半)引起了OS-waits。
平均每个自旋周期也限制在777178/35943=21.62，这表明，对于每个自旋周期，平均有22轮PAUSE循环。
Conclusion: 该Use-case表示中度竞争情况。
Use Case 3
RW-shared spins 39578, rounds 424553, OS waits 7329
RW-excl spins 5828, rounds 78225, OS waits 1341
RW-sx spins 11666, rounds 67297, OS waits 449
Spin rounds per wait: 10.73 RW-shared, 13.42 RW-excl, 5.77 RW-sx流程中自旋循环39K次。
只有7K(约占自旋循环的20%) 导致OS-waits。
每自旋周期平均数也限制为424553/39578=10。
Conclusion: 该Use-case表示低竞争情况。
参考资料
《数据库事务处理的艺术: 事务管理与并发控制》-李海翔老师
https://mysqlonarm.github.io/Understanding-InnoDB-rwlock-stats/
http://mysql.taobao.org/monthly/2020/03/07/
《深入浅出MGR》视频课程
戳此小程序即可直达B站
https://www.bilibili.com/medialist/play/1363850082?business=space_collection&business_id=343928&desc=0
文章推荐：
想看更多技术好文，点个“在看”吧！
以上是关于MySQL信号量等待日志阅读的主要内容，如果未能解决你的问题，请参考以下文章