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

p4publish and unexpected timeout - 300 seconds

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Critical
    • Resolution: Fixed
    • Component/s: p4-plugin
    • Labels:
    • Environment:
    • Similar Issues:

      Description

      In case long publish (more than 300s) - pipeline failed with error:
      ERROR: java.lang.InterruptedException
      Short/small submits - no errors

      Network activity show normal submit (200+ mbit/s)

      p4d logs - brocken pipe

      Timeout period looks like not on p4 submit, but on all stack of p4publish groovy commands (ex: 21:02:56 - 21:07:56)

      [Pipeline] p4publish
      21:02:56 ... p4 client -o XXX +
      21:02:56 ... p4 info +
      21:02:56 ... p4 client -o XXX +
      21:02:56 ... p4 client -i +
      21:02:56 ... client: XXX
      21:02:56 ... p4 client -o XXX  +
      21:02:56 ... p4 info +
      21:02:56 
      21:02:56 P4 Task: establishing connection.
      21:02:56 ... server: XXX:1666
      21:02:56 ... node: XXX
      21:02:56 
      21:02:56 P4 Task: reconcile files to changelist.
      21:02:56 ... p4 revert -k //XXX/... +
      21:02:56 ... p4 sync -k //XXX/... +
      21:02:56 ... p4 reconcile -e -a -f -d //XXX/... +
      21:02:59 ... p4 opened -CXXX //XXX/... +
      21:02:59 duration: 0m 2s
      21:02:59 
      21:02:59 P4 Task: publish files to Perforce.
      21:02:59 ... p4 change -i +
      21:02:59 ... p4 change -o 343 +
      21:02:59 ... pending change: 343
      21:02:59 ... p4 reopen -c343 -t+S1 //XXX/... +
      21:02:59 ... p4 opened -CXXX //XXX/... +
      21:02:59 ... ... add //XXX
      ...1500+ files
      21:02:59 ... ... add //XXX
      21:03:00 ... p4 describe -s 343 +
      21:03:00 ... p4 fixes -c343 +
      21:03:00 ... p4 submit -i +
      21:03:00 
      [Pipeline] }
      [Pipeline] // node
      [Pipeline] }
      [Pipeline] // stage
      [Pipeline] node
      21:07:56 Running on node_name in c:\jenkins-web\workspace\main_build
      [Pipeline] {
      [Pipeline] echo
      [Pipeline] error
      [Pipeline] }
      [Pipeline] // node
      [Pipeline] }
      [Pipeline] // timestamps
      [Pipeline] End of Pipeline
      ERROR: java.lang.InterruptedException
      Finished: FAILURE
      

      Pipeline(fragment):

       

         try {
              stage('Push results'){
                  node(WN_NODE) {
                      def p4_spec_name = "jenkins-${env.NODE_NAME}-${env.JOB_NAME}-bin"
                      def p4_mapping = """XXX"""
                      def p4_description = "${build_desc} ${job_tag}"
          p4publish credential: p4_credentials,
              publish: [$class: 'SubmitImpl', delete: true, description: p4_description, onlyOnSuccess: false, reopen: false, purge: '1'],
              workspace: [$class: 'ManualWorkspaceImpl', charset: 'auto', name: p4_spec_name, pinHost: false,
                  spec: [allwrite: true, clobber: false, compress: false, line: 'LOCAL', locked: false, modtime: false, rmdir: true, streamName: '', view: p4_mapping]]
      
                  }
      
              }
          }
          catch (err){
              node(WN_NODE){
                      error "${err}"
              }
          }
      
      

       

      p4sync - no error on long/big sync > 300s

      After failure - in perforce remain good changelist, p4v submit his without problem and timeout limits.

       

      In p4 credentials RPC_SOCKET_SO_TIMEOUT_NICK == 0

       

      Jenkins docker-compose.yml

       

      version: '2'
      services:
        jenkins:
          image: "jenkins:latest"
          restart: always
          ports:
            - 50000:50000
            - 8080:8080
          volumes:
            - ./jenkins_home:/var/jenkins_home
          logging:
            driver: json-file
            options:
              max-size: "10m"
              max-file: "3"
          environment:
            - JAVA_OPTS="-Duser.timezone=Europe/Kiev"
      

       

       

      docker logs at this period:

      May 22, 2017 9:00:35 PM org.jenkinsci.plugins.p4.PerforceScm guessBrowser
      INFO: Unable to guess repository browser.
      May 22, 2017 9:07:56 PM org.jenkinsci.plugins.workflow.job.WorkflowRun finish
      INFO: main_build #29 completed: FAILURE
      

       

       

        Attachments

          Issue Links

            Activity

            t_rex Oleksii Trekhov created issue -
            Hide
            t_rex Oleksii Trekhov added a comment - - edited

            looks like core problem - JNLP-slave ping:

            https://wiki.jenkins-ci.org/display/JENKINS/Features+controlled+by+system+properties

            hudson.slaves.ChannelPinger.pingIntervalSeconds 300 2.37 Frequency of pings between the master and slaves, in seconds

            reproduce on Windows slaves with

            • Launch agent via Java Web Start
            • Let Jenkins control this Windows slave as a Windows service
            Show
            t_rex Oleksii Trekhov added a comment - - edited looks like core problem - JNLP-slave ping: https://wiki.jenkins-ci.org/display/JENKINS/Features+controlled+by+system+properties hudson.slaves.ChannelPinger.pingIntervalSeconds 300 2.37 Frequency of  pings between the master and slaves , in seconds reproduce on Windows slaves with Launch agent via Java Web Start Let Jenkins control this Windows slave as a Windows service
            t_rex Oleksii Trekhov made changes -
            Field Original Value New Value
            Environment Jenkins ver. 2.46.2 (inside official docker image jenkins:latest)
            p4d Server version: P4D/LINUX26X86_64/2016.2/1509269 (2017/04/27)
            p4 Plugin ver: 1.7.0 + 1.6.2
            Jenkins ver. 2.46.2 (inside official docker image jenkins:latest)
            p4d Server version: P4D/LINUX26X86_64/2016.2/1509269 (2017/04/27)
            p4 Plugin ver: 1.7.0 + 1.6.2
            windows slaves (win10x64, java x64 ver. 8u131)
            t_rex Oleksii Trekhov made changes -
            Attachment jenkins 300.png [ 38114 ]
            Hide
            p4paul Paul Allen added a comment -

            Have you been able to lengthen the time or disable it?  Did this resolve the issue?

            https://wiki.jenkins-ci.org/display/JENKINS/Ping+Thread

            Show
            p4paul Paul Allen added a comment - Have you been able to lengthen the time or disable it?  Did this resolve the issue? https://wiki.jenkins-ci.org/display/JENKINS/Ping+Thread
            Hide
            t_rex Oleksii Trekhov added a comment -

            > Did this resolve the issue?

            No. Also in slave log

            May 23, 2017 11:04:47 PM FINE hudson.remoting.Channel
            Received hudson.remoting.Request$Cancel@62a4211d
            May 23, 2017 11:04:48 PM FINE hudson.remoting.Channel
            Received UserRequest:hudson.Launcher$RemoteLauncher$KillTask@e61e62
            May 23, 2017 11:04:48 PM FINER hudson.remoting.RemoteClassLoader
            fetch3(hudson.Launcher$RemoteLauncher$KillTask)

            +All p4submit pipeline logs print in jenkins web only after submit success or submit error - looks like logs stuck on slave... like submit block slave thread or master-slave communication

            21:02:56 ... p4 client -o XXX +
            21:02:56 ... p4 info +
            21:02:56 ... p4 client -o XXX +
            21:02:56 ... p4 client -i +
            21:02:56 ... p4 client -o XXX  +
            21:02:56 ... p4 info +
            21:02:56 ... p4 revert -k //XXX/... +
            21:02:56 ... p4 sync -k //XXX/... +
            21:02:56 ... p4 reconcile -e -a -f -d //XXX/... +
            21:02:59 ... p4 opened -CXXX //XXX/... +
            21:02:59 ... p4 change -i +
            21:02:59 ... p4 change -o 343 +
            21:02:59 ... pending change: 343
            21:02:59 ... p4 reopen -c343 -t+S1 //XXX/... +
            21:02:59 ... p4 opened -CXXX //XXX/... +
            21:03:00 ... p4 describe -s 343 +
            21:03:00 ... p4 fixes -c343 +
            21:03:00 ... p4 submit -i +
            
            Show
            t_rex Oleksii Trekhov added a comment - > Did this resolve the issue? No. Also in slave log May 23, 2017 11:04:47 PM FINE hudson.remoting.Channel Received hudson.remoting.Request$Cancel@62a4211d May 23, 2017 11:04:48 PM FINE hudson.remoting.Channel Received UserRequest:hudson.Launcher$RemoteLauncher$KillTask@e61e62 May 23, 2017 11:04:48 PM FINER hudson.remoting.RemoteClassLoader fetch3(hudson.Launcher$RemoteLauncher$KillTask) +All p4submit pipeline logs print in jenkins web only after submit success or submit error - looks like logs stuck on slave... like submit block slave thread or master-slave communication 21:02:56 ... p4 client -o XXX + 21:02:56 ... p4 info + 21:02:56 ... p4 client -o XXX + 21:02:56 ... p4 client -i + 21:02:56 ... p4 client -o XXX + 21:02:56 ... p4 info + 21:02:56 ... p4 revert -k //XXX/... + 21:02:56 ... p4 sync -k //XXX/... + 21:02:56 ... p4 reconcile -e -a -f -d //XXX/... + 21:02:59 ... p4 opened -CXXX //XXX/... + 21:02:59 ... p4 change -i + 21:02:59 ... p4 change -o 343 + 21:02:59 ... pending change: 343 21:02:59 ... p4 reopen -c343 -t+S1 //XXX/... + 21:02:59 ... p4 opened -CXXX //XXX/... + 21:03:00 ... p4 describe -s 343 + 21:03:00 ... p4 fixes -c343 + 21:03:00 ... p4 submit -i +
            Hide
            t_rex Oleksii Trekhov added a comment -

            We try another new windows slave and new fresh jenkins master w/o unnecessary plugins - same fail after 300 secs...

            Show
            t_rex Oleksii Trekhov added a comment - We try another new windows slave and new fresh jenkins master w/o unnecessary plugins - same fail after 300 secs...
            Hide
            t_rex Oleksii Trekhov added a comment -
            Show
            t_rex Oleksii Trekhov added a comment - maybe https://www.jfrog.com/jira/browse/HAP-893 same bug?
            Hide
            p4paul Paul Allen added a comment -

            The submit is blocking.  It might be possible to make submit use the Streaming Asynchronous Callback mechanism used by sync.

            Show
            p4paul Paul Allen added a comment - The submit is blocking.  It might be possible to make submit use the Streaming Asynchronous Callback mechanism used by sync.
            Hide
            t_rex Oleksii Trekhov added a comment -

            any terms for async?

            reproduce and on linux slave

            without master-slave communication:

            May 25, 2017 1:53:15 PM org.jenkinsci.plugins.p4.tasks.PublishTask task
            WARNING: Unable to publish workspace: com.perforce.p4java.exception.P4JavaException: Unable to submit change.
            May 25, 2017 1:53:15 PM org.jenkinsci.plugins.p4.tasks.AbstractTask tryTask
            WARNING: P4: Task Aborted!

            Show
            t_rex Oleksii Trekhov added a comment - any terms for async? reproduce and on linux slave without master-slave communication: May 25, 2017 1:53:15 PM org.jenkinsci.plugins.p4.tasks.PublishTask task WARNING: Unable to publish workspace: com.perforce.p4java.exception.P4JavaException: Unable to submit change. May 25, 2017 1:53:15 PM org.jenkinsci.plugins.p4.tasks.AbstractTask tryTask WARNING: P4: Task Aborted!
            Hide
            scm_issue_link SCM/JIRA link daemon added a comment -

            Code changed in jenkins
            User: Paul Allen
            Path:
            src/main/java/org/jenkinsci/plugins/p4/client/ClientHelper.java
            src/main/java/org/jenkinsci/plugins/p4/client/SubmitStreamingCallback.java
            http://jenkins-ci.org/commit/p4-plugin/d4f9b37ab821f8fccfcc69c53cee590897f2b775
            Log:
            Streaming Asynchronous Callback for Submit.

            JENKINS-44427

            Show
            scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Paul Allen Path: src/main/java/org/jenkinsci/plugins/p4/client/ClientHelper.java src/main/java/org/jenkinsci/plugins/p4/client/SubmitStreamingCallback.java http://jenkins-ci.org/commit/p4-plugin/d4f9b37ab821f8fccfcc69c53cee590897f2b775 Log: Streaming Asynchronous Callback for Submit. JENKINS-44427
            t_rex Oleksii Trekhov made changes -
            Environment Jenkins ver. 2.46.2 (inside official docker image jenkins:latest)
            p4d Server version: P4D/LINUX26X86_64/2016.2/1509269 (2017/04/27)
            p4 Plugin ver: 1.7.0 + 1.6.2
            windows slaves (win10x64, java x64 ver. 8u131)
            Jenkins ver. 2.46.2 (inside official docker image jenkins:latest)
            p4d Server version: P4D/LINUX26X86_64/2016.2/1509269 (2017/04/27)
            p4 Plugin ver: 1.7.0 + 1.6.2
            windows slaves (win10x64, java x64 ver. 8u131)
            linux slaves (ubuntu 16.04 x64)
            Hide
            t_rex Oleksii Trekhov added a comment -

            we try 1.7.1-SNAPSHOT (private-d4f9b37a-jenkins) - same behavior:

            • fail after 300 sec
            • no logs in time of submit
            Show
            t_rex Oleksii Trekhov added a comment - we try 1.7.1-SNAPSHOT (private-d4f9b37a-jenkins) - same behavior: fail after 300 sec no logs in time of submit
            Hide
            p4paul Paul Allen added a comment -

            If you are getting this on the master (no remote connection to the slave) then I am not sure what is breaking the connection.  Perhaps your Perforce administrator has set restrictions on the Jenkins process or user?  You might be best talking directly with Perforce Support.

            You will need to let them know the version of P4D, network topology (i.e. do you have any brokers, proxies) are there any clues in the server logs.  Any configurables set ('p4 configure show').

            Show
            p4paul Paul Allen added a comment - If you are getting this on the master (no remote connection to the slave) then I am not sure what is breaking the connection.  Perhaps your Perforce administrator has set restrictions on the Jenkins process or user?  You might be best talking directly with Perforce Support. You will need to let them know the version of P4D, network topology (i.e. do you have any brokers, proxies) are there any clues in the server logs.  Any configurables set ('p4 configure show').
            Hide
            t_rex Oleksii Trekhov added a comment -

            maybe in src\main\java\org\jenkinsci\plugins\p4\workflow\P4PublishStep.java use

            AbstractSynchronousNonBlockingStepExecution

            in

                public static class P4PublishStepExecution extends
                        AbstractSynchronousStepExecution<Void> {

            Show
            t_rex Oleksii Trekhov added a comment - maybe in src\main\java\org\jenkinsci\plugins\p4\workflow\P4PublishStep.java use AbstractSynchronousNonBlockingStepExecution in     public static class P4PublishStepExecution extends              AbstractSynchronousStepExecution <Void> {
            Hide
            t_rex Oleksii Trekhov added a comment -

            We try AbstractSynchronousNonBlockingStepExecution

            • p4publish log in "console output" immediately
            • big submit - success
              [Pipeline] p4publish
              11:39:56 
              ...
              ... p4 fixes -c1 +
              11:39:59 ... p4 submit -i +
              11:46:50 ... submitted in change: 1
              11:46:50 duration: 6m 52s
              11:46:50 
            Show
            t_rex Oleksii Trekhov added a comment - We try AbstractSynchronousNonBlockingStepExecution p4publish log in "console output" immediately big submit - success [Pipeline] p4publish 11:39:56 ... ... p4 fixes -c1 + 11:39:59 ... p4 submit -i + 11:46:50 ... submitted in change: 1 11:46:50 duration: 6m 52s 11:46:50
            Hide
            scm_issue_link SCM/JIRA link daemon added a comment -

            Code changed in jenkins
            User: Paul Allen
            Path:
            src/main/java/org/jenkinsci/plugins/p4/workflow/P4PublishStep.java
            http://jenkins-ci.org/commit/p4-plugin/0bbf1c54872e5c689e82c91c59af4d1a17b12056
            Log:
            Update Publish Step to use 'Step' and 'SynchronousNonBlockingStepExecution'

            JENKINS-44427

            Show
            scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Paul Allen Path: src/main/java/org/jenkinsci/plugins/p4/workflow/P4PublishStep.java http://jenkins-ci.org/commit/p4-plugin/0bbf1c54872e5c689e82c91c59af4d1a17b12056 Log: Update Publish Step to use 'Step' and 'SynchronousNonBlockingStepExecution' JENKINS-44427
            Hide
            p4paul Paul Allen added a comment -

            This uses the non deprecated Step and SynchronousNonBlockingStepExecution, hopefully it resolves your large sync issue. I will upgrade the other steps later.

            Show
            p4paul Paul Allen added a comment - This uses the non deprecated Step and SynchronousNonBlockingStepExecution, hopefully it resolves your large sync issue. I will upgrade the other steps later.
            Hide
            t_rex Oleksii Trekhov added a comment -

            Thanks! How about use parallel submit via p4 cli (like p4sync step)???

            Show
            t_rex Oleksii Trekhov added a comment - Thanks! How about use parallel submit via p4 cli (like p4sync step)???
            Hide
            p4paul Paul Allen added a comment -

            If you can wait a bit we have just added parallel sync to p4java for the 17.2 release and will be updating the p4-plugin for Jenkins to use the p4java api (no need for an external p4 binary). Parallel submit is also on the TODO list and hopefully 17.3 for p4java (perhaps July/Aug and shortly after for the p4-plugin for Jenkins).

            Show
            p4paul Paul Allen added a comment - If you can wait a bit we have just added parallel sync to p4java for the 17.2 release and will be updating the p4-plugin for Jenkins to use the p4java api (no need for an external p4 binary). Parallel submit is also on the TODO list and hopefully 17.3 for p4java (perhaps July/Aug and shortly after for the p4-plugin for Jenkins).
            Hide
            t_rex Oleksii Trekhov added a comment -

            Great!

            +1 question:

            Can i use p4groovy for receive file content from depot/stream without workspace - like "p4 print -q ..."

            Show
            t_rex Oleksii Trekhov added a comment - Great! +1 question: Can i use p4groovy for receive file content from depot/stream without workspace - like "p4 print -q ..."
            Hide
            p4paul Paul Allen added a comment -

            Not tried it, in theory yes you should get the file content back in the Map Object (although you might run out of memory on a large file).

            Show
            p4paul Paul Allen added a comment - Not tried it, in theory yes you should get the file content back in the Map Object (although you might run out of memory on a large file).
            Hide
            p4karl Karl Wirth added a comment -
            Show
            p4karl Karl Wirth added a comment - Code fix released in: https://swarm.workshop.perforce.com/changes/22256
            p4karl Karl Wirth made changes -
            Status Open [ 1 ] Resolved [ 5 ]
            Assignee Karl Wirth [ p4karl ]
            Resolution Fixed [ 1 ]
            p4paul Paul Allen made changes -
            Status Resolved [ 5 ] Closed [ 6 ]
            sean_sutherland Sean Sutherland made changes -
            Link This issue is related to JENKINS-55209 [ JENKINS-55209 ]

              People

              • Assignee:
                p4karl Karl Wirth
                Reporter:
                t_rex Oleksii Trekhov
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: