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

Exceptions when communicating with Perforce "No output for:" (probably slave-only)

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Component/s: perforce-plugin
    • Labels:
      None
    • Environment:
      Hudson 1.379, Perforce plugin 1.1.9

      Description

      I've seen a number of problems communicating with Perforce since upgrading to 1.1.9.
      The build log mentions "No output for: " and then a perforce command (e.g. counter/workspace). The build then fails.
      Usually the next build succeeds.
      See attached file.

      I've only seen it on slaves, i.e. remote clients.

      1. 2010-10-05-p4-no-output.txt
        2 kB
        torbent
      2. HUDSON-7664.diff
        2 kB
        Kohsuke Kawaguchi
      3. perforce.hpi
        295 kB
        Kohsuke Kawaguchi
      4. perforce-rpetti-54.hpi
        299 kB
        Rob Petti
      5. perforce-rpetti-58.hpi
        305 kB
        Rob Petti

        Issue Links

          Activity

          Hide
          rpetti Rob Petti added a comment -

          Do you actually have '::' in the client name? I don't think that's valid.

          Show
          rpetti Rob Petti added a comment - Do you actually have '::' in the client name? I don't think that's valid.
          Hide
          torbent torbent added a comment -

          Yes, I actually have '::' in the client name. We have that in (virtually) all our client names, and Perforce seems quite happy with that

          Show
          torbent torbent added a comment - Yes, I actually have '::' in the client name. We have that in (virtually) all our client names, and Perforce seems quite happy with that
          Hide
          rpetti Rob Petti added a comment -

          It doesn't seem very happy to me. =O

          There weren't any changes made to the tek42 stuff in 1.1.9, so I can't see how the upgrade might have caused this to break.

          Show
          rpetti Rob Petti added a comment - It doesn't seem very happy to me. =O There weren't any changes made to the tek42 stuff in 1.1.9, so I can't see how the upgrade might have caused this to break.
          Hide
          torbent torbent added a comment -

          Any suggestions for me, then?
          I know you've fixed some stuff concerning names of remote clients - I was thinking this might be related, perhaps vaguely?
          I've only seen this problem happen for builds on a slave (remote clients), but not all of those have used parameter substitution on their names. One of them did, the other 3-4 didn't.

          I think I actually deleted the extracted plugin subdirs this time before/during the upgrade, so there shouldn't be any conflicts with leftover code.

          Show
          torbent torbent added a comment - Any suggestions for me, then? I know you've fixed some stuff concerning names of remote clients - I was thinking this might be related, perhaps vaguely? I've only seen this problem happen for builds on a slave (remote clients), but not all of those have used parameter substitution on their names. One of them did, the other 3-4 didn't. I think I actually deleted the extracted plugin subdirs this time before/during the upgrade, so there shouldn't be any conflicts with leftover code.
          Hide
          rpetti Rob Petti added a comment -

          I would downgrade temporarily to see if the issue persists. It definitely looks like an environment issue to me, likely something to do with your connection to the slaves or to the perforce server.

          I've also got a CI build at http://www.drikanis.org/hudson/target/perforce.hpi that has some unrelated fixes you could try, but as with this last release, the code dealing with the tek42 interface has not been changed.

          Show
          rpetti Rob Petti added a comment - I would downgrade temporarily to see if the issue persists. It definitely looks like an environment issue to me, likely something to do with your connection to the slaves or to the perforce server. I've also got a CI build at http://www.drikanis.org/hudson/target/perforce.hpi that has some unrelated fixes you could try, but as with this last release, the code dealing with the tek42 interface has not been changed.
          Hide
          torbent torbent added a comment -

          I'll check the servers tomorrow. The slave machine did have a crash the other day, so perhaps it's not entirely well.

          Show
          torbent torbent added a comment - I'll check the servers tomorrow. The slave machine did have a crash the other day, so perhaps it's not entirely well.
          Hide
          rpetti Rob Petti added a comment -

          I don't suppose anyone who can reproduce this problem has the ability to build the perforce plugin? We may have to bisect the changes between 1.1.8 and 1.1.9 to see what is causing this. If not, I can provide a set of builds that you can test.

          Show
          rpetti Rob Petti added a comment - I don't suppose anyone who can reproduce this problem has the ability to build the perforce plugin? We may have to bisect the changes between 1.1.8 and 1.1.9 to see what is causing this. If not, I can provide a set of builds that you can test.
          Hide
          torbent torbent added a comment -

          No, I can't build plugins. I would be willing to test builds for you if that would help, and it fits your timezone (I'm in UTC+2 at the moment). I'm still seeing it happen from time to time, although mainly when the company is "busy" (vague term defined as many builds in Hudson and supposedly much activity on the perforce server(s)).
          Perhaps some (default?) value for timeout has changed?

          Show
          torbent torbent added a comment - No, I can't build plugins. I would be willing to test builds for you if that would help, and it fits your timezone (I'm in UTC+2 at the moment). I'm still seeing it happen from time to time, although mainly when the company is "busy" (vague term defined as many builds in Hudson and supposedly much activity on the perforce server(s)). Perhaps some (default?) value for timeout has changed?
          Hide
          swoyde swoyde added a comment - - edited

          I have downgraded to perforce plugin to 1.1.8. That seemed to work for a while, but in the meantime the builds fail again.

          In my scenarion I ugraded from hudson 1.346 with perforce plugin 1.1.8 to hudson 1.379 with perforce plugin 1.1.9. Downgrading the perforce plugin did not help. Unfortunately I don't think I can easily downgrade the hudson version, since I suppose the configuration file format changed.

          (More details in JENKINS-7700)

          Show
          swoyde swoyde added a comment - - edited I have downgraded to perforce plugin to 1.1.8. That seemed to work for a while, but in the meantime the builds fail again. In my scenarion I ugraded from hudson 1.346 with perforce plugin 1.1.8 to hudson 1.379 with perforce plugin 1.1.9. Downgrading the perforce plugin did not help. Unfortunately I don't think I can easily downgrade the hudson version, since I suppose the configuration file format changed. (More details in JENKINS-7700 )
          Hide
          torbent torbent added a comment -

          I only went from Hudson 1.375 via 1.378 (for an hour or so) to 1.379.
          There has been some work on the master/slave communication, as far as I remember ... ?

          Show
          torbent torbent added a comment - I only went from Hudson 1.375 via 1.378 (for an hour or so) to 1.379. There has been some work on the master/slave communication, as far as I remember ... ?
          Hide
          rpetti Rob Petti added a comment -

          Yeah, looks like 1.378 and 1.379 had some 'fixes' for master-slave communication.

          Show
          rpetti Rob Petti added a comment - Yeah, looks like 1.378 and 1.379 had some 'fixes' for master-slave communication.
          Hide
          rpetti Rob Petti added a comment -

          torbent, did you notice if the problem existed in 1.378?

          Show
          rpetti Rob Petti added a comment - torbent, did you notice if the problem existed in 1.378?
          Hide
          torbent torbent added a comment -

          Sorry, no. I only ran 1.378 for a short while - I read here in Jira that artifact archiving was prone to hanging, and sure enough it did so on my first build ... so I upgraded quickly to 1.379 which was out at that time.
          Would downgrading to 1.377 even be possible? I could try that. I'll check the changelog for any new features that I use already. Downgrading the p4 plugin won't be easy

          Show
          torbent torbent added a comment - Sorry, no. I only ran 1.378 for a short while - I read here in Jira that artifact archiving was prone to hanging, and sure enough it did so on my first build ... so I upgraded quickly to 1.379 which was out at that time. Would downgrading to 1.377 even be possible? I could try that. I'll check the changelog for any new features that I use already. Downgrading the p4 plugin won't be easy
          Hide
          torbent torbent added a comment -

          Seems OK to downgrade to 1.377. I'll do so first thing tomorrow morning and keep a sharp eye out for problems.

          Show
          torbent torbent added a comment - Seems OK to downgrade to 1.377. I'll do so first thing tomorrow morning and keep a sharp eye out for problems.
          Hide
          rpetti Rob Petti added a comment -

          You might want to hold off on that, and I'll try and reproduce the issue on my end first. Since the problem seems intermittent, you can probably set the "Retry Count" option in Advanced Project Options so hudson will try a couple times to checkout before giving up. At least then you can go about your business without too much trouble until we can get this fixed.

          Show
          rpetti Rob Petti added a comment - You might want to hold off on that, and I'll try and reproduce the issue on my end first. Since the problem seems intermittent, you can probably set the "Retry Count" option in Advanced Project Options so hudson will try a couple times to checkout before giving up. At least then you can go about your business without too much trouble until we can get this fixed.
          Hide
          torbent torbent added a comment -

          OK, will do. I had completely forgotten the "Retry Count"; will see if that helps.
          Will that handle problems with "p4 workspace", "p4 counter", etc, as well?

          Show
          torbent torbent added a comment - OK, will do. I had completely forgotten the "Retry Count"; will see if that helps. Will that handle problems with "p4 workspace", "p4 counter", etc, as well?
          Hide
          swoyde swoyde added a comment -

          I downgraded hudson to 1.377. I get lots of error messages at startup, but it seems to work.

          I still see

           WARN perforce - Perforce process terminated suddenly
           WARN perforce - java.io.IOException: Write end dead
          

          in the hudson.log, but I have not seen any builds failing as with 1.379.
          So my current setup is 1.377 with perforce plugin 1.1.8

          Show
          swoyde swoyde added a comment - I downgraded hudson to 1.377. I get lots of error messages at startup, but it seems to work. I still see WARN perforce - Perforce process terminated suddenly WARN perforce - java.io.IOException: Write end dead in the hudson.log, but I have not seen any builds failing as with 1.379. So my current setup is 1.377 with perforce plugin 1.1.8
          Hide
          torbent torbent added a comment -

          Increasing the Retry Count (to 3) has helped for me. I've seen it retry on a number of builds, but never more than once for the same build.
          So the problem is still there somewhere, even if I can mask out its symptoms

          Show
          torbent torbent added a comment - Increasing the Retry Count (to 3) has helped for me. I've seen it retry on a number of builds, but never more than once for the same build. So the problem is still there somewhere, even if I can mask out its symptoms
          Hide
          oeuftete oeuftete added a comment -

          I saw this as well ("No output for...") going from 1.376 to 1.380. Rolling back to 1.376 made the problem go away.

          Upping the retries sort of made it tolerable without rolling back, except the "workspace" commands when polling seem to be only tried once, and if they get no output, a build is triggered. So our slaves were getting swamped with builds that had no changes.

          Show
          oeuftete oeuftete added a comment - I saw this as well ("No output for...") going from 1.376 to 1.380. Rolling back to 1.376 made the problem go away. Upping the retries sort of made it tolerable without rolling back, except the "workspace" commands when polling seem to be only tried once, and if they get no output, a build is triggered. So our slaves were getting swamped with builds that had no changes.
          Hide
          vtintillier vtintillier added a comment -

          Does it only affects builds on slaves, also with a master only Hudson?

          Show
          vtintillier vtintillier added a comment - Does it only affects builds on slaves, also with a master only Hudson?
          Hide
          rpetti Rob Petti added a comment -

          Yes, we believe it only affects slaves.

          – Posted from Bugbox for Android

          Show
          rpetti Rob Petti added a comment - Yes, we believe it only affects slaves. – Posted from Bugbox for Android
          Hide
          mstave mstave added a comment -

          Risking muddying the waters with duplicate info, on the chance this might help you debug...

          With 1.379 / 1.1.10 intermittently seeing on slaves

          Caught exception communicating with perforce. No output for: p4 -P 081D60BBE62A54C109493A7A6329B84D describe -s 114822 com.tek42.perforce.PerforceException: No output for: p4 -P 081D60BBE62A54C109493A7A6329B84D describe -s 114822
          at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341)
          at com.tek42.perforce.parse.Changes.getChangelist(Changes.java:63)
          at com.tek42.perforce.parse.Changes.getChangelistsFromNumbers(Changes.java:381)
          at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:552)
          at hudson.model.AbstractProject.checkout(AbstractProject.java:1082)
          at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:479)
          at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:411)
          at hudson.model.Run.run(Run.java:1280)
          at hudson.matrix.MatrixRun.run(MatrixRun.java:137)
          at hudson.model.ResourceController.execute(ResourceController.java:88)
          at hudson.model.Executor.run(Executor.java:137)

          Show
          mstave mstave added a comment - Risking muddying the waters with duplicate info, on the chance this might help you debug... With 1.379 / 1.1.10 intermittently seeing on slaves Caught exception communicating with perforce. No output for: p4 -P 081D60BBE62A54C109493A7A6329B84D describe -s 114822 com.tek42.perforce.PerforceException: No output for: p4 -P 081D60BBE62A54C109493A7A6329B84D describe -s 114822 at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341) at com.tek42.perforce.parse.Changes.getChangelist(Changes.java:63) at com.tek42.perforce.parse.Changes.getChangelistsFromNumbers(Changes.java:381) at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:552) at hudson.model.AbstractProject.checkout(AbstractProject.java:1082) at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:479) at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:411) at hudson.model.Run.run(Run.java:1280) at hudson.matrix.MatrixRun.run(MatrixRun.java:137) at hudson.model.ResourceController.execute(ResourceController.java:88) at hudson.model.Executor.run(Executor.java:137)
          Hide
          rpetti Rob Petti added a comment -

          I was able to reproduce this behavior for 1.378-1.380. I tested with perforce plugin 1.1.8 and 1.1.10 with the same results, so it doesn't seem related to any plugin changes.

          The root cause is being sent to the hudson server log. I've opened a new issue (JENKINS-7809) against core, since this seems to be a problem with the remoting api changes made in 1.378. I'll continue to search for a work-around (especially for polling) but until then try not to upgrade past 1.377 if you can help it. Users who don't need polling can use torbent's Retry Count work-around.

          Show
          rpetti Rob Petti added a comment - I was able to reproduce this behavior for 1.378-1.380. I tested with perforce plugin 1.1.8 and 1.1.10 with the same results, so it doesn't seem related to any plugin changes. The root cause is being sent to the hudson server log. I've opened a new issue ( JENKINS-7809 ) against core, since this seems to be a problem with the remoting api changes made in 1.378. I'll continue to search for a work-around (especially for polling) but until then try not to upgrade past 1.377 if you can help it. Users who don't need polling can use torbent's Retry Count work-around.
          Hide
          torbent torbent added a comment -

          Thank you. I'll downgrade to 1.377 for the time being; I'll risk JENKINS-5977 over the current situation ...

          Show
          torbent torbent added a comment - Thank you. I'll downgrade to 1.377 for the time being; I'll risk JENKINS-5977 over the current situation ...
          Hide
          lkishalmi lkishalmi added a comment -

          It looks like that HudsonPipedOutputStream closes the stream before it can get processed. this caused by the new threading model between of channel communication introduced in 1.378-1.379.

          If we put a static sleep (1s) before the close then the no output problem has occurred rarely. Unfortunately this naive patch did not fix P4 vs Hudson issue. It created a new issue when Hudson is trying to setup P4 workspaces.

          Show
          lkishalmi lkishalmi added a comment - It looks like that HudsonPipedOutputStream closes the stream before it can get processed. this caused by the new threading model between of channel communication introduced in 1.378-1.379. If we put a static sleep (1s) before the close then the no output problem has occurred rarely. Unfortunately this naive patch did not fix P4 vs Hudson issue. It created a new issue when Hudson is trying to setup P4 workspaces.
          Hide
          scm_issue_link SCM/JIRA link daemon added a comment -

          Code changed in hudson
          User: : rpetti
          Path:
          trunk/hudson/plugins/perforce/src/main/java/hudson/plugins/perforce/HudsonPipedOutputStream.java
          http://jenkins-ci.org/commit/36985
          Log:
          JENKINS-7664 committing potential fix for errors caused by misbehaving remote api.

          Show
          scm_issue_link SCM/JIRA link daemon added a comment - Code changed in hudson User: : rpetti Path: trunk/hudson/plugins/perforce/src/main/java/hudson/plugins/perforce/HudsonPipedOutputStream.java http://jenkins-ci.org/commit/36985 Log: JENKINS-7664 committing potential fix for errors caused by misbehaving remote api.
          Hide
          lkishalmi lkishalmi added a comment -

          Wow. We dug ourselves so desperately into how the threading is done after 378-379 that we not even thought of flushing the stream! Thanks pointing that out! I've put the patch into production on our Hudson farm and it seems that it has passed our first tests.

          Show
          lkishalmi lkishalmi added a comment - Wow. We dug ourselves so desperately into how the threading is done after 378-379 that we not even thought of flushing the stream! Thanks pointing that out! I've put the patch into production on our Hudson farm and it seems that it has passed our first tests.
          Hide
          lkishalmi lkishalmi added a comment -

          I'm glad to announce that our heavy duty Hudson grid works well now with Perforce and 25 nodes stable without any error during the last day with the patch applied. I vote for release!

          Show
          lkishalmi lkishalmi added a comment - I'm glad to announce that our heavy duty Hudson grid works well now with Perforce and 25 nodes stable without any error during the last day with the patch applied. I vote for release!
          Hide
          rpetti Rob Petti added a comment -

          That's awesome to hear, lkishalmi! Thanks for putting it through it's paces. I'll close the bug and run a release right now.

          Show
          rpetti Rob Petti added a comment - That's awesome to hear, lkishalmi! Thanks for putting it through it's paces. I'll close the bug and run a release right now.
          Hide
          lkishalmi lkishalmi added a comment -

          I'm sorry to say, but I was too euphoric after the first day success. Unfortunately we still see this issue as random encounter. However it's far less frequent than before, so it worth a release anyway. So I believe that JENKINS-7809 is a different issue than flushing and are responsible for the rest.

          Show
          lkishalmi lkishalmi added a comment - I'm sorry to say, but I was too euphoric after the first day success. Unfortunately we still see this issue as random encounter. However it's far less frequent than before, so it worth a release anyway. So I believe that JENKINS-7809 is a different issue than flushing and are responsible for the rest.
          Hide
          kohsuke Kohsuke Kawaguchi added a comment -

          My proposed fix and the binary attached.

          I suspect the issue is caused by the use of PipedInput/OutputStream, which has various known issues (such as a requirement that writer/reader be always the same thread.) The proposed patch fixes that.

          If people seeing this problem can try the binary and report back their experience, that would be greatly appreciated.

          Show
          kohsuke Kohsuke Kawaguchi added a comment - My proposed fix and the binary attached. I suspect the issue is caused by the use of PipedInput/OutputStream, which has various known issues (such as a requirement that writer/reader be always the same thread.) The proposed patch fixes that. If people seeing this problem can try the binary and report back their experience, that would be greatly appreciated.
          Hide
          duckyd duckyd added a comment - - edited

          I have a dev instance of Hudson that I tried the fix out on, and it looked like it worked A-OK! I've put the new plugin (and an upgraded Hudson .war) in place in our production Hudson environment. We have a large number of builds using Perforce and about 10 build nodes - I haven't seen any problems so far. I'll give it a few days to bake and post an update.

          Thanks!!

          Show
          duckyd duckyd added a comment - - edited I have a dev instance of Hudson that I tried the fix out on, and it looked like it worked A-OK! I've put the new plugin (and an upgraded Hudson .war) in place in our production Hudson environment. We have a large number of builds using Perforce and about 10 build nodes - I haven't seen any problems so far. I'll give it a few days to bake and post an update. Thanks!!
          Hide
          lkishalmi lkishalmi added a comment -

          We've just gave 1.1.12-SNAPSHOT (private-11/23/2010 03:13-kohsuke) a chance. Unfortunately it seems not solving this stream truncation issue.

          Show
          lkishalmi lkishalmi added a comment - We've just gave 1.1.12-SNAPSHOT (private-11/23/2010 03:13-kohsuke) a chance. Unfortunately it seems not solving this stream truncation issue.
          Hide
          jchristi jchristi added a comment - - edited

          At first glance, 1.1.12-SNAPSHOT (private-11/23/2010 03:13-kohsuke) seems to have fixed my issues, at least from my log file perspective I do not see any "WARN perforce - java.io.IOException: Write end dead" messages anymore. I have no slaves, just a master.

          I did see one exception that may have been caused by the fix:

          5576473 [Handling GET /scm/PerforceSCM/checkChangeList : RequestHandlerThread1] INFO perforce - Executing: /usr/local/bin/p4 counter change
          Nov 28, 2010 9:36:00 PM hudson.plugins.perforce.PerforceSCM processWorkspaceBeforeDeletion
          INFO: Workspace is being deleted; enabling one-time force sync.
          Problem: Connect to server failed; check $P4PORT
          com.tek42.perforce.PerforceException: Connect to server failed; check $P4PORT
          at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:339)
          at com.tek42.perforce.parse.Changes.getChangeNumbers(Changes.java:137)
          at hudson.plugins.perforce.PerforceSCM.needToBuild(PerforceSCM.java:897)
          at hudson.plugins.perforce.PerforceSCM.pollChanges(PerforceSCM.java:793)
          at hudson.scm.SCM.poll(SCM.java:373)
          at hudson.model.AbstractProject.poll(AbstractProject.java:1237)
          at hudson.triggers.SCMTrigger$Runner.runPolling(SCMTrigger.java:425)
          at hudson.triggers.SCMTrigger$Runner.run(SCMTrigger.java:454)
          at hudson.util.SequentialExecutionQueue$QueueEntry.run(SequentialExecutionQueue.java:118)

          Show
          jchristi jchristi added a comment - - edited At first glance, 1.1.12-SNAPSHOT (private-11/23/2010 03:13-kohsuke) seems to have fixed my issues, at least from my log file perspective I do not see any "WARN perforce - java.io.IOException: Write end dead" messages anymore. I have no slaves, just a master. I did see one exception that may have been caused by the fix: 5576473 [Handling GET /scm/PerforceSCM/checkChangeList : RequestHandlerThread 1 ] INFO perforce - Executing: /usr/local/bin/p4 counter change Nov 28, 2010 9:36:00 PM hudson.plugins.perforce.PerforceSCM processWorkspaceBeforeDeletion INFO: Workspace is being deleted; enabling one-time force sync. Problem: Connect to server failed; check $P4PORT com.tek42.perforce.PerforceException: Connect to server failed; check $P4PORT at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:339) at com.tek42.perforce.parse.Changes.getChangeNumbers(Changes.java:137) at hudson.plugins.perforce.PerforceSCM.needToBuild(PerforceSCM.java:897) at hudson.plugins.perforce.PerforceSCM.pollChanges(PerforceSCM.java:793) at hudson.scm.SCM.poll(SCM.java:373) at hudson.model.AbstractProject.poll(AbstractProject.java:1237) at hudson.triggers.SCMTrigger$Runner.runPolling(SCMTrigger.java:425) at hudson.triggers.SCMTrigger$Runner.run(SCMTrigger.java:454) at hudson.util.SequentialExecutionQueue$QueueEntry.run(SequentialExecutionQueue.java:118)
          Hide
          duckyd duckyd added a comment - - edited

          I also no longer have "Write end dead" messages from perforce in my Hudson logs. It looks like builds have been working w/o any problems since installing the new perforce plugin. I do have messages in my logs like below, but they seem to be benign:

          Problem: No output for: /var/hudson/bin/p4 changes -m 2 //JobName--1660205398/... 
          com.tek42.perforce.PerforceException: No output for: /var/hudson/bin/p4 changes -m 2 //JobName--16
                at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341)
                at com.tek42.perforce.parse.Changes.getChangeNumbers(Changes.java:137)
                at hudson.plugins.perforce.PerforceSCM.needToBuild(PerforceSCM.java:897)
                at hudson.plugins.perforce.PerforceSCM.pollChanges(PerforceSCM.java:793)
                at hudson.scm.SCM.poll(SCM.java:373)      
                at hudson.model.AbstractProject.poll(AbstractProject.java:1237)
                at hudson.triggers.SCMTrigger$Runner.runPolling(SCMTrigger.java:425)
                at hudson.triggers.SCMTrigger$Runner.run(SCMTrigger.java:454)
                at hudson.util.SequentialExecutionQueue$QueueEntry.run(SequentialExecutionQueue.java:118)
                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
                at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
                at java.util.concurrent.FutureTask.run(FutureTask.java:138)
                at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
                at java.lang.Thread.run(Thread.java:619)  
          Nov 23, 2010 4:11:30 PM hudson.remoting.ProxyOutputStream$Chunk$1 run
          WARNING: Failed to write to stream
          java.io.IOException: Pipe is already closed
                at hudson.remoting.FastPipedOutputStream.write(FastPipedOutputStream.java:147)
                at hudson.remoting.FastPipedOutputStream.write(FastPipedOutputStream.java:131)
                at hudson.util.DelegatingOutputStream.write(DelegatingOutputStream.java:51)
                at hudson.remoting.ProxyOutputStream$Chunk$1.run(ProxyOutputStream.java:185)
                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
                at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
                at java.util.concurrent.FutureTask.run(FutureTask.java:138)
                at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
                at java.lang.Thread.run(Thread.java:619)  
          Caused by: hudson.remoting.FastPipedInputStream$ClosedBy: The pipe was closed at...
                at hudson.remoting.FastPipedOutputStream.close(FastPipedOutputStream.java:94)
                at hudson.plugins.perforce.HudsonPipedOutputStream$1.run(HudsonPipedOutputStream.java:43)
                ... 1 more
          
          Show
          duckyd duckyd added a comment - - edited I also no longer have "Write end dead" messages from perforce in my Hudson logs. It looks like builds have been working w/o any problems since installing the new perforce plugin. I do have messages in my logs like below, but they seem to be benign: Problem: No output for: /var/hudson/bin/p4 changes -m 2 //JobName--1660205398/... com.tek42.perforce.PerforceException: No output for: /var/hudson/bin/p4 changes -m 2 //JobName--16 at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341) at com.tek42.perforce.parse.Changes.getChangeNumbers(Changes.java:137) at hudson.plugins.perforce.PerforceSCM.needToBuild(PerforceSCM.java:897) at hudson.plugins.perforce.PerforceSCM.pollChanges(PerforceSCM.java:793) at hudson.scm.SCM.poll(SCM.java:373) at hudson.model.AbstractProject.poll(AbstractProject.java:1237) at hudson.triggers.SCMTrigger$Runner.runPolling(SCMTrigger.java:425) at hudson.triggers.SCMTrigger$Runner.run(SCMTrigger.java:454) at hudson.util.SequentialExecutionQueue$QueueEntry.run(SequentialExecutionQueue.java:118) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619) Nov 23, 2010 4:11:30 PM hudson.remoting.ProxyOutputStream$Chunk$1 run WARNING: Failed to write to stream java.io.IOException: Pipe is already closed at hudson.remoting.FastPipedOutputStream.write(FastPipedOutputStream.java:147) at hudson.remoting.FastPipedOutputStream.write(FastPipedOutputStream.java:131) at hudson.util.DelegatingOutputStream.write(DelegatingOutputStream.java:51) at hudson.remoting.ProxyOutputStream$Chunk$1.run(ProxyOutputStream.java:185) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619) Caused by: hudson.remoting.FastPipedInputStream$ClosedBy: The pipe was closed at... at hudson.remoting.FastPipedOutputStream.close(FastPipedOutputStream.java:94) at hudson.plugins.perforce.HudsonPipedOutputStream$1.run(HudsonPipedOutputStream.java:43) ... 1 more
          Hide
          rpetti Rob Petti added a comment -

          @duckyd: Unless there are no files in your view spec, this is the exact same problem the bug is describing.

          @jchristi: "Connect to server failed; check $P4PORT" is an error message from the p4 client, so the plugin is able to receive output through the pipe without any issues. The error message is likely because your perforce server has become unavailable temporarily for whatever reason. I don't believe it has anything to do with this issue, or kohsuke's patch.

          Show
          rpetti Rob Petti added a comment - @duckyd: Unless there are no files in your view spec, this is the exact same problem the bug is describing. @jchristi: "Connect to server failed; check $P4PORT" is an error message from the p4 client, so the plugin is able to receive output through the pipe without any issues. The error message is likely because your perforce server has become unavailable temporarily for whatever reason. I don't believe it has anything to do with this issue, or kohsuke's patch.
          Hide
          duckyd duckyd added a comment -

          @rpetti the error (in the logs) I'm seeing currently isn't causing builds to fail. The error that I was getting, which caused builds to fail (and which appears to be fixed) was:

          Caught exception communicating with perforce. No output for: /usr/local/bin/p4 workspace -o JobName-612004424 com.tek42.perforce.PerforceException: No output for: /usr/local/bin/p4 workspace -o JobName-612004424     at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341)
              at com.tek42.perforce.parse.Workspaces.getWorkspace(Workspaces.java:53)
              at hudson.plugins.perforce.PerforceSCM.getPerforceWorkspace(PerforceSCM.java:992)
              at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:504)
              at hudson.model.AbstractProject.checkout(AbstractProject.java:1119)
              at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:480)
              at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:412)
              at hudson.model.Run.run(Run.java:1325)
              at hudson.maven.MavenModuleSetBuild.run(MavenModuleSetBuild.java:293)
              at hudson.model.ResourceController.execute(ResourceController.java:88)
              at hudson.model.Executor.run(Executor.java:139)
          ERROR: Unable to communicate with perforce. No output for: /usr/local/bin/p4 workspace -o JobName-612004424 
          
          Show
          duckyd duckyd added a comment - @rpetti the error (in the logs) I'm seeing currently isn't causing builds to fail. The error that I was getting, which caused builds to fail (and which appears to be fixed) was: Caught exception communicating with perforce. No output for: /usr/local/bin/p4 workspace -o JobName-612004424 com.tek42.perforce.PerforceException: No output for: /usr/local/bin/p4 workspace -o JobName-612004424 at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341) at com.tek42.perforce.parse.Workspaces.getWorkspace(Workspaces.java:53) at hudson.plugins.perforce.PerforceSCM.getPerforceWorkspace(PerforceSCM.java:992) at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:504) at hudson.model.AbstractProject.checkout(AbstractProject.java:1119) at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:480) at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:412) at hudson.model.Run.run(Run.java:1325) at hudson.maven.MavenModuleSetBuild.run(MavenModuleSetBuild.java:293) at hudson.model.ResourceController.execute(ResourceController.java:88) at hudson.model.Executor.run(Executor.java:139) ERROR: Unable to communicate with perforce. No output for: /usr/local/bin/p4 workspace -o JobName-612004424
          Hide
          rpetti Rob Petti added a comment -

          The error "No output for: /usr/local/bin/p4" is the underlying cause, and affects all perforce commands run. It just happens to not be failing during p4 sync for you so far.

          Show
          rpetti Rob Petti added a comment - The error "No output for: /usr/local/bin/p4" is the underlying cause, and affects all perforce commands run. It just happens to not be failing during p4 sync for you so far.
          Hide
          duckyd duckyd added a comment -

          @rpetti I see. Thankfully, it doesn't appear to cause build to fail, which is a significant improvement. Prior to the fix, it was unusable (we had to revert to an earlier version of Hudson & the perforce plugin)

          Show
          duckyd duckyd added a comment - @rpetti I see. Thankfully, it doesn't appear to cause build to fail, which is a significant improvement. Prior to the fix, it was unusable (we had to revert to an earlier version of Hudson & the perforce plugin)
          Hide
          rpetti Rob Petti added a comment -

          All it's done is reduce the frequency of the problem... I'm betting you will still see failed builds in the future.

          Show
          rpetti Rob Petti added a comment - All it's done is reduce the frequency of the problem... I'm betting you will still see failed builds in the future.
          Hide
          avolanis avolanis added a comment -

          I have the exact same issue after upgrading from version 1.1.1 to 1.1.12. That is a large span of versions but I did a full Hudson upgrade this past weekend to the latest 1.387 and this seemed like a good time to try the new version of the p4 plugin. There have been no changes to the jobs since the upgrade and all is OK except for this error happening several times since then. The previous version 1.1.1 had never shown this error at all for months. It was very reliable in all aspects.

          I see this in Ubuntu, CentOS, Windows Server 64bit slaves. All exactly the same with the same exception. This sometimes passes with a few retries but it happens almost every build. It is just an unlucky coincidence when it passes with retries than fails completely.

          I am not sure if I could downgrade and how far back I would be able to get this to be back in stable mode.

          Any hints as to the root cause of this?

          Show
          avolanis avolanis added a comment - I have the exact same issue after upgrading from version 1.1.1 to 1.1.12. That is a large span of versions but I did a full Hudson upgrade this past weekend to the latest 1.387 and this seemed like a good time to try the new version of the p4 plugin. There have been no changes to the jobs since the upgrade and all is OK except for this error happening several times since then. The previous version 1.1.1 had never shown this error at all for months. It was very reliable in all aspects. I see this in Ubuntu, CentOS, Windows Server 64bit slaves. All exactly the same with the same exception. This sometimes passes with a few retries but it happens almost every build. It is just an unlucky coincidence when it passes with retries than fails completely. I am not sure if I could downgrade and how far back I would be able to get this to be back in stable mode. Any hints as to the root cause of this?
          Hide
          avolanis avolanis added a comment -

          FYI, you may remember I could build this plugin and try it out if that helps. I have not done it in some time because it has been very stable but it would be worth a try. Do you have any pointers as to what I should be looking for? It is very reproducible in my environment.

          Show
          avolanis avolanis added a comment - FYI, you may remember I could build this plugin and try it out if that helps. I have not done it in some time because it has been very stable but it would be worth a try. Do you have any pointers as to what I should be looking for? It is very reproducible in my environment.
          Hide
          rpetti Rob Petti added a comment -

          As mentioned in the comments above, this is an issue in hudson that was introduced in 1.378 that has yet to be fixed. Apart from the workarounds suggested, you have no option but to either deal with the random failures, or downgrade to 1.377.

          Show
          rpetti Rob Petti added a comment - As mentioned in the comments above, this is an issue in hudson that was introduced in 1.378 that has yet to be fixed. Apart from the workarounds suggested, you have no option but to either deal with the random failures, or downgrade to 1.377.
          Hide
          avolanis avolanis added a comment -

          I tried the binary patch provided by kohsuke and it seems to have fixed all issues. I am now running Hudson 1.387 with the 1.1.12-SNAPSHOT (private-11/23/2010 03:13-kohsuke) with 10 slaves and all the errors are gone. Builds are happy again.

          Show
          avolanis avolanis added a comment - I tried the binary patch provided by kohsuke and it seems to have fixed all issues. I am now running Hudson 1.387 with the 1.1.12-SNAPSHOT (private-11/23/2010 03:13-kohsuke) with 10 slaves and all the errors are gone. Builds are happy again.
          Hide
          rpetti Rob Petti added a comment -

          Getting a lot of mixed reports about that patch... I still think there is a problem with the underlying remoting functions in hudson, but if there's even a slight chance of improvement, then it's probably worth committing at this point.

          Show
          rpetti Rob Petti added a comment - Getting a lot of mixed reports about that patch... I still think there is a problem with the underlying remoting functions in hudson, but if there's even a slight chance of improvement, then it's probably worth committing at this point.
          Hide
          avolanis avolanis added a comment -

          Yes, although initially the patch seemed to help the errors are back but the frequency is reduced. It does point to something related to the remoting functions.

          Show
          avolanis avolanis added a comment - Yes, although initially the patch seemed to help the errors are back but the frequency is reduced. It does point to something related to the remoting functions.
          Hide
          gordonmcgregor GordonMcGregor added a comment - - edited

          We recently upgraded to the new version of the Perforce plugin (v 1.1.13) and have experienced it locking up our Perforce server (requiring a restart). It looks like a client -i command never completes, holding a lock on the perforce side that then blocks all subsequent commands.

          Edit: Downgrading to 1.1.11 hasn't fixed the issue of the server locking with multiple, parallel 'client -i' commands. I thought it had, seems I was wrong - just took longer to lock up.

          Hudson version 1.392
          Perforce plug-in versions 1.1.13 and 1.1.11

          ../perforce > ./p4d -V
          Perforce - The Fast Software Configuration Management System.
          Copyright 1995-2010 Perforce Software. All rights reserved.
          Rev. P4D/SOLARIS10X86_64/2010.1/273938 (2010/11/16).

          Show
          gordonmcgregor GordonMcGregor added a comment - - edited We recently upgraded to the new version of the Perforce plugin (v 1.1.13) and have experienced it locking up our Perforce server (requiring a restart). It looks like a client -i command never completes, holding a lock on the perforce side that then blocks all subsequent commands. Edit: Downgrading to 1.1.11 hasn't fixed the issue of the server locking with multiple, parallel 'client -i' commands. I thought it had, seems I was wrong - just took longer to lock up. Hudson version 1.392 Perforce plug-in versions 1.1.13 and 1.1.11 ../perforce > ./p4d -V Perforce - The Fast Software Configuration Management System. Copyright 1995-2010 Perforce Software. All rights reserved. Rev. P4D/SOLARIS10X86_64/2010.1/273938 (2010/11/16).
          Hide
          rpetti Rob Petti added a comment -

          Gordon: please file a new issue. Your problem is substantially different from this one. In any case, I would recommend trying hudson 1.377, just in case the root cause is the same for both issues. Also ensure that the plugin is configured to use the raw p4 client binary, and not some wrapper script.

          Show
          rpetti Rob Petti added a comment - Gordon: please file a new issue. Your problem is substantially different from this one. In any case, I would recommend trying hudson 1.377, just in case the root cause is the same for both issues. Also ensure that the plugin is configured to use the raw p4 client binary, and not some wrapper script.
          Hide
          kohsuke Kohsuke Kawaguchi added a comment -

          As can be seen in the changelog, my patch made it into 1.1.13. For those of you who are still seeing a problem, please provide a stack trace so that we can better understand if the problem is still there or not.

          Show
          kohsuke Kohsuke Kawaguchi added a comment - As can be seen in the changelog, my patch made it into 1.1.13. For those of you who are still seeing a problem, please provide a stack trace so that we can better understand if the problem is still there or not.
          Hide
          torbent torbent added a comment - - edited

          So ... would it be worth it to try upgrading?
          We're still running core 1.377 and p4 plugin 1.1.10, waiting for this issue to be fixed. I might try upgrading, but I really don't want to end up with these problems again.
          Actually I haven't upgraded anything Hudson-y at all since October because of this.

          If I should upgrade, what kind of input from me would help most? Just upgrade the p4 plugin with core, see what happens, then later update core? Or all at once?

          Let me also note that I also saw problems with the Cobertura plugin, as mentioned in the core issue (JENKINS-7809). Is there also an update of that?

          Show
          torbent torbent added a comment - - edited So ... would it be worth it to try upgrading? We're still running core 1.377 and p4 plugin 1.1.10, waiting for this issue to be fixed. I might try upgrading, but I really don't want to end up with these problems again. Actually I haven't upgraded anything Hudson-y at all since October because of this. If I should upgrade, what kind of input from me would help most? Just upgrade the p4 plugin with core, see what happens, then later update core? Or all at once? Let me also note that I also saw problems with the Cobertura plugin, as mentioned in the core issue ( JENKINS-7809 ). Is there also an update of that?
          Hide
          rpetti Rob Petti added a comment -

          The latest perforce plugin should work just fine, it's only after upgrading hudson past 1.377 that the problem arises.

          With kohsuke's patch, I wasn't able to reproduce the problem, but then again the rate of failure without it was only 1-2% in my tests. Others have said that the problem is still there, and that it just happens less frequently.

          I doubt it's fully fixed, torbent, but if you want to help then you could try upgrading and providing a stack trace if the problem presents itself again. If your hudson deployment is mission critical, then you should probably stay at 1.377...

          Show
          rpetti Rob Petti added a comment - The latest perforce plugin should work just fine, it's only after upgrading hudson past 1.377 that the problem arises. With kohsuke's patch, I wasn't able to reproduce the problem, but then again the rate of failure without it was only 1-2% in my tests. Others have said that the problem is still there, and that it just happens less frequently. I doubt it's fully fixed, torbent, but if you want to help then you could try upgrading and providing a stack trace if the problem presents itself again. If your hudson deployment is mission critical, then you should probably stay at 1.377...
          Hide
          jonasbovin jonasbovin added a comment - - edited

          Here is an output using the latest 1.394 Hudson and latest Perforce Plugin 1.1.14. I hope that this will help speed up the resolution for the issue which has halted out upgrades since 1.374...

          Using remote perforce client: HudsonSlaveWebTestClient--1608677735
          [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" workspace -o HudsonSlaveWebTestClient--1608677735
          [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" login -p
          Caught exception communicating with perforce. No output for: C:\Program Files\Perforce\p4.exe -P Enter password: workspace -o HudsonSlaveWebTestClient--1608677735 com.tek42.perforce.PerforceException: No output for: C:\Program Files\Perforce\p4.exe -P Enter password: workspace -o HudsonSlaveWebTestClient--1608677735
          at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341)
          at com.tek42.perforce.parse.Workspaces.getWorkspace(Workspaces.java:53)
          at hudson.plugins.perforce.PerforceSCM.getPerforceWorkspace(PerforceSCM.java:1004)
          at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:518)
          at hudson.model.AbstractProject.checkout(AbstractProject.java:1171)
          at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:480)
          at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:412)
          at hudson.model.Run.run(Run.java:1362)
          at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
          at hudson.model.ResourceController.execute(ResourceController.java:88)
          at hudson.model.Executor.run(Executor.java:145)
          ERROR: Unable to communicate with perforce. No output for: C:\Program Files\Perforce\p4.exe -P Enter password: workspace -o HudsonSlaveWebTestClient--1608677735
          [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" -P "Enter password: " workspace -o HudsonSlaveWebTestClient--1608677735

          Show
          jonasbovin jonasbovin added a comment - - edited Here is an output using the latest 1.394 Hudson and latest Perforce Plugin 1.1.14. I hope that this will help speed up the resolution for the issue which has halted out upgrades since 1.374... Using remote perforce client: HudsonSlaveWebTestClient--1608677735 [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" workspace -o HudsonSlaveWebTestClient--1608677735 [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" login -p Caught exception communicating with perforce. No output for: C:\Program Files\Perforce\p4.exe -P Enter password: workspace -o HudsonSlaveWebTestClient--1608677735 com.tek42.perforce.PerforceException: No output for: C:\Program Files\Perforce\p4.exe -P Enter password: workspace -o HudsonSlaveWebTestClient--1608677735 at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341) at com.tek42.perforce.parse.Workspaces.getWorkspace(Workspaces.java:53) at hudson.plugins.perforce.PerforceSCM.getPerforceWorkspace(PerforceSCM.java:1004) at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:518) at hudson.model.AbstractProject.checkout(AbstractProject.java:1171) at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:480) at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:412) at hudson.model.Run.run(Run.java:1362) at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46) at hudson.model.ResourceController.execute(ResourceController.java:88) at hudson.model.Executor.run(Executor.java:145) ERROR: Unable to communicate with perforce. No output for: C:\Program Files\Perforce\p4.exe -P Enter password: workspace -o HudsonSlaveWebTestClient--1608677735 [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" -P "Enter password: " workspace -o HudsonSlaveWebTestClient--1608677735
          Hide
          rpetti Rob Petti added a comment -

          jonasbovin: How frequently does this occur? Your problem looks different...

          Show
          rpetti Rob Petti added a comment - jonasbovin: How frequently does this occur? Your problem looks different...
          Hide
          emmulator emmulator added a comment -

          We just upgraded to Hudson 1.394 and Perforce Plugin 1.1.14, and our builds are also starting to fail, for example:

          Using remote perforce client: hudson-main-member-e2e-957586325
          [build111_main] $ p4 workspace -o hudson-main-member-e2e-957586325
          Last sync'd change: 109895
          [build111_main] $ p4 counter change
          [build111_main] $ p4 -s changes //hudson-main-member-e2e-957586325/...@109896,@109913
          [build111_main] $ p4 describe -s 109913
          Caught exception communicating with perforce. No output for: p4 describe -s 109913 com.tek42.perforce.PerforceException: No output for: p4 describe -s 109913 
          	at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341)
          	at com.tek42.perforce.parse.Changes.getChangelist(Changes.java:63)
          	at com.tek42.perforce.parse.Changes.getChangelistsFromNumbers(Changes.java:389)
          	at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:566)
          	at hudson.model.AbstractProject.checkout(AbstractProject.java:1171)
          	at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:480)
          	at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:412)
          	at hudson.model.Run.run(Run.java:1362)
          	at hudson.matrix.MatrixRun.run(MatrixRun.java:137)
          	at hudson.model.ResourceController.execute(ResourceController.java:88)
          	at hudson.model.Executor.run(Executor.java:145)
          ERROR: Unable to communicate with perforce. No output for: p4 describe -s 109913 
          

          So far I've only seen this on 2 of the matrix builds, at a rate of about 1 in 20 configurations throwing this error.

          I also see a lot of this in the master hudson log:

          Jan 20, 2011 1:51:05 PM hudson.remoting.ProxyOutputStream$Chunk$1 run
          WARNING: Failed to write to stream
          java.io.IOException: Pipe is already closed
                  at hudson.remoting.FastPipedOutputStream.write(FastPipedOutputStream.java:147)
                  at hudson.remoting.FastPipedOutputStream.write(FastPipedOutputStream.java:131)
                  at hudson.util.DelegatingOutputStream.write(DelegatingOutputStream.java:51)
                  at hudson.remoting.ProxyOutputStream$Chunk$1.run(ProxyOutputStream.java:185)
                  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
                  at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
                  at java.util.concurrent.FutureTask.run(FutureTask.java:138)
                  at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
                  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
                  at java.lang.Thread.run(Thread.java:619)
          Caused by: hudson.remoting.FastPipedInputStream$ClosedBy: The pipe was closed at...
                  at hudson.remoting.FastPipedInputStream.close(FastPipedInputStream.java:112)
                  at sun.nio.cs.StreamDecoder.implClose(StreamDecoder.java:358)
                  at sun.nio.cs.StreamDecoder.close(StreamDecoder.java:173)
                  at java.io.InputStreamReader.close(InputStreamReader.java:182)
                  at java.io.BufferedReader.close(BufferedReader.java:497)
                  at com.tek42.perforce.parse.AbstractPerforceTemplate.saveToPerforce(AbstractPerforceTemplate.java:222)
                  at com.tek42.perforce.parse.Workspaces.saveWorkspace(Workspaces.java:68)
                  at hudson.plugins.perforce.PerforceSCM.saveWorkspaceIfDirty(PerforceSCM.java:1162)
                  at hudson.plugins.perforce.PerforceSCM.pollChanges(PerforceSCM.java:790)
                  at hudson.scm.SCM.poll(SCM.java:373)
                  at hudson.model.AbstractProject.poll(AbstractProject.java:1289)
                  at hudson.triggers.SCMTrigger$Runner.runPolling(SCMTrigger.java:420)
                  at hudson.triggers.SCMTrigger$Runner.run(SCMTrigger.java:449)
                  at hudson.util.SequentialExecutionQueue$QueueEntry.run(SequentialExecutionQueue.java:118)
                  ... 6 more
          

          Perforce client version is:
          Rev. P4/LINUX26X86_64/2010.1/265509 (2010/09/23).

          Server:
          Server version: P4D/LINUX26X86_64/2010.1/265509 (2010/09/23)

          Java Version:
          Java(TM) SE Runtime Environment (build 1.6.0_16-b01)
          Java HotSpot(TM) 64-Bit Server VM (build 14.2-b01, mixed mode)

          Show
          emmulator emmulator added a comment - We just upgraded to Hudson 1.394 and Perforce Plugin 1.1.14, and our builds are also starting to fail, for example: Using remote perforce client: hudson-main-member-e2e-957586325 [build111_main] $ p4 workspace -o hudson-main-member-e2e-957586325 Last sync'd change: 109895 [build111_main] $ p4 counter change [build111_main] $ p4 -s changes //hudson-main-member-e2e-957586325/...@109896,@109913 [build111_main] $ p4 describe -s 109913 Caught exception communicating with perforce. No output for: p4 describe -s 109913 com.tek42.perforce.PerforceException: No output for: p4 describe -s 109913 at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:341) at com.tek42.perforce.parse.Changes.getChangelist(Changes.java:63) at com.tek42.perforce.parse.Changes.getChangelistsFromNumbers(Changes.java:389) at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:566) at hudson.model.AbstractProject.checkout(AbstractProject.java:1171) at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:480) at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:412) at hudson.model.Run.run(Run.java:1362) at hudson.matrix.MatrixRun.run(MatrixRun.java:137) at hudson.model.ResourceController.execute(ResourceController.java:88) at hudson.model.Executor.run(Executor.java:145) ERROR: Unable to communicate with perforce. No output for: p4 describe -s 109913 So far I've only seen this on 2 of the matrix builds, at a rate of about 1 in 20 configurations throwing this error. I also see a lot of this in the master hudson log: Jan 20, 2011 1:51:05 PM hudson.remoting.ProxyOutputStream$Chunk$1 run WARNING: Failed to write to stream java.io.IOException: Pipe is already closed at hudson.remoting.FastPipedOutputStream.write(FastPipedOutputStream.java:147) at hudson.remoting.FastPipedOutputStream.write(FastPipedOutputStream.java:131) at hudson.util.DelegatingOutputStream.write(DelegatingOutputStream.java:51) at hudson.remoting.ProxyOutputStream$Chunk$1.run(ProxyOutputStream.java:185) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619) Caused by: hudson.remoting.FastPipedInputStream$ClosedBy: The pipe was closed at... at hudson.remoting.FastPipedInputStream.close(FastPipedInputStream.java:112) at sun.nio.cs.StreamDecoder.implClose(StreamDecoder.java:358) at sun.nio.cs.StreamDecoder.close(StreamDecoder.java:173) at java.io.InputStreamReader.close(InputStreamReader.java:182) at java.io.BufferedReader.close(BufferedReader.java:497) at com.tek42.perforce.parse.AbstractPerforceTemplate.saveToPerforce(AbstractPerforceTemplate.java:222) at com.tek42.perforce.parse.Workspaces.saveWorkspace(Workspaces.java:68) at hudson.plugins.perforce.PerforceSCM.saveWorkspaceIfDirty(PerforceSCM.java:1162) at hudson.plugins.perforce.PerforceSCM.pollChanges(PerforceSCM.java:790) at hudson.scm.SCM.poll(SCM.java:373) at hudson.model.AbstractProject.poll(AbstractProject.java:1289) at hudson.triggers.SCMTrigger$Runner.runPolling(SCMTrigger.java:420) at hudson.triggers.SCMTrigger$Runner.run(SCMTrigger.java:449) at hudson.util.SequentialExecutionQueue$QueueEntry.run(SequentialExecutionQueue.java:118) ... 6 more Perforce client version is: Rev. P4/LINUX26X86_64/2010.1/265509 (2010/09/23). Server: Server version: P4D/LINUX26X86_64/2010.1/265509 (2010/09/23) Java Version: Java(TM) SE Runtime Environment (build 1.6.0_16-b01) Java HotSpot(TM) 64-Bit Server VM (build 14.2-b01, mixed mode)
          Hide
          jonasbovin jonasbovin added a comment -

          rpetti: The reason it looks different is probably due to the fact that we use ticket based authentication - which means it always fails on login and never gets beyond that.

          With regards to frequency, this is output from an automated WebTest run through Hudson itself and I use it on the test environment server. It verifies the existence of the bug and fails every time it is run (@daily). Before this test passes we cannot upgrade beyond the current version.

          I hope this helps. Please feel free to inquire again.

          Show
          jonasbovin jonasbovin added a comment - rpetti: The reason it looks different is probably due to the fact that we use ticket based authentication - which means it always fails on login and never gets beyond that. With regards to frequency, this is output from an automated WebTest run through Hudson itself and I use it on the test environment server. It verifies the existence of the bug and fails every time it is run (@daily). Before this test passes we cannot upgrade beyond the current version. I hope this helps. Please feel free to inquire again.
          Hide
          jonasbovin jonasbovin added a comment -

          Looks like I jumped the gun earlier, when running it more frequently I can achieve as much as 80% successes and 20% "no output error".
          Hope this helps.

          Show
          jonasbovin jonasbovin added a comment - Looks like I jumped the gun earlier, when running it more frequently I can achieve as much as 80% successes and 20% "no output error". Hope this helps.
          Hide
          rpetti Rob Petti added a comment -

          If anyone still able to reproduce this problem would care to try the attached build. I've made a minor change that will hopefully do the trick. perforce-rpetti-54.hpi

          Show
          rpetti Rob Petti added a comment - If anyone still able to reproduce this problem would care to try the attached build. I've made a minor change that will hopefully do the trick. perforce-rpetti-54.hpi
          Hide
          jonasbovin jonasbovin added a comment - - edited

          rpetti: I've tried the perforce-rpetti-54.hpi on a 1.394 Hudson, but unfortunately it just hangs after:

          ...
          Using master perforce client: HudsonWebTestClient
          --[workspace] $ "C:\Program Files\Perforce\p4.exe" workspace -o HudsonWebTestClient

          never gets beyond the workspace command - usually what happens is that it fails - as it is not logged in and then issues the login statement an gets a ticket (see below):

          When using the 1.1.14 plugin which every now and then get 'No output...'
          Using master perforce client: HudsonWebTestClient
          --[workspace] $ "C:\Program Files\Perforce\p4.exe" workspace -o HudsonWebTestClient
          --[workspace] $ "C:\Program Files\Perforce\p4.exe" login -p
          --[workspace] $ "C:\Program Files\Perforce\p4.exe" -P 20DADC12CB3FEA1432C78D34E289BAB2 workspace -o HudsonWebTestClient
          Last sync'd change: 183801

          When I try to cancel the hanging job, it resumes next line as above on 1.1.14 plugin. This also affects non-slaves, master will also hang until job is canceled manually from Hudson web-interface.

          Using remote perforce client: HudsonSlaveWebTestClient--1608677735
          [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" workspace o HudsonSlaveWebTestClient-1608677735 (first halted, then I canceled job manually)
          [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" login -p (haltes, then I canceled job manually)
          Caught exception communicating with perforce. Unable to login via p4 login due to IOException: nullcom.tek42.perforce.PerforceException: Unable to login via p4 login due to IOException: null
          at com.tek42.perforce.parse.AbstractPerforceTemplate.login(AbstractPerforceTemplate.java:488)
          at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:350)
          at com.tek42.perforce.parse.Workspaces.getWorkspace(Workspaces.java:53)
          at hudson.plugins.perforce.PerforceSCM.getPerforceWorkspace(PerforceSCM.java:1081)
          at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:541)
          at hudson.model.AbstractProject.checkout(AbstractProject.java:1171)
          at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:480)
          at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:412)
          at hudson.model.Run.run(Run.java:1362)
          at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
          at hudson.model.ResourceController.execute(ResourceController.java:88)
          at hudson.model.Executor.run(Executor.java:145)
          ERROR: Unable to communicate with perforce. Unable to login via p4 login due to IOException: null
          Finished: FAILURE

          Show
          jonasbovin jonasbovin added a comment - - edited rpetti: I've tried the perforce-rpetti-54.hpi on a 1.394 Hudson, but unfortunately it just hangs after: ... Using master perforce client: HudsonWebTestClient -- [workspace] $ "C:\Program Files\Perforce\p4.exe" workspace -o HudsonWebTestClient never gets beyond the workspace command - usually what happens is that it fails - as it is not logged in and then issues the login statement an gets a ticket (see below): When using the 1.1.14 plugin which every now and then get 'No output...' Using master perforce client: HudsonWebTestClient -- [workspace] $ "C:\Program Files\Perforce\p4.exe" workspace -o HudsonWebTestClient -- [workspace] $ "C:\Program Files\Perforce\p4.exe" login -p -- [workspace] $ "C:\Program Files\Perforce\p4.exe" -P 20DADC12CB3FEA1432C78D34E289BAB2 workspace -o HudsonWebTestClient Last sync'd change: 183801 When I try to cancel the hanging job, it resumes next line as above on 1.1.14 plugin. This also affects non-slaves, master will also hang until job is canceled manually from Hudson web-interface. Using remote perforce client: HudsonSlaveWebTestClient--1608677735 [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" workspace o HudsonSlaveWebTestClient -1608677735 (first halted, then I canceled job manually) [SlaveAutotestHelper] $ "C:\Program Files\Perforce\p4.exe" login -p (haltes, then I canceled job manually) Caught exception communicating with perforce. Unable to login via p4 login due to IOException: nullcom.tek42.perforce.PerforceException: Unable to login via p4 login due to IOException: null at com.tek42.perforce.parse.AbstractPerforceTemplate.login(AbstractPerforceTemplate.java:488) at com.tek42.perforce.parse.AbstractPerforceTemplate.getPerforceResponse(AbstractPerforceTemplate.java:350) at com.tek42.perforce.parse.Workspaces.getWorkspace(Workspaces.java:53) at hudson.plugins.perforce.PerforceSCM.getPerforceWorkspace(PerforceSCM.java:1081) at hudson.plugins.perforce.PerforceSCM.checkout(PerforceSCM.java:541) at hudson.model.AbstractProject.checkout(AbstractProject.java:1171) at hudson.model.AbstractBuild$AbstractRunner.checkout(AbstractBuild.java:480) at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:412) at hudson.model.Run.run(Run.java:1362) at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46) at hudson.model.ResourceController.execute(ResourceController.java:88) at hudson.model.Executor.run(Executor.java:145) ERROR: Unable to communicate with perforce. Unable to login via p4 login due to IOException: null Finished: FAILURE
          Hide
          seanhoughton seanhoughton added a comment -

          I tried 1.1.15 and got the same result: hang on the workspace command. With 1.1.14 I get the "no output" problem 3 out of 12 times.

          I'm fully willing to keep trying beta versions if you keep posting them. Alternatively, my email is "shoughton at highmoonstudios.com".

          Show
          seanhoughton seanhoughton added a comment - I tried 1.1.15 and got the same result: hang on the workspace command. With 1.1.14 I get the "no output" problem 3 out of 12 times. I'm fully willing to keep trying beta versions if you keep posting them. Alternatively, my email is "shoughton at highmoonstudios.com".
          Hide
          rpetti Rob Petti added a comment -

          I was able to reproduce the problem (or one strikingly similar) and was able to fix it by reimplementing the remote calls performed by the plugin. Can someone else test it? (perforce-rpetti-58.hpi)

          If it works for others, then I'll release it and update JENKINS-7809 with my findings.

          Show
          rpetti Rob Petti added a comment - I was able to reproduce the problem (or one strikingly similar) and was able to fix it by reimplementing the remote calls performed by the plugin. Can someone else test it? ( perforce-rpetti-58.hpi ) If it works for others, then I'll release it and update JENKINS-7809 with my findings.
          Hide
          laszlo_kishalmi László Kishalmi added a comment -

          Well I've installed the new plugin last friday morning. Since then we did not experience any perforce "no output" related problems. This is a good sign. We keep watching it!

          Show
          laszlo_kishalmi László Kishalmi added a comment - Well I've installed the new plugin last friday morning. Since then we did not experience any perforce "no output" related problems. This is a good sign. We keep watching it!
          Hide
          kohsuke Kohsuke Kawaguchi added a comment -

          Rob, I'm eagerly waiting for your findings wrt JENKINS-7809!

          Show
          kohsuke Kohsuke Kawaguchi added a comment - Rob, I'm eagerly waiting for your findings wrt JENKINS-7809 !
          Hide
          rpetti Rob Petti added a comment -

          Work around released in perforce plugin version 1.2.0.

          Show
          rpetti Rob Petti added a comment - Work around released in perforce plugin version 1.2.0.
          Hide
          torbent torbent added a comment -

          That's SO great! This means I may finally move on from Hudson 1.377 – to Jenkins, naturally

          Show
          torbent torbent added a comment - That's SO great! This means I may finally move on from Hudson 1.377 – to Jenkins, naturally
          Hide
          torbent torbent added a comment -

          This issue started on Hudson, and our Hudson installation is actually still at 1.377 because of it. We've since moved some of our jobs to Jenkins and haven't seen the slightest trace of this problem, so I think it's (about) time to close it.

          Show
          torbent torbent added a comment - This issue started on Hudson, and our Hudson installation is actually still at 1.377 because of it. We've since moved some of our jobs to Jenkins and haven't seen the slightest trace of this problem, so I think it's (about) time to close it.

            People

            • Assignee:
              rpetti Rob Petti
              Reporter:
              torbent torbent
            • Votes:
              18 Vote for this issue
              Watchers:
              27 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: