登录/ 注册
 找回密码
 立即注册
关闭

CSDN热搜

程序园 精品问答 技术交流 资源下载
返回列表 发新帖
首页 › 业界区 › 业界 ›复杂业务系统线上问题排查过程

复杂业务系统线上问题排查过程

讣丢 昨天 11:57
背景

5月份，我接手了一个业务比较复杂的系统，原来负责这块的是我的同事，离职了，这期间有问题或者开发任务，都是一个合作方同事在负责，我由于手里事情太多了，暂时没时间管这套系统。
这套系统的客户是股票投资者，股票投资者可以将一部分持仓的股票和资金授权交给我们代为操作，我们这边也不是人工操作，而是由量化算法去买卖，而且是日内T+0的，也就是说，早上你把资金和股票交给我们，我们日内的量化算法，尽力去捕捉交易机会，比如高卖低买（反向T）或者低买高卖（正向T），当然，我们A股是T+1的，所以需要有历史持仓才能这么玩。
每天T日交易完成后的第二天早上0点左右，会有批处理任务去计算用户昨日的收益情况。
7月9日，业务反馈，有客户反馈7月8日，量化算法是有成交的，但是查看收益的地方，显示收益为0.
这个bug呢，是需要马上介入处理的，不过也没有那么紧急，毕竟收益还是有（没注意是盈还是亏），只是看不到。
当日排查过程

相关流程介绍

用户看到的，没显示昨日收益的地方，接口中是查询了如下表（以下表皆为示意表）：
1.png

我们这边，负责这块的合作方同事A在深圳，他最熟悉业务，这部分全是他写的；我在成都，我leader在深圳，运维同事也是成都，我们三个人都不熟悉业务，运维在运维室里是台式机，台式机还不带声卡，沟通起来着实有点困难，勉强靠微信语音和腾讯会议沟通着。
在同事A的指导下，查了下上述的stock_total_profit表，这个表是存放总收益的，不过里面也有一个昨日收益字段。运维查了下，昨日收益字段为0. 接下来，开始沟通，这个字段怎么计算出来的。
沟通的结果，是说通过xxljob定时任务计算出来的，源表是stock_daily_profit，这个是存放用户每天的收益情况。
接下来，同事A发了个sql过来查了下这个表，发现是昨日（20250708）日的profit字段不为0.
2.png

这下，源表没问题，最终表有问题，同事A也懵了，怀疑起了代码里别的方向，比如用户是不是昨天用了量化策略2，也就是说，是量化策略类型没匹配上导致的bug，把我们听得也很懵。
总收益计算逻辑

只能让他给我们把逻辑讲一下，这块的计算逻辑是这样的：
对上面这个日收益表，先计算总收益：
3.png

然后，再弄个sql，查询昨日的收益：
4.png

最后，把这两个数据根据用户名组合一下，然后写入到总收益表：
5.png

逻辑就是这么个逻辑，为啥有问题还不知道。
xxljob日志

一方面，同事A在指导运维同事，对比最近几天的数据啥的；我和leader这边，则在查看xxljob的运行日志，发现这个job好像不是那么简单。
6.png

实际的日志中，报什么和数据库相关的问题，什么socket is not closed，什么urgent packet，这些报错我之前确实没咋遇到，还有没截全的部分如下，还包含什么read time out啥的：
  1. socket is not closed; Urgent packet sent to backend successfully; An I/O error occured while sending to the backend.detail:Read timed out;
复制代码
问题是，同事A没说job里要同步什么资金流水吧。由于这个job是从凌晨开始，每10分钟执行一次，看了几次调度执行的日志，发现日志还乱七八糟的。
看代码

开始看这块的代码，发现job开始，要去调一个接口，然后对查询回来的遍历处理，后面逐步才沟通清楚这里是去另一个服务，查询要执行哪些表相关的任务，如，每天凌晨第一次执行的时候，会执行下面的第一个红框中的两个表：资金交收流水表（可以理解为股票交易流水）、股票每日收益表。
7.png

为了避免大家理解困难，我先拨开些迷雾：
8.png

我们当时就看到，xxljob里，对于股票交易明细表的相关sql，报了错，就是上面那一堆：
  1. socket is not closed; Urgent packet sent to backend successfully; An I/O error occured while sending to the backend.detail:Read timed out;
复制代码
但是后续还在继续执行：股票日收益的计算，且：从日志来看，说股票日收益计算成功了。看下图，上面有股票明细相关的报错，但是下面的日志看，日收益的计算没问题。
9.png

也就是说，同事A认为，下面的日收益表的数据是可信的：
10.png

