一次生产环境数据错误的排查记录

一次生产环境数据错误的排查记录

本文旨在记录一次生产环境数据错误的完整排查过程，既非通用技术指导，也不涉及复杂高深的技术。它更像是一份“工具与经验结合”的工作纪实——问题本身并不复杂，但排查中的思路与方法值得总结。同时，也希望通过本文，让读者了解我在技术团队中的职责定位与日常工作方式。

一、问题触发：业务反馈的数据异常

我正埋头处理前任同事遗留的“历史代码”时，技术支持同事抛来了一个问题：某账户在流水正常、账户余额无误的情况下，冻结资金本应归零却未归零。据他所说，类似情况之前出现过一两次，当时仅临时处理未深究。

他后续补充了不少业务细节和流水生成逻辑，但我对该业务尚不熟悉，听下来更像是一串“&##!**@^^>@@4”。不过核心关系我还是理清了：账户设计初期只有“余额”字段，无“冻结余额”；后来因需求变更新增“冻结余额”——在预付款场景下，会先冻结部分金额，后续触发扣款时，需同时扣减“余额”与“冻结余额”。正常情况下，无预付款的账户，冻结金额应始终为0。

但这里有个关键局限：流水表只记录了账户余额，未记录冻结金额。这意味着，单查流水无法定位到冻结金额异常的具体环节。

二、代码溯源：定位核心逻辑漏洞

我从业务接口追踪到同事编写的核心代码，整理为如下伪代码（原代码包含递归、原子操作等一堆花哨且无必要的代码，此处简化核心流程）：

/**
accountId 账户id
chargeFee 扣款金额
**/
void trade(accountId, chargeFee){var balance; // 余额var freeze;  // 冻结余额int tryCount = 0;while(true){ // 重试逻辑// 1. 查询当前账户余额与冻结余额balance, freeze = sql("select balance, freeze from account where id = $accountId");// 2. 计算更新后的值（注：原逻辑中chargeFee为扣款，此处需确认业务方向，暂保留原计算逻辑）newBalance = balance + chargeFee; newFreeze = freeze - chargeFee; // 3. 采用CAS（Compare and Set）方式修改数据，防止并发问题updatedSuc = sql("update account set balance = $newBalance, freeze = $newFreeze where freeze = $freeze");if(updatedSuc){ // 修改成功，跳出循环break;} else {if(tryCount ++ > 5) {   // 重试5次失败则抛异常throwException("账户更新失败，已重试5次");}}}// 4. 插入流水记录（仅记录余额相关信息，无冻结金额）sql("insert into flow (cur_balance, old_balance, ...) values (...)");
}

需补充两个关键背景：

1. 代码中加入重试逻辑，是为了应对并发场景下的数据更新冲突；
2. 整个代码的事务级别设为“Read Committed”（读已提交），若级别更高（如Repeatable Read），重试逻辑将失去意义。

三、错误分析：从代码猜测到日志验证

1. 初步代码判断

从伪代码能明显看到一个问题：CAS更新时，WHERE条件仅校验了“freeze（冻结余额）”，未校验“balance（余额）”。这意味着，若并发场景下余额先被其他线程修改，当前线程仍可能基于旧的余额计算结果更新数据，存在逻辑漏洞。

但我将这个判断同步给团队同事时，他认为“没问题”——理由是“每次冻结金额变化一定会伴随余额变化，出现错误的概率极低”。由于缺乏直接证据，我无法完全确认自己的猜测，于是决定通过日志进一步验证。

2. 日志拉取与整理

项目部署在阿里云，我直接使用阿里云SLS（日志服务）排查，未额外搭建日志分析系统。

• 第一步：按“表名+update关键字”筛选，定位到账户表（biz_advance_account）的所有更新语句，最终发现两类核心SQL：
  1. 不处理冻结金额的更新：UPDATE biz_advance_account SET balance=?, latest_balance_time=? WHERE DEL_FLAG=0 AND (balance = ? AND id = ?)
  2. 处理冻结金额的更新：UPDATE biz_advance_account SET balance=?, frozen_amount=?, latest_balance_time=? WHERE DEL_FLAG=0 AND (id = ? AND balance = ?)
