tomcat-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From slaur...@apache.org
Subject 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
Date Thu, 07 Apr 2011 20:50:28 GMT
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 &lt;=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


Mime
View raw message