全部产品
云市场

故障排查

更新时间:2019-09-20 17:30:37

SOFARPC

错误 RPC-02306:无法获取 RPC 服务地址问题

RPC 客户端调用服务时,收到如下错误:

RPC-02306: 没有获得服务 [{0}] 的调用地址,请检查服务是否已经推送

排查思路

  1. 检查服务地址是否推送

    登录客户端,查看 /home/admin/logs/rpc/sofa-registry.log 日志,可以用服务接口名过滤日志找到最后一次推送记录。如果发现服务端地址没有推送到客户端,建议首选排查服务是否注册成功。

    例如,以下日志中有 可调用目标地址[0]个 的记录,则说明 com.alipay.share.rpc.facade.SampleService 的服务端地址没有推送到客户端:

    1. RPC-REGISTRY - RPC-00204: 接收 RPC 服务地址:服务名[com.alipay.share.rpc.facade.SampleService:1.0@DEFAULT]
    2. 可调用目标地址[0]个
  2. 检查客户端启动时是否收到 RPC Config 推送

    查看 /home/admin/logs/rpc/rpc-registry.log 日志,确定最近一次 RPC 客户端的启动时间。根据客户端上次启动时间和服务接口名过滤日志,检查对应的接口是否有 Receive Rpc Config info 的记录。如果没有也会导致后续无法调用服务,可以考虑重启客户端。

  3. 检查服务是否注册成功

    登录 脚手架 查看服务注册情况,或登录服务端查看 /home/admin/logs/confreg/config.client.log 日志。如果有服务发布相关的错误,可根据日志信息进一步排查。

  4. 检查服务调用是否早于地址推送时间

    如果客户端日志 sofa-registry.log 显示服务地址已经推送,但是 RPC-02306 错误发生的时间在服务地址推送之前,这种情况多发生在业务系统自己通过定时任务或者在 bean 初始化完成后就开始调用服务,而此时客户端应用还没启动完成。此种情况可以通过配置如下 address-wait-time 解决。
    address-wait-time:reference 生成时,等待服务注册中心将地址推送到消费方的时间。address-wait-time 的最大值为 30000 ms,超过这个值的配置将调整为 30000 ms。默认值为 0 (ms)。

  5. 检查 RPC 服务端和客户端应用配置信息是否匹配

    分别打开服务端和客户端应用的配置文件 application.properties,查看以下参数是否配置相同,如配置不同,RPC 客户端无法感知 RPC 服务端。

    • com.alipay.instanceid
    • com.antcloud.antvip.endpoint
  6. 检查服务注册中心连接

    运行以下命令以检查客户端和服务端与服务注册中心的连接情况:

    1. netstat -a |grep 9600

    9600 端口是服务注册中心的监听端口,客户端和服务端与 9600 端口建立长连接,向服务注册中心发布和订阅服务。如果客户端或者服务端与 9600 端口的连接断开,则需要重启应用恢复,并进一步排查端口异常断开的原因。

  7. 检查RPC服务端地址绑定

    登录 RPC 服务端,运行以下命令:

    1. ps -ef|grep java

    查看进程启动参数rpc_bind_network_interfacerpc_enabled_ip_range 是否绑定了正确的IP地址。

如何排查 RPC 超时问题

若调用 RPC 服务超时,在客户端的 logs/tracelog/middleware_error.log 日志中,可看到如下异常信息:

  1. 2018-07-06 13:21:20.463,sofa2-rpc-client,707c27b9153085447746110464663,0,main,timeout_error,rpc,invokeType=sync&uid=&protocol=bolt&targetApp=sofa2-rpc-server&targetIdc=&targetCity=&paramTypes=&methodName=message&serviceName=com.alipay.share.rpc.facade.SampleService:1.0&targetUrl=10.160.34.141:12200&targetZone=&,,com.alipay.sofa.rpc.core.exception.SofaTimeOutException: com.alipay.remoting.rpc.exception.InvokeTimeoutException: Rpc invocation timeout[responseCommand TIMEOUT]! the address is 10.160.34.141:12200

RPC 调用时序图

时序图

有关客户端和服务端各阶段的耗时信息,请参考 RPC Tracer 日志

排查思路

PRC 调用超时一般可以按照如下顺序逐步排查:

  1. 服务本身确实超时,如业务代码处理时间过长。
  2. 服务端 RPC 线程池耗尽
  3. 发生垃圾回收(Garbage Collection,简称 GC),导致线程停止。
  4. 发生网络问题
  5. 其他外部因素影响服务器性能,如定时任务、批处理,或者与宿主机上其他虚拟机、容器发生资源争抢。
服务本身超时

默认情况下,RPC 的超时时间为 3 秒。要确定某个请求的实际处理时间,您可登录服务端,查看 logs/tracelog/rpc-server-digest.log 日志。根据客户端超时日志中的 traceID,如 707c27b9153085447746110464663,找到服务端处理对应请求的日志。

