spring-cloud-tencent icon indicating copy to clipboard operation
spring-cloud-tencent copied to clipboard

Published 20 hours ago • verified publisher icon Tencent

Spring Cloud Tencent Config 链接的远程主机无法打开时未显示标注出错误

Open Jansora opened this issue 1 year ago • 7 comments

Describe the bug

官方给的 polaris 地址是这个

Console Address : http://14.116.241.63:8080/ Username: polaris Password: polaris Server Address: grpc://183.47.111.80:8091 The example addresses under spring-cloud-tencent-example all point to the experience service address (grpc://183.47.111.80:8091) by default. If you only experience Spring Cloud Tencent, you can run any example directly with one click.

官方提供的 polaris-config-example demo 的 bootstrap.yml 是这个

server:
  port: 48084
spring:
  application:
    name: polaris-config-example
  cloud:
    polaris:
      address: grpc://183.47.111.80:8091
      namespace: default
      config:
        auto-refresh: true # auto refresh when config file changed
        groups:
          - name: ${spring.application.name} # group name
            files: [ "config/application.properties", "config/bootstrap.yml" ] # config/application.properties takes precedence over config/bootstrap.yml
        refresh-behavior: specific_bean
management:
  endpoints:
    web:
      exposure:
        include:
          - polaris-config

我调整了 polaris 的 properties 文件的内容

server.port=11111

image

此时配置项是正常的. 问题1. 当我将地址从 grpc://183.47.111.80:8091 调整为 grpc://111.111.111.111:111 . 很明显 该 ip无法访问, 启动时应该提示报错. 然而应用启动时正常的, 启动日志是这样的

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::       (v2.3.12.RELEASE)

