• 定时任务突然“挂了”该如何正确排查?
  • 发布于 11小时前
  • 10 热度
    0 评论
那天产品突然找到我,一脸焦急:“用户反馈,一个月前的3笔订单奖励到现在都没发,你看看咋回事?”。我心里咯噔一下。这功能跑了好几年了,之前从没出过岔子。产品懂点技术,第一反应是:“定时任务是不是挂了?” 我没急着下结论,先从最基础的排查开始。

一、先看定时任务到底“活没活”
这功能的逻辑不复杂:用户下单后,系统会往order_task表插一条待执行的任务,状态是wait;然后定时任务每5分钟扫一次表,挑出下单超过24小时的任务,发奖励、改状态。
正常的SQL应该是这样:
SELECT * FROM order_task 
WHERE order_type='complete_order_prize' 
  and task_status='wait' 
  and gmt_create < now-86400; -- 86400秒=24小时
产品怀疑定时任务挂了,我先去公司的定时任务平台查日志。不看不知道,一看懵了:过去一个月,这任务调度是成功的(机器没挂,任务能启动),但执行结果全是失败!调度成功≠执行成功。就像外卖小哥按时取单了,但没送到顾客手里——问题出在“送”的过程。

二、代码没动过,锅会在哪?
这平台很久没迭代了,底层是PHP写的。我翻了代码仓库,最近半年没人改过相关逻辑。排除代码变更的锅。那只剩一种可能:数据出问题了。先贴一下处理奖励发放的核心PHP代码(简化后),咱们一句句扒:
/**
 * 堆代码 duidaima.com
 * 定时任务脚本:处理订单奖励金发放
 * @return bool
 */
public function finishSignOrderTask() {
    load_module_model('xxx');
    $start_time = time() - 86400; // 计算“下单24小时后”的时间戳

    // 步骤1:查符合条件的最老的一条待处理任务
    $oldest_record = $this->CI->xxx_sign_task->getWaitFinishTask(
        self::TASK_ID_ORDER_TASK, 
        $start_time, 
        \Xxx_sign_task::TASK_STATUS_COMPLETE, 
        'asc'
    );
    if (empty($oldest_record)) {
        return TRUE; // 没任务就直接返回
    }
    $start = $oldest_record->id; // 最老任务的id作为起始点

    // 步骤2:查符合条件的最新的一条待处理任务
    $end_id = $this->CI->xxx_sign_task->getWaitFinishTask(
        self::TASK_ID_ORDER_TASK, 
        $start_time, 
        \Xxx_sign_task::TASK_STATUS_COMPLETE, 
        'desc'
    )->id; // 最新任务的id作为结束点

    // 步骤3:分页处理任务,每次查100条
    $page_size = 100;
    $xxxSignAwardService = XxxSignAwardService::getInstance();
    while (TRUE) {
        // 组装查询条件:id在[start, start+100)之间,且满足任务类型、状态、时间条件
        $where = [
            'id >= ' . $start,
            'id < ' . ($start + $page_size),
            'task_id = ' . self::TASK_ID_ORDER_TASK,
            'task_status < ' . \Xxx_sign_task::TASK_STATUS_FINISH,
            'gmt_begin < ' . $start_time,
        ];
        // 查这100条任务
        $records = $this->CI->xxx_sign_task->get_by_where($where, '*', 1, $page_size);
        
        if (!empty($records)) {
            foreach ($records as $record) {
                // 校验订单是否存在
                $order = $this->CI->xxx_order->get_by_oid($record->biz_value);
                if (empty($order)) {
                    $this->logger->error("oid_deal_not_found", [$record]);
                    $this->updateTaskStatus(FALSE, $record); // 订单不存在,关闭任务
                    continue;
                }
                // 发放奖励的逻辑...
            }
        }

        // 退出循环条件:处理到最新任务了
        if ($start > $end_id) {
            break;
        }
        $start += $page_size; // 下一页
    }

    return TRUE;
}
这段代码的思路看似合理:先找到最早和最新的待处理任务,然后从最早的开始,每次查100条处理,直到处理完最新的。但问题就出在“最早的任务”上。

三、一条2020年的任务,拖垮了整个定时任务
我查了order_task表的数据,发现了一个惊悚的事实:有一条2020年12月的任务,状态一直是wait(待处理),而且它的订单流水不知咋没了(可能当初插入失败,也可能被删了)。这条“幽灵任务”导致了什么?咱们模拟一下数据:
任务1:id=1000000,2020-12-27(最老的待处理任务)
任务2:id=1000001,2020-12-27
...
任务N:id=2000001,2021-04-27(用户反馈的订单)
...
任务Z:id=2100001,2021-06-04(最新的待处理任务)
按照代码逻辑:
1.$start会被设为1000000(任务1的id)
2.$end_id是2100001(任务Z的id)
3.循环每次查id >= start且id < start+100的任务,处理完后start += 100
看起来没问题?但你算一下:从1000000到2100001,差了110万id。每次查100条,需要循环11000次!

更坑的是:2020年的任务1到2021年的任务N之间,大部分任务早就被处理过了(状态不是wait)。这意味着代码会循环10000多次,每次都去查数据库,但查出来的都是空数据!
.每次查库就算200ms,10000次就是2000秒(33分钟)
.定时任务每5分钟执行一次,上一次还没跑完,下一次就被“丢弃”了
.循环次数太多,日志输出和内存占用暴涨,PHP直接“崩了”
用户那3笔订单的任务,就卡在这堆无效循环后面,永远没机会被执行。

四、改一行代码解决问题,但教训得记牢
解决方法很简单:给任务加个时间边界。既然是“下单24小时后发奖励”,那超过3个月的老任务(大概率是异常数据)就没必要处理了。改一下查询条件,加上gmt_create > 三个月前的时间:
// 原来的where条件
$where = [
    'id >= ' . $start,
    'id < ' . ($start + $page_size),
    'task_id = ' . self::TASK_ID_ORDER_TASK,
    'task_status < ' . \Xxx_sign_task::TASK_STATUS_FINISH,
    'gmt_begin < ' . $start_time,
];

// 改后加个时间上限
$where = [
    'id >= ' . $start,
    'id < ' . ($start + $page_size),
    'task_id = ' . self::TASK_ID_ORDER_TASK,
    'task_status < ' . \Xxx_sign_task::TASK_STATUS_FINISH,
    'gmt_begin < ' . $start_time,
    'gmt_begin > ' . strtotime('-3 months') // 只处理近3个月的任务
];
加了这行,2020年的“幽灵任务”就不会被查到了,循环次数骤减,定时任务5分钟内就能跑完,用户的订单奖励自然就发出去了。

最后说两句大实话
别当产品语言的“翻译机”。产品说“24小时后发奖励”,你得想“如果有几年前的老任务咋办?” 边界条件多问一句,能少掉很多坑。日志!日志!日志!这破事排查了2小时,一半时间在找日志——代码里关键步骤不打日志,出了问题就是“盲人摸象”。老系统别轻视。越是没人维护的代码,越可能藏着早年的“骚操作”,数据积累久了,啥妖魔鬼怪都能冒出来。
吃一堑长一智,希望你永远用不上这个教训。
用户评论