日志格式如下所示:

  1. 2018-07-06 13:21:22.441,sofa2-rpc-server,707c27b9153085447746110464663,0,com.alipay.share.rpc.facade.SampleService:1.0,message,bolt,,10.160.33.96,sofa2-rpc-client,,,4001ms,0ms,SofaBizProcessor-12200-0-T46,02,,,1ms,,

上述日志中服务端业务代码处理时间为 4001 毫秒。

由于 RPC 调用默认的超时时间是 3 秒,如果日志中的耗时大于 3 秒或者非常接近 3 秒,建议首先从服务端本身排查:

  • 服务端业务代码执行慢。
  • 服务端本身有外网服务调用,或者服务端又调用了其他 RPC 服务(client > RPC Server A > RPC Server B),此种情况需要分别排查 A 和 B,定位问题。
  • 服务端有数据库操作,如数据库连接耗时、慢 SQL 等。
服务端 RPC 线程池耗尽

登录服务端查看 rpc/tr-threadpool 日志。如果发生 RPC 线程池队列阻塞,先确认是否发生超时的时间段有业务请求高峰,或者用 jstack 查看业务线程是否有等待或者死锁情况,导致 RPC 线程耗尽。

更多信息,请参见 SOFARPC 进阶指南 > 配置说明

GC 问题

某些 GC 类型会触发“stop the world”问题,会将所有线程挂起。若要排查是否是 GC 导致的超时问题,可以通过以下方法开启 GC 日志。

方法一

config/java_opts 文件中加入以下启动参数,并重新打包发布。

  1. -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/home/admin/logs/gc.log

方法二

  1. kill -15 命令结束服务端进程。
  2. 手动启动 RPC 服务。运行 su admin 进入 admin 用户,用如下 nohup 形式启动 RPC 服务:
    1. $ nohup java -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/home/admin/logs/gc.log -Drpc_bind_network_interface=eth0 -Dspring.profiles.active=&{工作空间标识} -jar /home/admin/app-run/sofa2-rpcserver-service-1.0-SNAPSHOT-executable.jar &

    说明工作空间标识 可在控制台中选择 金融分布式架构 > 资源管理 > 工作空间 中查看。

等待下次 RPC 超时发生后,查看 gc.log 验证超时的时间段是否有耗时较长的 GC,尤其是 Full GC。

网络延时抖动

排查是否由于网络问题导致RPC调用超时:

1.在客户端和服务端运行 tsar -i 1 查看问题发生的时间点是否有网络重传。

2.在客户端和服务端同时部署 tcpdump 进行循环抓包,问题发生后分析网络包。

3.在客户端和服务端运行 ping 观察是否存在网络延时。

打印客户端RPC调用统计

以下示例语句打印调用 sofa2-rpc-server 的应用超过3秒的请求总数、服务端IP、服务应用和客户端IP。实际使用时,将 sofa2-rpc-server 替换成对应的服务端应用名称,并根据日志中处理时长所对应列的具体位置调整 $18 数值。打印信息也可以根据需要调整。

  1. $ grep sofa2-rpc-server rpc-client-digest.log | awk -F, '{if(int($18)>3000)print $9,$10,$27}' |sort | uniq -c | sort -n

定时任务

日常研发时无法收到任务触发

建议按以下步骤依次排查问题:

  1. 在界面上手动触发任务,确认是否提示 成功
  2. 查看调度界面上的 EventCode 是否与代码中的一致。
  3. 查看消息队列界面上消息类型、订阅关系是否完成配置,状态是否为 生效
  4. 查看代码中的 GroupId/Topic/EventCode 是否与管控界面上的配置一致。
  5. 查看服务器 netstat –an|grep 9529 是否连上消息中心。
  6. 确认消息客户端日志 logs/tracelog/msg-sub-digest.log 是否有接收对应的 EventCode。
  7. 如果 msg-sub-digest 有日志,业务日志未打印,则可能是业务处理出现异常,应从 UniformEventMessageListener 进行排查,查看是否有其他报错。

消息重复投递

问题描述:我们在界面上已经停止了调度任务,但是依然收到了触发消息。

问题分析:定时任务依赖消息队列来完成调度任务投递,消息队列为了确保高可靠,对于业务处理异常或者业务处理耗时太长,都会认为是客户端处理失败,会发起重试,一般包括以下场景:

  • 消息接收端处理失败,直接抛出异常;
  • 消息接收端处理耗时太长,超过 8s,服务端会认定客户端处理失败,发起重试;
  • 调度界面任务触发频率很高,消息量太大,无法接收新的消息(所以建议开发工作空间下将定时任务配置为暂停状态,开发完成后,评估单机实际处理能力再设置一个可靠的 CRON)。

解决方案:查看 logs/msgbroker/common-default.log 或者 common-error.log 是否有异常报错,如果有报错,异常堆栈一般从业务代码中抛出,请结合业务代码确认异常原因进行修复。