tomcat-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From kkoli...@apache.org
Subject svn commit: r1356246 - in /tomcat/tc6.0.x/trunk: ./ java/org/apache/catalina/valves/ webapps/docs/ webapps/docs/config/
Date Mon, 02 Jul 2012 14:24:11 GMT
Author: kkolinko
Date: Mon Jul  2 14:24:08 2012
New Revision: 1356246

URL: http://svn.apache.org/viewvc?rev=1356246&view=rev
Log:
Fix https://issues.apache.org/bugzilla/show_bug.cgi?id=50306
New StuckThreadDetectionValve to detect requests that
take a long time to process, which might indicate that their processing
threads are stuck. Based on a patch provided by TomLu.

Added:
    tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java  
(with props)
Modified:
    tomcat/tc6.0.x/trunk/STATUS.txt
    tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/LocalStrings.properties
    tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml
    tomcat/tc6.0.x/trunk/webapps/docs/changelog.xml
    tomcat/tc6.0.x/trunk/webapps/docs/config/valve.xml

Modified: tomcat/tc6.0.x/trunk/STATUS.txt
URL: http://svn.apache.org/viewvc/tomcat/tc6.0.x/trunk/STATUS.txt?rev=1356246&r1=1356245&r2=1356246&view=diff
==============================================================================
--- tomcat/tc6.0.x/trunk/STATUS.txt (original)
+++ tomcat/tc6.0.x/trunk/STATUS.txt Mon Jul  2 14:24:08 2012
@@ -144,17 +144,6 @@ PATCHES PROPOSED TO BACKPORT:
   +1: markt, kfujino, kkolinko
   -1:
 
-* Fix https://issues.apache.org/bugzilla/show_bug.cgi?id=50306
-  New StuckThreadDetectionValve to detect requests that
-  take a long time to process, which might indicate that their processing
-  threads are stuck. Based on a patch provided by TomLu.
-  Patch:
-   https://issues.apache.org/bugzilla/attachment.cgi?id=28966
-  Eol-Style:
-   svn propset svn:eol-style native java/org/apache/catalina/valves/StuckThreadDetectionValve.java
-  +1: kkolinko, markt, kfujino
-  -1:
-
 
 PATCHES/ISSUES THAT ARE STALLED
 

Modified: tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/LocalStrings.properties
URL: http://svn.apache.org/viewvc/tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/LocalStrings.properties?rev=1356246&r1=1356245&r2=1356246&view=diff
==============================================================================
--- tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/LocalStrings.properties (original)
+++ tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/LocalStrings.properties Mon Jul 
2 14:24:08 2012
@@ -56,6 +56,10 @@ remoteIpValve.syntax=Invalid regular exp
 
 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}" (id={6}) 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}" (id={3}) 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/tc6.0.x/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java
URL: http://svn.apache.org/viewvc/tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java?rev=1356246&view=auto
==============================================================================
--- tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java (added)
+++ tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java Mon
Jul  2 14:24:08 2012
@@ -0,0 +1,297 @@
+/*
+ * 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.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.
+ */
+public class StuckThreadDetectionValve extends ValveBase {
+
+    /**
+     * 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 final ConcurrentHashMap<Long, MonitoredThread> activeThreads =
+            new ConcurrentHashMap<Long, MonitoredThread>();
+    /**
+     *
+     */
+    private final 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;
+    }
+
+
+    private void notifyStuckThreadDetected(MonitoredThread monitoredThread,
+        long activeTime, int numStuckThreads) {
+        if (log.isWarnEnabled()) {
+            String msg = sm.getString(
+                "stuckThreadDetectionValve.notifyStuckThreadDetected",
+                monitoredThread.getThread().getName(),
+                Long.valueOf(activeTime),
+                monitoredThread.getStartTime(),
+                Integer.valueOf(numStuckThreads),
+                monitoredThread.getRequestUri(),
+                Integer.valueOf(threshold),
+                String.valueOf(monitoredThread.getThread().getId())
+                );
+            // msg += "\n" + getStackTraceAsString(trace);
+            Throwable th = new Throwable();
+            th.setStackTrace(monitoredThread.getThread().getStackTrace());
+            log.warn(msg, th);
+        }
+    }
+
+    private void notifyStuckThreadCompleted(CompletedStuckThread thread,
+            int numStuckThreads) {
+        if (log.isWarnEnabled()) {
+            String msg = sm.getString(
+                "stuckThreadDetectionValve.notifyStuckThreadCompleted",
+                thread.getName(),
+                Long.valueOf(thread.getTotalActiveTime()),
+                Integer.valueOf(numStuckThreads),
+                String.valueOf(thread.getId()));
+            // 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 = Long.valueOf(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(),
+                            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, numStuckThreads);
+        }
+    }
+
+    public long[] getStuckThreadIds() {
+        List<Long> idList = new ArrayList<Long>();
+        for (MonitoredThread monitoredThread : activeThreads.values()) {
+            if (monitoredThread.isMarkedAsStuck()) {
+                idList.add(Long.valueOf(monitoredThread.getThread().getId()));
+            }
+        }
+
+        long[] result = new long[idList.size()];
+        for (int i = 0; i < result.length; i++) {
+            result[i] = idList.get(i).longValue();
+        }
+        return result;
+    }
+
+    public String[] getStuckThreadNames() {
+        List<String> nameList = new ArrayList<String>();
+        for (MonitoredThread monitoredThread : activeThreads.values()) {
+            if (monitoredThread.isMarkedAsStuck()) {
+                nameList.add(monitoredThread.getThread().getName());
+            }
+        }
+        return nameList.toArray(new String[nameList.size()]);
+    }
+
+    private static 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 static class CompletedStuckThread {
+
+        private final String threadName;
+        private final long threadId;
+        private final long totalActiveTime;
+
+        public CompletedStuckThread(Thread thread, long totalActiveTime) {
+            this.threadName = thread.getName();
+            this.threadId = thread.getId();
+            this.totalActiveTime = totalActiveTime;
+        }
+
+        public String getName() {
+            return this.threadName;
+        }
+
+        public long getId() {
+            return this.threadId;
+        }
+
+        public long getTotalActiveTime() {
+            return this.totalActiveTime;
+        }
+    }
+
+    private enum MonitoredThreadState {
+        RUNNING, STUCK, DONE;
+    }
+}

