性能分析之死锁和日志相关的一个实例

前言

这个例子在做性能测试的时候出现的。

问题现象

团队在做性能测试，其实量并不大。只是我觉得没有什么明显的结果，于是我就自己把脚本拿来跑了一下。感觉怎么那么慢呢？

20 vusers：

40 vusers：

除了时间增加了，其他都没啥变化。系统资源也没上去。
当然，还有报错。

问题分析

然后我就乐呵呵的找日志去了。
但是日志吧？唉，真是看不下去，那写的叫一个乱。于是我把我们的架构师给拉进来了，让他看日志去。
看着看着，一开始吧，资源都用不上去。原因是在云服务器上用了公网 iP。这种的插曲，我都不乐意截图说明了，问题低级。
修改成内网 IP 之后，流量就能上来了，但是还是不乐观。
于是开始找新问题。

在性能分析的过程中一定要记得的事情是：找到时间消耗在哪。
找的手段和过程在每个系统中都会不一样，我就不再描述了。
当找到到这里的时候，基本上问题点就清晰了。

20 vusers:

40 vusers:

数据库耗时增加了。同时也看到了如下专业的错误提示：

Cause:com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlockfound when trying to get lock; try restarting transaction; SQL []; Deadlock found when trying to getlock; try restarting transaction; 

要知道死锁是很容易看出来的，但是数据库日志中居然没报日志。
当架构师发这个给我看的时候，我就两字怼回去：不信。
我要能看到具体的死锁日志，谁锁了谁，为啥要死锁呢，多大的仇呢？
于是让架构师接着折腾，他查了代码逻辑是有问题的。

性能调优

简单来说，就是之前这个事务是直接做 update，不管有没有记录，这就导致在 mysql 中当没有记录时会产生 X-gap 锁，这时候接着做insert，但是 insert 还没有做完的时候；另一个 session 的 update、insert 又开始了，这个 session 同样没有记录，又要加 X-Gap 锁。于是死锁信息出现了。

其实这个吧，有开发经验的应该都知道这种的处理逻辑。

在这个例子中，当然修改不止这些。其他还有修改的是：

1. 索引。这个索引的修改并没有引起性能的飙升，所以就不再细说了。

2. 日志。日志是影响性能的很重要也是很常见的因素，尽量把日志合理的写出去，又小又巧的日志是最合理的。

3. 一些参数啥的。

然后，再看下测试的结果：

每秒请求数可以到 400 左右了。
这时候系统资源也用起来了。

总结

性能分析吧，在每一个细节的事情里，几乎都是要关注的。
但是耐心还是很重要的，要不然就会像老司机一样开车不看路了。