[HUDSON-1646] In 1.273, Added...

[HUDSON-1646] In 1.273, Added http://server/hudson/descriptor/hudson.triggers.SCMTrigger/ to show the summary of SCM polling activities and how long it's taking, to assist the trouble-shooting of this issue.

From this page, please jump to the polling log page of individual projects, to see why they are stuck.

git-svn-id: https://hudson.dev.java.net/svn/hudson/trunk/hudson/main@14354 71c3de6d-444a-0410-be80-ed276b4c234a

core/src/main/java/hudson/scm/SubversionSCM.java

@@ -831,6 +831,8 @@ public class SubversionSCM extends SCM implements Serializable {
             }
         }
 
+        Thread.sleep(60*1000);  // debug
+
         return false; // no change
     }
 

core/src/main/java/hudson/triggers/SCMTrigger.java

@@ -9,6 +9,7 @@ import hudson.model.Item;
 import hudson.model.Project;
 import hudson.model.SCMedItem;
 import hudson.util.StreamTaskListener;
+import hudson.util.TimeUnit2;
 import org.kohsuke.stapler.StaplerRequest;
 import org.kohsuke.stapler.DataBoundConstructor;
 
@@ -25,6 +26,7 @@ import java.util.Set;
 import java.util.ArrayList;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
+import java.util.concurrent.ThreadPoolExecutor;
 import java.util.concurrent.locks.ReentrantLock;
 import java.util.logging.Level;
 import java.util.logging.Logger;
@@ -107,7 +109,7 @@ public class SCMTrigger extends Trigger<SCMedItem> {
         /**
          * Used to control the execution of the polling tasks.
          */
-        transient volatile ExecutorService executor;
+        transient volatile ThreadPoolExecutor executor;
 
         /**
          * Whether the projects should be polled all in one go in the order of dependencies. The default behavior is
@@ -144,6 +146,21 @@ public class SCMTrigger extends Trigger<SCMedItem> {
             return executor;
         }
 
+        /**
+         * Returns true if the SCM polling thread queue has too many jobs
+         * than it can handle.
+         */
+        public boolean isClogged() {
+            for( Runnable r : executor.getQueue() ) {
+                if (r instanceof Runner) {// this should be always true, but let's be defensive.
+                    Runner rr = (Runner) r;
+                    if(rr.isStarving())
+                        return true;
+                }
+            }
+            return false;
+        }
+
         /**
          * Gets the snapshot of {@link Runner}s that are performing polling.
          */
@@ -202,7 +219,8 @@ public class SCMTrigger extends Trigger<SCMedItem> {
          */
         /*package*/ synchronized void resizeThreadPool() {
             // swap to a new one, and shut down the old one gradually
-            ExecutorService newExec = maximumThreads==0 ? Executors.newCachedThreadPool() : Executors.newFixedThreadPool(maximumThreads);
+            ThreadPoolExecutor newExec = (ThreadPoolExecutor)
+                    (maximumThreads==0 ? Executors.newCachedThreadPool() : Executors.newFixedThreadPool(maximumThreads));
             ExecutorService old = executor;
             executor = newExec;
             if(old!=null)
@@ -260,6 +278,14 @@ public class SCMTrigger extends Trigger<SCMedItem> {
          */
         private volatile long startTime;
 
+        /**
+         * When was this object submitted to {@link DescriptorImpl#getExecutor()}?
+         *
+         * <p>
+         * This field is used to check if the queue is clogged.
+         */
+        public final long submissionTime = System.currentTimeMillis();
+
         /**
          * Where the log file is written.
          */
@@ -288,6 +314,17 @@ public class SCMTrigger extends Trigger<SCMedItem> {
             return Util.getTimeSpanString(System.currentTimeMillis()-startTime);
         }
 
+        /**
+         * Returns true if too much time is spent since this item is put into the queue.
+         *
+         * <p>
+         * This property makes sense only when called before the task actually starts,
+         * as the {@link #run()} method may take a long time to execute.
+         */
+        public boolean isStarving() {
+            return System.currentTimeMillis()-submissionTime > STARVATION_THRESHOLD;
+        }
+
         private boolean runPolling() {
             try {
                 // to make sure that the log file contains up-to-date text,
@@ -354,4 +391,9 @@ public class SCMTrigger extends Trigger<SCMedItem> {
             }
         }
     }
+
+    /**
+     * How long is too long for a polling activity to be in the queue?
+     */
+    public static long STARVATION_THRESHOLD =Long.getLong(SCMTrigger.class.getName()+".starvationThreshold", TimeUnit2.HOURS.toMillis(1));
 }

core/src/main/resources/hudson/triggers/SCMTrigger/DescriptorImpl/index.jelly

 <j:jelly xmlns:j="jelly:core" xmlns:st="jelly:stapler" xmlns:d="jelly:define" xmlns:l="/lib/layout" xmlns:t="/lib/hudson" xmlns:f="/lib/form">
-  <l:layout title="${%SCM Polling}">
+  <l:layout title="${%Current SCM Polling Activities}">
     <st:include it="${app}" page="sidepanel.jelly" />
     <l:main-panel>
-      <h1>${%SCM Polling}</h1>
+      <h1>${%Current SCM Polling Activities}</h1>
+
+      <j:if test="${it.isClogged()}">
+        <div class="warning" style="margin:1em;">
+          ${%clogged}
+        </div>
+      </j:if>
 
       <j:set var="runners" value="${it.runners}"/>
       <j:choose>
@@ -12,6 +18,9 @@
           </p>
         </j:when>
         <j:otherwise>
+          <p>
+            ${%The following polling activities are currently in progress:}
+          </p>
           <table id="threads" class="sortable pane bigtable">
             <tr>
               <th initialSortDir="down">${%Project}</th>

core/src/main/resources/hudson/triggers/SCMTrigger/DescriptorImpl/index.properties

+clogged=There are more polling activities scheduled than handled, so \
+  the threads are not keeping up with the demands. Check if your polling isn't \
+  hanging, and/or increase the number of threads if necessary.   
\ No newline at end of file