组件信息
Nacos 2.2.3
SpringCloud微服务
部署环境：centerOS
部署方式：k8s
前言
- nacos开启鉴权，nacos地址通过变量方式传入服务中
PropsUtil.setProperty(props, "spring.cloud.nacos.discovery.server-addr", "${NACOS_ADDR}");
PropsUtil.setProperty(props, "spring.cloud.nacos.config.server-addr", "${NACOS_ADDR}");
PropsUtil.setProperty(props, "spring.cloud.nacos.discovery.password", "${NACOS_PASSWORD}");
PropsUtil.setProperty(props, "spring.cloud.nacos.discovery.username", "${NACOS_USERNAME}");
PropsUtil.setProperty(props, "spring.cloud.nacos.config.password", "${NACOS_PASSWORD}");
PropsUtil.setProperty(props, "spring.cloud.nacos.config.username", "${NACOS_USERNAME}");- k8s在传入${NACOS_ADDR}时先对地址做了base64编码
服务启动异常
下面是服务启动异常的日志
2023-08-23 15:25:53.187 [traceId:] [TID: N/A] ERROR 1 --- [ main] c.a.n.c.a.i.process.HttpLoginProcessor [getResponse][102]: [NacosClientAuthServiceImpl] login http request failed url: http://****.****.svc.cluster.local:8848
/nacos/v1/auth/users/login, params: {username=nacos}, bodyMap: {password=****}, errorMsg: Illegal character in authority at index 7: http://****.****.svc.cluster.local:8848
/nacos/v1/auth/users/login?username=nacos
2023-08-23 15:25:53.191 [traceId:] [TID: N/A] ERROR 1 --- [naming.security] c.a.n.c.a.i.process.HttpLoginProcessor [getResponse][102]: [NacosClientAuthServiceImpl] login http request failed url: http://****.****.svc.cluster.local:8848
/nacos/v1/auth/users/login, params: {username=nacos}, bodyMap: {password=*******}, errorMsg: Illegal character in authority at index 7: http://****.****.svc.cluster.local:8848
/nacos/v1/auth/users/login?username=nacos
2023-08-23 15:25:53.198 [traceId:] [TID: N/A] INFO 1 --- [ main] com.alibaba.nacos.common.remote.client [lambda$createClient$0][108]: [RpcClientFactory] create a new rpc client of e1146c19-413a-4f6f-8371-60242423f418
2023-08-23 15:25:53.205 [traceId:] [TID: N/A] INFO 1 --- [ main] com.alibaba.nacos.common.remote.client [printIfInfoEnabled][63]: [e1146c19-413a-4f6f-8371-60242423f418] RpcClient init, ServerListFactory = com.alibaba.nacos.client.naming.core.ServerListManager
2023-08-23 15:25:53.206 [traceId:] [TID: N/A] INFO 1 --- [ main] com.alibaba.nacos.common.remote.client [printIfInfoEnabled][63]: [e1146c19-413a-4f6f-8371-60242423f418] Registry connection listener to current client:com.alibaba.nacos.client.naming.remote.gprc.redo.NamingGrpcRedoService
2023-08-23 15:25:53.207 [traceId:] [TID: N/A] INFO 1 --- [ main] com.alibaba.nacos.common.remote.client [printIfInfoEnabled][63]: [e1146c19-413a-4f6f-8371-60242423f418] Register server push request handler:com.alibaba.nacos.client.naming.remote.gprc.NamingPushRequestHandler
2023-08-23 15:25:53.208 [traceId:] [TID: N/A] INFO 1 --- [ main] com.alibaba.nacos.common.remote.client [printIfInfoEnabled][63]: [e1146c19-413a-4f6f-8371-60242423f418] Try to connect to server on start up, server: {serverIp = '****.****.svc.cluster.local', server main port = 8848}
2023-08-23 15:25:53.208 [traceId:] [TID: N/A] INFO 1 --- [ main] c.a.n.c.remote.client.grpc.GrpcClient [createNewManagedChannel][182]: grpc client connection server:****.****.svc.cluster.local ip,serverPort:9848,grpcTslConfig:{"sslProvider":"","enableTls":false,"mutualAuthEnable":false,"trustAll":false}
2023-08-23 15:25:53.326 [traceId:] [TID: N/A] INFO 1 --- [ main] com.alibaba.nacos.common.remote.client [printIfInfoEnabled][63]: [e1146c19-413a-4f6f-8371-60242423f418] Success to connect to server [****.****.svc.cluster.local:8848] on start up, connectionId = 1692775552671_200.0.6.31_37904
2023-08-23 15:25:53.327 [traceId:] [TID: N/A] INFO 1 --- [t.remote.worker] com.alibaba.nacos.common.remote.client [printIfInfoEnabled][63]: [e1146c19-413a-4f6f-8371-60242423f418] Notify connected event to listeners.
2023-08-23 15:25:53.327 [traceId:] [TID: N/A] INFO 1 --- [ main] com.alibaba.nacos.common.remote.client [printIfInfoEnabled][63]: [e1146c19-413a-4f6f-8371-60242423f418] Register server push request handler:com.alibaba.nacos.common.remote.client.RpcClient$ConnectResetRequestHandler
2023-08-23 15:25:53.327 [traceId:] [TID: N/A] INFO 1 --- [t.remote.worker] com.alibaba.nacos.client.naming [onConnected][78]: Grpc connection connect
2023-08-23 15:25:53.327 [traceId:] [TID: N/A] INFO 1 --- [ main] com.alibaba.nacos.common.remote.client [printIfInfoEnabled][63]: [e1146c19-413a-4f6f-8371-60242423f418] Register server push request handler:com.alibaba.nacos.common.remote.client.RpcClient$$Lambda$253/1690859824
2023-08-23 15:25:54.224 [traceId:] [TID: N/A] INFO 1 --- [ main] o.s.b.a.e.web.EndpointLinksResolver [<init>][58]: Exposing 7 endpoint(s) beneath base path ''
2023-08-23 15:25:54.539 [traceId:] [TID: N/A] WARN 1 --- [ main] c.n.c.sources.URLConfigurationSource [<init>][126]: No URLs will be polled as dynamic configuration sources.
2023-08-23 15:25:56.889 [traceId:] [TID: N/A] INFO 1 --- [ main] com.alibaba.nacos.client.naming [subscribe][167]: [SUBSCRIBE-SERVICE] service:***, group:DEFAULT_GROUP, clusters:DEFAULT
2023-08-23 15:25:56.909 [traceId:] [TID: N/A] ERROR 1 --- [ main] c.a.cloud.nacos.discovery.NacosWatch [start][127]: namingService subscribe failed, properties:NacosDiscoveryProperties{serverAddr='nacos-*****.****.svc.cluster.local:8848
', endpoint='', namespace='test', watchDelay=30000, logName='', service='', weight=1.0, clusterName='DEFAULT', group='DEFAULT_GROUP', namingLoadCacheAtStart='false', metadata={management.endpoints.web.base-path=/, preserved.register.source=SPRING_CLOUD}, registerEnabled=true, ip='**.**.**.**', networkInterface='', port=-1, secure=false, accessKey='', secretKey='', heartBeatInterval=null, heartBeatTimeout=null, ipDeleteTimeout=null}com.alibaba.nacos.api.exception.NacosException: user not found!at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.requestToServer(NamingGrpcClientProxy.java:359)at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.doSubscribe(NamingGrpcClientProxy.java:311)at com.alibaba.nacos.client.naming.remote.gprc.NamingGrpcClientProxy.subscribe(NamingGrpcClientProxy.java:296)at com.alibaba.nacos.client.naming.remote.NamingClientProxyDelegate.subscribe(NamingClientProxyDelegate.java:173)at com.alibaba.nacos.client.naming.NacosNamingService.subscribe(NacosNamingService.java:405)at com.alibaba.cloud.nacos.discovery.NacosWatch.start(NacosWatch.java:123)问题排查
- 首先通过异常日志com.alibaba.nacos.api.exception.NacosException: user not found!可以看出是服务没有连接到nacos
- nacos2.2.3是开启鉴权的，所以服务在连接nacos之前肯定先进行登录，调用/nacos/v1/auth/users/login接口
- 再通过日志找到登录是报错的：[NacosClientAuthServiceImpl] login http request failed url
- 日志打印出的nacos url是http://****.****.svc.cluster.local:8848
/nacos/v1/auth/users/login, params: {username=nacos}, bodyMap: {password=****} - 且打印出errorMsg日志：errorMsg: Illegal character in authority at index 7:
问题定位
通过排查过程，通过 errorMsg: Illegal character in authority at index 7: 把问题最终定位到nacos url上;
前言中已经提到 “k8s在传入${NACOS_ADDR}时先对地址做了base64编码” ，所以把编码之后的地址解析出来发现k8s在编码时多加了换行；
这也是日志打印出nacos地址时，uri和接口地址不在同一行的原因，正确的url地址应该是 http://****.****.svc.cluster.local:8848/nacos/v1/auth/users/login 不会换行；
解决办法
重新对nacos url 进行正确的base64编码，修改${NACOS_ADDR}的base64值。
结束
至此，nacos连接异常问题解决。
)
