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-unsubscr...@tomcat.apache.org For additional commands, e-mail: dev-h...@tomcat.apache.org