我们另外几个，也不懂这块业务，既然这个日收益表的数据没问题，那就重跑下计算总收益的那个xxljob，把总收益计算出来，应该就行了吧，至于为啥总收益之前没计算出来，现在来说，不那么重要，修复问题更要紧。
重跑整个job

计算总收益，代码逻辑其实是在包含在：股票每日收益表的逻辑。
11.png

这个日收益的job，在完成对日收益的计算后，会触发月收益代码：
12.png

月收益完成后，又触发年收益：
13.png

年收益里，又触发了总收益计算：
14.png

而上述那部分代码，又是包含在更大的job中的，如下图所示:
15.png

先是调接口，查询要跑哪些任务，正常查询到两个：
16.png

然后由于股票交易流水的任务在前，所以先执行；执行时，就是从另外的原始股票明细表（会通过数仓传到我们的数据库里），转存到我们自己的股票明细表，正常来说，转存成功后的股票明细表如下（这个也代表，当天T+0策略，触发了交易）：
17.png

但问题是出现在，这里其实会失败（可能是这个表数据量很大，存储了两年多的股票明细），报那个：
  1. socket is not closed; Urgent packet sent to backend successfully; An I/O error occured while sending to the backend.detail:Read timed out;
复制代码
18.png

但此时异常被捕获了，接着开始执行日收益计算：这里必须要说的是，日收益计算这个task，其实是依赖股票交易流水这个任务的。你想啊，股票的交易明细如果没成功，此时你去计算股票日收益，那能算出来吗，很可能就是查不到相关的股票交易明细，导致算出来的日收益表中的收益为0。
其实，这里我真正的猜想是，在股票交易明细的任务这里，是sql执行时间太长了，但其实数据库还在继续执行；而我们的程序，等了一段时间后，就超时了（read time out），关闭了连接，然后开始执行日收益。此时相当于在并发操作数据库的这个表：
19.png

但我们当时看的那个用户的日收益（有几个股票的日收益不是0了），貌似是对的，就没注意这块。
不管咋说吧，我们就是准备重跑xxljob。结果重跑却没有实际执行，因为，查询任务的接口提示：这两个任务已经是已执行状态了。
20.png

所以没法重跑。当然，其实我们可以把数据库字段改一下就行了，不过同事A说，可以单独跑另一个job。
只重跑计算总收益的job

只重新计算出现问题的总收益部分，这块有个单独的job，这个job平时是不运行，就是为了出现问题时，手动重跑：
21.png

这个job的逻辑呢，我们其实在最开始的相关流程介绍那里讲了，就是把下面两个sql的结果在内存里拼一下，再写入stock_total_profit即可。
  1. SELECT NAME,SUM(profit) FROM stock_daily_profit
  2. GROUP BY NAME,profit
  4. SELECT NAME,SUM(profit) FROM stock_daily_profit
  5. WHERE trade_day ='20250708'
  6. GROUP BY NAME,profit
复制代码
结果，重跑这个job，发现失败了，依然是前面遇到的：
  1. socket is not closed; Urgent packet sent to backend successfully; An I/O error occured while sending to the backend.detail:Read timed out;
复制代码
只是这次报错的sql，是下面这个sql，这个表，整表聚合，表数据大概是300w左右，实际的sql比这个复杂（8个字段聚合，select里也有各种计算）
  1. SELECT NAME,SUM(profit) FROM stock_daily_profit
  2. GROUP BY NAME
复制代码
这个sql，在xxljob中失败，我们就拿到可视化工具里手动执行了下，发现要执行13秒左右。
然后当时没别的办法，又去xxljob中试了下，这次成功了。（当时大家猜：因为在可视化工具中执行，可能有缓存了，所以这次10s内就返回了，程序就没超时）
由于成功了，这次的问题大体也就算修复了。但，这里的sql超时等问题，还是需要解决，这个就留待次日了。
次日排查过程

本地复现

这一天的核心，是解决sql超时问题。这天一早，运维同事就又说，这一天的xxljob又失败了，还是超时，问题现象一样。我们就靠手动重跑，暂时解决这个问题。
其实，我现在看来（写文章的此刻），这一天的数据可能还是有问题：必须确保股票交易明细数据没问题后，才能执行日收益计算。否则，就有并发的可能性，可能我在计算日收益的时候，还查不到股票交易明细。
至于为啥现在也没人反馈这些，因为这块应该是没有对账程序，嗐，我们这个草台班子；用户不反馈，我们也就不知道。
不管怎么说，这一天我们手动重跑，认为已经解决了问题。
然后开始研究sql超时问题。
需要先在本地模拟一下，本地数据库的表里，只有几十万数据，查询很快就返回了；我只能是建一个测试表出来：
然后下面的sql多执行几遍，数据就翻到了300w，当然，我这么造数据是可以的（业务上可能不太对），毕竟模拟那个慢sql足够了
  1. insert
  2.         into
  3.         stock_daily_profit_test(trddate,
  4.         custid,
  5.         fundid,
  6.         xxx1,
  7.         xxx2)
  8. select
  9.         trddate,
  10.         custid,
  11.         fundid,
  12.         xxx1,
  13.         xxx2
  14. from
  15.         stock_daily_profit
