前言
最近在改造一个老项目的时候出现了这样的一个问题, 在项目启动了之后, 日志不断地输出如下的日志, 然后就很奇怪, 我的 app.properties 是一直都没有调整, 也没有改动的
然后 为什么客户端, 服务器这边的交互, 会造成 服务器这边一直都是 app.properties 呢 ?
2023-09-06 16:28:12.143 INFO 36736 --- [.26_8858-public] c.a.n.client.config.impl.ClientWorker : [fixed-10.30.2.26_8858-public] [polling-resp] config changed. dataId=app.properties, group=DEFAULT_GROUP, tenant=public
2023-09-06 16:28:12.143 INFO 36736 --- [.26_8858-public] c.a.n.client.config.impl.ClientWorker : get changedGroupKeys:[app.properties+DEFAULT_GROUP+public]
2023-09-06 16:28:12.268 INFO 36736 --- [.26_8858-public] c.a.n.client.config.impl.ClientWorker : [fixed-10.30.2.26_8858-public] [data-received] dataId=app.properties, group=DEFAULT_GROUP, tenant=public, md5=3be94293cbd3d785fe3c18913b53c785, content=
# mongo.properties
common.mongo.tableNames=wb0097CompanyBlacklist,wb0099RecordCollectiveDiscussion..., type=properties
2023-09-06 16:28:12.447 INFO 36736 --- [.26_8858-public] c.a.n.client.config.impl.ClientWorker : [fixed-10.30.2.26_8858-public] [polling-resp] config changed. dataId=app.properties, group=DEFAULT_GROUP, tenant=public
2023-09-06 16:28:12.447 INFO 36736 --- [.26_8858-public] c.a.n.client.config.impl.ClientWorker : get changedGroupKeys:[app.properties+DEFAULT_GROUP+public]
2023-09-06 16:28:12.556 INFO 36736 --- [.26_8858-public] c.a.n.client.config.impl.ClientWorker : [fixed-10.30.2.26_8858-public] [data-received] dataId=app.properties, group=DEFAULT_GROUP, tenant=public, md5=3be94293cbd3d785fe3c18913b53c785, content=
# mongo.properties
common.mongo.tableNames=wb0097CompanyBlacklist,wb0099RecordCollectiveDiscussion..., type=properties
2023-09-06 16:28:12.685 INFO 36736 --- [.26_8858-public] c.a.n.client.config.impl.ClientWorker : [fixed-10.30.2.26_8858-public] [polling-resp] config changed. dataId=app.properties, group=DEFAULT_GROUP, tenant=public
2023-09-06 16:28:12.685 INFO 36736 --- [.26_8858-public] c.a.n.client.config.impl.ClientWorker : get changedGroupKeys:[app.properties+DEFAULT_GROUP+public]
2023-09-06 16:28:12.805 INFO 36736 --- [.26_8858-public] c.a.n.client.config.impl.ClientWorker : [fixed-10.30.2.26_8858-public] [data-received] dataId=app.properties, group=DEFAULT_GROUP, tenant=public, md5=3be94293cbd3d785fe3c18913b53c785, content=
# mongo.properties
common.mongo.tableNames=wb0097CompanyBlacklist,wb0099RecordCollectiveDiscussion..., type=properties首先是先总结一下 这个问题的情况
在我们通常情况下, 我们项目会使用 public 作为 nacos 交互的名称空间, 然后 public 这个名称空间, nacos 服务器这边会将 tenant 为 空 的配置, 也响应给客户端
然后 就造成了我们这里的问题
客户端这边拿着 “app.properties+DEFAULT_GROUP+public” 去 nacos 服务器这边来轮询目标配置是否有改动, 然后 nacos 服务器这边, 根据 “app.properties+DEFAULT_GROUP+public” 去查询配置, 结果没有找到目标配置, 然后识别为了 目标配置发生了变化
然后通知到客户端这边 “app.properties+DEFAULT_GROUP+public” 发生了变化, 然后通知客户端这边获取 最新的配置, 等等流程
然后这个 ClientWorker 这里的 “LongPollingRunnable” 会一直递归去处理这个, 拿着客户端这边关心的 配置列表, 向 nacos 服务器这边 “/config/listener” 进行轮询 是否有改动, 如果改动了, 则客户端这边 重新获取最新的配置
本文 主要是在已知问题的情况下去调试这一系列流程, 相比于 刚碰到这个问题的时候, 会简单的多
客户端和服务器的交互
主要是 “/config/listener” 的这个轮询请求
携带的参数为 “Listening-Configs” 中包含了请求的一个配置列表, 每一个配置包含了 dataId, groupId, tenantId
比如这里拆解为三个配置如下, 然后发送给 naocs 服务器这边
xmay+DEFAULT_GROUP+public -> NULL
xmay.properties+DEFAULT_GROUP+public -> 3be94293cbd3d785fe3c18913b53c785
xmay-security.properties+DEFAULT_GROUP+public -> NULL
Nacos 服务器这边的处理如下, 根据 “xmay.properties+DEFAULT_GROUP+public” 去查询, 没有找到对应的缓存配置
因为服务端这边的配置缓存是根据 数据库中的记录的 tenant 来进行存储的, 该记录在数据库中 tenant 为 “”, 然后缓存的 key 是 “xmay.properties+DEFAULT_GROUP”
然后这里返回服务端的 md5 为 空字符串, 然后 外层比较失败
然后将给定的 groupKey 添加到变动列表中, 视为变动了
然后 再外层结束本次 “/config/listener” 的请求, 然后这里的 probeRequestSize 是请求的 “Listening-Configs” 的数据长度, 为客户端这边传递过来的 “Listening-Configs” 字符串
服务器这边 groupKey 的生成
在 nacos 中 容器初始化的时候, ExternelDumpService 实例初始化的时候, 从数据库中加载 各个配置信息, 添加到 ConfigCacheService.CACHE 中
这里是生成 groupKey, makeSure 是生成新的 CacheItem, 然后将给定的条目添加到 ConfigCacheService.CACHE 中
然后这个 groupKey 的生成规则如下, 如果 tenant 为空, 则会去掉 tenant
比如我们这里 数据库中的 tenant 为空, 则 key 为 “xmay.properties+DEFAULT_GROUP”
客户端这边 groupKey 的生成
这里是从 cacheDatas 中获取的各个配置项, 配置项中携带了 dataId, groupId, tenant 等等信息
然后 cacheDatas 的数据来自于 ClientWorker, 然后我们看一下这部分的配置 从哪里来
虽然 我们基本上都知道 tenant, 是来自于 bootstrap.yml 中配置的 spring.cloud.nacos.config.namespace, spring.cloud.nacos.config.group, 但是我们这里需要从代码层面 跟踪一下
CacheData 的 tenant 的数据来自于上游的 ServerHttpAgent
然后 ServerHttpAgent 的配置信息来自于 nacosConfigProperties.assembleConfigServiceProperties
然后这里是 nacosConfigProperties.assembleConfigServiceProperties 的处理如下, 读取的就是 spring.cloud.nacos.config 中的相关的配置了
解决方式
- 因为数据库中, 我们对应的需要获取的配置信息 namespace 为 空, 所以我们这里客户端将 namespace 配置为 “” 既可以解决问题
- 使用一个固定的 namespace, 比如 xxx, 而不是使用 默认的 “” namespace
- 在较高版本的 nacos 客户端中, 可以通过 spring.cloud.nacos.config.refreshEnabled 关闭配置的刷新, 进而就不会有 LongPollingRunnable 的执行线程, 也可以解决问题
- 关闭这部分输出日志, 眼不见为净, 但是实际上 nacos 客户端 和 服务器 在一直交互, 在我们的项目中很多地方, 默认都是灭有这块的日志, 但是 nacos 客户端 和 服务器 在一直交互
LongPollingRunnable 的开关
在 ApplicationContext 加载完成之后, 这里的处理会将各个配置项添加到 ClientWorker.cacheMap
然后后面 ClientWorker 发现 ClientWorker.cacheMap 中有需要监听的 配置信息, 则会启动 LongPollingRunnable
然后 各个配置项上面有一个 isRefreshable 的标记, 比如 ext-config 的这部分的 isRefreshable 默认为 false
namespace 为 “public” 是怎么获取到 nacos 这边的 tenant 为空 的配置的?
来自于 nacos 这边的兼容处理, 将客户端这边的 “public” 的 namespace 转换为了获取服务器这边的 “” 的 namespace
也就是客户端那边传递 “” 或者传递 “public”, 服务器这边均是获取的 “” 的 namespace 的数据
存在的问题就是, 如果服务器这边加入的 “public” 的 namespace 的 config_info 的记录, 从客户端这边永远也获取不到
原始问题的原始推导
呵呵 原始问题, 我们这边只能够获取客户端这边的相关信息, 客户端这边发送的请求, 客户端这边拿到的服务器的响应
可以很明显观察到的一个现象是 “/config/listener” 这边很快的就响应回来了, 然后 按照正常情况 nacos 这边配置没有更新的话, 它应该是有一定的超时时间的, 是客户端这边传入的 “Long-Pulling-Timeout” 默认值为 30s
但是 它立即就返回回来了, 然后 响应了一个改动 “xmay.properties+DEFAULT_GROUP+public”
这里面肯定是存在问题的, 然后接着 是来代码层面跟一下 nacos 这边的处理, 大致的判断一下问题, 结合日志, dump 信息 确认一下问题
在 “/config/listener” 中看到一部分代码很相似, 这部分代码会立即返回 响应改动的 配置列表给客户端, 然后就这里的是会输出日志的, 然后我们结合日志 来确认一下走的是这段代码
日志信息如下, 搜索 “instant” 可以发现 代码中仅有此处有如下 字面量, 可以确认 “/config/listener” 这边确实是走的如下逻辑, 可以推断出的就是 整个比较过程是在 Md5Util.compareMd5
2023-09-06 16:01:07,023|1|null|10.70.202.14|get|xmay.properties|DEFAULT_GROUP|public||unknown
2023-09-06 16:01:07,238|1|instant|10.70.202.14|polling|3|144|1
2023-09-06 16:01:07,344|2|null|10.70.202.14|get|xmay.properties|DEFAULT_GROUP|public||unknown
2023-09-06 16:01:07,557|0|instant|10.70.202.14|polling|3|144|1比较的处理如下, 最开始我以为是 客户端 和 服务器 这边计算 md5 的方式有差异, 到时 md5 的计算一直匹配不上, 然后 这就需要 服务器这边的 dump 的信息了
然后 从 nacos 上面 dump 一份 堆dump 文件, 然后 基于 jhat 来进行分析
找到 groupKey 包含 “xmay.properties” 的 com.alibaba.nacos.config.server.model.CacheItem
可以看到的是 md5 这边计算的结果, 服务器 和 客户端这边是一致的
然后 偶然的情况下 看到了这个 groupKey, 发现 服务器这边的groupKey 和 客户端这边传递过来服务器生成的groupKey 是不匹配的, 然后就有了 本文上面开篇的调试流程
完
