느리거나 정지된 요청 발견
requestTiming-1.0 기능은 요청의 지속 시간이 구성된 임계값을 초과하는 경우 진단 정보를 제공합니다.
느린 요청 발견
요청이 구성된 시간보다 더 오래 실행되는 경우에는 메시지 로그 파일에 경고 메시지가 기록됩니다. 요청의 세부사항 및 요청을 구성하는 이벤트가 캡처됩니다.[12/1/14 11:58:09:629 IST] 0000001d com.ibm.ws.request.timing.SlowRequestTimer W TRAS0112W: Request AABjnS+lIn0_AAAAAAAAAAb has been running on thread 00000021 for at least 10003.571ms. The following stack trace shows what this thread is currently running.
at java.util.HashMap.getEntry(HashMap.java:516)
at java.util.HashMap.get(HashMap.java:504)
at org.apache.derby.iapi.store.access.BackingStoreHashtable.get(Unknown Source)
at org.apache.derby.impl.sql.execute.HashScanResultSet.getNextRowCore(Unknown Source)
at org.apache.derby.impl.sql.execute.NestedLoopJoinResultSet.getNextRowCore(Unknown Source)
at org.apache.derby.impl.sql.execute.ProjectRestrictResultSet.getNextRowCore(Unknown Source)
at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(Unknown Source)
at org.apache.derby.impl.sql.execute.DeleteResultSet.setup(Unknown Source)
at org.apache.derby.impl.sql.execute.DeleteResultSet.open(Unknown Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(Unknown Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source)
at com.ibm.ws.rsadapter.jdbc.WSJdbcPreparedStatement.executeUpdate(WSJdbcPreparedStatement.java:626)
at com.ibm.websphere.samples.trade.direct.TradeDirect.resetTrade(TradeDirect.java:1832)
at com.ibm.websphere.samples.trade.web.TradeConfigServlet.doResetTrade(TradeConfigServlet.java:65)
at com.ibm.websphere.samples.trade.web.TradeConfigServlet.service(TradeConfigServlet.java:348)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:668)
at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1275)
....
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1121)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:614)
at java.lang.Thread.run(Thread.java:769)
Duration Operation
10007.571ms + websphere.servlet.service | TradeWeb | TradeConfigServlet?action=resetTrade
3.923ms websphere.datasource.psExecuteUpdate | jdbc/TradeDataSource | delete from holdingejb where holdingejb.account_accountid is null
0.853ms websphere.datasource.psExecuteUpdate | jdbc/TradeDataSource | delete from accountprofileejb where userid like 'ru:%'
5271.341ms + websphere.datasource.psExecuteUpdate | jdbc/TradeDataSource | delete from orderejb where account_accountid in (select accountid from accountejb a where a.profile_useri like 'ru:%')
TRAS0112W: Request <(Request ID)> has been running on thread <THREADID> for at least <DURATION>. The following stack trace shows what this thread is currently running.
<STACK TRACE>
<DURATION AND OPERATIONS Table>
- REQUEST ID
- 이 ID는 요청에 대응하는 로그 및 추적 메시지를 검색하는 데 사용할 수 있습니다. 특히, 2진 로깅을 사용하는 경우에는 2진 로그 명령을 사용하여 동일한 requestID 확장이 있는 로그 및 추적 항목을 검색할 수 있습니다.
- STACK TRACE
- 실행 중인 메소드를 표시합니다. 이전 샘플에서는 TRAS0112W 행 뒤에 현재 요청의 스택 추적이 표시되어 있습니다.
- DURATION AND OPERATIONS Table
- 스택 추적 뒤에는 지속 시간 및 조작(이벤트라고도 함)을 보여주는 표 형식의 요청이 있습니다. Duration 열은 요청의 해당 조작에 소요된 시간을 표시합니다. 더하기 부호(+)는 아직 실행 중인 요청 내의 이벤트를 표시합니다. 다음 행은 +가 없는 지속 기간을 표시합니다. 이는 지정된 지속 기간 내에 해당 조작이 완료되었음을 나타냅니다. Operation은 해당 조작의 EVENT TYPE 및 CONTEXT INFO(선택사항)를 표시합니다. 이벤트 유형 및 컨텍스트 정보에 대한 자세한 정보는 이벤트 로깅의 내용을 참조하십시오.
메시지를 분석하면 이 요청이 느린 이유를 파악할 수 있습니다. 그러나 이 요청이 이 시점에 정지했는지 아니면 느리게 실행되고 있는지는 판별하기 어려울 수 있습니다. 따라서 지정된 <slowRequestThreshold>의 간격으로 느린 요청에 대해 세 개의 메시지가 로깅됨을 볼 수 있습니다. 세 개의 서로 다른 스택 추적 및 요청 데이터를 사용하면 이 문제에 대해 좀 더 자세한 정보를 알 수 있습니다. 세 번째 경고 후에는 요청의 지속 시간이 정지 요청 발견 임계값을 초과하지 않는 한 추가 경고가 로깅되지 않습니다.
정지 요청 발견
요청이 기본 hungRequestThreshold 또는 구성된 임계값을 초과하면 메시지 로그 파일에 경고 메시지가 요청에 대한 세부사항과 함께 기록됩니다. 요청의 세부사항 및 요청을 구성하는 이벤트가 캡처됩니다. 정지 요청 발견의 경우에는 연속된 세 개의 스레드 덤프(javacore)가 1분 간격으로 작성됩니다. 다음 로그 메시지 샘플은 정지 요청 발견 임계값을 초과한 요청에 대한 로그 메시지를 보여줍니다. 기본 지속 시간 값은 10분입니다. 다음 예제에 구성되어 있는 값은 4분입니다.Duration Operation
240001.754ms + websphere.servlet.service | TestWebApp | TestServlet?sleepTime=480000
0.095ms websphere.session.setAttribute | mCzBMyzMvAEnjMJJx9zQYIw | userID
0.007ms websphere.session.setAttribute | mCzBMyzMvAEnjMJJx9zQYIw | visitCount
TRAS0115W: Request AAA7WlpP7l7_AAAAAAAAAAA
이전에
정지된 것으로 발견되고 479999.681초 이후에 완료되었습니다. ![[17.0.0.3 and later]](../ng_v17003plus.gif)
![[17.0.0.3 and later]](../ng_v17003plus.gif)
느리고 정지한 요청 임계값 구성
server.xml 파일의 <requestTiming/> 구성에서 slowRequestThreshold 및 hungRequestThreshold를 설정하여 느리고 정지한 요청 임계값을 구성합니다. 이 설정은 시간 제한이 있는 모든 요청에 대해 느리고 정지한 단일 요청 임계값을 설정합니다.
또한 다른 유형의 요청에 대해 느리고 정지한 요청 임계값을 서로 다르게 설정할 수 있습니다. server.xml 파일의 임베디드 <servletTiming/> 또는 <jdbcTiming/> 구성은 <requestTiming/>에 정의되어 구성된 느리고 정지한 요청 임계값을 대체합니다. <servletTiming/> 구성은 애플리케이션 이름, 서블릿 이름 또는 둘 모두에 의해 느리고 정지한 요청 임계값을 설정할 수 있습니다. <jdbcTiming/> 구성은 데이터 소스 이름, SQL 문자열 또는 둘 모두에 의해 느리고 정지한 요청 임계값을 설정할 수 있습니다. 두 경우 모두 eventLogging-1.0 기능에 의해 보고된 대로 요청의 컨텍스트 정보에서 이름을 가져옵니다.
이벤트 로그에는 서버가 처리한 각 요청에 대한 유형 및 컨텍스트 정보가 포함되어 있습니다. 유형 및 컨텍스트 정보를 사용하여 다른 임계값이 필요한 요청에 대해 server.xml 파일의 <servletTiming/> 또는 <jdbcTiming/> 구성을 작성할 수 있습니다.
각 요청에 대해 제공되는 컨텍스트 정보에 대한 자세한 정보는 제품 문서에서 이벤트 로깅의 내용을 참조하십시오. <servletTiming/> 또는 <jdbcTiming/> 구성은 루트 레벨 요청 시간을 제한하는 데에만 사용할 수 있습니다. 예를 들어, 서블릿 요청이 JDBC 조회를 작성하는 경우 서블릿 요청이 루트 레벨 요청이기 때문에 JDBC 조회 시간을 제한할 수 없습니다.
<requestTiming slowRequestThreshold="10s" hungRequestThreshold="10m">
<servletTiming servletName="Arm10Servlet" hungRequestThreshold=”20s”/>
<servletTiming appName="SecurityExchangeApp” hungRequestThreshold=”2h”/>
</requestTiming>