生产事故-走近科学之消失的JWT
入职多年,面对生产环境,尽管都是小心翼翼,慎之又慎,还是难免捅出篓子。轻则满头大汗,面红耳赤。重则系统停摆,损失资金。每一个生产事故的背后,都是宝贵的经验和教训,都是项目成员的血泪史。为了更好地防范和遏制今后的各类事故,特开此专题,长期更新和记录大大小小的各类事故。有些是亲身经历,有些是经人耳传口授,但无一例外都是真实案例。
注意:为了避免不必要的麻烦和商密问题,文中提到的特定名称都将是化名、代称。
0x00 大纲
0x01 事故背景
2021年11月26日01时10分,P公司正在进行某业务系统的生产环境部署操作,但其实早在00时30分的时候,他们已经完成过一次部署了,但是奇怪的是无论如何都通不过验证,无奈只好推倒重来,如此反复了有若干次。为何反复尝试,却不尝试去寻找问题呢?问题就在于该系统同一份代码在开发环境和 UAT 环境均一切正常,唯独部署到生产环境上面就不行。这是一个前后端分离的业务系统,前端与后端接口基于 JWT 而不是传统 Session 进行鉴权认证。故障的现象也很简单,就是无法登录——准确的说,是登录后不能维持登录状态,一访问其他需要鉴权的资源立马又被重定向到登录页面。2020年10月25日02时30分,在运维人员多次尝试无果,开发人员排查代码也未发现问题后,P公司不得不直呼见鬼。那么真相究竟是什么呢?
0x02 事故分析
在 RFC 7519 规范中对于 JWT 是这样描述的:
JSON Web Token (JWT) is a compact, URL-safe means of representing claims to be transferred between two parties. The claims in a JWT are encoded as a JSON object that is used as the payload of a JSON Web Signature (JWS) structure or as the plaintext of a JSON Web Encryption (JWE) structure, enabling the claims to be digitally signed or integrity protected with a Message Authentication Code(MAC) and/or encrypted.
JWT (JSON Web Token) 是一种紧凑、URL 安全的表示方式,用于表达要在两个参与方之间传输的安全声明。JWT 中的声明被编码为 JSON 对象,作为 JSON Web Signature (JWS) 结构的有效载荷或 JSON Web Encryption (JWE) 结构的明文,使得声明可以使用消息认证码 (MAC) 进行数字签名或完整性保护和/或加密。
说人话呢意思就是 JWT 是一种安全令牌的标准化实现,用于参与双方之间的可信交互认证。既然不好定位是环境还是代码的问题,不妨先捋一捋 JWT 鉴权认证的过程,看看问题可能发生在哪一步:
- 从故障现象来看,步骤①出问题的可能性基本被排除,从前端请求和后端日志来看账号和密码的验证过程已经正确完成;
- 那么步骤②有没有可能出问题呢?当时也是怀疑过的,但是使用浏览器的 F12 开发者工具,看到 login 的网络请求响应中已经将后端生成的 JWT 返回来了;
- 莫非是步骤③没有将 JWT 正确携带,导致后续验证不通过?但是查看登陆后,对其他接口的请求,里面确实已经携带了步骤②中提供的 JWT,而且数值也一致;
- 验证JWT的代码逻辑会不会有问题呢?可能性不大,因为在测试环境和 UAT 环境已经反复验证过。
那么问题还是出在步骤③携带 JWT 这一步。前面分析过前端发起请求时,已经携带了 JWT,那么有没有可能是后端没收到或者收到的值不正确呢?很可惜,后端收到 JWT 后没有打印相关的日志……只有简单的提示验证失败的信息。但其实到这里,已经可以怀疑是环境的问题了,因为同样的代码只在生产环境出错。
随机抽取一个运维小伙子,让他说说生产的系统结构,从他口中得知,生产上除了为了部署多个节点,使用了 Nginx 作为负载均衡和反向代理外,其他地方没有区别。凭借往常的经验呢,P公司的员工们首先呢就没有怀疑过反代和负载会影响这个业务功能,但是我们的理性分析又提示我们问题很有可能出在这里。
不妨找个机器验证一下,安装和生产环境相同版本的 Nginx,然后配置一下反代和负载。对了,这回啊,在后端把打印 JWT 的Debug
日志加上。然后果不出所料,前端虽然在请求头中携带了 JWT,但是到了后端,却显示没有这个信息,这个头,它丢到哪里去了呢?
0x03 事故原因
前端在步骤③请求头中携带的 JWT 如下,HTTP_HEADER_NAME 为 “JWT_TOKEN”,HTTP_HEADER_VALUE 为 JWT 的值:
JWT_TOKEN: eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJkYXRhIjpbb2x0...
在后端日志中,除了 JWT_TOKEN 以外,其他的头部信息都正常传递,我们注意到,它的 HTTP_HEADER_NAME 包含了下划线,这是它与众不同的地方。难道是被 Nginx 过滤了?
在 Nginx 的官方文档里,有这么一段话:
Missing (disappearing) HTTP Headers
If you do not explicitly set underscores_in_headers on;, NGINX will silently drop HTTP headers with underscores (which are perfectly valid according to the HTTP standard). This is done in order to prevent ambiguities when mapping headers to CGI variables as both dashes and underscores are mapped to underscores during that process.
消失的 HTTP Headers
如果你没有显式设置 underscores_in_headers on;,NGINX 会静悄悄地干掉带有下划线的 HTTP 请求头(虽然它们符合 HTTP 规范,毁灭你与你何干……)。这样做是为了防止在将请求头映射到 CGI 变量时出现歧义,因为在此过程中,短划线和下划线都映射到下划线。
在 ngx_http_parse.c 中,这个开关是这样处理的:
/* header name */
case sw_name:
c = lowcase[ch];
if (c) {
hash = ngx_hash(hash, c);
r->lowcase_header[i++] = c;
i &= (NGX_HTTP_LC_HEADER_LEN - 1);
break;
}
if (ch == '_') {
if (allow_underscores) {
hash = ngx_hash(hash, ch);
r->lowcase_header[i++] = ch;
i &= (NGX_HTTP_LC_HEADER_LEN - 1);
} else {
r->invalid_header = 1;
}
break;
}
// ……(太长只截取关键部分)
break;
如果没有开启underscores_in_headers
开关,对应变量allow_underscores
,则默认情况下,带有下划线的 HTTP_HEADER 会被标记为 INVALID_HEADER.而标记为 INVALID_HEADER 的信息默认情况下,会被忽略掉,为什么说默认呢?因为这个行为同时还受到另一个开关ignore_invalid_headers
控制,如果它被开启,那么带有下划线的 HTTP_HEADER 就真的神秘消失了。
关于 underscores_in_headers 选项:
Syntax: underscores_in_headers on | off;
Default: underscores_in_headers off;
Context: http, server
Enables or disables the use of underscores in client request header fields. When the use of underscores is disabled, request header fields whose names contain underscores are marked as invalid and become subject to the ignore_invalid_headers directive.
关于 ignore_invalid_headers 选项:
Syntax: ignore_invalid_headers on | off;
Default: ignore_invalid_headers on;
Context: http, server
Controls whether header fields with invalid names should be ignored. Valid names are composed of English letters, digits, hyphens, and possibly underscores (as controlled by the underscores_in_headers directive).
可以看到underscores_in_headers
选项默认情况下是关闭的,而ignore_invalid_headers
选项默认情况下是开启的,这也就导致了我们 JWT_TOKEN 的神秘失踪,至此问题已经定位完毕。
0x04 事故复盘
这次可以说是纯纯的意外,但是这个意外本可以发现的更早:
- 再穷也好,至少也要申请一个与生产环境相同/相仿的复刻环境。
- 统一且规范的命名,或许可以避免很多不必要的麻烦。
- 所谓
Debug
日志就是,没事的时候,你看到它嫌它烦;出事的时候,你烦看不到它…… - 排查问题时,还是大意了,没有去看 Nginx 的日志,因为通过源码可以发现 INVALID_HEADER 默认情况下是会触发 ERROR 日志的:
if (rc == NGX_OK) { r->request_length += r->header_in->pos - r->header_name_start; if (r->invalid_header && cscf->ignore_invalid_headers) { /* there was error while a header line parsing */ ngx_log_error(NGX_LOG_INFO, c->log, 0, "client sent invalid header line: \"%*s\"", r->header_end - r->header_name_start, r->header_name_start); continue; } // ……(太长只截取关键部分) }
0x05 事故影响
使P公司新业务系统上线时间延长了3小时,相关人员连夜跟老板申请服务器经费。(知道了,下次还是不批)。