2022-08-05 10:30:54.966  INFO 71390 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file. file = ConfigFile{namespace='default', fileGroup='polaris-config-example', fileName='application.properties'}
2022-08-05 10:31:06.971  INFO 71390 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file. file = ConfigFile{namespace='default', fileGroup='polaris-config-example', fileName='application.yml'}
2022-08-05 10:31:15.001  INFO 71390 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file. file = ConfigFile{namespace='default', fileGroup='polaris-config-example', fileName='bootstrap.properties'}
2022-08-05 10:31:26.010  INFO 71390 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file. file = ConfigFile{namespace='default', fileGroup='polaris-config-example', fileName='bootstrap.yml'}
2022-08-05 10:31:33.028  INFO 71390 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file success. namespace = default, group = polaris-config-example, fileName = config/application.properties
2022-08-05 10:31:43.110  INFO 71390 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file success. namespace = default, group = polaris-config-example, fileName = config/bootstrap.yml
2022-08-05 10:31:43.113  INFO 71390 --- [           main] b.c.PropertySourceBootstrapConfiguration : Located property source: [BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-application.properties'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-application.yml'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-bootstrap.properties'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-bootstrap.yml'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-config/application.properties'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-config/bootstrap.yml'}]
2022-08-05 10:31:43.117  INFO 71390 --- [           main] .c.p.c.e.PolarisConfigExampleApplication : No active profile set, falling back to default profiles: default
2022-08-05 10:31:43.363  WARN 71390 --- [           main] o.s.boot.actuate.endpoint.EndpointId     : Endpoint ID 'polaris-metadata' contains invalid characters, please migrate to a valid format.
2022-08-05 10:31:43.368  WARN 71390 --- [           main] o.s.boot.actuate.endpoint.EndpointId     : Endpoint ID 'polaris-config' contains invalid characters, please migrate to a valid format.
2022-08-05 10:31:43.533  INFO 71390 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=f48492e2-2530-3f9c-9c0b-791505a95396
2022-08-05 10:31:43.689  INFO 71390 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 48084 (http)
2022-08-05 10:31:43.695  INFO 71390 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-08-05 10:31:43.695  INFO 71390 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.46]
2022-08-05 10:31:43.758  INFO 71390 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-08-05 10:31:43.758  INFO 71390 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 633 ms
2022-08-05 10:31:43.973  INFO 71390 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2022-08-05 10:31:44.044  INFO 71390 --- [           main] c.t.c.c.metadata.StaticMetadataManager   : [SCT] Loaded static metadata info. StaticMetadataManager{envMetadata={}, envTransitiveMetadata={}, configMetadata={}, configTransitiveMetadata={}, customSPIMetadata={}, customSPITransitiveMetadata={}, mergedStaticMetadata={}, mergedStaticTransitiveMetadata={}, zone='null', region='null', campus='null'}
2022-08-05 10:31:44.197  INFO 71390 --- [           main] c.t.c.p.c.s.a.SpringValueProcessor       : Monitoring key: SPRING_UTIL_TIMEOUT_SEC, beanName: inetUtilsProperties, field: org.springframework.cloud.commons.util.InetUtilsProperties.timeoutSeconds
2022-08-05 10:31:44.197  INFO 71390 --- [           main] c.t.c.p.c.s.a.SpringValueProcessor       : Monitoring key: spring.util.timeout.sec, beanName: inetUtilsProperties, field: org.springframework.cloud.commons.util.InetUtilsProperties.timeoutSeconds
2022-08-05 10:31:44.223  INFO 71390 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 1 endpoint(s) beneath base path '/actuator'
2022-08-05 10:31:44.275  INFO 71390 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 48084 (http) with context path ''
2022-08-05 10:31:44.283  INFO 71390 --- [           main] c.t.c.p.c.s.a.SpringValueProcessor       : Monitoring key: timeout, beanName: scopedTarget.configController, field: com.tencent.cloud.polaris.config.example.ConfigController.timeout
2022-08-05 10:31:44.292  INFO 71390 --- [           main] .c.p.c.e.PolarisConfigExampleApplication : Started PolarisConfigExampleApplication in 69.658 seconds (JVM running for 70.227)
2022-08-05 10:31:44.576  INFO 71390 --- [(2)-10.45.18.74] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-08-05 10:31:44.576  INFO 71390 --- [(2)-10.45.18.74] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-08-05 10:31:44.580  INFO 71390 --- [(2)-10.45.18.74] o.s.web.servlet.DispatcherServlet        : Completed initialization in 4 ms

问题2. 当我将地址从 grpc://183.47.111.80:8091 调整为 grpc://183.47.111.80:1111 . 很明显该端口无法访问, 启动时应该提示报错. 然而应用启动时正常的, 并且正常加载了 grpc://183.47.111.80:8091 时的配置(server.port=11111) 启动日志是这样的

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::       (v2.3.12.RELEASE)

