Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Cannot Reproduce
    • Component/s: p4-plugin
    • Labels:
    • Environment:
      1.8.4 plugin, jenkins 2.89.2
    • Similar Issues:

      Description

      Trying to debug why we receive so many of these in our log files.

      Jun 14, 2018 2:35:23 PM org.jenkinsci.plugins.p4.client.ConnectionHelper connect
      SEVERE: P4: Unable to connect: com.perforce.p4java.exception.ConnectionException: Unexpected release2 message in protocol dispatcher
      Jun 14, 2018 2:35:23 PM org.jenkinsci.plugins.p4.client.ConnectionHelper connectionRetry
      SEVERE: P4: Connection retry: 1
      Jun 14, 2018 2:35:23 PM org.jenkinsci.plugins.p4.client.ConnectionHelper connect
      SEVERE: P4: Unable to login: com.perforce.p4java.exception.ConnectionException: Unexpected release2 message in protocol dispatcher
      Jun 14, 2018 2:35:23 PM org.jenkinsci.plugins.p4.client.ConnectionHelper connectionRetry
      SEVERE: P4: Connection retry: 1
      Jun 14, 2018 2:35:26 PM org.jenkinsci.plugins.p4.client.ConnectionHelper connectionRetry
      SEVERE: P4: Connection retry giving up...
      Jun 14, 2018 2:35:26 PM org.jenkinsci.plugins.p4.tasks.AbstractTask tryTask
      WARNING:
      P4 Task: Unable to connect.
      Jun 14, 2018 2:35:26 PM org.jenkinsci.plugins.p4.client.ConnectionHelper connectionRetry
      SEVERE: P4: Connection retry giving up...

      Is there any way we can get the 'job name' or any other info?

      According to the source we shouldn't ever be seeing release2 messages.

      Are there any p4 plugin settings we can change / get more debug? Are there other jenkins settings that would give us more info?

        Attachments

          Activity

          Hide
          mhall4 Matthew Hall added a comment -

          Getting full stacktraces.

          Jun 14, 2018 2:48:22 PM org.jenkinsci.plugins.p4.client.ClientHelper clientLogin
          SEVERE: P4: Unable to use Workspace: com.perforce.p4java.exception.ConnectionException: Unexpected release2 message in protocol dispatcher
          com.perforce.p4java.exception.ConnectionException: Unexpected release2 message in protocol dispatcher
          at com.perforce.p4java.impl.mapbased.rpc.packet.RpcPacketDispatcher.dispatch(RpcPacketDispatcher.java:225)
          at com.perforce.p4java.impl.mapbased.rpc.OneShotServerImpl.execMapCmdList(OneShotServerImpl.java:363)
          at com.perforce.p4java.impl.mapbased.rpc.OneShotServerImpl.execMapCmdList(OneShotServerImpl.java:203)
          at com.perforce.p4java.impl.mapbased.server.cmd.BaseDelegator.execMapCmdList(BaseDelegator.java:138)
          at com.perforce.p4java.impl.mapbased.server.cmd.ClientDelegator.getClient(ClientDelegator.java:62)
          at com.perforce.p4java.impl.mapbased.server.Server.getClient(Server.java:1408)
          at org.jenkinsci.plugins.p4.client.ClientHelper.clientLogin(ClientHelper.java:123)
          at org.jenkinsci.plugins.p4.client.ClientHelper.<init>(ClientHelper.java:108)
          at org.jenkinsci.plugins.p4.tasks.AbstractTask.getConnection(AbstractTask.java:161)
          at org.jenkinsci.plugins.p4.tasks.AbstractTask.setWorkspace(AbstractTask.java:78)
          at org.jenkinsci.plugins.p4.PerforceScm.pollWorkspace(PerforceScm.java:388)
          at org.jenkinsci.plugins.p4.PerforceScm.compareRemoteRevisionWith(PerforceScm.java:328)
          at hudson.scm.SCM.compareRemoteRevisionWith(SCM.java:391)
          at hudson.scm.SCM.poll(SCM.java:408)
          at hudson.model.AbstractProject._poll(AbstractProject.java:1384)
          at hudson.model.AbstractProject.poll(AbstractProject.java:1287)
          at hudson.triggers.SCMTrigger$Runner.runPolling(SCMTrigger.java:594)
          at hudson.triggers.SCMTrigger$Runner.run(SCMTrigger.java:640)
          at hudson.util.SequentialExecutionQueue$QueueEntry.run(SequentialExecutionQueue.java:119)
          at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
          at java.lang.Thread.run(Thread.java:745)
          Caused by: com.perforce.p4java.exception.ProtocolError: Unexpected release2 message in protocol dispatcher
          at com.perforce.p4java.impl.mapbased.rpc.func.proto.ProtocolFunctionDispatcher.dispatch(ProtocolFunctionDispatcher.java:110)
          at com.perforce.p4java.impl.mapbased.rpc.packet.RpcPacketDispatcher.dispatch(RpcPacketDispatcher.java:189)
          ... 23 more
          Jun 14, 2018 2:48:22 PM org.jenkinsci.plugins.p4.tasks.AbstractTask setWorkspace
          SEVERE: P4: Unable to setup workspace: com.perforce.p4java.exception.ConnectionException: Unexpected release2 message in protocol dispatcher

          Show
          mhall4 Matthew Hall added a comment - Getting full stacktraces. Jun 14, 2018 2:48:22 PM org.jenkinsci.plugins.p4.client.ClientHelper clientLogin SEVERE: P4: Unable to use Workspace: com.perforce.p4java.exception.ConnectionException: Unexpected release2 message in protocol dispatcher com.perforce.p4java.exception.ConnectionException: Unexpected release2 message in protocol dispatcher at com.perforce.p4java.impl.mapbased.rpc.packet.RpcPacketDispatcher.dispatch(RpcPacketDispatcher.java:225) at com.perforce.p4java.impl.mapbased.rpc.OneShotServerImpl.execMapCmdList(OneShotServerImpl.java:363) at com.perforce.p4java.impl.mapbased.rpc.OneShotServerImpl.execMapCmdList(OneShotServerImpl.java:203) at com.perforce.p4java.impl.mapbased.server.cmd.BaseDelegator.execMapCmdList(BaseDelegator.java:138) at com.perforce.p4java.impl.mapbased.server.cmd.ClientDelegator.getClient(ClientDelegator.java:62) at com.perforce.p4java.impl.mapbased.server.Server.getClient(Server.java:1408) at org.jenkinsci.plugins.p4.client.ClientHelper.clientLogin(ClientHelper.java:123) at org.jenkinsci.plugins.p4.client.ClientHelper.<init>(ClientHelper.java:108) at org.jenkinsci.plugins.p4.tasks.AbstractTask.getConnection(AbstractTask.java:161) at org.jenkinsci.plugins.p4.tasks.AbstractTask.setWorkspace(AbstractTask.java:78) at org.jenkinsci.plugins.p4.PerforceScm.pollWorkspace(PerforceScm.java:388) at org.jenkinsci.plugins.p4.PerforceScm.compareRemoteRevisionWith(PerforceScm.java:328) at hudson.scm.SCM.compareRemoteRevisionWith(SCM.java:391) at hudson.scm.SCM.poll(SCM.java:408) at hudson.model.AbstractProject._poll(AbstractProject.java:1384) at hudson.model.AbstractProject.poll(AbstractProject.java:1287) at hudson.triggers.SCMTrigger$Runner.runPolling(SCMTrigger.java:594) at hudson.triggers.SCMTrigger$Runner.run(SCMTrigger.java:640) at hudson.util.SequentialExecutionQueue$QueueEntry.run(SequentialExecutionQueue.java:119) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: com.perforce.p4java.exception.ProtocolError: Unexpected release2 message in protocol dispatcher at com.perforce.p4java.impl.mapbased.rpc.func.proto.ProtocolFunctionDispatcher.dispatch(ProtocolFunctionDispatcher.java:110) at com.perforce.p4java.impl.mapbased.rpc.packet.RpcPacketDispatcher.dispatch(RpcPacketDispatcher.java:189) ... 23 more Jun 14, 2018 2:48:22 PM org.jenkinsci.plugins.p4.tasks.AbstractTask setWorkspace SEVERE: P4: Unable to setup workspace: com.perforce.p4java.exception.ConnectionException: Unexpected release2 message in protocol dispatcher
          Hide
          mhall4 Matthew Hall added a comment -

          Only other thing of note is that there are ~300 jobs using 'H/15 * * * * ' poll spec.

          Show
          mhall4 Matthew Hall added a comment - Only other thing of note is that there are ~300 jobs using 'H/15 * * * * ' poll spec.
          Hide
          p4karl Karl Wirth added a comment -

          Hi Matthew Hall

          Are you still seeing these? We have sometimes seen this error with networking problems but it can also sometimes occur with parallel syncs.

          Do you have a Perforce support contract? If you do can you please send an email into support@perforce.com for attention of me and I can then get some confidential information about your setup, logs etc.

          Thanks in advance,

          Karl

          Show
          p4karl Karl Wirth added a comment - Hi Matthew Hall Are you still seeing these? We have sometimes seen this error with networking problems but it can also sometimes occur with parallel syncs. Do you have a Perforce support contract? If you do can you please send an email into support@perforce.com for attention of me and I can then get some confidential information about your setup, logs etc. Thanks in advance, Karl
          Hide
          mhall4 Matthew Hall added a comment -

          This message has since disappeared. These things were likely/possibly the cause :

          1) Sheer number of builds configured (400+) with H/15 or H/5 polling. (every 15 or every 5 minute).
          Solution : Normalized polling to H/15 across all builds.
          2) Limited nproc, which limited the # of java threads. Since each build consumes a polling thread, the larger the number of builds, the more likely to hit the limit.
          Solution : Raised nproc limit for the jenkins user.

          Finally, we moved to a Poke model, with a backup "poll every 2 hours".

          From observation, I think the "spike" at whatever H/15 or H/5 time for our builds (psuedo random), hitting the p4 server at once, was most likely the cause of the network issue.

          Show
          mhall4 Matthew Hall added a comment - This message has since disappeared. These things were likely/possibly the cause : 1) Sheer number of builds configured (400+) with H/15 or H/5 polling. (every 15 or every 5 minute). Solution : Normalized polling to H/15 across all builds. 2) Limited nproc, which limited the # of java threads. Since each build consumes a polling thread, the larger the number of builds, the more likely to hit the limit. Solution : Raised nproc limit for the jenkins user. Finally, we moved to a Poke model, with a backup "poll every 2 hours". From observation, I think the "spike" at whatever H/15 or H/5 time for our builds (psuedo random), hitting the p4 server at once, was most likely the cause of the network issue.
          Hide
          p4karl Karl Wirth added a comment -

          Hi Matthew. Thanks for getting back to me. For now I will assume it was congestion but if it occurs again just let me know and we can investigate further.

          Show
          p4karl Karl Wirth added a comment - Hi Matthew. Thanks for getting back to me. For now I will assume it was congestion but if it occurs again just let me know and we can investigate further.
          Hide
          p4karl Karl Wirth added a comment -

          Possible cause - network congestion. Next step would involve a sniffer such as Wireshark and log files.

          Show
          p4karl Karl Wirth added a comment - Possible cause - network congestion. Next step would involve a sniffer such as Wireshark and log files.

            People

            • Assignee:
              p4karl Karl Wirth
              Reporter:
              mhall4 Matthew Hall
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: