接口偶尔出现卡顿排查解决
接口路由节点: nginx > zuul > k8s svc > pod
排查问题1:
--通过域名访问(偶尔几秒偶尔0.2秒,(偶尔几秒偶尔0.2秒,不正常))
for((i=1;i<=100;i++));
do curl "https://m8.XXXXX.com.cn/XXXXX/pe/coupon/queryGiftCouponByUser?ver=0.43384155157615356 -o /dev/null -s -w "time_connect: %{time_connect}\ntime_starttransfer: %{time_starttransfer}\ntime_total: %{time_total}\n" done --直接访问k8s zuul svc的应用url (偶尔几秒偶尔0.2秒,不正常) for((i=1;i<=150;i++)); do curl "http://svc-XXXXX-gate:8765/XXXXX/pe/coupon/queryGiftCouponByUser?ver=0.43384155157615356 -o /dev/null -s -w "time_connect: %{time_connect}\ntime_starttransfer: %{time_starttransfer}\ntime_total: %{time_total}\n" donefor((i=1;i<=100;i++)); (偶尔几秒偶尔0.2秒,不正常)
do curl "http://localhost:8765/XXXXX/pe/coupon/queryGiftCouponByUser?ver=0.43384155157615356 -o /dev/null -s -w "time_connect: %{time_connect}\ntime_starttransfer: %{time_starttransfer}\ntime_total: %{time_total}\n" donesleep 0.5
--直接访问k8s svc的应用url (一直0.2秒,正常) for((i=1;i<=50;i++)); do curl "http://svc-XXXXX-pe:9003/coupon/queryGiftCouponByUser?ver=0.43384155157615356 -o /dev/null -s -w "time_connect: %{time_connect}\ntime_starttransfer: %{time_starttransfer}\ntime_total: %{time_total}\n" done--直接访问docker内部的应用url,(一直是0.2秒,正常)
for((i=1;i<=50;i++)); do curl "http://localhost:9003/coupon/queryGiftCouponByUser?ver=0.43384155157615356 -o /dev/null -s -w "time_connect: %{time_connect}\ntime_starttransfer: %{time_starttransfer}\ntime_total: %{time_total}\n" done排查问题2:给应用加资源cpu内存还是存在问题
排查问题3:查看应用jvm gc日志也是正常的-----------------log------------------------------------------
XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.366 | http-nio-8765-exec-9 | DEBUG | o.s.web.servlet.DispatcherServlet.processDispatchResult(1044) | Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.366 | http-nio-8765-exec-9 | DEBUG | o.s.web.servlet.DispatcherServlet.processRequest(1000) | Successfully completed request XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.366 | http-nio-8765-exec-9 | DEBUG | o.s.c.s.instrument.web.TraceFilter.detachOrCloseSpans(216) | Closing the span [Trace: 635fa133781b8221, Span: 635fa133781b8221, Parent: null, exportable:false] since the response was successful XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.366 | http-nio-8765-exec-9 | DEBUG | o.s.c.s.zipkin.ZipkinSpanListener.report(216) | The span [Trace: 635fa133781b8221, Span: 635fa133781b8221, Parent: null, exportable:false] will not be sent to Zipkin due to sampling XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.591 | http-nio-8765-exec-5 | DEBUG | o.s.c.s.instrument.web.TraceFilter.doFilter(130) | Received a request to uri [/XXXXX/pe/coupon/queryGiftCouponByUser] that should not be sampled [false] XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.591 | http-nio-8765-exec-5 | DEBUG | o.s.c.s.instrument.web.TraceFilter.createSpan(316) | No parent span present - creating a new span XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.591 | http-nio-8765-exec-5 | DEBUG | o.s.web.servlet.DispatcherServlet.doService(865) | DispatcherServlet with name 'dispatcherServlet' processing GET request for [/XXXXX/pe/coupon/queryGiftCouponByUser] XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.591 | http-nio-8765-exec-5 | DEBUG | o.s.web.servlet.DispatcherServlet.doDispatch(951) | Last-Modified value for [/XXXXX/pe/coupon/queryGiftCouponByUser] is: -1 XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.592 | http-nio-8765-exec-5 | INFO | c.d.cloud.gate.filter.PreZuulFilter.run(60) | /XXXXX/pe/coupon/queryGiftCouponByUser进入服务器: XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.592 | http-nio-8765-exec-5 | INFO | c.d.cloud.gate.filter.PreZuulFilter.run(61) | GET >>> http://svc-XXXXX-gate:8765/XXXXX/pe/coupon/queryGiftCouponByUser XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.592 | http-nio-8765-exec-5 | DEBUG | o.s.c.s.i.zuul.TracePreZuulFilter.runFilter(74) | Current span is [Trace: 02cdd3adda96d990, Span: 02cdd3adda96d990, Parent: null, exportable:true] XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.592 | http-nio-8765-exec-5 | DEBUG | o.s.c.s.i.zuul.TracePreZuulFilter.runFilter(82) | New Zuul Span is [Trace: 02cdd3adda96d990, Span: 90297cf6a00a9f48, Parent: 02cdd3adda96d990, exportable:true] XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.592 | http-nio-8765-exec-5 | DEBUG | o.s.c.s.i.zuul.TracePreZuulFilter.runFilter(86) | Result of Zuul filter is [SUCCESS] XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.613 | http-nio-8765-exec-5 | DEBUG | o.s.c.s.i.zuul.TracePostZuulFilter.run(58) | Closing current client span [Trace: 02cdd3adda96d990, Span: 90297cf6a00a9f48, Parent: 02cdd3adda96d990, exportable:true] XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:33.653 | http-nio-8765-exec-5 | INFO | c.d.cloud.gate.filter.PostZuulFilter.run(36) | /XXXXX/pe/coupon/queryGiftCouponByUser 返回响应, 耗时 5061 根据日志发现: XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:28.613 | http-nio-8765-exec-5 | DEBUG | o.s.c.s.i.zuul.TracePostZuulFilter.run(58) | Closing current client span [Trace: 02cdd3adda96d990, Span: 90297cf6a00a9f48, Parent: 02cdd3adda96d990, exportable:true] XXXXX-gate | deploy-XXXXX-gate-59bf5f5f8c-ssj9p | 2019-04-12 13:40:33.653 | http-nio-8765-exec-5 | INFO | c.d.cloud.gate.filter.PostZuulFilter.run(36) | /XXXXX/pe/coupon/queryGiftCouponByUser 返回响应, 耗时 5061结论:根据测试发现是zuul问题
o.s.c.s.i.zuul.TracePostZuulFilter.run(58) 到 c.d.cloud.gate.filter.PostZuulFilter.run(36) 花5秒
=============解决方案========================= spring: sleuth: enabled: false =================解决后的log================ XXXXX-gate | deploy-XXXXX-gate-6d79bb6655-d6ph7 | 2019-04-12 16:03:53.377 | http-nio-8765-exec-7 | INFO | c.d.cloud.gate.filter.PreZuulFilter.run(60) | /XXXXX/pe/coupon/queryGiftCouponByUser进入服务器: XXXXX-gate | deploy-XXXXX-gate-6d79bb6655-d6ph7 | 2019-04-12 16:03:53.377 | http-nio-8765-exec-7 | INFO | c.d.cloud.gate.filter.PreZuulFilter.run(61) | GET >>> http://svc-XXXXX-gate:8765/XXXXX/pe/coupon/queryGiftCouponByUser XXXXX-gate | deploy-XXXXX-gate-6d79bb6655-d6ph7 | 2019-04-12 16:03:53.410 | http-nio-8765-exec-7 | INFO | c.d.cloud.gate.filter.PostZuulFilter.run(36) | /XXXXX/pe/coupon/queryGiftCouponByUser 返回响应, 耗时 33 XXXXX-gate | deploy-XXXXX-gate-6d79bb6655-d6ph7 | 2019-04-12 16:03:53.412 | http-nio-8765-exec-7 | DEBUG | o.s.web.servlet.DispatcherServlet.processDispatchResult(1044) | Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling XXXXX-gate | deploy-XXXXX-gate-6d79bb6655-d6ph7 | 2019-04-12 16:03:53.412 | http-nio-8765-exec-7 | DEBUG | o.s.web.servlet.DispatcherServlet.processRequest(1000) | Successfully completed request 问题出现在:TracePostZuulFilter spring-cloud-sleuth:1.1.0.RELEASE spring-cloud-netflix:1.2.3.RELEASE