apache / servicecomb-java-chassis

ServiceComb Java Chassis is a Software Development Kit (SDK) for rapid development of microservices in Java, providing service registration, service discovery, dynamic routing, and service management features
Apache License 2.0
1.91k stars 811 forks source link

性能问题咨询 #2491

Closed five111 closed 3 years ago

five111 commented 3 years ago

客户端低频但必现Connection was closed 几个小时会报错一个报错 增加了metirc日志后 搜集到信息如下 第一类 ** [simpleConsumerThread-0]2021-07-30 22:12:51.344 [WARN ] | slow(1 ms) invocation, CONSUMER rest ude.udeS*##er.launchTasks:[N] http method: POST[N]
url : /scheduler/launchtasks/[N]
server : rest://172.18.1.135:5559?sslEnabled=true&urlPrefix=%2Fbfs%2Frest[N]
status code: 490[N]
total : 1648.425 ms[N]
prepare : 0.25 ms[N]
handlers request : 0.307 ms[N]
client filters request : 0.133 ms[N]
send request : 1629.543 ms[N]
get connection : 1629.205 ms[N]
write to buf : 0.338 ms[N]
wait response : 2.967 ms[N]
wake consumer : 0.1 ms[N]
client filters response: 0.0 ms[N]
handlers response : 15.445 ms | org.apache.servicecomb.metrics.core.publish.SlowInvocationLogger.warn(TraceIdLogger.java:56) **

没有改过超时时间,时间类配置都是默认配置 1.6s就超时了 ,对应的服务端没有任何日志

第二类 runlog.20210730213035.1.log.gz:[simpleConsumerThread-0]2021-07-30 20:55:34.585 [WARN ] | slow(1 ms) invocation, CONSUMER rest databusmanager.TaskManagerController.launchTasks:[N]
http method: POST[N] url : /rest/v1/scheduler/launchTasks/[N] server : rest://172.18.0.152:8087?sslEnabled=true&urlPrefix=%2Fdatabus%2Frest%2Fcse[N]
status code: 408[N]
total : 30003.297 ms[N]
prepare : 0.7 ms[N]
handlers request : 0.141 ms[N]
client filters request : 0.106 ms[N]
send request : 0.0 ms[N]
get connection : 0.0 ms[N]
write to buf : 0.0 ms[N]
wait response : 0.0 ms[N]
wake consumer : 0.0 ms[N]
client filters response: 0.0 ms[N]
handlers response : 0.0 ms | org.apache.servicecomb.metrics.core.publish.SlowInvocationLogger.warn(TraceIdLogger.java:56) runlog.20210731024455.1.log.gz:[simpleConsumerThread-0]2021-07-31 02:15:32.511 [WARN ] | slow(1 ms) invocation, CONSUMER rest databusmanager.TaskManagerController.launchTasks:[N]
http method: POST[N] url : /rest/v1/scheduler/launchTasks/[N] server : rest://172.18.0.152:8087?sslEnabled=true&urlPrefix=%2Fdatabus%2Frest%2Fcse[N]
status code: 408[N]
total : 30002.336 ms[N]
prepare : 0.4 ms[N]
handlers request : 0.85 ms[N]
client filters request : 0.61 ms[N]
send request : 0.0 ms[N]
get connection : 0.0 ms[N]
write to buf : 0.0 ms[N]
wait response : 0.0 ms[N]
wake consumer : 0.0 ms[N]
client filters response: 0.0 ms[N]
handlers response : 0.0 ms | org.apache.servicecomb.metrics.core.publish.SlowInvocationLogger.warn(TraceIdLogger.java:56) runlog.20210731092506.1.log.gz:[simpleConsumerThread-0]2021-07-31 08:30:33.741 [WARN ] | slow(1 ms) invocation, CONSUMER rest databusmanager.TaskManagerController.launchTasks:[N]
http method: POST[N] url : /rest/v1/scheduler/launchTasks/[N] server : rest://172.18.0.200:8087?sslEnabled=true&urlPrefix=%2Fdatabus%2Frest%2Fcse[N]
status code: 408[N]
total : 30001.925 ms[N]
prepare : 0.7 ms[N]
handlers request : 0.115 ms[N]
client filters request : 0.108 ms[N]
send request : 0.0 ms[N]
get connection : 0.0 ms[N]
write to buf : 0.0 ms[N]
wait response : 0.0 ms[N]
wake consumer : 0.0 ms[N]
client filters response: 0.0 ms[N]
handlers response : 0.0 ms | org.apache.servicecomb.metrics.core.publish.SlowInvocationLogger.warn(TraceIdLogger.java:56)
的确是30s时间超时 但是一致的在send request 就没有了时间统计 ,对端也是没有日志的

麻烦帮忙分析下可能性,感谢 java-chassis版本2.1.5 服务端客户端 都是结合springboot使用的rest-over-servlet模式

five111 commented 3 years ago

https://github.com/apache/servicecomb-java-chassis/issues/1971 这个issue的描述似乎和我们相似

liubao68 commented 3 years ago

第一类:这个是一个警告,当一个请求处理时间超过1秒的时候(默认值),就会输出。 第二类:这个是超时的情况下, 对于 send request/get connection的时间统计问题, 记得有修复过类似问题。

从提供的信息看, 直接的原因可能是获取连接慢。 详细原因,可能还得结合线程池统计、连接池统计信息等综合分析。

five111 commented 3 years ago

第一类:这个是一个警告,当一个请求处理时间超过1秒的时候(默认值),就会输出。

这个不是个警告,这次请求是失败的

five111 commented 3 years ago

第二类:这个是超时的情况下, 对于 send request/get connection的时间统计问题, 记得有修复过类似问题。

这个是哪个版本合入的?方便贴下pr吗