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 Ausführung einer Anforderung länger dauert, als in der Konfiguration vorgesehen, wird eine Warnnachricht 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>
<DURATION AND OPERATIONS Table>
- 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 einer 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
TRAS0115W: Request AAA7WlpP7l7_AAAAAAAAAAA
Sie wurde zuvor als blockiert erkannt und wurde nach 479999,681 Sekunden abgeschlossen.![[17.0.0.3 und höher]](../ng_v17003plus.gif)
![[17.0.0.3 und höher]](../ng_v17003plus.gif)
Schwellenwerte für langsame und blockierte Anforderungen konfigurieren
Die Schwellenwerte für die langsamen und blockierten Anforderungen werden konfiguriert, indem Sie slowRequestThreshold und hungRequestThreshold über die <requestTiming/>-Konfiguration in der Datei server.xml festlegen. Diese Einstellung legt einen einzigen Schwellenwert für langsame und blockierte Anforderungen für alle Anforderungen fest, die zeitgesteuert sind.
Sie können auch unterschiedliche Schwellenwerte für langsame und blockierte Anforderungen für unterschiedliche Anforderungstypen festlegen. Eine integrierte <servletTiming/>- oder <jdbcTiming/>-Konfiguration in der Datei server.xml überschreibt den konfigurierten Schwellenwert für langsame und blockierte Anforderungen, der über die <requestTiming/>-Konfiguration definiert wurde. Eine <servletTiming/>-Konfiguration kann den Schwellenwert für langsame und blockierte Anforderungen nach Anwendungsnamen, Servletnamen oder beides angeben. Eine <jdbcTiming/>-Konfiguration kann den Schwellenwert für langsame und blockierte Anforderungen nach Datenquellennamen, SQL-Zeichenfolge oder beides angeben. In beiden Fällen werden die Namen aus den Kontextinformationen für die Anforderung entnommen, wie sie über das Feature eventLogging-1.0 berichtet werden.
Das Ereignisprotokoll enthält die Typ- und Kontextinformationen für jede Anforderung, die vom Server verarbeitet wurde. Sie können mit den Typ- und Kontextinformationen eine <servletTiming/>- oder <jdbcTiming/>-Konfiguration in der Datei server.xml für die Anforderungen erstellen, für die unterschiedliche Schwellenwerte erforderlich sind.
Weitere Informationen darüber, welche Kontextinformationen für jede Anforderung bereitgestellt werden, finden Sie in der Produktdokumentation unter Ereignisprotokollierung. Eine <servletTiming/>- oder <jdbcTiming/>-Konfiguration kann nur für die Zeitsteuerung einer Anforderung auf Stammebene verwendet werden. Wenn beispielsweise eine Servletanforderung eine JDBC-Abfrage absetzt, kann die JDBC-Abfrage nicht zeitgesteuert werden, weil es sich bei der Servletanforderung um eine Anforderung auf Stammebene handelt.
<requestTiming slowRequestThreshold="10s" hungRequestThreshold="10m">
<servletTiming servletName="Arm10Servlet" hungRequestThreshold=”20s”/>
<servletTiming appName="SecurityExchangeApp” hungRequestThreshold=”2h”/>
</requestTiming>