Propchange: tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/StuckThreadDetectionValve.java
------------------------------------------------------------------------------
    svn:eol-style = native

Modified: tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml
URL: http://svn.apache.org/viewvc/tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml?rev=1356246&r1=1356245&r2=1356246&view=diff
==============================================================================
--- tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml (original)
+++ tomcat/tc6.0.x/trunk/java/org/apache/catalina/valves/mbeans-descriptors.xml Mon Jul  2
14:24:08 2012
@@ -459,4 +459,31 @@
                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="className"
+               description="Fully qualified class name of the managed object"
+               type="java.lang.String"
+               writeable="false"/>
+
+    <attribute name="stuckThreadIds"
+               description="IDs of the threads currently considered stuck. Each ID can then
be used with the Threading MBean to retrieve data about it."
+               type="long[]"
+               writeable="false"/>
+
+    <attribute name="stuckThreadNames"
+               description="Names of the threads currently considered stuck."
+               type="java.lang.String[]"
+               writeable="false"/>
+
+    <attribute name="threshold"
+               description="Duration in seconds after which a request is considered as stuck"
+               type="int"/>
+
+  </mbean>
 </mbeans-descriptors>

Modified: tomcat/tc6.0.x/trunk/webapps/docs/changelog.xml
URL: http://svn.apache.org/viewvc/tomcat/tc6.0.x/trunk/webapps/docs/changelog.xml?rev=1356246&r1=1356245&r2=1356246&view=diff
==============================================================================
--- tomcat/tc6.0.x/trunk/webapps/docs/changelog.xml (original)
+++ tomcat/tc6.0.x/trunk/webapps/docs/changelog.xml Mon Jul  2 14:24:08 2012
@@ -46,6 +46,11 @@
 <section name="Tomcat 6.0.36 (jfclere)" rtext="">
   <subsection name="Catalina">
     <changelog>
+      <add>
+        <bug>50306</bug>: New StuckThreadDetectionValve to detect requests that
+        take a long time to process, which might indicate that their processing
+        threads are stuck. Based on a patch provided by TomLu. (kkolinko)
+      </add>
       <fix>
         <bug>50570</bug>: Enable FIPS mode to be set in AprLifecycleListener.
         Based upon a patch from Chris Beckey. Note that this mode requires

Modified: tomcat/tc6.0.x/trunk/webapps/docs/config/valve.xml
URL: http://svn.apache.org/viewvc/tomcat/tc6.0.x/trunk/webapps/docs/config/valve.xml?rev=1356246&r1=1356245&r2=1356246&view=diff
==============================================================================
--- tomcat/tc6.0.x/trunk/webapps/docs/config/valve.xml (original)
+++ tomcat/tc6.0.x/trunk/webapps/docs/config/valve.xml Mon Jul  2 14:24:08 2012
@@ -873,6 +873,50 @@
 </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 and names of the stuck threads are available through JMX in the
+    <code>stuckThreadIds</code> and <code>stuckThreadNames</code>
attributes.
+    The IDs can be used with the standard Threading JVM MBean
+    (<code>java.lang:type=Threading</code>) to retrieve other information
+    about each stuck thread.</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