问题
发现
美妙的一天，从在群里面被人艾特开始...
描述
celery定时任务修改了执行时间，页面展示的时间生效，但实际执行的时间不生效，还是使用按照原来的时间运行文章源自玩技e族-https://www.playezu.com/193151.html
代码
with transaction.atomic():
# 更新PeriodicTask的字段
if crontab_str := fields_kv.get('crontab', ''):
logger.info(f'update field: {crontab_str=}')
celery_model_operation.update_celery_crontab(
celery_id=obj.celery_task.id,
crontab_str=crontab_str,
)
if (is_enabled := fields_kv.get('is_enabled', None)) is not None:
logger.info(f'update field: {is_enabled=}')
celery_model_operation.update_celery_status(
id=obj.celery_task.id,
is_enabled=is_enabled,
)
if marker_name := fields_kv.get('marker_name', None):
logger.info(f'update field: {marker_name=}')
celery_task_obj = celery_model_operation.get_celery_obj_by_id(obj.celery_task.id)
celery_task_obj.name = f'{obj.project_id}:{marker_name}'
kwargs: dict = json.loads(obj.celery_task.kwargs)
kwargs['marker_name'] = marker_name
celery_task_obj.kwargs = json.dumps(kwargs)
celery_task_obj.save()
# 更新页面展示表的字段
return super().partial_update(id, user_email, **fields_kv)
def get_celery_obj_by_id(id: int) -> PeriodicTask:
return PeriodicTask.objects.get(id=id)
def update_celery_status(id: int, is_enabled: bool) -> None:
celery_task_obj = get_celery_obj_by_id(id)
celery_task_obj.enabled = is_enabled
celery_task_obj.save()
def update_celery_crontab(celery_id: int, crontab_str: str) -> None:
celery_task_obj = get_celery_obj_by_id(celery_id)
crontab_obj = get_or_create_crontab_obj(crontab_str=crontab_str)
celery_task_obj.crontab = crontab_obj
celery_task_obj.save()
排查
问题确认
- 检查生产环境数据库，确实存在问题
- 生产环境界面操作，问题能复现
本地环境
手动接口检查
- 找到对应接口
- postman 调用接口，看日志
- 数据库检查数据
- 一切正常，完全没毛病
测试环境
页面操作
- 页面修改数据
- 检查前端入参
- 看接口日志
- 数据库检查数据
- 一切正常，还是没毛病
手动接口检查
- 找到对应接口
- 调用接口，看日志
- 数据库检查数据
- 一切正常，依然是一点毛病都没有
生产环境再查
页面操作 - 整个对象修改
- 页面修改数据
- 检查前端入参
- 看接口日志
- 数据库检查数据
- 问题重现!!!
页面操作 - 单个字段修改
在页面上，任务的开关有个快捷修改入口，直接放在列表
测试一下，发现页面展示表和 celery 表字段都被正常修改
内心 os: 这会是一个突破口吗？
检查前端传参：文章源自玩技e族-https://www.playezu.com/193151.html
- 修改任务开关，只是传了一个参数
- 编辑任务，传整个对象
手动检查接口，字段差异对比
- 模拟修改任务开关请求，只传开关一个字段，结果符合预期
- 开关字段 + 其他字段
a，还是老问题，页面展示表字段被修改，celery字段没被修改 - 难道是是字段
a的问题? - 开关字段 + 其他字段
b，跟字段a一样，看来并不是字段a的问题，真是令人头大
原因猜想
数据差异?
这时不禁问，难道是生产环境和本地，测试环境的数据差异？
那试一下呗，正好本地和测试都有那批数据
本地和测试都再来一遍上面的检查步骤，问题还是没有复现文章源自玩技e族-https://www.playezu.com/193151.html
特殊数据？
难道是生产环境个别特殊数据才会这样?
换个数据试一下，问题还是必现！
那看来并不是特殊数据的问题？文章源自玩技e族-https://www.playezu.com/193151.html
群里面问问?
遇事不决，加日志
这似乎也看不出来什么问题啊，怎么办？
看来加日志也是很需要讲究的
但是这时候已经快下班了，明天再搞吧文章源自玩技e族-https://www.playezu.com/193151.html
高铁上的探索
真的能放下不管，明天再搞？
作为一名有强迫症的程序员，那是肯定放不下的
在深圳回来广州的高铁上，还是忍不住继续去思考
虽然高铁上，iPhone 的信号很差，可是依然是无法阻止我探索的欲望
于是，查到了这篇文章Learn the subtle differences between Save and Update in Django
恍然大悟，我代码
save()方法是没有指定更新字段的，后面更新的记录，会覆盖掉前面更新的字段。不对，不对，不对。为啥在本地和测试环境并没有这个问题，在生产环境却有。文章源自玩技e族-https://www.playezu.com/193151.html
验证update_fields
被这个bug困扰了一个晚上，睡眠并不是很好
一早醒来，迫不及待的去验证save()方法增加update_fields参数的方案
哇塞，加上update_fields之后，还真的可以！页面显示表和celery表的数据都完美更新了
那就直接修改完，提交代码，叫leader合并，搞定！
这显然是不行，即使结果是对的，但依然没有解释清楚，为啥本地和测试环境没问题，但生产环境就有问题！
数据库主从模式的坑
既然本地，测试，生产环境代码都是一样，那有啥是不一样的。
没错，那就是数据库配置了。生产环境数据库为了高可用，是主从模式，而测试和本地都是单机模式。
说是这么说，那怎么验证呢？
毫无疑问，还是得加日志。
那加在哪里，这个很关键
突然想起了群里面ayo同学的一句话，在此非常感谢ayo同学
加了
68行的日志
本地日志
本地
68,71,59行可以看出来更新前
crontab_id=395，新crontab_id是399在更新
status时，获取到crontab_id值也是399，符合预期生产日志
生产
68,71,59行可以看出来更新前
crontab_id=399，新crontab_id是1107在更新
status时，但获取到crontab_id却是旧值399，不符合预期至此，就可以解释清楚，为啥本地和测试环境没问题，但生产环境就有问题
因为本地和测试环境更新
crontab是写入的是主库在更新
status时，读取的也是主库。始终都是在一个数据库上操作生产环境更新
crontab，写入的是主库更新
status时，读取却是走了从库。数据库主从同步是有延迟的，肯定没有代码执行的快，所以从库的数据就还是旧数据
在没有指定
update_fields时，更新的是所有字段，最终导致，crontab_id就被旧值覆盖了。最终的效果就是
页面展示表数据是正常更新的，但celery表看起来没有被更新一样，实际是被旧值覆盖解决
- 读取时数据库，指定走主库
- 更新字段时，使用
update_fields指定只更新需要的字段
总结
- 性能不敏感时，可以增加更多的日志，尤其是更新数据时，可以打印出更新前后的数据，方便后续排查
-
Django save()方法一定要小心，可能出现旧数据覆盖问题，可考虑使用update方法代替 - 数据库是主从模式，且从库是只读时；在更新数据时，必须指定走主库，从库延迟会导致读取到旧数据
原文
我在【玩技博客 系列征文活动 | 有意思的 bug】https://玩技博客.com/topics/33905 等你，一起 day day up！软件测试基础