Uploaded image for project: 'Jenkins'
  1. Jenkins
  2. JENKINS-26855

Unreachable objects "remoting.Channel" can not garbage collect

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved (View Workflow)
    • Priority: Critical
    • Resolution: Duplicate
    • Component/s: remoting
    • Labels:
      None
    • Environment:
    • Similar Issues:

      Description

      My jenkins server old generationis 20GB, use than 90%, It should trigger full gc, but memory does not decrease
      so i dump the heap, found 10GB+ "remoting.Channel" unreachable objects in heap.

        Attachments

        1. channel-listobjects.png
          channel-listobjects.png
          185 kB
        2. jenkins_men_Leak_Suspects.zip
          83 kB
        3. jstat.png
          jstat.png
          277 kB
        4. slave-c-d.png
          slave-c-d.png
          224 kB

          Issue Links

            Activity

            Hide
            denger denger tung added a comment - - edited

            FYI jenkins_men_Leak_Suspects.zip

            Show
            denger denger tung added a comment - - edited FYI jenkins_men_Leak_Suspects.zip
            Hide
            denger denger tung added a comment -

            2015-02-10T01:57:25.841+0800: 94114.387: [CMS-concurrent-sweep-start]
            2015-02-10T01:57:26.905+0800: 94115.451: [CMS-concurrent-sweep: 1.030/1.064 secs] [Times: user=1.54 sys=0.15, real=1.06 secs]
            2015-02-10T01:57:26.905+0800: 94115.451: [CMS-concurrent-reset-start]
            2015-02-10T01:57:27.007+0800: 94115.553: [CMS-concurrent-reset: 0.094/0.102 secs] [Times: user=0.18 sys=0.02, real=0.10 secs]
            2015-02-10T01:57:29.010+0800: 94117.556: [GC [1 CMS-initial-mark: 34116805K(37748736K)] 35337096K(41523648K), 0.2135940 secs] [Times: user=0.22 sys=0.00, real=0.21 secs]
            2015-02-10T01:57:29.224+0800: 94117.770: [CMS-concurrent-mark-start]
            2015-02-10T01:57:30.770+0800: 94119.316: [CMS-concurrent-mark: 1.481/1.546 secs] [Times: user=6.56 sys=0.34, real=1.54 secs]
            2015-02-10T01:57:30.770+0800: 94119.316: [CMS-concurrent-preclean-start]
            2015-02-10T01:57:30.855+0800: 94119.401: [CMS-concurrent-preclean: 0.085/0.085 secs] [Times: user=0.09 sys=0.00, real=0.09 secs]
            2015-02-10T01:57:30.856+0800: 94119.401: [CMS-concurrent-abortable-preclean-start]
            CMS: abort preclean due to time 2015-02-10T01:57:35.990+0800: 94124.535: [CMS-concurrent-abortable-preclean: 3.800/5.134 secs] [Times: user=3.86 sys=0.00, real=5.13 secs]
            2015-02-10T01:57:35.993+0800: 94124.538: [GC[YG occupancy: 1955888 K (3774912 K)]2015-02-10T01:57:35.993+0800: 94124.538: [Rescan (parallel) , 0.6148460 secs]2015-02-10T01:57:36.608+0800: 94125.153: [weak refs processing, 0.0000520 secs]2015-02-10T01:57:36.608+0800: 94125.153: [scrub string table, 0.0026450 secs] [1 CMS-remark: 34116805K(37748736K)] 36072693K(41523648K), 0.6178070 secs] [Times: user=6.03 sys=0.00, real=0.61 secs]

            Show
            denger denger tung added a comment - 2015-02-10T01:57:25.841+0800: 94114.387: [CMS-concurrent-sweep-start] 2015-02-10T01:57:26.905+0800: 94115.451: [CMS-concurrent-sweep: 1.030/1.064 secs] [Times: user=1.54 sys=0.15, real=1.06 secs] 2015-02-10T01:57:26.905+0800: 94115.451: [CMS-concurrent-reset-start] 2015-02-10T01:57:27.007+0800: 94115.553: [CMS-concurrent-reset: 0.094/0.102 secs] [Times: user=0.18 sys=0.02, real=0.10 secs] 2015-02-10T01:57:29.010+0800: 94117.556: [GC [1 CMS-initial-mark: 34116805K(37748736K)] 35337096K(41523648K), 0.2135940 secs] [Times: user=0.22 sys=0.00, real=0.21 secs] 2015-02-10T01:57:29.224+0800: 94117.770: [CMS-concurrent-mark-start] 2015-02-10T01:57:30.770+0800: 94119.316: [CMS-concurrent-mark: 1.481/1.546 secs] [Times: user=6.56 sys=0.34, real=1.54 secs] 2015-02-10T01:57:30.770+0800: 94119.316: [CMS-concurrent-preclean-start] 2015-02-10T01:57:30.855+0800: 94119.401: [CMS-concurrent-preclean: 0.085/0.085 secs] [Times: user=0.09 sys=0.00, real=0.09 secs] 2015-02-10T01:57:30.856+0800: 94119.401: [CMS-concurrent-abortable-preclean-start] CMS: abort preclean due to time 2015-02-10T01:57:35.990+0800: 94124.535: [CMS-concurrent-abortable-preclean: 3.800/5.134 secs] [Times: user=3.86 sys=0.00, real=5.13 secs] 2015-02-10T01:57:35.993+0800: 94124.538: [GC [YG occupancy: 1955888 K (3774912 K)] 2015-02-10T01:57:35.993+0800: 94124.538: [Rescan (parallel) , 0.6148460 secs] 2015-02-10T01:57:36.608+0800: 94125.153: [weak refs processing, 0.0000520 secs] 2015-02-10T01:57:36.608+0800: 94125.153: [scrub string table, 0.0026450 secs] [1 CMS-remark: 34116805K(37748736K)] 36072693K(41523648K), 0.6178070 secs] [Times: user=6.03 sys=0.00, real=0.61 secs]
            Hide
            denger denger tung added a comment - - edited

            Many warning log in tomcat:

             10, 2015 2:38:09  hudson.node_monitors.AbstractNodeMonitorDescriptor$Record <init>
            waring: Previous Architecture monitoring activity still in progress. Interrupting
             10, 2015 2:38:09  hudson.node_monitors.AbstractAsyncNodeMonitorDescriptor monitor
            waring: Failed to monitor oped-slave-08-argus-cp185 for Clock Difference
            hudson.remoting.ChannelClosedException: channel is already closed
            	at hudson.remoting.Channel.send(Channel.java:549)
            	at hudson.remoting.Request.callAsync(Request.java:204)
            	at hudson.remoting.Channel.callAsync(Channel.java:778)
            	at hudson.node_monitors.AbstractAsyncNodeMonitorDescriptor.monitor(AbstractAsyncNodeMonitorDescriptor.java:76)
            	at hudson.node_monitors.AbstractNodeMonitorDescriptor$Record.run(AbstractNodeMonitorDescriptor.java:280)
            Caused by: java.nio.channels.AsynchronousCloseException
            	at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:205)
            	at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:412)
            	at hudson.remoting.SocketChannelStream$1.read(SocketChannelStream.java:35)
            	at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:65)
            	at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:109)
            	at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
            	at java.io.InputStream.read(InputStream.java:101)
            	at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:81)
            	at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:82)
            	at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2293)
            	at java.io.ObjectInputStream$BlockDataInputStream.peek(ObjectInputStream.java:2586)
            	at java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2596)
            	at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1318)
            	at java.io.ObjectInputStream.readObject(ObjectInputStream.java:370)
            	at hudson.remoting.Command.readFrom(Command.java:92)
            	at hudson.remoting.ClassicCommandTransport.read(ClassicCommandTransport.java:70)
            	at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:48)
            
             10, 2015 2:38:09  hudson.node_monitors.AbstractNodeMonitorDescriptor$Record <init>
            waring: Previous Clock Difference monitoring activity still in progress. Interrupting
             10, 2015 2:38:09  hudson.node_monitors.AbstractNodeMonitorDescriptor$Record <init>
            
            Show
            denger denger tung added a comment - - edited Many warning log in tomcat: 10, 2015 2:38:09 hudson.node_monitors.AbstractNodeMonitorDescriptor$Record <init> waring: Previous Architecture monitoring activity still in progress. Interrupting 10, 2015 2:38:09 hudson.node_monitors.AbstractAsyncNodeMonitorDescriptor monitor waring: Failed to monitor oped-slave-08-argus-cp185 for Clock Difference hudson.remoting.ChannelClosedException: channel is already closed at hudson.remoting.Channel.send(Channel.java:549) at hudson.remoting.Request.callAsync(Request.java:204) at hudson.remoting.Channel.callAsync(Channel.java:778) at hudson.node_monitors.AbstractAsyncNodeMonitorDescriptor.monitor(AbstractAsyncNodeMonitorDescriptor.java:76) at hudson.node_monitors.AbstractNodeMonitorDescriptor$Record.run(AbstractNodeMonitorDescriptor.java:280) Caused by: java.nio.channels.AsynchronousCloseException at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:205) at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:412) at hudson.remoting.SocketChannelStream$1.read(SocketChannelStream.java:35) at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:65) at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:109) at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103) at java.io.InputStream.read(InputStream.java:101) at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:81) at hudson.remoting.FlightRecorderInputStream.read(FlightRecorderInputStream.java:82) at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2293) at java.io.ObjectInputStream$BlockDataInputStream.peek(ObjectInputStream.java:2586) at java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2596) at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1318) at java.io.ObjectInputStream.readObject(ObjectInputStream.java:370) at hudson.remoting.Command.readFrom(Command.java:92) at hudson.remoting.ClassicCommandTransport.read(ClassicCommandTransport.java:70) at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:48) 10, 2015 2:38:09 hudson.node_monitors.AbstractNodeMonitorDescriptor$Record <init> waring: Previous Clock Difference monitoring activity still in progress. Interrupting 10, 2015 2:38:09 hudson.node_monitors.AbstractNodeMonitorDescriptor$Record <init>
            Hide
            denger denger tung added a comment -

            Some slave has been disconnected and connected.....

            Show
            denger denger tung added a comment - Some slave has been disconnected and connected.....
            Hide
            danielbeck Daniel Beck added a comment -

            Stephen Connolly Does this look like what you fixed in 1.609.3(ish)?

            Show
            danielbeck Daniel Beck added a comment - Stephen Connolly Does this look like what you fixed in 1.609.3(ish)?
            Hide
            stephenconnolly Stephen Connolly added a comment -

            Looks exactly like JENKINS-28844 to me

            Show
            stephenconnolly Stephen Connolly added a comment - Looks exactly like JENKINS-28844 to me
            Hide
            oleg_nenashev Oleg Nenashev added a comment -

            Another related issue is JENKINS-34213

            Show
            oleg_nenashev Oleg Nenashev added a comment - Another related issue is JENKINS-34213
            Hide
            oleg_nenashev Oleg Nenashev added a comment -

            Closing as a duplicate of JENKINS-28844

            Show
            oleg_nenashev Oleg Nenashev added a comment - Closing as a duplicate of JENKINS-28844

              People

              • Assignee:
                Unassigned
                Reporter:
                denger denger tung
              • Votes:
                0 Vote for this issue
                Watchers:
                5 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: