You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by sl...@apache.org on 2011/04/07 22:50:28 UTC
svn commit: r1090003 - in /tomcat/trunk:
java/org/apache/catalina/valves/LocalStrings.properties
java/org/apache/catalina/valves/StuckThreadDetectionValve.java
java/org/apache/catalina/valves/mbeans-descriptors.xml
webapps/docs/config/valve.xml
Author: slaurent
Date: Thu Apr 7 20:50:28 2011
New Revision: 1090003
URL: http://svn.apache.org/viewvc?rev=1090003&view=rev
Log:
https://issues.apache.org/bugzilla/show_bug.cgi?id=50306
StuckThreadDetectionValve, based on code proposed by TomLu
Added:
tomcat/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java (with props)
Modified:
tomcat/trunk/java/org/apache/catalina/valves/LocalStrings.properties
tomcat/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml
tomcat/trunk/webapps/docs/config/valve.xml
Modified: tomcat/trunk/java/org/apache/catalina/valves/LocalStrings.properties
URL: http://svn.apache.org/viewvc/tomcat/trunk/java/org/apache/catalina/valves/LocalStrings.properties?rev=1090003&r1=1090002&r2=1090003&view=diff
==============================================================================
--- tomcat/trunk/java/org/apache/catalina/valves/LocalStrings.properties (original)
+++ tomcat/trunk/java/org/apache/catalina/valves/LocalStrings.properties Thu Apr 7 20:50:28 2011
@@ -44,6 +44,10 @@ remoteIpValve.syntax=Invalid regular exp
sslValve.certError=Failed to process certificate string [{0}] to create a java.security.cert.X509Certificate object
sslValve.invalidProvider=The SSL provider specified on the connector associated with this request of [{0}] is invalid. The certificate data could not be processed.
+#Stuck thread detection Valve
+stuckThreadDetectionValve.notifyStuckThreadDetected=Thread "{0}" has been active for {1} milliseconds (since {2}) to serve the same request for {4} and may be stuck (configured threshold for this StuckThreadDetectionValve is {5} seconds). There is/are {3} thread(s) in total that are monitored by this Valve and may be stuck.
+stuckThreadDetectionValve.notifyStuckThreadCompleted=Thread "{0}" was previously reported to be stuck but has completed. It was active for approximately {1} milliseconds.{2,choice,0#|0< There is/are still {2} thread(s) that are monitored by this Valve and may be stuck.}
+
# HTTP status reports
http.100=The client may continue ({0}).
http.101=The server is switching protocols according to the "Upgrade" header ({0}).
Added: tomcat/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java
URL: http://svn.apache.org/viewvc/tomcat/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java?rev=1090003&view=auto
==============================================================================
--- tomcat/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java (added)
+++ tomcat/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java Thu Apr 7 20:50:28 2011
@@ -0,0 +1,302 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package org.apache.catalina.valves;
+
+import java.io.IOException;
+import java.util.ArrayList;
+import java.util.Date;
+import java.util.List;
+import java.util.Queue;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.ConcurrentLinkedQueue;
+import java.util.concurrent.atomic.AtomicInteger;
+
+import javax.servlet.ServletException;
+
+import org.apache.catalina.LifecycleException;
+import org.apache.catalina.connector.Request;
+import org.apache.catalina.connector.Response;
+import org.apache.juli.logging.Log;
+import org.apache.juli.logging.LogFactory;
+import org.apache.tomcat.util.res.StringManager;
+
+/**
+ * This valve allows to detect requests that take a long time to process, which might
+ * indicate that the thread that is processing it is stuck.
+ * Based on code proposed by TomLu in Bugzilla entry #50306
+ *
+ * @author slaurent
+ *
+ */
+public class StuckThreadDetectionValve extends ValveBase {
+
+ /**
+ * The descriptive information related to this implementation.
+ */
+ private static final String info =
+ "org.apache.catalina.valves.StuckThreadDetectionValve/1.0";
+ /**
+ * Logger
+ */
+ private static final Log log = LogFactory.getLog(StuckThreadDetectionValve.class);
+
+ /**
+ * The string manager for this package.
+ */
+ private static final StringManager sm =
+ StringManager.getManager(Constants.Package);
+
+ /**
+ * Keeps count of the number of stuck threads detected
+ */
+ private final AtomicInteger stuckCount = new AtomicInteger(0);
+
+ /**
+ * In seconds. Default 600 (10 minutes).
+ */
+ private int threshold = 600;
+
+ /**
+ * The only references we keep to actual running Thread objects are in
+ * this Map (which is automatically cleaned in invoke()s finally clause).
+ * That way, Threads can be GC'ed, eventhough the Valve still thinks they
+ * are stuck (caused by a long monitor interval)
+ */
+ private ConcurrentHashMap<Long, MonitoredThread> activeThreads =
+ new ConcurrentHashMap<Long, MonitoredThread>();
+ /**
+ *
+ */
+ private Queue<CompletedStuckThread> completedStuckThreadsQueue =
+ new ConcurrentLinkedQueue<CompletedStuckThread>();
+
+ /**
+ * Specify the threshold (in seconds) used when checking for stuck threads.
+ * If <=0, the detection is disabled. The default is 600 seconds.
+ *
+ * @param threshold
+ * The new threshold in seconds
+ */
+ public void setThreshold(int threshold) {
+ this.threshold = threshold;
+ }
+
+ /**
+ * @see #setThreshold(int)
+ * @return The current threshold in seconds
+ */
+ public int getThreshold() {
+ return threshold;
+ }
+
+ @Override
+ protected void initInternal() throws LifecycleException {
+ super.initInternal();
+
+ if (log.isDebugEnabled()) {
+ log.debug("Monitoring stuck threads with threshold = "
+ + threshold
+ + " sec");
+ }
+ }
+
+ /**
+ * Return descriptive information about this Valve implementation.
+ */
+ @Override
+ public String getInfo() {
+ return info;
+ }
+
+ private void notifyStuckThreadDetected(MonitoredThread monitoredThread,
+ long activeTime, int numStuckThreads) {
+ if (log.isWarnEnabled()) {
+ String msg = sm.getString(
+ "stuckThreadDetectionValve.notifyStuckThreadDetected",
+ monitoredThread.getThread().getName(), activeTime,
+ monitoredThread.getStartTime(), numStuckThreads,
+ monitoredThread.getRequestUri(), threshold);
+ // msg += "\n" + getStackTraceAsString(trace);
+ Throwable th = new Throwable();
+ th.setStackTrace(monitoredThread.getThread().getStackTrace());
+ log.warn(msg, th);
+ }
+ }
+
+ private void notifyStuckThreadCompleted(String threadName,
+ long activeTime, int numStuckThreads) {
+ if (log.isWarnEnabled()) {
+ String msg = sm.getString(
+ "stuckThreadDetectionValve.notifyStuckThreadCompleted",
+ threadName, activeTime, numStuckThreads);
+ // Since the "stuck thread notification" is warn, this should also
+ // be warn
+ log.warn(msg);
+ }
+ }
+
+ /**
+ * {@inheritDoc}
+ */
+ @Override
+ public void invoke(Request request, Response response)
+ throws IOException, ServletException {
+
+ if (threshold <= 0) {
+ // short-circuit if not monitoring stuck threads
+ getNext().invoke(request, response);
+ return;
+ }
+
+ // Save the thread/runnable
+ // Keeping a reference to the thread object here does not prevent
+ // GC'ing, as the reference is removed from the Map in the finally clause
+
+ Long key = new Long(Thread.currentThread().getId());
+ StringBuffer requestUrl = request.getRequestURL();
+ if(request.getQueryString()!=null) {
+ requestUrl.append("?");
+ requestUrl.append(request.getQueryString());
+ }
+ MonitoredThread monitoredThread = new MonitoredThread(Thread.currentThread(),
+ requestUrl.toString());
+ activeThreads.put(key, monitoredThread);
+
+ try {
+ getNext().invoke(request, response);
+ } finally {
+ activeThreads.remove(key);
+ if (monitoredThread.markAsDone() == MonitoredThreadState.STUCK) {
+ completedStuckThreadsQueue.add(
+ new CompletedStuckThread(monitoredThread.getThread().getName(),
+ monitoredThread.getActiveTimeInMillis()));
+ }
+ }
+ }
+
+ @Override
+ public void backgroundProcess() {
+ super.backgroundProcess();
+
+ long thresholdInMillis = threshold * 1000;
+
+ // Check monitored threads, being careful that the request might have
+ // completed by the time we examine it
+ for (MonitoredThread monitoredThread : activeThreads.values()) {
+ long activeTime = monitoredThread.getActiveTimeInMillis();
+
+ if (activeTime >= thresholdInMillis && monitoredThread.markAsStuckIfStillRunning()) {
+ int numStuckThreads = stuckCount.incrementAndGet();
+ notifyStuckThreadDetected(monitoredThread, activeTime, numStuckThreads);
+ }
+ }
+ // Check if any threads previously reported as stuck, have finished.
+ for (CompletedStuckThread completedStuckThread = completedStuckThreadsQueue.poll();
+ completedStuckThread != null; completedStuckThread = completedStuckThreadsQueue.poll()) {
+
+ int numStuckThreads = stuckCount.decrementAndGet();
+ notifyStuckThreadCompleted(completedStuckThread.getName(),
+ completedStuckThread.getTotalActiveTime(), numStuckThreads);
+ }
+ }
+
+ public long[] getStuckThreadIds() {
+ List<Long> idList = new ArrayList<Long>();
+ for (MonitoredThread monitoredThread : activeThreads.values()) {
+ if (monitoredThread.isMarkedAsStuck()) {
+ idList.add(monitoredThread.getThread().getId());
+ }
+ }
+
+ long[] result = new long[idList.size()];
+ for (int i = 0; i < result.length; i++) {
+ result[i] = idList.get(i);
+ }
+ return result;
+ }
+
+ private class MonitoredThread {
+
+ /**
+ * Reference to the thread to get a stack trace from background task
+ */
+ private final Thread thread;
+ private final String requestUri;
+ private final long start;
+ private final AtomicInteger state = new AtomicInteger(
+ MonitoredThreadState.RUNNING.ordinal());
+
+ public MonitoredThread(Thread thread, String requestUri) {
+ this.thread = thread;
+ this.requestUri = requestUri;
+ this.start = System.currentTimeMillis();
+ }
+
+ public Thread getThread() {
+ return this.thread;
+ }
+
+ public String getRequestUri() {
+ return requestUri;
+ }
+
+ public long getActiveTimeInMillis() {
+ return System.currentTimeMillis() - start;
+ }
+
+ public Date getStartTime() {
+ return new Date(start);
+ }
+
+ public boolean markAsStuckIfStillRunning() {
+ return this.state.compareAndSet(MonitoredThreadState.RUNNING.ordinal(),
+ MonitoredThreadState.STUCK.ordinal());
+ }
+
+ public MonitoredThreadState markAsDone() {
+ int val = this.state.getAndSet(MonitoredThreadState.DONE.ordinal());
+ return MonitoredThreadState.values()[val];
+ }
+
+ boolean isMarkedAsStuck() {
+ return this.state.get() == MonitoredThreadState.STUCK.ordinal();
+ }
+ }
+
+ private class CompletedStuckThread {
+
+ private String threadName;
+ private long totalActiveTime;
+
+ public CompletedStuckThread(String threadName, long totalActiveTime) {
+ this.threadName = threadName;
+ this.totalActiveTime = totalActiveTime;
+ }
+
+ public String getName() {
+ return this.threadName;
+ }
+
+ public long getTotalActiveTime() {
+ return this.totalActiveTime;
+ }
+ }
+
+ private enum MonitoredThreadState {
+ RUNNING, STUCK, DONE;
+ }
+}
Propchange: tomcat/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java
------------------------------------------------------------------------------
svn:eol-style = native
Propchange: tomcat/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java
------------------------------------------------------------------------------
svn:keywords = Author Date Id Revision
Modified: tomcat/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml
URL: http://svn.apache.org/viewvc/tomcat/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml?rev=1090003&r1=1090002&r2=1090003&view=diff
==============================================================================
--- tomcat/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml (original)
+++ tomcat/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml Thu Apr 7 20:50:28 2011
@@ -390,4 +390,41 @@
writeable="false" />
</mbean>
+
+ <mbean name="StuckThreadDetectionValve"
+ description="Detect long requests for which their thread might be stuck"
+ domain="Catalina"
+ group="Valve"
+ type="org.apache.catalina.valves.StuckThreadDetectionValve">
+
+ <attribute name="asyncSupported"
+ description="Does this valve support async reporting."
+ is="true"
+ type="boolean"/>
+
+ <attribute name="className"
+ description="Fully qualified class name of the managed object"
+ type="java.lang.String"
+ writeable="false"/>
+
+ <attribute name="info"
+ description="Information about this implementation"
+ type="java.lang.String"
+ writeable="false"/>
+
+ <attribute name="stateName"
+ description="The name of the LifecycleState that this component is currently in"
+ type="java.lang.String"
+ writeable="false"/>
+
+ <attribute name="stuckThreadIds"
+ description="IDs of the thread currently considered stuck. Each ID can then be used with the ThreadMXBean to retrieve data about it."
+ type="long[]"
+ writeable="false"/>
+
+ <attribute name="threshold"
+ description="Duration in seconds after which a request is considered as stuck"
+ type="int"/>
+
+ </mbean>
</mbeans-descriptors>
Modified: tomcat/trunk/webapps/docs/config/valve.xml
URL: http://svn.apache.org/viewvc/tomcat/trunk/webapps/docs/config/valve.xml?rev=1090003&r1=1090002&r2=1090003&view=diff
==============================================================================
--- tomcat/trunk/webapps/docs/config/valve.xml (original)
+++ tomcat/trunk/webapps/docs/config/valve.xml Thu Apr 7 20:50:28 2011
@@ -1106,7 +1106,46 @@
</section>
+<section name="Stuck Thread Detection Valve">
+ <subsection name="Introduction">
+
+ <p>This valve allows to detect requests that take a long time to process, which might
+ indicate that the thread that is processing it is stuck.</p>
+ <p>When such a request is detected, the current stack trace of its thread is written
+ to tomcat log with a WARN level.</p>
+ <p>The IDs of the stuck threads are available through JMX in the
+ <code>stuckThreadIds</code> attribute. The JVM Thread MBean can then be used to
+ retrieve other information about each stuck thread (name, stack trace...).</p>
+
+ </subsection>
+
+ <subsection name="Attributes">
+
+ <p>The <strong>Stuck Thread Detection Valve</strong> supports the
+ following configuration attributes:</p>
+
+ <attributes>
+
+ <attribute name="className" required="true">
+ <p>Java class name of the implementation to use. This MUST be set to
+ <strong>org.apache.catalina.valves.StuckThreadDetectionValve</strong>.
+ </p>
+ </attribute>
+
+ <attribute name="threshold" required="false">
+ <p>Minimum duration in seconds after which a thread is considered stuck.
+ Default is 600 seconds. If set to 0, the detection is disabled.</p>
+ <p>Note: since the detection is done in the background thread of the Container
+ (Engine, Host or Context) declaring this Valve, the threshold should be higher
+ than the <code>backgroundProcessorDelay</code> of this Container.</p>
+ </attribute>
+
+ </attributes>
+
+ </subsection>
+
+</section>
</body>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org