求解 springboot+mysql 随机出现的异常延迟 两行紧挨着的代码,很简单的根据 id 更新一行数据,然后打印函数执行到此时的耗时
打印出来的日志如下
正常情况下两个打印出来的耗时差值应该是 10ms 以内 但是每天会随机出现几个时间点,两个耗时差值会大于 1s 甚至 10 ~ 20s 日志中可以看到并不是语句执行出现耗时,mybatis 已经把执行结果打印出来了 耗时出现在语句执行之后,但是出现结果之后应该就立即到打印日志了,这之间没有其他代码了,没明白这个延时是怎么产生的,求助
你这样算时间是极不靠谱的,编译器会对指令重排序
不只是看日志打印的时间数据,最近看每天的 16:10 分大概率会出现这个情况,这个时候去测试请求接口,也验证了确实会出现接口高延迟
测试环境可重试的话,尝试用 arthas 抓一下看看是哪个方法的问题
是不是那个时间点数据库连接池占满了
但是语句不是已经执行完了吗,这个时候连接池满也会有影响吗?
会不会集群或网络里面有两个 mysql 实例,形成了负载均衡,其中一个是性能较差的
内部系统,所以是内网部署的单实例数据库
代码硬看不出问题的话,看一下时段的主机、服务、数据库的情况
把 GC 日志也开了,full gc 也会引起类似情况。既然是每天的 16:10 分左右,那要排查下四点之后有没有计划任务,不局限于这个进程。
如果 op 用的 druid ,可能耗时在 druid 的获取连接和归还连接那边。jstack 配合 arthas 抓一下吧
备份进程导致高 io ?
1.数据库用了连接池吗? 2.更新会有行锁吗?
应该是有其他大事务把 id=220269386 这条记录锁住了。 锁住的可能有几种,update 的条件命中 id=220269386 或者 lock_status = 4 或者 lock_etime=1726041977 都会锁住这条记录,可以看一下慢查询日志
日志里已经出现 updates: 1 ,按照我的理解这应该已经完成提交了吧,查了数据库的 binlog ,也看到已经很快 commit 了
是的,那考虑下是不是 10 楼说的归还连接 以及 fullgc 影响
给你个极端的原因,定期 roll 日志文件的时候 io 塞住了
随机卡,还一卡卡那么久,考虑是随机数生成器问题了. -Djava.security.egd=file:/dev/urandom