开发者社区> superdba> 正文

一个锁等待现象的诊断案例

简介: 一个锁问题的排查案例,过程比较折腾,现在看看还是有些地方值得借鉴的
+关注继续查看

  前两天与一个客户交流的时候,客户提出了一些对mysql隔离级别以及锁的疑问,然后问到了出现锁等待现象的排查思路。和客户进行了简单交流之后,翻了翻之前的一个诊断案例,当时折腾了两三天,现在看看还是有些借鉴价值的。

问题描述

数据库实例:主库XXXX:3306 

问题详情:客户反映,涉及到user_site表相关的程序回调操作很慢,部分操作会超时报错;

下单操作很慢甚至直接报错失败

程序端报错信息如下:

General error: 1205 Lock wait timeout exceeded; try restarting transaction"

分析

这是个典型的锁等待超时退出的报错,原因可能是某些事务未及时提交导致锁资源不被释放导致

1、慢SQL分析

思路:通过rds控制台查看最近一段时间的慢SQL,看是否出现user_site表相关的DML或者select锁定读操作。 

查看慢SQL方式见下图

c07670ae0d2ee68522199f4336b07a9ce3d68dc8

很可惜,并没有找到相关的慢SQL,那么就代表SQL执行都很快,事务的处理上出现了问题,因此,我们更相信是某些程序没有及时提交事务导致的了。 

不过,还是有些收获的,我们发现一些潜在的问题,就是top前几的慢SQL。都是非锁定select,因此和本次现象无关,但是这几个查询操作最长需要近百秒,十分消耗CPU以及内存资源,需要优化。

2、事务阻塞分析

思路:通过一个脚本,定期采集出现阻塞的事务信息,只要再次进行相关操作,阻塞事件的参与事务信息便被计入日志,可对其进行详细分析。 

采集脚本如下:

#!/bin/bash


SQL="select r.trx_id waiting_trx_id,r.trx_mysql_thread_id waiting_thread,r.trx_query waiting_query,b.trx_id blocking_trx_id,b.trx_mysql_thread_id blocking_thread,b.trx_query blocking_query from information_schema.innodb_lock_waits w inner join information_schema.innodb_trx b on b.trx_id=w.blocking_trx_id inner join information_schema.innodb_trx r ON r.trx_id=w.requesting_trx_id\G"

 

while :

do

echo "================================="

echo "采集时间:"`date +%Y-%m-%d_%H:%M:%S`

echo "================================="

mysql -hXXXX -uXXXX -pXXXXXXXX -e "$SQL"

echo ""

 

sleep 5

done  

大约半小时后,日志中抓取到相关的信息

 

通过分析日志,我们发现每隔一段时间会出现较为严重的连环锁等待现象,主要是以下两种情况 

*************************** 1. row ***************************

 waiting_trx_id: 8822773749

 waiting_thread: 7297307

  waiting_query: SELECT funding FROM user_site where user_id = 38440594 and site_id = 3 FOR UPDATE

blocking_trx_id: 8822773748

blocking_thread: 7297310

 blocking_query: SELECT funding FROM user_site where user_id = 4 and site_id = 3 FOR UPDATE

*************************** 2. row ***************************

 waiting_trx_id: 8822773748

 waiting_thread: 7297310

  waiting_query: SELECT funding FROM user_site where user_id = 4 and site_id = 3 FOR UPDATE

blocking_trx_id: 8822602949

blocking_thread: 7120018

 blocking_query: NULL

 

  waiting_trx_id: 8814966658

 waiting_thread: 15064606

  waiting_query: UPDATE user_site SET id='85989170', user_id='71457291', site_id='3', password='a14f

2c3bae708de1d439c1d796ab319b', funding='0.64', subscribe_weixin='0', subscribe_alipay='0', rank='0',

 loginType='9', publishprojectNumber='0', supportNumber='4', followNumber='3', active='1', created='

2016-08-11 15:41:46', updated='2016-09-26 18:19:19', conf=NULL, identity='31' WHERE id = 85989170

blocking_trx_id: 8814920762

blocking_thread: 15012709

 blocking_query: NULL

 

解释下上面的日志输出:

waiting_trx_id: 被阻塞的事务ID

waiting_thread:被阻塞的mysql线程ID

waiting_query:被阻塞的SQL语句

blocking_trx_id: 阻塞者的事务ID

blocking_thread: 阻塞者的mysql线程ID

blocking_query: 阻塞者的SQL语句

 

我们发现,阻塞者总是处于非活跃状态,而后的相继操作会进入一个等待队列。之所以会发生阻塞,就是这个空事务持有着被阻塞事务所需要的锁资源,也就是说,以锁定的方式,访问到了相同的记录。

参考前面的慢SQL分析结果,进一步推论,事务内部的SQL执行应该是较快的,那么程序可能处理完SQL之后没有进行提交操作。

定位程序

与客户开发同学后沟通后,对该场景进行重现。实时输出日志,得到阻塞者的线程ID,通过information_schema.processlist视图查询出访问mysql数据库的程序。

客户开发同学仔细排查代码,很可惜也并没有发现未提交事务的代码。那么问题就可能出现在程序自身,是程序处理慢,而并非SQL。提交事务之前,程序极有可能经过一个缓慢的处理过程,至于处理什么,需要下一步做进一步的验证。

