search

scouter-project / scouter

Scouter is an open source APM (Application Performance Management) tool.
Other
2.09k stars 563 forks source link

web api / summary 호출시.. #690

Open yuna-seo opened 4 years ago

yuna-seo commented 4 years ago

안녕하세요~!

사내에서 summary api를 통해서 내부적으로 error reporting을 진행하고 있습니다. 현재 내부 개선에 아주 잘사용하고 있어서 관심이 높아지고 있어요~!

문의 드리고 싶은게 2가지가 있습니다.

1) summary api로 호출시, java.sql.SQLException가 9개로 확인되는데요, 실제로 해당 xlog들을 전부 열어보면 첫번째만 sql exception이고 나머지는 동일한 sevice명의 slow sql 에러더라구요

9번 sql exception이 발생한 것으로 착각하여 혼선이 있을것 같은데 혹시 해당 건을 구분하여 summary 데이터를 구성할 수 있는 다른 방법이 있을까요?

2) 특정 시간대에 xlog의 양이 많아지면 summary api 호출시에 아래와 같이 server에서 socket time out이 발생하는 경우가 종종 있는데요, server에서 아래 설정을 변경하여 하는게 맞을까요..? 설정을 변경하여도 여전히 time out은 발생하네요ㅠ 조언 부탁드립니다.

(startTimeMillis과 endTimeMillis 를 줄이면 summary 데이터가 발췌됩니다.)

image

-- server webapp에러 첨부드립니다..

10:26:05.167 [scouterx.webapp.framework.client.server.ServerManager] INFO s.w.framework.client.net.ClientTCP[62] - Connected scouterx.webapp.framework.client.net.ClientTCP@10a6e253 to 127.0.0.1:6001 10:26:05.174 [XLogThread-127.0.0.1:6001-0] INFO s.w.framework.client.net.ClientTCP[62] - Connected scouterx.webapp.framework.client.net.ClientTCP@325c62eb to 127.0.0.1:6001

i6l0 10:26:38.099 [qtp376563421-70] INFO org.reflections.Reflections[232] - Reflections took 22 ms to scan 1 urls, producing 284 keys and 388 values

i6l11 11:00:27.262 [qtp376563421-195] INFO s.w.framework.client.net.TcpProxy[110] - TcpProxy closed : pool-size:5, scouterx.webapp.framework.client.net.TcpProxy@17354dd, stack:

i6l11 11:00:27.270 [qtp376563421-195] ERROR s.w.f.e.m.GenericExceptionMapper[95] - [ErrorStateException] 500 - internal server error - java.net.SocketTimeoutException: Read timed out, [uri]v1/summary/error/ofType/tomcat_30prd at scouterx.webapp.framework.exception.ErrorState.newException(ErrorState.java:67)

