排查守候在零点两分的 bug
今日文章由作者 @林乐扬 投稿分享。
最近接手泛前端团队的服务稳定性治理,遇到一些很有特点的线上问题,这边记录一次『有趣的 bug』排查。
背景
故事的开始是由老板的一个艾特开始的:
当时排查了下没啥思路,就放弃了(以为偶现,过几天它能自己好起来!)。直到某一天我又收到了同样的告警,我回想了下最近好几天都有这个告警。
抬头一看:
心里一惊:别搞出事故啊!就开始了我的排查之路。
排查思路
根据告警错误栈显示,这是一个 "unhandledRejection":
[ERROR][2020-09-16T23:59:59.582+0800][default:process.<anonymous> at /home/xxx/xxx/xxx/lib/app.js:49:10] _undef||traceid=64594b155f6231298ae0e2b114a1a02||spanid=38197e8a96a6d96a||pid=1431||msg=on unhandledRejection, error: { Error: ERR invalid expire time in set
at JavascriptReplyParser.parseResult (/home/xxx/xxx/xxx/node_modules/redis-parser/lib/javascript.js:90:16)
at JavascriptReplyParser.tryParsing (/home/xxx/xxx/xxx/node_modules/redis-parser/lib/javascript.js:117:21)
at JavascriptReplyParser.run (/home/xxx/xxx/xxx/node_modules/redis-parser/lib/javascript.js:131:22)
at JavascriptReplyParser.execute (/home/xxx/xxx/xxx/node_modules/redis-parser/lib/javascript.js:112:10)
at Socket.<anonymous> (/home/xxx/xxx/xxx/node_modules/redis/index.js:223:27)
at emitOne (events.js:116:13)
at Socket.emit (events.js:211:7)
at addChunk (_stream_readable.js:263:12)
at readableAddChunk (_stream_readable.js:250:11)
at Socket.Readable.push (_stream_readable.js:208:10) command: 'SET', code: 'ERR' }
所以一层一层往上找,是找不到抛错的源头的!猜测了一通无果,于是我去翻告警群的记录,我发现了一个惊人的规律,该告警只要出现,必定是每天凌晨 00:02:
因此排查思路锁定在以下几个:
- 存在每天定时任务设置某个 redis 值的超时时间?
- 服务器时间存在误差?
排查过程
剧透下,并不是上述两个原因。
经过多番搜索代码,发现了几处设置 redis 值的代码,同时结合 Google,有人指出 Redis 设置的超时时间不能为小于 0。经过本地验证,的确发现超时时间不能为 0:
于是排查方向转为代码中哪里出现了设置超时时间小于 0 的逻辑。可疑代码如下:
setRedisKey(
redisTeamKey,
data,
24 * 3600 - getPastTimeOfToday() / 1000,
)
那么这个值 24*3600 - getPastTimeOfToday() / 1000
可能为 0 或者负数吗?我们来看看完整逻辑:
const getPastTimeOfToday = () => {
const date = new Date()
const year = date.getFullYear()
const month = strPadding(date.getMonth() + 1, '0', 2)
const day = strPadding(date.getDate(), '0', 2)
const todayStartTs = +new Date(`${year}/${month}/${day} 00:00:00`)
return +new Date() - +new Date(todayStartTs)
}
这个值代表当前这个时间点,离今天结束还有多少秒的时间。可是这个值不可能小于 0,我甚至猜测是否执行上述代码第二行时是昨天,而第七行的时候是今天,这样能验证我们的猜测,即这个函数返回的值大于 24*3600
,那 24*3600 - getPastTimeOfToday() / 1000
就小于 0 了。不过这个可能性比较低,于是我转而去服务器复现这个 bug,编写如下代码并执行:
const { setRedisKey } = require('./lib/xxx/xxx/redis')
process.on('unhandledRejection', console.log)
setRedisKey('abc', 'value', 0)
执行结果如下,与告警的错误栈一致:
image-20201009144722346
既然复现了错误,回头继续找 bug,深入到 setRedisKey
代码:
const setRedisKey = (key, value, expireTime = DEFAULT_EXPIRETIME) => {
return redis.set(key, value, 'EX', Math.floor(expireTime))
}
过期时间 expireTime
被 Math.floor 包裹,也就是说当 0 < expireTime < 1
时,Math.floor(expireTime)
的值为 0。那么当服务器时间到无限接近 00:00:00 时,getPastTimeOfToday
将返回 (24*3600-x)*1000
,因为无限接近 00:00:00,因此 x 的值介于 0 - 1 之间(毕竟时间戳的最小单位是毫秒,想象下『当天剩余毫秒数』还有不到 1000 的情况)。
为什么 unhandledRejection
对了,为什么该错误没有被捕获?如果一开始被捕获,也就有完整的错误栈,那么排查过程肯定会顺利很多。业务代码如下(已脱敏):
Promise.resolve().then(() => {
Promise.reject(new Error('出错了!'))
}).catch(console.error)
大家发现了吧,then 中的 Promise 没有返回,那么我返回了就一定会被捕获吗?在这种写法下是会的,大家可以尝试下,但是你写成下面这样,还是会 unhandledRejection
:
new Promise((resolve, reject) => {
if (false) {
resolve('对了!')
}
if (true) {
return Promise.reject(new Error('出错了!'))
}
reject(new Error('兜底逻辑!'))
}).catch(console.warn)
为什么呢?因为需要手动调用 reject 才可抛错,这就需要层层将 resolve 和 reject 传入可能报错的 Promise 才行,珍爱生命远离 Promise,大家还是尽量用 async/await
语法(相同功能下)。
解决方式
原因既然依旧找到,解决方式也就出来了:
- 向下取整 Math.floor 改为向上取整 Math.ceil(不过极端情况下还是存在当天剩余毫秒数恰好为 0 的情况)
- 判断
expireTime
值小于等于 0 时,赋值为 1(续一秒,蛤蛤蛤),同时记录 warn 警告日志 - 排查未 return 的 Promise,统一返回
尝试找了下 typescript 限制 number 为正整数的方式,没有找到,有的话求大神告知?
推广时间
我叫林乐扬,点击 “阅读原文” 阅读我的更多文章,觉得有收获记得打开原文链接给我点个赞,或者关注我哦~
本文作者@林乐扬 | 原文@https://zhuanlan.zhihu.com/p/252689936
- END -
- hdu---1024Max Sum Plus Plus(动态规划)
- Go语言异步服务器框架原理和实现
- nyoj------布线问题(kruscal+求最小值)
- nyoj-----127星际之门(一)
- nyoj------20吝啬的国度
- HDUOJ-------2493Timer(数学 2008北京现场赛H题)
- go sync.Mutex 设计思想与演化过程 (一)
- HDUOJ--------A simple stone game(尼姆博弈扩展)(2008北京现场赛A题)
- HDUOJ----2485 Destroying the bus stations(2008北京现场赛A题)
- Go语言实践:从新手入门到上线真实的小型服务所遇到的那些坑
- Node.js真的无所不能?那些不适用的应用领域分析
- hdu-----2491Priest John's Busiest Day(2008 北京现场赛G)
- nyoj------79拦截导弹
- HDUOJ-------2719The Seven Percent Solution
- JavaScript 教程
- JavaScript 编辑工具
- JavaScript 与HTML
- JavaScript 与Java
- JavaScript 数据结构
- JavaScript 基本数据类型
- JavaScript 特殊数据类型
- JavaScript 运算符
- JavaScript typeof 运算符
- JavaScript 表达式
- JavaScript 类型转换
- JavaScript 基本语法
- JavaScript 注释
- Javascript 基本处理流程
- Javascript 选择结构
- Javascript if 语句
- Javascript if 语句的嵌套
- Javascript switch 语句
- Javascript 循环结构
- Javascript 循环结构实例
- Javascript 跳转语句
- Javascript 控制语句总结
- Javascript 函数介绍
- Javascript 函数的定义
- Javascript 函数调用
- Javascript 几种特殊的函数
- JavaScript 内置函数简介
- Javascript eval() 函数
- Javascript isFinite() 函数
- Javascript isNaN() 函数
- parseInt() 与 parseFloat()
- escape() 与 unescape()
- Javascript 字符串介绍
- Javascript length属性
- javascript 字符串函数
- Javascript 日期对象简介
- Javascript 日期对象用途
- Date 对象属性和方法
- Javascript 数组是什么
- Javascript 创建数组
- Javascript 数组赋值与取值
- Javascript 数组属性和方法
- PHP远程连接oracle数据库操作实现方法图文详解
- 微信公众平台开发教程②微信端分享功能图文详解
- 微信公众平台开发教程⑥ 微信开发集成类的使用图文详解
- keras分类之二分类实例(Cat and dog)
- 详解Python 循环嵌套
- PHP中quotemeta()函数的用法讲解
- 微信公众号实现扫码获取微信用户信息(网页授权)
- 实例说明js脚本语言和php脚本语言的区别
- 在Ubuntu 18.04上安装PHP 7.3 7.2和7.0的方法
- PHP7匿名类的用法示例
- laravel配置Redis多个库的实现方法
- PHP中Static(静态)关键字功能与用法实例分析
- 详解PHP 二维数组排序保持键名不变
- 详解PHP的抽象类和抽象方法以及接口总结
- keras的ImageDataGenerator和flow()的用法说明