2022-08-05 10:35:20.311  INFO 74896 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file. file = ConfigFile{namespace='default', fileGroup='polaris-config-example', fileName='application.properties'}
2022-08-05 10:35:20.389  INFO 74896 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file. file = ConfigFile{namespace='default', fileGroup='polaris-config-example', fileName='application.yml'}
2022-08-05 10:35:20.472  INFO 74896 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file. file = ConfigFile{namespace='default', fileGroup='polaris-config-example', fileName='bootstrap.properties'}
2022-08-05 10:35:20.549  INFO 74896 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file. file = ConfigFile{namespace='default', fileGroup='polaris-config-example', fileName='bootstrap.yml'}
2022-08-05 10:35:20.620  INFO 74896 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file success. namespace = default, group = polaris-config-example, fileName = config/application.properties
2022-08-05 10:35:20.684  INFO 74896 --- [           main] c.t.c.p.c.a.PolarisConfigFileLocator     : [SCT Config] Load and inject polaris config file success. namespace = default, group = polaris-config-example, fileName = config/bootstrap.yml
2022-08-05 10:35:20.684  INFO 74896 --- [           main] b.c.PropertySourceBootstrapConfiguration : Located property source: [BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-application.properties'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-application.yml'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-bootstrap.properties'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-bootstrap.yml'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-config/application.properties'}, BootstrapPropertySource {name='bootstrapProperties-default-polaris-config-example-config/bootstrap.yml'}]
2022-08-05 10:35:20.688  INFO 74896 --- [           main] .c.p.c.e.PolarisConfigExampleApplication : No active profile set, falling back to default profiles: default
2022-08-05 10:35:20.951  WARN 74896 --- [           main] o.s.boot.actuate.endpoint.EndpointId     : Endpoint ID 'polaris-metadata' contains invalid characters, please migrate to a valid format.
2022-08-05 10:35:20.957  WARN 74896 --- [           main] o.s.boot.actuate.endpoint.EndpointId     : Endpoint ID 'polaris-config' contains invalid characters, please migrate to a valid format.
2022-08-05 10:35:21.116  INFO 74896 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=f48492e2-2530-3f9c-9c0b-791505a95396
2022-08-05 10:35:21.272  INFO 74896 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 11111 (http)
2022-08-05 10:35:21.277  INFO 74896 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-08-05 10:35:21.277  INFO 74896 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.46]
2022-08-05 10:35:21.337  INFO 74896 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-08-05 10:35:21.337  INFO 74896 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 639 ms
2022-08-05 10:35:21.552  INFO 74896 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2022-08-05 10:35:21.626  INFO 74896 --- [           main] c.t.c.c.metadata.StaticMetadataManager   : [SCT] Loaded static metadata info. StaticMetadataManager{envMetadata={}, envTransitiveMetadata={}, configMetadata={}, configTransitiveMetadata={}, customSPIMetadata={}, customSPITransitiveMetadata={}, mergedStaticMetadata={}, mergedStaticTransitiveMetadata={}, zone='null', region='null', campus='null'}
2022-08-05 10:35:21.775  INFO 74896 --- [           main] c.t.c.p.c.s.a.SpringValueProcessor       : Monitoring key: SPRING_UTIL_TIMEOUT_SEC, beanName: inetUtilsProperties, field: org.springframework.cloud.commons.util.InetUtilsProperties.timeoutSeconds
2022-08-05 10:35:21.775  INFO 74896 --- [           main] c.t.c.p.c.s.a.SpringValueProcessor       : Monitoring key: spring.util.timeout.sec, beanName: inetUtilsProperties, field: org.springframework.cloud.commons.util.InetUtilsProperties.timeoutSeconds
2022-08-05 10:35:21.802  INFO 74896 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 1 endpoint(s) beneath base path '/actuator'
2022-08-05 10:35:21.857  INFO 74896 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 11111 (http) with context path ''
2022-08-05 10:35:21.862  INFO 74896 --- [           main] c.t.c.p.c.s.a.SpringValueProcessor       : Monitoring key: timeout, beanName: scopedTarget.configController, field: com.tencent.cloud.polaris.config.example.ConfigController.timeout
2022-08-05 10:35:21.871  INFO 74896 --- [           main] .c.p.c.e.PolarisConfigExampleApplication : Started PolarisConfigExampleApplication in 3.046 seconds (JVM running for 3.619)
2022-08-05 10:35:22.072  INFO 74896 --- [(1)-10.45.18.74] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-08-05 10:35:22.072  INFO 74896 --- [(1)-10.45.18.74] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-08-05 10:35:22.077  INFO 74896 --- [(1)-10.45.18.74] o.s.web.servlet.DispatcherServlet        : Completed initialization in 5 ms

To Reproduce 见描述

Expected behavior 当问题 1 和问题2 中的配置变更无法访问时, 应显著表示出错误日志表述出错误产生的原因, 而不是提供一个隐式的解决方法

Environment

  • Version: [1.7.0-Hoxton.SR12 ]
  • OS: [MACOS 11.0 ]

Additional context