接下来,对上面的推论做验证

3、SQL审计分析

思路:想要找到是哪块代码的问题,盲目的找无疑是大海捞针,所幸的是,RDS提供SQL审计功能,只要找到事务提交之前的SQL操作,这个问题的定位就应该清晰明了了。

 

通过前面排查的线程ID,搜索相关的SQL审计记录。SQL审计可以通过下图方式查看。

f0da11b8d33089389d822bc96e2b7f5cf4275c2c 

点击数据库安全SQL审计。输入筛选条件:database name,程序访问数据库的用户名,关键字输入线程ID,并选择有效的时间范围。

 

这次,终于有些收获了,并且应该可以对本次现象做出合理的解释了。以下是可疑的数据库操作

32282327a1b55985448c226c9fc3be46cacec4fa 

 

1b79a3c56732c2476c775253c6968945b26be512

 

我们发现,事务开启后,立即进行了几个SQL操作,而这几个SQL都没有被计入慢日志,因此SQL执行很快(2S以内),从前面的日志输出我们也能看出,SQL执行是瞬间完成的,因为我们根本抓取不到事务的SQL语句。

而事务的提交操作却发生在十几分钟之后,那么现在的疑问就是解决问题的关键了。长达十几分钟的事务,而SQL执行总共不到2S,那么其余的时间程序在干什么?

有了针对性的目的后,该客户开发同学马上定位到程序并找到了问题所在,在提交之前,程序会去进行插入队列和删除缓存的操作,而这些操作,占用的都是事务的持有锁且非活动时间。

 

届此,该问题的分析过程全部结束,出现问题的原因就在于事务内部的非数据库操作 

处理方案

根因分析

事务内部进行的不只是数据库操作,程序进行的插入队列以及删除缓存操作,让一个2S之内完成的事务,延长至十几分钟;也就意味着,这十几分钟内,凡是请求事务内部锁资源的SQL操作,必须进入锁等待状态

处理建议

1.事务内部只进行SQL操作,程序的处理一律放在事务提交之后或开始之前

2.如果存在逻辑问题不可修改,可为相关处理过程设计处理队列,抛出指令即可,而不用等待这个过程处理完毕再提交事务

 

 

 

 

 

版权声明:本文内容由阿里云实名注册用户自发贡献,版权归原作者所有,阿里云开发者社区不拥有其著作权,亦不承担相应法律责任。具体规则请查看《阿里云开发者社区用户服务协议》和《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容,填写侵权投诉表单进行举报,一经查实,本社区将立刻删除涉嫌侵权内容。

相关文章
如何设置阿里云服务器安全组?阿里云安全组规则详细解说
阿里云安全组设置详细图文教程(收藏起来) 阿里云服务器安全组设置规则分享,阿里云服务器安全组如何放行端口设置教程。阿里云会要求客户设置安全组,如果不设置,阿里云会指定默认的安全组。那么,这个安全组是什么呢?顾名思义,就是为了服务器安全设置的。安全组其实就是一个虚拟的防火墙,可以让用户从端口、IP的维度来筛选对应服务器的访问者,从而形成一个云上的安全域。
19825 0
阿里云服务器如何登录?阿里云服务器的三种登录方法
购买阿里云ECS云服务器后如何登录?场景不同,阿里云优惠总结大概有三种登录方式: 登录到ECS云服务器控制台 在ECS云服务器控制台用户可以更改密码、更换系.
29215 0
阿里云服务器安全组设置内网互通的方法
虽然0.0.0.0/0使用非常方便,但是发现很多同学使用它来做内网互通,这是有安全风险的,实例有可能会在经典网络被内网IP访问到。下面介绍一下四种安全的内网互联设置方法。 购买前请先:领取阿里云幸运券,有很多优惠,可到下文中领取。
22543 0
阿里云服务器ECS登录用户名是什么?系统不同默认账号也不同
阿里云服务器Windows系统默认用户名administrator,Linux镜像服务器用户名root
16489 0
阿里云服务器端口号设置
阿里云服务器初级使用者可能面临的问题之一. 使用tomcat或者其他服务器软件设置端口号后,比如 一些不是默认的, mysql的 3306, mssql的1433,有时候打不开网页, 原因是没有在ecs安全组去设置这个端口号. 解决: 点击ecs下网络和安全下的安全组 在弹出的安全组中,如果没有就新建安全组,然后点击配置规则 最后如上图点击添加...或快速创建.   have fun!  将编程看作是一门艺术,而不单单是个技术。
20725 0
阿里云服务器怎么设置密码?怎么停机?怎么重启服务器?
如果在创建实例时没有设置密码,或者密码丢失,您可以在控制台上重新设置实例的登录密码。本文仅描述如何在 ECS 管理控制台上修改实例登录密码。
23590 0
+关注
superdba
Super, not a DBA, not a programmer. May be a singer, poet, ITer, and so on.
18
文章
0
问答
文章排行榜
最热
最新
相关电子书
更多
JS零基础入门教程(上册)
立即下载
性能优化方法论
立即下载
手把手学习日志服务SLS,云启实验室实战指南
立即下载