springboot的 nacos 配置获取不到导致启动失败及日志不输出问题
前言
问题
1. 本地启动应用时,一切正常,但是部署 docker 后,会因为获取不到 nacos 中的配置导致服务启动失败。
2.当 docker 中的服务一直重启,可能会突然某一次启动成功,之后只要不重新构建 docker 镜像,就不会再出现 nacos 配置获取不到的问题。
3.明明获取不到 nacos 配置,但是却没有输出任何 nacos 相关的日志
相关依赖
springboot:2.7.15
nacos:2.2.3
logback:1.2.12
配置
springboot 2.7.15 有提供两种 nacos 配置方式,一种是用 bootstrap.yml,另一种采用的是spring.config.import。我使用的是 spring.config.import 方式,配置如下所示。( nacos 配置加载流程可以看 nacos配置加载流程)
spring:
cloud:
nacos:
config:
server-addr: ${ip}
namespace: ${port}
config:
import:
- optional:nacos:app.yaml
docker 使用的是 host 模式
解决方案:
配置获取不到问题
nacos 角度
从 nacos 角度排查的原因是因为nacos 服务端服务检测超时了,所以可以增加检测的超时时间。修改启动命令如下所示
java -Dnacos.remote.client.grpc.server.check.timeout=5000 -jar app.jar
当然这种方法治标不治本,应该解决的是为什么会超时,但是从 nacos 方面没定位出来为什么超时。但本文主要讲的是 nacos 方面的问题ding'we
非nacos的角度
docker 日志中可以看到 InetAddress.getLocalHost().getHostName took 10007 之类的错误,如下图所示,根据这个错误百度会发现是因为没有在 hosts 配置主机名导致的获取超时,且是在 host 模式才会。
还有就是 docker 在 bridge 模式下也不会上述问题
上面的错误是出于 spring,并非出于 nacos,非本文重点,后续不会再次说明。
nacos 日志不输出问题
只需要用如下配置即可在容器中的 remote.log 中看到相关的日志信息
public static void main(String[] args) {
SpringApplication springApplication = new SpringApplication(SimAppExperimentApplication.class);
springApplication.addListeners(new LoggingListener());
springApplication.run(args);
}
public static class LoggingListener implements ApplicationListener<ApplicationEnvironmentPreparedEvent>, Ordered {
@Override
public int getOrder() {
return LoggingSystemShutdownListener.DEFAULT_ORDER + 1;
}
@Override
public void onApplicationEvent(ApplicationEnvironmentPreparedEvent event) {
//用这种方法目前测试会导致服务启动后的一些日志无法输出
// LoggingSystem loggingSystem = LoggingSystem.get(ClassUtils.getDefaultClassLoader());
// loggingSystem.cleanUp();
ILoggerFactory factory = StaticLoggerBinder.getSingleton().getLoggerFactory();
Assert.isInstanceOf(LoggerContext.class, factory,
() -> String.format(
"LoggerFactory is not a Logback LoggerContext but Logback is on "
+ "the classpath. Either remove Logback or the competing "
+ "implementation (%s loaded from %s). If you are using "
+ "WebLogic you will need to add 'org.slf4j' to "
+ "prefer-application-packages in WEB-INF/weblogic.xml",
factory.getClass(), getLocation(factory)));
LoggerContext loggerContext = (LoggerContext) factory;
loggerContext.getTurboFilterList().clear();
}
private Object getLocation(ILoggerFactory factory) {
try {
ProtectionDomain protectionDomain = factory.getClass().getProtectionDomain();
CodeSource codeSource = protectionDomain.getCodeSource();
if (codeSource != null) {
return codeSource.getLocation();
}
} catch (SecurityException ex) {
// Unable to determine location
}
return "unknown location";
}
}
然后就可以在 remote.log 文件里看到对应的 nacos 日志输出
之所以是在 remote.log 里,是因为 nacos-client.jar 的 nacos-lombok.xml 配置了输出方式
上述配置调试 nacos 问题的时候可以用,但不建议放生产环境,因为不确定是否会出现莫名其妙的情况
问题分析
配置获取不到问题
注意:下面的代码图片中可以看到好多地方都是有输出相关的错误日志的,但是在服务器中却无法看到相关的日志。导致问题不好排查。
nacos 配置加载流程可以看 nacos配置加载流程
本文 nacos 的配置获取是在 EnvironmentPostProcessorApplicationListener 中监听到 ApplicationEnvironmentPreparedEventEvent 事件后触发的。
然后获取配置时的第一个错误是在 NacosConfigService.getConfigInner ,异常信息为 ErrCode:-401,ErrorMsg:Client not connected, current status:STARTING ,具体如下图所示
上面的错误是因为 RpcClient.request 执行的时候,RpcClient 的status 是STARTING,而非RUNNING ,具体如下图所示
RpcClient 的 status 是在 RpcClient.start 里面设置为 running。设置分为同步和异步。
1.同步设置
如下图所示,RpcClient.start 会直接调用 RpcClient.connectToServer 连接nacos。一旦连接成功就会将 status 设置为 running。如下图所示
然后在 RpcClient.connectToServer 连接过程中,会在 RpcClient.connectToServer ,如下图所示
而这里一旦连接 nacos 超时,那自然就无法获取到 nacos 服务端的相关配置,启动服务也会因为无关键配置而报错失败。
所以从这方面看,解决就可以考虑增加超时时间(默认3s)。当然,如果继续深入排查,也许也能发现是因为 hosts 没有配置主机映射导致的。但只是到这个地方的话,我是没想到为什么请求localhost:9848,怎么会因为 hosts 没有配置主机名而超时呢?难不成请求的时候还会基于主机名进行 dns 查询吗?
2.异步设置
由于是异步设置,所以即使异步能成功,但是服务启动的时候是不会等异步成功后在去加载配置的。
如下图所示,当同步设置没成功时,会开启异步任务重新连接 nacos (红框标错,异步任务是最后一行 switchServerAsync 触发的。后续再调整)
然后会在 RpcClient.reconnect 中进行重连,成功后也会把 status 改为 RUNNING
日志不输出问题
首先,在LoggingApplicationListener 会监听 ApplicationStartingEvent事件,然后调用 LoggingSystem.beforeInitalize 方法
logback 的 LoggingSystem.beforeInitalize 方法会添加一个 TurboFilter
这个TurboFilter 会直接 return FilterReply.DENY
而当 logger 在打日志的时候,会校验是否开启对应的日志 level(info、debug 等),这个校验会调用所有的 TurboFilter 进行,当有 TurboFilter 拿到 FilterReply.DENY的时候就不会输出日志
然后LoggingSystemShutdownListener在接收到ApplicationEnvironmentPreparedEventEvent 后也会触发添加一个固定返回 FilterReply.DENY 的TurboFilter 。这个是在在LoggingApplicationListener 接收 ApplicationEnvironmentPreparedEventEvent 逻辑之前执行的
而该 TurboFilter 的会在 LoggingApplicationListener 接收到ApplicationEnvironmentPreparedEventEvent 时间后移除(initialize 里面的逻辑)
综上所述在LoggingApplicationListener接收ApplicationStartingEvent 和ApplicationEnvironmentPreparedEventEvent 之间的时间内,Logger 是无法正常输出的。(不只局限于nacos)
而要解决该问题,就需要在LoggingSystemShutdownListener 接收到ApplicationEnvironmentPreparedEventEvent 之后,EnvironmentPostProcessorApplicationListener ApplicationEnvironmentPreparedEventEvent 接受到ApplicationEnvironmentPreparedEventEvent 之前,将对应的 TurboFilter 移除,即前面的解决方案。
成功一次后不重构镜像就一直成功的原因
主要是因为 NacosConfigService.getConfigInner 获取配置失败时会从本地快照尝试获取配置
而当获取一次成功后,会将相应配置写入本地快照。
原文地址:https://blog.csdn.net/g5zhu5896/article/details/144300861
免责声明:本站文章内容转载自网络资源,如本站内容侵犯了原著者的合法权益,可联系本站删除。更多内容请关注自学内容网(zxcms.com)!