scouterx.webapp.framework.exception.ErrorStateException: java.net.SocketTimeoutException: Read timed out at scouterx.webapp.framework.exception.ErrorState.newException(ErrorState.java:67) at scouterx.webapp.model.summary.Summary.of(Summary.java:58) at scouterx.webapp.layer.consumer.SummaryConsumer.retrieveErrorSummary(SummaryConsumer.java:148) at scouterx.webapp.layer.service.SummaryService.retrieveErrorSummary(SummaryService.java:59) at scouterx.webapp.layer.controller.SummaryController.retrieveErrorSummary(SummaryController.java:275) at scouterx.webapp.layer.controller.SummaryController.retrieveErrorSummaryByType(SummaryController.java:254) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:76) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:148) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:191) at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:243) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:103) at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:493) at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:415) at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:104) at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:277) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268) at org.glassfish.jersey.internal.Errors.process(Errors.java:316) at org.glassfish.jersey.internal.Errors.process(Errors.java:298) at org.glassfish.jersey.internal.Errors.process(Errors.java:268) at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289) at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:256) at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:703) at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:416) at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:370) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:389) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:342) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:229) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:841) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1650) at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:206) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637) at scouterx.webapp.framework.filter.ReleaseResourceFilter.doFilter(ReleaseResourceFilter.java:44) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637) at scouterx.webapp.framework.filter.NoCacheFilter.doFilter(NoCacheFilter.java:40) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637) at scouterx.webapp.framework.filter.CorsFilter.doFilter(CorsFilter.java:65) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637) at scouterx.webapp.framework.filter.LoggingInitServletFilter.doFilter(LoggingInitServletFilter.java:50) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:521) at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) at org.eclipse.jetty.server.Server.handle(Server.java:564) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:317) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124) at org.eclipse.jetty.util.thread.Invocable.invokePreferred(Invocable.java:128) at org.eclipse.jetty.util.thread.Invocable$InvocableExecutor.invoke(Invocable.java:222) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:294) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:199) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:673) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:591) at java.lang.Thread.run(Thread.java:745) Caused by: java.lang.RuntimeException: java.net.SocketTimeoutException: Read timed out at scouterx.webapp.framework.client.net.TcpProxy.process(TcpProxy.java:206) at scouterx.webapp.framework.client.net.TcpProxy.process(TcpProxy.java:131) at scouterx.webapp.framework.client.model.TextModel.load(TextModel.java:165) at scouterx.webapp.framework.client.model.TextModel.getText(TextModel.java:119) at scouterx.webapp.framework.client.model.TextModel.getTextIfNullDefault(TextModel.java:99) at scouterx.webapp.model.summary.ErrorSummaryItem.toSummary(ErrorSummaryItem.java:103) at scouterx.webapp.model.summary.Summary.of(Summary.java:56) ... 69 common frames omitted Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) at java.io.BufferedInputStream.read1(BufferedInputStream.java:286) at java.io.BufferedInputStream.read(BufferedInputStream.java:345) at java.io.DataInputStream.readFully(DataInputStream.java:195) at java.io.DataInputStream.readFully(DataInputStream.java:169) at scouter.io.DataInputX.read(DataInputX.java:78) at scouter.io.DataInputX.readBlob(DataInputX.java:107) at scouter.io.DataInputX.readText(DataInputX.java:143) at scouter.lang.value.TextValue.read(TextValue.java:73) at scouter.io.DataInputX.readValue(DataInputX.java:256) at scouter.lang.pack.MapPack.read(MapPack.java:178) at scouter.io.DataInputX.readPack(DataInputX.java:268) at scouterx.webapp.framework.client.net.TcpProxy.lambda$process$0(TcpProxy.java:132) at scouterx.webapp.framework.client.net.TcpProxy.process(TcpProxy.java:197) ... 75 common frames omitted

gunlee01 commented 4 years ago

클라이언트 타임아웃은 net_tcp_client_so_timeout_ms로 조정이 가능합니다. (collector 설정)

gunlee01 commented 4 years ago

webapi에서 collector간의 timeout은 현재 15초로 고정되어 있고 설정이 불가능합니다. 차후 버전에 옵션을 추가될 듯 합니다. 그 전까지는 조회 범위를 낮추어 사용해야 할 것 같습니다.

yuna-seo commented 4 years ago
  • slow 쿼리에 대한 exception marking은 java agent에서 xlog_error_sql_time_max_ms xlog_error_on_sqlexception_enabled 설정으로 조정이 가능합니다.

클라이언트 타임아웃은 net_tcp_client_so_timeout_ms로 조정이 가능합니다. (collector 설정)

이 문제관련해서 설명이 제가 좀 부족했던것 같은데.. 관련내용 좀더 자세히 설명드리면 아래와 같습니다.

먼저, xlog에서 slow sql도 확인을 원하는 상태입니다. (slow sql, sql exception 둘다 확인을 원하고 있어요)

두개를 모두 수집하는 상태에서, summary api의 scouter/v1/summary/error/ofType 을 호출했을때, 동일한 service 에러에 대해서는 slow sql, sql exception이 분리되지 않고 합쳐진 값이 리턴되는것 같습니다.

예를 들면, 아래와 같이 /test라는 서비스에 대해서 25번 SQL syntax error가 발생한것 처럼 summary response를 확인할 수 있는 경우,

image

실제로 해당 service의 에러를 scouter에서 찾아보면 그 안에는 slow sql등과 같은 다른 error도 포함이 되어 있더라구요.

동일 서비스에 대해서 error에 따라 구분되지는 않는것 같은데, 혹시 이부분 구분할 수 있는 방법이 있을지 해서 문의드렸습니다.

예를 들면, 아래와 같은 결과를 원하는 것입니다.

image

지원 감사합니다~!

gunlee01 commented 4 years ago

2.8.1 버전에서 Web api이 타입아웃은 Web App 설정에서 net_webapp_tcp_client_so_timeout 으로 조정이 가능합니다. summary API 관련해서는 좀 더 확인해봐야 할 듯 합니다.