
![[8.5.5.6 oder höher]](../ng_v8556.gif)
Erkennung langsamer und blockierter Anforderungen
Das Feature requestTiming-1.0 stellt Diagnoseinformationen bereit, wenn die Dauer einer Anforderung den konfigurierten Schwellenwert überschreitet.
Erkennung langsamer Anforderungen
Wenn die Dauer einer Anforderung den konfigurierten Zeitwert überschreitet, wird eine Warnung in die Nachrichtenprotokolldatei geschrieben. Einzelheiten zu der Anforderung und zu den Ereignissen, aus denen sich die Anforderung zusammensetzt, werden erfasst.[12/1/14 11:58:09:629 IST] 0000001d com.ibm.ws.request.timing.SlowRequestTimer W TRAS0112W: Die Anforderung AABjnS+lIn0_AAAAAAAAAAb im Thread 00000021 ist seit mindestens 10003,571 ms aktiv. Der folgende Stack-Trace zeigt, was momentan in diesem Thread ausgeführt wird.
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: Die Anforderung < (Anforderungs-ID)> im Thread <THREAD-ID> ist seit mindestens <DAUER> aktiv. Der folgende Stack-Trace zeigt, was momentan in diesem Thread ausgeführt wird.
<STACK-TRACE>
<Tabelle DURATION AND OPERATIONS>
- ANFORDERUNGS-ID
- Anhand dieser ID kann nach Protokoll- und Tracenachrichten für die Anforderung gesucht werden. Wenn Sie die Binärprotokollierung verwenden, können Sie mithilfe des Befehls für Binärprotokolle nach Protokoll- und Traceeinträgen mit der Erweiterung Anforderung-ID suchen.
- STACK-TRACE
- Zeigt die ausgeführte Methode an. Im vorherigen Beispiel sehen Sie den Stack-Trace der aktuellen Anforderung hinter der Zeile TRAS0112W.
- Tabelle DURATION AND OPERATIONS
- Im Anschluss an den Stack-Trace finden Sie das tabellarische Format der Anforderung mit den Angaben zur Dauer und zu den Operationen (auch als Ereignisse bezeichnet). Die Spalte Duration enthält die Dauer der entsprechenden Operation der Anforderung. Das Pluszeichen (+) kennzeichnet Ereignisse in der Anforderung, die immer noch aktiv sind. In der nächsten Zeile wird die Dauer ohne Pluszeichen angezeigt, was bedeutet, dass die entsprechende Operation innerhalb des festgelegten Zeitraums ausgeführt wurde. In der Spalte ""Operation" werden der Ereignistyp und Kontextinformationen (optional) für die jeweilige Operation angezeigt. Weitere Informationen zu den Ereignistypen und Kontextinformationen finden Sie unter Ereignisprotokollierung.
Durch Analyse der Nachrichten können Sie herausfinden, warum die Anforderung langsam ist. Ob die Anforderung an einem bestimmten Punkt feststeckt oder ob sie weiterhin langsam ausgeführt wird, lässt sich jedoch möglicherweise nur schwer feststellen. Deshalb sehen Sie drei Nachrichten, die für jede langsame Anforderung in dem mit <slowRequestThreshold> festgelegten Intervall protokolliert werden. Mithilfe der drei verschiedenen Stack-Trace- und Anforderungsdaten können Sie einen besseren Einblick in das Problem gewinnen. Nach der dritten Warnung werden keine weiteren Warnungen zu der Anforderung protokolliert, sofern die Dauer der Anforderung nicht den Schwellenwert für die Erkennung blockierter Anforderungen überschreitet.
Erkennung blockierter Anforderungen
Wenn die Anforderung den Standardwert bzw. den konfigurierten Schwellenwert für hungRequestThreshold überschreitet, wird eine Warnung zusammen mit den Anforderungsdetails in die Nachrichtenprotokolldatei geschrieben. Einzelheiten zu der Anforderung und zu den Ereignissen, aus denen sich die Anforderung zusammensetzt, werden erfasst. Bei der Erkennung einer blockierten Anforderung wird eine Serie von drei Threadspeicherauszügen (Java-Kernspeicherauszüge) mit einer Verzögerung von jeweils 1 Minute zwischen den Speicherauszügen erstellt. Das folgende Nachrichtenprotokollbeispiel zeigt die Protokollnachrichten für eine Anforderung, die den Schwellenwert für die Erkennung blockierter Anforderungen überschritten hat. Der Wert für die Standarddauer ist 10 Minuten. Der im folgenden Beispiel konfigurierte Wert ist 4 Minuten.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