Jansora avatar Aug 05 '22 02:08 Jansora

@Jansora
Thank you for your feedback ;

According to the information you provided, the expected behavior is to do a health check on the configured remote address before the application is started, and if a problem is found with the remote address, the normal start of the application is directly blocked ？

misselvexu avatar Aug 05 '22 06:08 misselvexu

@Jansora Thank you for your feedback ;

According to the information you provided, the expected behavior is to do a health check on the configured remote address before the application is started, and if a problem is found with the remote address, the normal start of the application is directly blocked ？

on a test machine, it is too common to have several instances on a machine.

when i have multi polaris instances in a linux machine, obviously, their listening port is different.

when a polaris instance is down. and my application has specified to connect the down polaris instance. but application has connected to other healthy instance.

this hidden result is not what I want.

Jansora avatar Aug 05 '22 06:08 Jansora

@Jansora 可以在polaris/logs/polaris.log内看到拉取配置的异常日志。原则上这里不阻塞主进程，不过可以考虑将北极星SDK的error或者warn级别的日志也打印在控制台？

image

SkyeBeFreeman avatar Aug 05 '22 08:08 SkyeBeFreeman

@Jansora 可以在polaris/logs/polaris.log内看到拉取配置的异常日志。原则上这里不阻塞主进程，不过可以考虑将北极星SDK的error或者warn级别的日志也打印在控制台？

image

首先我认为这是个BUG, 因为实际应用启动链接到的 polaris 并不是我想要的, 我不确定这是 STC 或者 polaris sdk 导致的, 其次在配置项明显错误(链接到一个不存在的 polaris)的情况下应用依然启动成功了, 至于日志相关的问题, 我觉得在默认情况下, 至少 ERROR 级别的 polaris 日志应该是被打印出来的.

Jansora avatar Aug 05 '22 09:08 Jansora

关于日志, 我站在用户的角度说下我的个人看法哈, 日志打的多点没关系, 我可以通过配置项来屏蔽掉, 如果日志打的少了, 尤其是缺失关键的 ERROR 日志时, 还是比较难定位哪里出现的问题

Jansora avatar Aug 05 '22 09:08 Jansora

关于日志, 我站在用户的角度说下我的个人看法哈, 日志打的多点没关系, 我可以通过配置项来屏蔽掉, 如果日志打的少了, 尤其是缺失关键的 ERROR 日志时, 还是比较难定位哪里出现的问题

日志是打印了的，只是没有打印在控制台，北极星的日志目前只输出在文件内。

SkyeBeFreeman avatar Aug 05 '22 09:08 SkyeBeFreeman

这里面有两个问题：

问题一：标准输出日志里没有打印 ERROR 日志，只打印到 polaris.log 日志文件里

这里我觉得可以把 ERROR 和 WARN 都默认打印到标准输出里。 INFO 级别的话，最早的时候也都是打印到标准输出里，然后有用户觉得北极星日志打印太多了，所以当时做了一个优化，就是把北极星日志打到独立的 polaris.log 里。

所以总结一下的话，就是可以优先把 ERROR 和 WARN 都默认打印到标准输出里。至于 INFO 日志，最好是让用户也可以配置。但是目前可能做不到，改动点比较多。

问题二：应用启动时，连不上配置中心，是不是应该阻塞应用启动

这个问题确实很关键。按我之前的经验，有些场景下，配置拉失败，应用起不来是最安全的。但是在某些紧急情况下，业务期望不强依赖配置中心，即使配置中心挂了，应用也可以启起来。

解决方案：

  1. 默认改成强依赖配置中心，应用启动时，当从配置中心获取不到配置时，启动失败，这种方式最保守。
  2. 也暴露一个开关，用户可以设置不强依赖。当配置拉取失败也可以启动成功。

以上两点，我们排期优化一下。感谢 @Jansora 的意见~

lepdou avatar Aug 05 '22 10:08 lepdou