背景
- 生产环境, XXL-JOB, 会假死, 应用还活着 但已经不调度了
- 数据库为磐维分布式数据
定位
- 运维排查得知, 假死时数据库存在多xxl_job_info的锁表
- 存在几十个xxl_job_info的配置, 也不多啊, 总不能几十个xxl_job就有并发卡死这种大bug吧?
- 但理清楚XXL-JOB原理也好, 等下看看理出来
- 梳理XXL-JOB调度逻辑
- 入口
JobScheduleHelper.getInstance().start();
- 主流程
目前我的理解到:
(1)最多默认支持6000任务配置
(2)调度有效时间5秒和预读取时间范围一致, 可能是人为规定的当前时间严重超过期望执行时间则放弃本次, 等待下次
不过这个影响不大, 只是个设计, 也可能我还理解不到位
(3)其它场景, 要么轻微过期立刻调度, 要么加入时间轮
-
时间轮其实有线程安全问题, 时间轮本体是ConcurrentMap没啥问题, 但是!
- pushTimeRing和时间轮本体while调度执行的remove, 没有考虑极端情况, 比如999ms时执行到pushTimeRing, 然后remove那里正好取走了......吗 ?
显然xxl-job考虑到了, 所以冗余向前取一个刻度 - 接着上一点, 确实考虑了极端整秒的情况, 但如果jobScheduler线程和时间轮线程赶巧了, jobScheduler执行ringData.get后, 时间轮立刻ringData.remove, 这俩同时操作一个list, 非常极端情况下可能出现: 时间轮addAll的不全, jobScheduler正好往后面又追加了几个jobInfo, 此时确实丢了.....
但对于半夜的定时任务来说没那么多, 预读取5秒呢, 不可能cost时间足够触发这个场景
高频的任务丢一个就丢了, 又不是不能用- 好, 很好, 锻炼了逻辑分析能力, 但是这并不会导致我们的生产问题......
- pushTimeRing和时间轮本体while调度执行的remove, 没有考虑极端情况, 比如999ms时执行到pushTimeRing, 然后remove那里正好取走了......吗 ?
public void start(){
// schedule thread
scheduleThread = new Thread(new Runnable() {
@Override
public void run() {
try {
TimeUnit.MILLISECONDS.sleep(5000 - System.currentTimeMillis()%1000 );
} catch (InterruptedException e) {
if (!scheduleThreadToStop) {
logger.error(e.getMessage(), e);
}
}
logger.info(">>>>>>>>> init xxl-job admin scheduler success.");
// pre-read count: treadpool-size * trigger-qps (each trigger cost 50ms, qps = 1000/50 = 20)
//todo 默认预读取:300*20=6000条定时任务配置, 也就是xxl-job默认支持最多6000个配置, 我们显然达不到
//todo
int preReadCount = (XxlJobAdminConfig.getAdminConfig().getTriggerPoolFastMax() + XxlJobAdminConfig.getAdminConfig().getTriggerPoolSlowMax()) * 20;
while (!scheduleThreadToStop) {
// Scan Job
long start = System.currentTimeMillis();
Connection conn = null;
Boolean connAutoCommit = null;
PreparedStatement preparedStatement = null;
boolean preReadSuc = true;
try {
conn = XxlJobAdminConfig.getAdminConfig().getDataSource().getConnection();
connAutoCommit = conn.getAutoCommit();
conn.setAutoCommit(false);
preparedStatement = conn.prepareStatement( "select * from xxl_job_lock where lock_name = 'schedule_lock' for update" );
preparedStatement.execute();
// tx start
// 1、pre read
long nowTime = System.currentTimeMillis();
//todo 预读取5s内要执行的任务 xxl_job_info.trigger_next_time<=?
//todo 可能存在gc导致的时间问题? 不至于吧也不是什么业务服务只是个调度super demo
List<XxlJobInfo> scheduleList = XxlJobAdminConfig.getAdminConfig().getXxlJobInfoDao().scheduleJobQuery(nowTime + PRE_READ_MS, preReadCount);
if (scheduleList!=null && scheduleList.size()>0) {
// 2、push time-ring
for (XxlJobInfo jobInfo: scheduleList) {
// time-ring jump
//todo 有`2个时间段
//todo 1 nowTime|--------| 一个是nowTime+PRE_READ_MS : 扫描的范围 默认扫描5秒内,然后更新下次时间
//todo 2 |--------| nowTime 不能大于这个的右侧 否则放弃这次调度,
// 但为什么要这么设计呢? 即使依旧正常调度, 不也可以更新下次调度时间然后继续定时扫调度吗?
// 感觉这个只是人为定义的5秒就过期, 少一次调度
if (nowTime > jobInfo.getTriggerNextTime() + PRE_READ_MS) {
// 2.1、trigger-expire > 5s：pass && make next-trigger-time
logger.warn(">>>>>>>>>>> xxl-job, schedule misfire, jobId = " + jobInfo.getId());
// fresh next
refreshNextValidTime(jobInfo, new Date());
} else if (nowTime > jobInfo.getTriggerNextTime()) {
//todo 当前时间已经过了, 赶紧直接调度
// 2.2、trigger-expire < 5s：direct-trigger && make next-trigger-time
// 1、trigger
JobTriggerPoolHelper.trigger(jobInfo.getId(), TriggerTypeEnum.CRON, -1, null, null, null);
logger.debug(">>>>>>>>>>> xxl-job, schedule push trigger : jobId = " + jobInfo.getId() );
// 2、fresh next
refreshNextValidTime(jobInfo, new Date());
// next-trigger-time in 5s, pre-read again
if (jobInfo.getTriggerStatus()==1 && nowTime + PRE_READ_MS > jobInfo.getTriggerNextTime()) {
// 1、make ring second
int ringSecond = (int)((jobInfo.getTriggerNextTime()/1000)%60);
// 2、push time ring
pushTimeRing(ringSecond, jobInfo.getId());
// 3、fresh next
refreshNextValidTime(jobInfo, new Date(jobInfo.getTriggerNextTime()));
}
} else {
//todo 没到时间, 加入时间轮
// 2.3、trigger-pre-read：time-ring trigger && make next-trigger-time
// 1、make ring second
int ringSecond = (int)((jobInfo.getTriggerNextTime()/1000)%60);
// 2、push time ring
pushTimeRing(ringSecond, jobInfo.getId());
// 3、fresh next
refreshNextValidTime(jobInfo, new Date(jobInfo.getTriggerNextTime()));
}
}
// 3、update trigger info
for (XxlJobInfo jobInfo: scheduleList) {
//todo 沿朝定位为这里不断出现锁表
//todo 但这玩意是单线程的啊.... 上面调度执行也有分布式锁, 起多少个实例都没用
//todo 沿朝说降低cron的频率就好了, 但降不降调度频率, xxl的扫表都是1秒1扫的啊...然后单线程串行调度完执行这个更新
//todo 只是说 更多的时间只会是1秒空扫, 每5s扫到调度一批; 然后降低了频率变成了每20秒; 所以这个update的锁5s都不够磐维同步????
XxlJobAdminConfig.getAdminConfig().getXxlJobInfoDao().scheduleUpdate(jobInfo);
}
} else {
preReadSuc = false;
}
// tx stop
} catch (Exception e) {
if (!scheduleThreadToStop) {
logger.error(">>>>>>>>>>> xxl-job, JobScheduleHelper#scheduleThread error:{}", e);
}
} finally {
//todo 那就只能猜想commit出现问题了? 或者就是分布式节点锁同步有问题? 不可能呀
// commit
if (conn != null) {
try {
conn.commit();
} catch (SQLException e) {
if (!scheduleThreadToStop) {
logger.error(e.getMessage(), e);
}
}
try {
conn.setAutoCommit(connAutoCommit);
} catch (SQLException e) {
if (!scheduleThreadToStop) {
logger.error(e.getMessage(), e);
}
}
try {
conn.close();
} catch (SQLException e) {
if (!scheduleThreadToStop) {
logger.error(e.getMessage(), e);
}
}
}
// close PreparedStatement
if (null != preparedStatement) {
try {
preparedStatement.close();
} catch (SQLException e) {
if (!scheduleThreadToStop) {
logger.error(e.getMessage(), e);
}
}
}
}
long cost = System.currentTimeMillis()-start;
// Wait seconds, align second
//todo cost小于1秒啦, 1秒是最小cron最小间隔, 就主动等等
if (cost < 1000) { // scan-overtime, not wait
try {
// pre-read period: success > scan each second; fail > skip this period;
TimeUnit.MILLISECONDS.sleep((preReadSuc?1000:PRE_READ_MS) - System.currentTimeMillis()%1000);
} catch (InterruptedException e) {
if (!scheduleThreadToStop) {
logger.error(e.getMessage(), e);
}
}
}
}
logger.info(">>>>>>>>>>> xxl-job, JobScheduleHelper#scheduleThread stop");
}
});
scheduleThread.setDaemon(true);
scheduleThread.setName("xxl-job, admin JobScheduleHelper#scheduleThread");
scheduleThread.start();
// ring thread
ringThread = new Thread(new Runnable() {
@Override
public void run() {
// align second
try {
TimeUnit.MILLISECONDS.sleep(1000 - System.currentTimeMillis()%1000 );
} catch (InterruptedException e) {
if (!ringThreadToStop) {
logger.error(e.getMessage(), e);
}
}
while (!ringThreadToStop) {
try {
// second data
List<Integer> ringItemData = new ArrayList<>();
int nowSecond = Calendar.getInstance().get(Calendar.SECOND); // 避免处理耗时太长，跨过刻度，向前校验一个刻度；
for (int i = 0; i < 2; i++) {
List<Integer> tmpData = ringData.remove( (nowSecond+60-i)%60 );
if (tmpData != null) {
ringItemData.addAll(tmpData);
}
}
// ring trigger
logger.debug(">>>>>>>>>>> xxl-job, time-ring beat : " + nowSecond + " = " + Arrays.asList(ringItemData) );
if (ringItemData.size() > 0) {
// do trigger
for (int jobId: ringItemData) {
// do trigger
JobTriggerPoolHelper.trigger(jobId, TriggerTypeEnum.CRON, -1, null, null, null);
}
// clear
ringItemData.clear();
}
} catch (Exception e) {
if (!ringThreadToStop) {
logger.error(">>>>>>>>>>> xxl-job, JobScheduleHelper#ringThread error:{}", e);
}
}
// next second, align second
try {
TimeUnit.MILLISECONDS.sleep(1000 - System.currentTimeMillis()%1000);
} catch (InterruptedException e) {
if (!ringThreadToStop) {
logger.error(e.getMessage(), e);
}
}
}
logger.info(">>>>>>>>>>> xxl-job, JobScheduleHelper#ringThread stop");
}
});
ringThread.setDaemon(true);
ringThread.setName("xxl-job, admin JobScheduleHelper#ringThread");
ringThread.start();
}
- 开头提到了, 运维检查发现是数据库锁, 我们理了xxl-job的逻辑其实有些自己的私心啦, 所以看后面的finally的代码, commit, close
- 锁表会很明显的导向"是不是没commit"这个疑问, 因为国产化嘛呵呵呵呵, 所以点进去看下源码吧
- 一点就发现问题了, 这两个都是磐维方提供的驱动!!!!!一个集中式的一个分布式的
- 检查了nacos配置, 没有用错, 是pg那个分布式的版本驱动
结论
- 检查驱动
- 这里是之前帮助别的省定位问题时遇到过, 所以快速得到结论了, 正常来说下一步是加日志看这个connection的各步骤信息了, 最后才能发现是实际生效的驱动和指定的驱动类不一致
- 结论为:[JAVA][国产化奇奇怪怪的问题]事后谈-数据库驱动混乱/未按预期连接服务端背景: AndDB和GoldenDB, 原 - 掘金 (juejin.cn)
- pom顺序符合触发这个问题的条件: 即现加载panwei.Driver(集中式) 后加载的 opengauss(分布式)
- 还是套壳套的不同驱动不同服务端数据库,能够混乱的握手成功导致的
- 驱动瞎猫碰死耗子连上了, 但出现些锁的处理的不同也很合理, 对吧! 黑盒的事不要纠结, 拉数据库厂商上会支持就完事了!🤭
- 把不同分支仅保留自己需要的那个驱动, 收工!
规范总结
- pom依赖应去除非必要项
- 数据库驱动应尽早确定分布式/集中式, 并留痕邮件
