前天遇到一个诡异的Apollo 401问题,开发、测试环境都正常,就预生产有问题。
我们Apollo是部署在k8s的容器内,其他应用也部署在k8s上,通过mata server服务发现的方式,直接通过ip访问config service,是正常的。
但是我这个应用比较特殊,部署在另外的宿主机,没法直接访问容器ip,因此只能通过kong(nginx)进行反向代理来配置configService。
然后程序一启动,就会打警告日志:
2022-01-10 22:37:45.772 WARN [Apollo-RemoteConfigLongPollService-1] RemoteConfigLongPollService.doLongPollingRefresh(197) - Long polling failed, will retry in 1 seconds
......此处省略一些不重要的信息
Server returned HTTP response code: 401 for URL: http://xxx/notifications/v2?cluster=default[Cause: Server returned HTTP response code: 401 for URL: http://xxx/notifications/v2?cluster=default&xxx
大家都知道Apollo开启了密钥的情况,如果客户端没配置密钥,请求配置时就会401。但是我很肯定,我的密钥配置是没问题的(中间让运维帮忙临时开通pod id访问,直接使用IP进行请求,是没问题的)
基本可以确定就是kong这里的问题。
对比开发环境(正常)和预生产环境(401)的kong的配置,发现唯一的区别就是开发环境kong的超时时间设置的10分钟,预生产环境设置的60秒(明明60秒更合理嘛)。
然后抱着试一试的心态,把预生产kong的超时时间改成10分钟,然后问题居然解决了。
简直有点不敢相信,改个超时时间怎么就好了呢。
决定深入研究一下这个问题
服务器上很难调试到底是哪里有问题,因此本地使用fiddler进行请求抓包,如下图:
可以看出程序刚启动的时候,请求Apollo是200,这说明密钥确实是没问题的。正常情况如果配置没有修改,后续的请求状态码应该都是304才对,但是这里的请求是304和401混在一起。
最开始以为是有时候行有时候不行,以为是某个节点有问题。后面发现这里是由于粗心被误导了。。。导致走了好多弯路。
仔细看的话能发现,这里其实是有两个接口,一个是/notifications/v2接口,一个是/configs接口,每次都是/notifications/v2这个接口401.
然后还发现一个情况,发起请求时会先阻塞1分钟,然后才返回401,猜测这里是Apollo设计上使用了长轮询。
为了验证猜想,查看Apollo源码
Apollo服务端是用spring boot写的,还比较友好
密钥校验的代码在com.ctrip.framework.apollo.configservice.filter.ClientAuthenticationFilter这个类,利用了servlet的filter机制,算是比较常规的一个做法
校验的大致逻辑如下:
1、先查看应用是否有配置密钥,没有配置密钥则直接通过,否则进行后续校验操作
2、获取请求头中的Timestamp,进行时间戳校验,如果时间戳和当前时间相差1分钟,则直接返回401。日志中会打印Invalid timestamp
3、获取请求头中的Authorization,解析得到参数签名
4、将时间戳、请求路径、请求参数、密钥等一起进行hash计算得到签名,和上一步中得到的参数签名进行比较,如果不相等则返回401.日志中会打印Invalid authorization
查看Apollo日志,根据关键字Invalid进行搜索,发现确实有Invalid timestamp信息,可以判断出是请求参数的时间戳过期导致返回401
再查看/notifications/v2接口的代码,在com.ctrip.framework.apollo.configservice.controller.NotificationControllerV2这个类
这个接口使用了spring的DeferredResult来实现长轮询。
大致逻辑是:如果有新的配置通知则立刻返回,否则阻塞一段时间(long.polling.timeout配置,默认60s)后才返回304.
正常如果时间戳不合法,应该直接就返回401了。
那为何会先阻塞60s才返回401呢
猜测是kong配了失败重试,第一次请求参数合法,阻塞60s后超时,然后触发重试,这时候时间戳已经过期,所以返回401
查看kong的配置,retries设置的是5,5次失败重试。。。
为了进一步验证猜想,做以下实验:
把kong的retries设置成0,会阻塞60s再返回504timeout;
把kong的超时时间改成30s,retries设置成3,会阻塞60s再返回401;
把kong的超时时间改成61s,不再出现401;
果然程序是不会骗人的,深入了解细节,看起诡异的问题,其实就很简单了。