复制代码
在搞个接口来调用这个sql：
22.png

sql就是我前面提到的：
  1. SELECT NAME,SUM(profit) FROM stock_daily_profit
  2. GROUP BY NAME
复制代码
然后调下这个接口，果然就报了一模一样的错误了。
debug&&修改配置

debug这部分就不在这里说了，我们用的数据库是国产信创的库，其实是基于pg改的，但是，厂商只有二进制的驱动jar包，没有源码，这部分只能靠debug了。
访问数据库的话，我们从上到下的组件，依次是：com.baomidou.mybatisplus  --> mybatis --> 阿里druid--》 厂商给的类postgre驱动包。
23.png

24.png

这部分，慢慢去debug就行了，有空了可以单独写一下这部分。
我们程序在线上的表现是，超过10s，没等到数据库的响应报文，就会自己断开tcp连接（没在线上抓包确认，我其实命令发给运维了，当时时间赶，忘记执行了；但我本地复现出来现象一模一样，而我在本地是抓了包的，本地就是自己主动断开的）。至于为啥是10s，这个其实就是个默认设置。
我们同事说，我们配置文件里，配了超时时间的呀，好像没生效：
25.png

嗯。。经过我一番debug，发现问题出现在，我们引入了动态数据源组件：
  1. <dependency>
  2.     <groupId>com.baomidou</groupId>
  3.     dynamic-datasource-spring-boot-starter</artifactId>
  4. </dependency>
复制代码
这个组件呢，是去spring.datasource.dynamic下面找配置的，根本不会在上述的spring.datasource.druid里找配置：
26.png

最终就是要调整下配置的位置，把那一段全放到dynamic下：
27.png

另外，超时的配置就是这个：
28.png

最终，对我们来说，就是把配置挪下位置，然后超时时间改长一点，先临时解决这个问题，后续再优化这里的sql。
这一天，走了个紧急流程，把这个变更上线了，就等第二天20250711看结果。
而第二天，果然就没啥问题了，资金流水的任务也不超时了，各种sql都不超时了，压力最终还是给到了数据库，总算是临时解决了
job存在的问题

就那个流程很长的job来说，问题真的不少。
日收益任务在执行前未检查前置任务是否成功

这里都出错了，怎么还能继续往下走呢？得改。
29.png

日收益任务，在未完全执行完成时即报告任务执行成功

下图这两把叉这里，先就报告任务成功了；但后续还在执行月收益、年收益、总收益的计算。我觉得应该得放到最后才行，这块在排查过程中就发现了，同事A知道这个bug。
30.png

月收益、年收益计算时，分页查询导致数据库压力大

31.png

那个sql和下面sql类似，计算月收益，实际sql也比这复杂很多：
  1. SELECT NAME,SUM(profit) FROM stock_daily_profit
  2. WHERE trade_day  BETWEEN '20250708' AND '20250608'
  3. GROUP BY NAME
复制代码
这里这个sql这么复杂，每次执行都要很久，每次返回的结果也是一样的，结果数量总数也并不算多；分页查询导致了这个sql被执行了几十次。。。
年收益、总收益的地方也是类似的，难怪那个xxljob执行了二十多分钟。
总结

问题的解决在最后看起来很简单，但是在当时的层层迷雾情况下，还是比较头疼。这块的逻辑也比较复杂，甚至于在解决完问题后没两天，我就忘了代码整体的流程了，这也是记录下来的意义吧，在想办法给大家讲明白的过程中，我也更清晰了，也发现了一些潜在的问题。

来源：程序园用户自行投稿发布，如果侵权，请联系站长删除
免责声明：如果侵犯了您的权益，请联系站长，我们会及时删除侵权内容，谢谢合作！

使用道具 举报
B Color Image Link Quote Code Smilies
您需要登录后才可以回帖 登录 | 立即注册
发帖
讣丢
昨天 11:57

0

粉丝关注

18

主题发布

板块介绍填写区域，请于后台编辑
微信扫一扫