Détection des demandes lentes ou suspendues
La fonction requestTiming-1.0 fournit des informations de diagnostic lorsque la durée d'une demande dépasse le seuil configuré.
Détection de demandes lentes
Lorsque l'exécution d'une demande dépasse la durée configurée, un message d'avertissement est écrit dans le fichier journal des messages. Les détails sur les demandes et les événements formant la demande sont capturés.[12/1/14 11:58:09:629 IST] 0000001d com.ibm.ws.request.timing.SlowRequestTimer W TRAS0112W : La demande AABjnS+lIn0_AAAAAAAAAAb s'est exécutée sur l'unité d'exécution 00000021 pendant au moins 10003.571ms.
La trace de pile suivante montre ce qu'exécute cette unité d'exécution.
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: La demande <(ID DEMANDE)> s'est exécutée sur l'unité d'exécution <ID_UNITE_EXECUTION> pendant au moins <DUREE>. La trace de pile suivante montre ce qu'exécute cette unité d'exécution.
<TRACE DE PILE>
<Tableau DUREE et OPERATIONS>
- ID DEMANDE
- Ce même ID peut être utilisé pour rechercher les messages de journal et de trace correspondant à la demande. En particulier, si vous utilisez la journalisation binaire, vous pouvez rechercher les entrées de journal et de trace avec la même extension requestID en utilisant la commande de journal binaire.
- TRACE DE PILE
- Indique la méthode en cours d'exécution. Dans l'exemple précédent, vous pouvez voir une trace de pile de la demande en cours après la ligne TRAS0112W.
- Tableau DUREE et OPERATIONS
- Après la trace de pile se trouve le format tabulaire de la demande qui indique la durée et l'opération (également appelée événement). La colonne Duration indique la durée occupée par l'opération correspondante de la demande. Le signe plus (+) signale les événements de la demande qui sont toujours en cours d'exécution. La ligne suivante montre la durée sans +, ce qui indique que l'opération correspondante a été achevée dans les temps indiqués. L'opération affiche EVENT TYPE et CONTEXT INFO (facultatif) pour cette opération. Pour en savoir plus sur les types d'événements et les informations de contexte, consultez Journalisation des événements.
En analysant les messages, vous pouvez déterminer la raison pour laquelle la demande est lente. Cependant, il peut être difficile de déterminer si la demande est suspendue à ce moment donné ou si elle continue de s'exécuter lentement. C'est pourquoi trois messages sont consignés pour les demandes lentes à l'intervalle spécifié par <slowRequestThreshold>. Les trois enregistrements différents relatifs à la trace de pile et à la requête vous permettrons de mieux cerner le problème. Après le troisième avertissement, aucun autre avertissement n'est consigné au sujet de la demande, à moins que la durée de la demande ne dépasse le seuil de détection des demandes suspendues.
Détection des demandes suspendues
Si la demande dépasse la valeur par défaut définie pour hungRequestThreshold ou la valeur de seuil configurée, un message d'avertissement est écrit dans le fichier journal des messages, avec les détails de la demande. Les détails sur les demandes et sur les événements formant la demande sont capturés. Pour une détection de demande suspendue, une série de trois vidages de l'unité d'exécution (javacores) est initiée, à une minute d'intervalle. L'exemple suivant montre les messages de journal d'une requête ayant dépassé le seuil de détection des demandes suspendues. La durée par défaut est de 10 minutes. La valeur configurée dans l'exemple suivant est de 4 minutes.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
It was previously
detected to be hung and completed after 479999.681 s.![[17.0.0.3 and later]](../ng_v17003plus.gif)
![[17.0.0.3 and later]](../ng_v17003plus.gif)
Configuration des seuils de demandes lentes et suspendues
Les seuils des demandes lentes et suspendues sont configurés en définissant slowRequestThreshold et hungRequestThreshold dans la configuration <requestTiming/> dans le fichier server.xml. Ce réglage définit un seuil de demande lente et suspendu unique pour toutes les demandes temporisées.
Vous pouvez également définir différents seuils de demandes lentes et suspendues pour les différents types de demandes. Une configuration <servletTiming/> ou <jdbcTiming/> imbriquée dans le fichier server.xml remplace le seuil de demande lente et suspendue configuré défini dans <requestTiming/>. une configuration <servletTiming/> peut définir le seuil de demande lente et suspendue par nom d'application, par nom de servlet, ou les deux. Une configuration <jdbcTiming/> peut définir le seuil de demande lente et suspendue par nom de source de données, par chaîne sql, ou les deux. Dans les deux cas, les noms sont tirés des informations contextuelles de la demande, conformément au rapport de la fonction eventLogging-1.0.
Le journal des événements contient des informations sur le type et le contexte de chaque demande traitée par le serveur. Avec les informations sur le type et le contexte, vous pouvez créer une configuration <servletTiming/> ou <jdbcTiming/> dans le fichier server.xml pour les demandes qui nécessitent des valeurs de seuil différentes.
Pour en savoir plus sur les informations contextuelles fournies pour chaque demande, voir Journalisation des événements dans la documentation du produit. Une configuration <servletTiming/> ou <jdbcTiming/> peut uniquement être utilisée pour temporiser une demande au niveau de la racine. Par exemple, si une demande de servlet effectue une requête JDBC, la requête JDBC ne peut pas être temporisée car la demande de servlet est la demande de niveau racine.
<requestTiming slowRequestThreshold="10s" hungRequestThreshold="10m">
<servletTiming servletName="Arm10Servlet" hungRequestThreshold=”20s”/>
<servletTiming appName="SecurityExchangeApp” hungRequestThreshold=”2h”/>
</requestTiming>