[JENKINS-22853]

Digging deeper into the excessive unexport problem by adding more diagnostics. We want to track where the unexport command is created on the other side of the channel.
jenkinsci · May 20, 2014 · 1eeccd4 · 1eeccd4
1 parent 6434c43
commit 1eeccd4
Show file tree

Hide file tree

Showing 9 changed files with 41 additions and 21 deletions.
diff --git a/src/main/java/hudson/remoting/Channel.java b/src/main/java/hudson/remoting/Channel.java
@@ -596,8 +596,8 @@ public <T> T export(Class<T> type, T instance) {
         return exportedObjects.get(oid);
     }
 
-    /*package*/ void unexport(int id) {
-        exportedObjects.unexportByOid(id);
+    /*package*/ void unexport(int id, Throwable cause) {
+        exportedObjects.unexportByOid(id,cause);
     }
 
     /**

diff --git a/src/main/java/hudson/remoting/ExportTable.java b/src/main/java/hudson/remoting/ExportTable.java
@@ -104,15 +104,15 @@ void pin() {
                 referenceCount += Integer.MAX_VALUE/2;
         }
 
-        void release() {
+        void release(Throwable callSite) {
             if(--referenceCount==0) {
                 table.remove(id);
                 reverse.remove(object);
 
                 // hack to store some information about the object that got unexported
                 // don't want to keep the object alive, and toString() seems bit risky
                 object = (T)object.getClass().getName();
-                releaseTrace = new ReleasedAt();
+                releaseTrace = new ReleasedAt(callSite);
 
                 unexportLog.add(this);
                 while (unexportLog.size()>UNEXPORT_LOG_SIZE)
@@ -148,20 +148,34 @@ String dump() {
     static class Source extends Exception {
         protected final long timestamp = System.currentTimeMillis();
 
-        Source() {
+        /**
+         * @param callSite
+         *      Optional location that indicates where the actual call site was that triggered the activity,
+         *      in case it was requested from the other side of the channel.
+         */
+        Source(Throwable callSite) {
+            super(callSite);
             // force the computation of the stack trace in a Java friendly data structure,
             // so that the call stack can be seen from the heap dump after the fact.
             getStackTrace();
         }
     }
 
     static class CreatedAt extends Source {
+        CreatedAt() {
+            super(null);
+        }
+
         public String toString() {
             return "  Created at "+new Date(timestamp);
         }
     }
 
     static class ReleasedAt extends Source {
+        ReleasedAt(Throwable callSite) {
+            super(callSite);
+        }
+
         public String toString() {
             return "  Released at "+new Date(timestamp);
         }
@@ -179,10 +193,10 @@ private ExportList() {
             old=lists.get();
             lists.set(this);
         }
-        void release() {
+        void release(Throwable callSite) {
             synchronized(ExportTable.this) {
                 for (Entry e : this)
-                    e.release();
+                    e.release(callSite);
             }
         }
         void stopRecording() {
@@ -215,7 +229,7 @@ public boolean isRecording() {
      * Exports the given object.
      *
      * <p>
-     * Until the object is {@link #unexport(Object) unexported}, it will
+     * Until the object is {@link #unexport(Object,Throwable) unexported}, it will
      * not be subject to GC.
      *
      * @return
@@ -280,27 +294,29 @@ private synchronized IllegalStateException diagnoseInvalidId(int id) {
     /**
      * Removes the exported object from the table.
      */
-    public synchronized void unexport(T t) {
+    synchronized void unexport(T t, Throwable callSite) {
         if(t==null)     return;
         Entry e = reverse.get(t);
         if(e==null) {
             LOGGER.log(SEVERE, "Trying to unexport an object that's not exported: "+t);
             return;
         }
-        e.release();
+        e.release(callSite);
     }
 
     /**
      * Removes the exported object for the specified oid from the table.
      */
-    public synchronized void unexportByOid(Integer oid) {
+    public synchronized void unexportByOid(Integer oid, Throwable callSite) {
         if(oid==null)     return;
         Entry e = table.get(oid);
         if(e==null) {
             LOGGER.log(SEVERE, "Trying to unexport an object that's already unexported", diagnoseInvalidId(oid));
+            if (callSite!=null)
+                LOGGER.log(SEVERE, "2nd unexport attempt is here", callSite);
             return;
         }
-        e.release();
+        e.release(callSite);
     }
 
     /**

diff --git a/src/main/java/hudson/remoting/Pipe.java b/src/main/java/hudson/remoting/Pipe.java
@@ -216,7 +216,7 @@ protected void execute(final Channel channel) {
                 public void run() {
                     try {
                         final ProxyOutputStream ros = (ProxyOutputStream) channel.getExportedObject(oidRos);
-                        channel.unexport(oidRos);
+                        channel.unexport(oidRos,createdAt);
                         // the above unexport cancels out the export in writeObject above
                         ros.connect(channel, oidPos);
                     } catch (IOException e) {

diff --git a/src/main/java/hudson/remoting/ProxyInputStream.java b/src/main/java/hudson/remoting/ProxyInputStream.java
@@ -149,7 +149,7 @@ public EOF(int oid) {
 
         protected void execute(Channel channel) {
             InputStream in = (InputStream) channel.getExportedObject(oid);
-            channel.unexport(oid);
+            channel.unexport(oid,createdAt);
             try {
                 in.close();
             } catch (IOException e) {

diff --git a/src/main/java/hudson/remoting/ProxyOutputStream.java b/src/main/java/hudson/remoting/ProxyOutputStream.java
@@ -349,7 +349,7 @@ public Unexport(int ioId, int oid) {
         protected void execute(final Channel channel) {
             channel.pipeWriter.submit(ioId,new Runnable() {
                 public void run() {
-                    channel.unexport(oid);
+                    channel.unexport(oid,createdAt);
                 }
             });
         }
@@ -381,7 +381,7 @@ protected void execute(final Channel channel) {
             final OutputStream os = (OutputStream) channel.getExportedObject(oid);
             markForIoSync(channel,requestId,channel.pipeWriter.submit(ioId,new Runnable() {
                 public void run() {
-                    channel.unexport(oid);
+                    channel.unexport(oid,createdAt);
                     try {
                         if (error!=null && os instanceof ErrorPropagatingOutputStream)
                             ((ErrorPropagatingOutputStream) os).error(error);

diff --git a/src/main/java/hudson/remoting/ProxyWriter.java b/src/main/java/hudson/remoting/ProxyWriter.java
@@ -319,7 +319,7 @@ public Unexport(int ioId, int oid) {
         protected void execute(final Channel channel) {
             channel.pipeWriter.submit(ioId,new Runnable() {
                 public void run() {
-                    channel.unexport(oid);
+                    channel.unexport(oid,createdAt);
                 }
             });
         }
@@ -347,7 +347,7 @@ protected void execute(final Channel channel) {
             final Writer os = (Writer) channel.getExportedObject(oid);
             channel.pipeWriter.submit(ioId, new Runnable() {
                 public void run() {
-                    channel.unexport(oid);
+                    channel.unexport(oid,createdAt);
                     try {
                         os.close();
                     } catch (IOException e) {

diff --git a/src/main/java/hudson/remoting/UnexportCommand.java b/src/main/java/hudson/remoting/UnexportCommand.java
@@ -35,7 +35,7 @@ public UnexportCommand(int oid) {
     }
 
     protected void execute(Channel channel) {
-        channel.unexport(oid);
+        channel.unexport(oid,createdAt);
     }
 
     private static final long serialVersionUID = 1L;

diff --git a/src/main/java/hudson/remoting/UserRequest.java b/src/main/java/hudson/remoting/UserRequest.java
@@ -183,7 +183,11 @@ private byte[] serialize(Object o, Channel localChannel) throws IOException {
     }
 
     public void releaseExports() {
-        exports.release();
+        releaseExports(null);
+    }
+
+    /*package*/ void releaseExports(Throwable callSite) {
+        exports.release(callSite);
     }
 
     public String toString() {

diff --git a/src/test/java/hudson/remoting/ExportTableTest.java b/src/test/java/hudson/remoting/ExportTableTest.java
@@ -15,7 +15,7 @@ public void testDiagnosis() throws Exception {
         int i = e.export("foo");
         assertEquals("foo", e.get(i));
 
-        e.unexportByOid(i);
+        e.unexportByOid(i,null);
         try {
             e.get(i);
             fail();