记一次微服务链路追踪分析

情景：再一次压力测试下，制定的指标有单线程请求服务，响应时间要控制在200ms内。然后测试结果是，每一次请求的响应都是在300-350ms，由此引出一个问题耗时点在哪里；

1.多次请求业务接口，选取一次正常响应速度在350ms左右的请求

1.1 先通过链路分析大概耗时

因为我们平台代码里面是集成了阿里云的链路追踪分析产品，所以很简单，第一步就是打开阿里云产品，找到这次请求对应的链路记录，从最外围请求开始记录，逐个记录下每次操作的耗时(阿里云链路分析产品里面主要记录的还是每一次rest调用以及数据库操作的时间)；
结果是：
1.数据库查询耗时在3-5ms；
2.数据库插入以及更新耗时在9-12ms；
3.微服务调用具体看每个服务中交易处理时间；

1.2 开始分析每一次调用时间的额外耗时

由于在链路分析阶段并没有发现明显的耗时操作，但是在每一次相邻的两个调用之间发现有一些额外的耗时，所以由此找到对应两次操作之间的代码，分析是否存在有耗时操作；操作方式为在上一次查询结束后开始一个时间点，然后在第二次查询开始前输出这中间的耗时(这些是需要在代码里面写入的)；这些写完以后再进行请求，查看输出耗时是否比较久，再一步步的找到具体耗时点；
结果是：代码中并没有找到特别大的耗时点，之前有发现 BeanUtils.copyProperties()方法的耗时，然后用main方法测试发现确实耗时，然后再在业务代码中测试发现并不耗时，所以否定了这个点；

1.3 开始分析不属于我们业务代码的耗时点

到这里是检查完了我们业务代码也就是自己写的代码的耗时，开始分析框架的耗时；因为在之前的分析中我们也没有发现耗时点，每次查询操作耗时3-5ms，但是在链路追踪里面两次数据库操作打印日志的时间间隔却是8ms左右，所以怀疑有额外的耗时操作大概消耗了3-4ms，虽然单个看并没有很耗时，但是我们有很多次操作数据库，如果操作10次，就会有额外的40ms时间花费，那么响应时间就变慢了；但是这个地方不知道怎么验证，个人怀疑耗时在数据库获取连接和数据库释放连接等方法；
因为我们用的是spring cloud框架，cloud框架的远程调用方法是rest方式的，然后我们用的是feign和restTemplent;我怀疑这两种方法的耗时不一样；我的验证步骤是在调用前埋点，调用后打印时间，在被调用方法进入前埋点，返回前打印时间；通过这两个时间减出来的差值就是额外花去的时间；
结论：
1.多次数据库累计造成的耗时；
2.feign调用的额外耗时大概比rest耗时多40ms；

feign-交易处理耗时.png feign-调用耗时.png sql耗时截图.png rest-open-api耗时截图.png rest-交易服务耗时.png