同事A:小王,你写的系统又出bug了
我:怎么可能,早上还好好的,你刷新下页面或者用chrome试试
同事A:试过了啊,我电脑连重启都试了
我:……得,您稍等,我看看啥情况
bug现象:
- 前端新建数据
- 点击提交按钮,前端开始通过ajax像后台post数据
- 浏览器处于pending状态,始终无法返回数据,最后显示504 GatewayTimeout,表示它已经尽力了
问题排查:
- 账号权限问题(无提交权限):用同事及我的浏览器测试无法同样正常提交,排除账号权限问题
- 前端问题(ajax部分):反复修改并对比了系统的其他前端提交功能,确认ajax代码没问题
- 后端问题:最近就修改了一个数据提交检验,在线下测试发现提交功能完全正常,但更新到线上仍然无法提交。线下数据上周已与线上同步过一次,恢复上个版本的代码后发现线上仍然存在无法提交的问题,MD这就让人恼火了。注意其实这里有个坑,稍后总结再说
bug定位过程:
大家都下班了,确保没有使用者了开始调试线上,因为prod配置文件设置了全量debug,任何程序涉及数据交互的地方都会打log,图中画圈的地方
看到新建数据的数据其实已经提交到后台了,但是好像进入到某个死循环了,一直在疯狂的输出某条数据库的固定查询:
最终发现在django model里重写save部分存在问题(非真实代码,但逻辑一样):
def save(self, *args, **kwargs):
if not self.pk:
num = AplLevel.objects.count() + 1 # 根据当前数据量生成新的编号
self.pk = 'APL-L' + str(num)
while AplLevel.objects.filter(id=self.pk): #如果该编号存在,则对编号进行+1操作
num = AplLevel.objects.count() + 1
self.pk = 'APL-L' + str(num)
super(AplLevel, self).save(*args, **kwargs)
下面发生的事情你大概知道了,当我的数据里删除了一条老的数据,导致save进入while循环后就永远出不来了。例如:
APL-L1、APL-L2、APL-L3,假如我删除了APL-L2,那么再添加新数据时,num结果为3,得到新的主键为APL-L3,接着查询数据库发现该条数据已存在,于是更新num,还是得到num=3,其实这里应该将“num = AplLevel.objects.count() + 1”改为“num += 1”,如下所示:
def save(self, *args, **kwargs):
if not self.pk:
num = AplLevel.objects.count() + 1
self.pk = 'APL-L' + str(num)
while AplLevel.objects.filter(id=self.pk):
num += 1
self.pk = 'APL-L' + str(num)
super(AplLevel, self).save(*args, **kwargs)
这样逻辑就对了,有了新的主键就会跳出while循环进行新数据的保存
总结
- 开全量日志很重要,在django里你不开全量日志是无法看到该bug的问题的,仅仅看到一个请求返回504然后就结束了,bug真正发生的地方你永远看不到
- 线下数据一定要和线上同步debug才有意义,因为有时候你的bug真的是需要特殊的数据才能触发,比如上面讲的,我的线下没有删除某条历史数据所以线下没发生bug
- 前端pending不一定是前端的问题,很有可能是后端问题,因为浏览器请求无返回基本就是服务端跑飞了,连个出错都不返回,你再怎么狂按F12也没用
发生bug的地方多出现数据交互、数据处理的地方,先找这几个关键点会事半功倍。
最后:自己拉的屎留着泪也要处理掉,这么明显的逻辑错误我是一定要骂人的,直到我看到了提交者的姓名……