Detecting long-running web requests

Apache Tomcat provides the ability to log any request thread that has been processing for more than some specified period of time by setting the org.apache.catalina.valves.StuckThreadDetectionValve parameter in the server.xml file. This feature is available in NexJ Model Server.

By default, the valve is disabled. You can enable the valve by setting the stuckThreadThreshold attribute in your environment file to a positive integer. For example:

TEXT

<Environment ... stuckThreadThreshold="600" ... >

When the valve is enabled, logging occurs for NexJ Model Server web requests that run longer than the set threshold (measured in seconds). If you set the attribute to 0, the valve is disabled.

Examples

The following example shows the information that was logged after a thread reached the threshold:

TEXT

; 10:39:05,881 WARN [StuckThreadDetectionValve] (ContainerBackgroundProcessor[StandardEngine[nexj.teee.node1]]) Thread [http-nio-7080-exec-3] (id=[124]) has been active for [17,147] milliseconds (since [4/28/20 10:38 AM]) to serve the same request for [http://localhost:7080/nexj/channel/sso:Login?goto=http%3A%2F%2Flocalhost%3A7080%2Fnexj%2FSysAdmin.htma] and may be stuck (configured threshold for this StuckThreadDetectionValve is [10] seconds). There is/are [2] thread(s) in total that are monitored by this Valve and may be stuck.
java.lang.Throwable
at nexj.core.rpc.http.GenericHTTPServlet.service(GenericHTTPServlet.java:174)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at nexj.core.rpc.http.GZipFilter.doFilter(GZipFilter.java:146)
at nexj.core.rpc.http.GZipFilter.doFilter(GZipFilter.java:109)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at nexj.core.rpc.http.session.SessionManager.intercept(SessionManager.java:1385)
at nexj.core.rpc.http.session.PersistenceFilter.doFilter(PersistenceFilter.java:55)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at nexj.core.rpc.http.ChannelPartitionFilter.doFilter(ChannelPartitionFilter.java:30)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at nexj.core.rpc.http.LoggerFilter.doFilter(LoggerFilter.java:54)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:610)
at nexj.core.container.platform.teee.JNDIContextValve.invoke(JNDIContextValve.java:70)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.valves.StuckThreadDetectionValve.invoke(StuckThreadDetectionValve.java:206)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)

The following example shows the information that is logged if and when a thread completes:

TEXT

; 10:39:35,883 WARN [StuckThreadDetectionValve] (ContainerBackgroundProcessor[StandardEngine[nexj.teee.node1]]) Thread [http-nio-7080-exec-3] (id=[124]) was previously reported to be stuck but has completed. It was active for approximately [45,132] milliseconds. There is/are still [1] thread(s) that are monitored by this Valve and may be stuck.