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

Remoting object pinning can result in an object that is released immediately

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Component/s: remoting
    • Labels:
    • Similar Issues:

      Description

      The current logic for reference counting and pinning contains a potential bug that could give rise to objects being unexported.

              void pin() {
                  if (referenceCount<Integer.MAX_VALUE/2)
                      referenceCount += Integer.MAX_VALUE/2;
              }
      

      So if we have the sequence:

      • Export table entry created -> 0x00000000
      • Object pinned -> 0x3FFFFFFF
      • ...
      • Object released -> 0x3FFFFFFE
      • Object pinned -> 0x7FFFFFFD
      • Object addRef -> 0x7FFFFFFE
      • Object addRef -> 0x80000000
      • Object deallocated as refcount < 0

      The number one symptom of this bug is:

      2017-02-07 11:11:21.087-0500 [id=47743]	WARNING	h.n.AbstractAsyncNodeMonitorDescriptor#monitor: Failed to monitor ___REDACTED___ for Clock Differencejava.util.concurrent.ExecutionException: java.io.IOException: Cannot locate RemoteClassLoader.ClassLoaderProxy(-1) in the channel exported table
      	at hudson.remoting.Channel$2.adapt(Channel.java:829)
      	at hudson.remoting.Channel$2.adapt(Channel.java:824)
      	at hudson.remoting.FutureAdapter.get(FutureAdapter.java:59)
      	at hudson.node_monitors.AbstractAsyncNodeMonitorDescriptor.monitor(AbstractAsyncNodeMonitorDescriptor.java:96)
      	at hudson.node_monitors.AbstractNodeMonitorDescriptor$Record.run(AbstractNodeMonitorDescriptor.java:305)
      Caused by: java.io.IOException: Cannot locate RemoteClassLoader.ClassLoaderProxy(-1) in the channel exported table
      	at hudson.remoting.MultiClassLoaderSerializer$Input.readClassLoader(MultiClassLoaderSerializer.java:102)
      	at hudson.remoting.MultiClassLoaderSerializer$Input.resolveClass(MultiClassLoaderSerializer.java:123)
      	at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1612)
      	at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1517)
      	at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1771)
      	at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1350)
      	at java.io.ObjectInputStream.readObject(ObjectInputStream.java:370)
      	at hudson.remoting.UserRequest.deserialize(UserRequest.java:217)
      	at hudson.remoting.UserResponse.retrieve(UserRequest.java:250)
      	at hudson.remoting.Channel$2.adapt(Channel.java:827)
      	... 4 more
      Caused by: java.util.concurrent.ExecutionException: Invalid object ID 2 iota=26
      	at hudson.remoting.ExportTable.diagnoseInvalidObjectId(ExportTable.java:408)
      	at hudson.remoting.ExportTable.get(ExportTable.java:333)
      	at hudson.remoting.Channel.getExportedObject(Channel.java:633)
      	at hudson.remoting.MultiClassLoaderSerializer$Input.readClassLoader(MultiClassLoaderSerializer.java:100)
      	... 13 more
      Caused by: java.lang.Exception: Object appears to be deallocated at lease before Tue Feb 07 11:08:06 EST 2017
      	at hudson.remoting.ExportTable.diagnoseInvalidObjectId(ExportTable.java:404)
      	... 16 more
      

      Specifically that this is Invalid object ID 2

      object ID 1 is always the Channel exported as an IChannel

      object ID 2 is always the RemoteClassLoader$ClassLoaderProxy exported as an hudson.remoting.RemoteClassLoader$IClassLoader

      There is no circumstances I can see where object ID 2 should ever be safe to remove. In fact there is code that explicitly pins the classloader

      Strangely when I look at the export tables from agents, however I see things like:

      #2 (ref.571) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.1073744046) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.456) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.516) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.517) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.513) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.1028) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.403) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.313) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.494) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.1073742439) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.447) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.316) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.314) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.316) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.1073742160) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.324) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.321) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.326) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.324) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.318) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.323) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      #2 (ref.320) : object=hudson.remoting.RemoteClassLoader$ClassLoaderProxy@1a1feb69[WebAppClassLoader=Jenkins v2.19.4@1a1feb69] type=hudson.remoting.RemoteClassLoader$ClassLoaderProxy interfaces=[hudson.remoting.RemoteClassLoader$IClassLoader]
      

      which is interesting, because we have some of these pinned (i.e. values like 1073744046, 1073742439 and 1073742160) and some unpinned...

      This is rather indicative of something strange going on

        Attachments

          Activity

            People

            • Assignee:
              stephenconnolly Stephen Connolly
              Reporter:
              stephenconnolly Stephen Connolly
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: