前言

本篇主要讲解的是前阵子的一个压测问题.那么就直接开门见山

可能有的朋友不并不知道forceTransactionTemplate这个是干嘛的,首先这里先普及一下,在Java中,我们一般开启事务就有三种方式

XML中根据service及方法名配置切面,来开启事务(前几年用的频率较高,现在基本很少用)
@Transactional注解开启事务(使用频率最高)
采用spring的事务模板(截图中的方式,几乎没什么人用)

我们先不纠结为什么使用第三种,后面在讲事务传播机制的时候我会专门介绍,我们聚焦一下主题,你现在只要知道,那个是开启事务的意思就行了.我特意用红色和蓝色把日志代码圈起来,意思就是,进入方法的时候打印日志,然后开启事务后,再打印一个日志.一波压测之后,发现接口频繁超时,数据一致压不上去.我们查看日志如下:

我们发现.这两个日志输出的时间间隔,竟然用了接近5秒!开个事务为何用了5秒?事出反常必有妖!

如何切入解决问题

线上遇到高并发的问题,由于一般高并发问题重现难度比较大,所以一般肥朝都是采用眼神编译,九浅一深静态看源码的方式来分析.具体可以参考本地可跑,上线就崩?慌了!.但是考虑到肥朝公众号仍然有小部分新关注的粉丝尚未掌握分析问题的技巧,本篇就再讲一些遇到此类问题的一些常见分析方式,不至于遇到问题时,慌得一比!

好在这个并发问题的难度并不大,本篇案例排查非常适合小白入门,我们可以通过本地模拟场景重现,将问题范围缩小,从而逐步定位问题.

本地重现

首先我们可以准备一个并发工具类,通过这个工具类,可以在本地环境模拟并发场景.手机查看代码并不友好,但是没关系,以下代码均是给你复制粘贴进项目重现问题用的,并不是给你手机上看的.至于这个工具类为什么能模拟并发场景,由于这个工具类的代码**全是JDK中的代码**,核心就是CountDownLatch类,这个原理你根据我提供的关键字对着你喜欢的搜索引擎搜索即可.

CountDownLatchUtil.java

public class CountDownLatchUtil {

    private CountDownLatch start;
    private CountDownLatch end;
    private int pollSize = 10;

    public CountDownLatchUtil() {
        this(10);
    }

    public CountDownLatchUtil(int pollSize) {
        this.pollSize = pollSize;
        start = new CountDownLatch(1);
        end = new CountDownLatch(pollSize);
    }

    public void latch(MyFunctionalInterface functionalInterface) throws InterruptedException {
        ExecutorService executorService = Executors.newFixedThreadPool(pollSize);
        for (int i = 0; i < pollSize; i++) {
            Runnable run = new Runnable() {
                @Override
                public void run() {
                    try {
                        start.await();
                        functionalInterface.run();
                    } catch (InterruptedException e) {
                        e.printStackTrace();
                    } finally {
                        end.countDown();
                    }
                }
            };
            executorService.submit(run);
        }

        start.countDown();
        end.await();
        executorService.shutdown();
    }

    @FunctionalInterface
    public interface MyFunctionalInterface {
        void run();
    }
}

HelloService.java

public interface HelloService {

    void sayHello(long timeMillis);

}

HelloServiceImpl.java

@Service
public class HelloServiceImpl implements HelloService {

    private final Logger log = LoggerFactory.getLogger(HelloServiceImpl.class);

    @Transactional
    @Override
    public void sayHello(long timeMillis) {
        long time = System.currentTimeMillis() - timeMillis;
        if (time > 5000) {
            //超过5秒的打印日志输出
            log.warn("time : {}", time);
        }
        try {
            //模拟业务执行时间为1s
            Thread.sleep(1000);
        } catch (Exception e) {
            e.printStackTrace();
        }
    }
}

HelloServiceTest.java

@RunWith(SpringRunner.class)
@SpringBootTest
public class HelloServiceTest {

    @Autowired
    private HelloService helloService;

    @Test
    public void testSayHello() throws Exception {
        long currentTimeMillis = System.currentTimeMillis();
        //模拟1000个线程并发
        CountDownLatchUtil countDownLatchUtil = new CountDownLatchUtil(1000);
        countDownLatchUtil.latch(() -> {
            helloService.sayHello(currentTimeMillis);
        });
    }

}

我们从本地调试的日志中,发现了大量超过5s的接口,并且还有一些规律,肥朝特地用不同颜色的框框给大家框起来

为什么这些时间,都是5个为一组,且每组数据相差是1s左右呢?

真相大白

@Transactional的核心代码如下(后续我会专门一个系列分析这部分源码,关注肥朝以免错过核心内容).这里简单说就是TransactionInfo txInfo = createTransactionIfNecessary(tm, txAttr, joinpointIdentification);方法会去获取数据库连接.

if (txAttr == null || !(tm instanceof CallbackPreferringPlatformTransactionManager)) {
	// Standard transaction demarcation with getTransaction and commit/rollback calls.
	TransactionInfo txInfo = createTransactionIfNecessary(tm, txAttr, joinpointIdentification);
	Object retVal = null;
	try {
		// This is an around advice: Invoke the next interceptor in the chain.
		// This will normally result in a target object being invoked.
		retVal = invocation.proceedWithInvocation();
	}
	catch (Throwable ex) {
		// target invocation exception
		completeTransactionAfterThrowing(txInfo, ex);
		throw ex;
	}
	finally {
		cleanupTransactionInfo(txInfo);
	}
	commitTransactionAfterReturning(txInfo);
	return retVal;
}

然后肥朝为了更好的演示这个问题,将数据库连接池(本篇用的是Druid)的参数做了以下设置

//初始连接数
spring.datasource.initialSize=1
//最大连接数
spring.datasource.maxActive=5

由于最大连接数是5.所以当1000个线程并发进来的时候,你可以想象是一个队伍有1000个人排队,最前面的5个,拿到了连接,并且执行业务时间为1秒.那么队伍中剩下的995个人,就在门外等候.等这5个执行完的时候.释放了5个连接,依次向后的5个人又进来,又执行1秒的业务操作.通过简单的小学数学,都可以计算出最后5个执行完,需要多长时间.通过这里分析,你就知道,为什么上面的日志输出,是5秒为一组了,并且每组间隔为1s了.

怎么解决

看过肥朝源码实战的粉丝都知道,肥朝从来不耍流氓,凡是抛出问题,都会相应给出其中一种解决方案.当然方案没有最优只有更优!

比如看到这里有的朋友可能会说,你最大连接数设置得**就像平时赞赏肥朝的金额一样小**,如果设置大一点,自然就不会有问题了.当然这里为了方便向大家演示问题,设置了最大连接数是5.正常生产的连接数是要根据业务特点和不断压测才能得出合理的值,当然肥朝也了解到,部分同学公司机器的配置,竟然比不过市面上的千元手机!!!

但是其实当时压测的时候,数据库的最大连接数设置的是200,并且当时的压测压力并不大.那为什么还会有这个问题呢?那么仔细看前面的代码

其中这个校验的代码是RPC调用,该接口的同事并没有像肥朝一样值得托付终身般的高度可靠,导致耗时时间较长,从而导致后续线程获取数据库连接等待的时间过长.你再根据前面说的小学数学来算一下就很容易明白该压测问题出现的原因.

敲黑板划重点

之前肥朝就反复说过,遇到问题,要经过深度思考.比如这个问题,我们能得到什么拓展性的思考呢?我们来看一下之前一位粉丝的面试经历

其实他面试遇到的这个问题,和我们这个压测问题基本是同一个问题,只不过面试官的结论其实并不够准确.我们来一起看一下阿里巴巴的开发手册

那么什么样叫做滥用呢?其实肥朝认为,即使这个方法经常调用,但是都是单表insert、update操作,执行时间非常短,那么承受较大并发问题也不大.关键是,这个事务中的所有方法调用,是否是有意义的,或者说,事务中的方法是否是真的要事务保证,才是关键.因为部分同学,在一些比较传统的公司,做的多是能用就行的CRUD工作,很容易一个service方法,就直接打上事务注解开始事务,然后在一个事务中,进行大量和事务一毛钱关系都没有的无关耗时操作,比如文件IO操作,比如查询校验操作等.例如本文中的业务校验就完全没必要放在事务中.平时工作中没有相应的实战场景,加上并没有关注肥朝的公众号,对原理源码真实实战场景一无所知.面试稍微一问原理就喊痛,面试官也只好换个方向再继续深入!

通过这个经历我们又有什么拓展性的思考呢?因为问题是永远解决不完的,但是我们可以通过不断的思考,把这个问题压榨出更多的价值!我们再来看一下阿里规范手册

用大白话概括就是,尽量减少锁的粒度.并且尽量避免在锁中调用RPC方法,因为RPC方法涉及网络因素,他的调用时间存在很大的不可控,很容易就造成了占用锁的时间过长.

其实这个和我们这个压测问题是一样的.首先你本地事务中调用RPC既不能起到事务作用(RPC需要分布式事务保证),但是又会因为RPC不可控因素导致数据库连接占用时间过长.从而引起接口超时.当然我们也可以通过APM工具来梳理接口的耗时拓扑,将此类问题在压测前就暴露.

写在最后