• 第二步：带上异常账户的ID，筛选出该账户的所有更新日志，并通过SLS的“导出”功能（界面红色导出按钮）将日志保存为CSV格式，方便本地分析。

3. 日志格式解析

以下是一条典型日志的格式，关键信息已标注：

2025-10-05 12:08:24.820 DEBUG [js-net-freight,9cb1d4f9f0b1a49b,9cb1d4f9f0b1a49b] 1 --- [o-8080-exec-854] c.j.t.n.p.m.AdvanceAccountMapper.update  : traceId:64c2d5d24b190405af17a8a904bbbe4c spanId:53ae089d41bc8183 ==> Parameters: 2426.80(BigDecimal), 2025-10-05 12:08:24.819(Timestamp), 2487.02(BigDecimal), 18928(Long)

• 日志中包含两个traceId：前一个是业务系统生成，后一个是阿里云APM（应用性能监控）自动添加（后续计划将两个ID统一，方便追踪）；
• “Parameters”后的内容即为SQL执行时的实际参数，是后续分析的核心数据。

4. 本地日志分析（Python Pandas）

我使用Python的Pandas库解析CSV日志（虽有点“大材小用”，但胜在高效），核心逻辑是提取日志中的参数并结构化。以下是关键代码片段（基于IPython历史记录整理）：

mlist = []
for line in mdf['logcontent']:params = line.split(',')item = {}# 按参数个数区分“处理冻结金额”与“不处理冻结金额”的日志if len(params) == 4:item = {'balance': params[0],'latest_balance_time': params[1],'where_balance': params[2],'where_id': params[3]}elif len(params) == 5:item = {'balance': params[0],'frozen_amount': params[1],'latest_balance_time': params[2],'where_id': params[3],'where_balance': params[4]}else:print(f"异常日志格式：{line}")mlist.append(item)

最终将结构化后的数据保存为Excel表格，格式清晰呈现了每次更新的“当前值”“条件值”与“时间戳”，便于追溯数据变化。

5. 人工核验：锁定并发问题

我没有继续独自排查，而是将Excel表格交给了技术支持同事——他熟悉业务逻辑，能快速对应“每笔余额/冻结金额变化”是否符合业务预期。

很快，他定位到了异常数据：某线程正在处理冻结金额扣减时，另一个线程插入了一笔余额更新操作，导致原线程的CAS校验“失效”，最终出现了ABA问题（即数据从A变为B，又变回A，CAS仅校验最终值A，忽略了中间的B状态）。这也印证了我最初的代码判断。

四、问题修复：补充CAS校验条件

核心修复方案很简单：在原UPDATE语句的WHERE条件中，同时加入“balance（余额）”的校验，确保只有“余额”与“冻结余额”均未被修改时，才能执行更新。修改后的关键SQL如下：

UPDATE account set balance = $newBalance, freeze = $newFreeze where balance = $balance AND freeze = $freeze

五、排查后记：日志与数据追踪的思考

这次排查让我更深刻地感受到：日志是分析Bug的核心利器。此前我就曾通过阿里云日志与监控系统，为两个核心模块搭建了异常预警机制。

• 对于普通错误（如接口报错、参数异常），通过“关键字+traceId”通常能快速定位；
• 但对于无明显报错的并发问题，需将日志拉到本地，用Pandas等工具结构化分析，才能理清数据变化脉络。

不过也遇到一个局限：若业务日志混乱，有时需依赖binlog（数据库二进制日志）追踪数据变化，但binlog无法与业务日志关联。由此想到一个优化方向：若在账户表中新增“traceId”字段，每次更新数据时同步写入当前traceId，后续分析binlog时，就能通过traceId关联业务日志，大幅提升排查效率。

目前还在思考：是否有关系型数据库支持在“插入/更新数据时，自动携带元数据信息（如标签、traceId等）”？若有，将进一步简化数据追踪流程。