분당 200,000 개 이상의 요청을 처리하는 JBoss 7에 처리량이 높은 응용 프로그램이 배포되었습니다. 응용 프로그램은 http 요청을 읽고 처리합니다. 평균 요청 페이로드 크기는 1.5Kb입니다.SocketInputStream.socketRead0은 응용 프로그램 시간의 30 %를 차지합니다.
55 % 시간 : Unsafe.park
(스레드가 할당 기다리고?)
30 % 시간 : SocketInputStream.socketRead0
(? 아마 소켓 해제 요청을 읽기)
8 % 시간
는 CPU 스레드 프로파일 러
는 다음을 보여줍니다 : 처리를 위해 전체 응용 프로그램 코드는4 %의 시간을 요청 봄 코드
사람이 너무 많은 시간의 힘이 Unsafe.park
및 SocketInputStream.socketRead0
에 소요되는 이유에 대한 몇 가지 빛을 던질 수 있습니까? 다른 stackoverflow 게시물에 따라, Unsafe.park
은 할당 대기중인 스레드 (예약 용량을 나타냄) (확실하지 않음). 나머지 45 %는 실제 사용 된 용량 일 것입니다.
가장 놀라운 부분은 SocketInputStream.socketRead0
(아래의 스레드 덤프 스택 프레임)이 30 %의 시간을 차지한다는 것입니다. 여러 네트워크 조회를 포함하여 복잡한 응용 프로그램 코드 전체를 처리하는 요청은 시간의 8 % 만 차지합니다.
사용량이 45 %라고 가정하면 SocketInputStream.socketRead0
에 67 %의 시간이 걸립니다.
주된 질문은 SocketInputStream.socketRead0
에 너무 많은 시간이 걸릴 수 있습니다. 모든 포인터가 도움이 될 것입니다.
스레드 덤프 SocketInputStream.socketRead0
org.jboss.threads.JBossThread.run() :122
java.lang.Thread.run() :745
org.jboss.threads.QueueExecutor$Worker.run() :835,825,840,842
org.jboss.threads.QueueExecutor.access$100(org.jboss.threads.QueueExecutor, java.lang.Runnable) :45
org.jboss.threads.QueueExecutor.runTask(java.lang.Runnable) :801
org.jboss.threads.SimpleDirectExecutor.execute(java.lang.Runnable) :33
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run() :520,518
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(java.net.Socket) :671
org.apache.coyote.http11.Http11Processor.process(java.net.Socket) :838,877,904,844
org.apache.coyote.http11.InternalInputBuffer.parseRequestLine() :369,368
org.apache.coyote.http11.InternalInputBuffer.fill() :731
java.net.SocketInputStream.read(byte[], int, int) :122
java.net.SocketInputStream.read(byte[], int, int, int) :152
java.net.SocketInputStream.socketRead0(java.io.FileDescriptor, byte[], int, int, int) :native
스택에 대해 다음 스택 추적 프레임을 보여준다는 Unsafe.park
을위한 프레임 :
org.jboss.threads.JBossThread.run() :122
java.lang.Thread.run() :745
org.jboss.threads.QueueExecutor$Worker.run() :835,825,840,842
org.jboss.threads.QueueExecutor.access$100(org.jboss.threads.QueueExecutor, java.lang.Runnable) :45
org.jboss.threads.QueueExecutor.runTask(java.lang.Runnable) :801
org.jboss.threads.SimpleDirectExecutor.execute(java.lang.Runnable) :33
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run() :520,518
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(java.net.Socket) :671
org.apache.coyote.http11.Http11Processor.process(java.net.Socket) :838,877,904,844
org.apache.catalina.connector.CoyoteAdapter.service(org.apache.coyote.Request, org.apache.coyote.Response) :395,368,364,365
org.apache.catalina.core.StandardEngineValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) :109
org.apache.catalina.valves.ErrorReportValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) :123,131,102
org.apache.catalina.core.StandardHostValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) :125,143,185,155
org.jboss.as.web.security.SecurityContextAssociationValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) :159,155,93,153,72,86,158,92,83,109
org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke :50,47
org.apache.catalina.core.StandardContextValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) :161
org.apache.catalina.core.StandardWrapperValve.invoke(org.apache.catalina.connector.Request, org.apache.catalina.connector.Response) :283,253,275
org.apache.catalina.core.ApplicationFilterChain.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) :248
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) :280
org.springframework.web.filter.OncePerRequestFilter.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse, javax.servlet.FilterChain) :76,74,-1,67,83
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, javax.servlet.FilterChain) :88
org.apache.catalina.core.ApplicationFilterChain.doFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) :248
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(javax.servlet.ServletRequest, javax.servlet.ServletResponse) :329
javax.servlet.http.HttpServlet.service(javax.servlet.ServletRequest, javax.servlet.ServletResponse) :848,-1,847
javax.servlet.http.HttpServlet.service(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) :754,781
org.springframework.web.servlet.FrameworkServlet.doPost(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) :789
org.springframework.web.servlet.FrameworkServlet.processRequest(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) :867,920,873,882,866,919,870
org.springframework.web.servlet.DispatcherServlet.doService(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) :842,848,840,849,839,852,841
org.springframework.web.servlet.DispatcherServlet.doDispatch(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) :886,934,923,963,893,910,-1,984,914
org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, java.lang.Object) :80,-1
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, org.springframework.web.method.HandlerMethod) :578
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, org.springframework.web.method.HandlerMethod) :621,610,606,-1,609,608,617,612,614,618
org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(org.springframework.web.context.request.NativeWebRequest, org.springframework.web.method.support.ModelAndViewContainer, java.lang.Object[]) :96
org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(org.springframework.web.context.request.NativeWebRequest, org.springframework.web.method.support.ModelAndViewContainer, java.lang.Object[]) :126,117
org.springframework.web.method.support.InvocableHandlerMethod.invoke(java.lang.Object[]) :213
java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) :606
sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) :43
sun.reflect.GeneratedMethodAccessor405.invoke(java.lang.Object, java.lang.Object[])
com.myco.myapp.AppController.process(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, java.io.Writer, @RequestHeader java.lang.String, @PathVariable java.lang.String, @RequestParam java.lang.String) :84,83,82
EDIT (:
org.jboss.threads.JBossThread.run() :122
java.lang.Thread.run() :745
org.jboss.threads.QueueExecutor$Worker.run() :835,825,840,842
org.jboss.threads.QueueExecutor.access$400(org.jboss.threads.QueueExecutor) :45
org.jboss.threads.QueueExecutor.takeTask() :746
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await() :2039,2043
java.util.concurrent.locks.LockSupport.park(java.lang.Object) :186
sun.misc.Unsafe.park(boolean, long) :native
스택 호출하는 응용 프로그램 코드를 프레임 Apr 8) :
30 % socketRead0
에 대한 위의 스택 프레임은 요청 본문이 아닌 "요청 라인"만을 읽는 것입니다.
org.apache.coyote.http11.InternalInputBuffer.parseRequestLine() :369,368
는 "요청 본문은"실제로 8 %의 응용 프로그램 코드에서 읽을되고 있으며 전체 시간의 (아직도해야보다 높은 것) 1.7 %를 복용 밝혀 위를 참조하십시오. 요청 본문을 표시하는 응용 프로그램 코드를 호출하는 위의 스택 프레임의 연속 읽기되고 :
1. 30 %의 시간이 socketRead0
에서 보낸 이유 :
com.myco.myapp.AppController.process(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, java.io.Writer, @RequestHeader java.lang.String, @PathVariable java.lang.String, @RequestParam java.lang.String) :84,83,82
com.myco.myapp.AppController.getRequestBody(javax.servlet.http.HttpServletRequest, java.lang.String) :229,221,222,-1
org.apache.catalina.connector.CoyoteReader.readLine() :190,203,158,201,192,204
org.apache.catalina.connector.CoyoteReader.read(char[], int, int) :105
org.apache.catalina.connector.InputBuffer.read(char[], int, int) :447
org.apache.tomcat.util.buf.CharChunk.substract(char[], int, int) :445
org.apache.catalina.connector.InputBuffer.realReadChars(char[], int, int) :398
org.apache.catalina.connector.InputBuffer.realReadBytes(byte[], int, int) :347
org.apache.coyote.Request.doRead(org.apache.tomcat.util.buf.ByteChunk) :438
org.apache.coyote.http11.InternalInputBuffer.doRead(org.apache.tomcat.util.buf.ByteChunk, org.apache.coyote.Request) :706
org.apache.coyote.http11.filters.IdentityInputFilter.doRead(org.apache.tomcat.util.buf.ByteChunk, org.apache.coyote.Request) :116
org.apache.coyote.http11.InternalInputBuffer$InputStreamInputBuffer.doRead(org.apache.tomcat.util.buf.ByteChunk, org.apache.coyote.Request) :777
org.apache.coyote.http11.InternalInputBuffer.fill() :747
java.net.SocketInputStream.read(multiple parameter matches) :-1,122
java.net.SocketInputStream.read(byte[], int, int, int) :152
java.net.SocketInputStream.socketRead0(java.io.FileDescriptor, byte[], int, int, int) :native
질문은 여전히 동일하다? Unsafe.park
에서 55 %를 왜 사용해야하나요?