copy artifact fails on windows XP slaves due to failing to set a timestamp

kohsuke, can you take a look at this? I don't think copyartifact plugin should need to check the system type and avoid calling this API for windows..

I see this also on Win2008R2/x64, but only occasionally when copying artifacts from an upstream job. Stack trace is pretty much the same as the attached one.

Same here, we rolled back to jenkins 1.427 and all works fine.

I also have this problem. Windows XP slave and jenkins server (currently 1.432) on debian 6
(the same job worked before, but stopped working around versions 1.428 to 1.430)

Just tried to upgrade from 1.424 to 1.432 and experienced this issue

I had the same problem with Jenkins 1.432 and Copy Artifact Plugin 1.18, rolled back to Copy Artifact Plugin 1.16 to avoid the problem.

Thanks for the hint luke, rolling back to copyartifact plugin manually to 1.16 also helped me too.
(you can get it here: http://updates.jenkins-ci.org/download/plugins/copyartifact/)

Will the bug be ever fixed?
We're experiencing this nasty bug on Windows Server 20003 R2 SP2 x64 starting from I guess 1.429 (1.428 works fine).
We've tried several newer versions including 1.437 - the bug is still there

13:10:54 ERROR: Failed to copy artifacts from XXX with filter: build/YYY.*.zip
13:10:54 hudson.util.IOException2: remote file operation failed: C:_JenkinsCI\workspace\ZZZ\YYY.ABCD.zip at hudson.remoting.Channel@581d0d:hudson32
13:10:54 at hudson.FilePath.act(FilePath.java:781)
13:10:54 at hudson.FilePath.act(FilePath.java:767)
13:10:54 at hudson.FilePath.touch(FilePath.java:1063)
13:10:54 at hudson.FilePath.copyToWithPermission(FilePath.java:1429)
13:10:54 at hudson.plugins.copyartifact.FilePathCopyMethod.copyOne(FilePathCopyMethod.java:58)
13:10:54 at hudson.plugins.copyartifact.CopyArtifact.perform(CopyArtifact.java:231)
13:10:54 at hudson.plugins.copyartifact.CopyArtifact.perform(CopyArtifact.java:200)
13:10:54 at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:19)
13:10:54 at hudson.model.AbstractBuild$AbstractRunner.perform(AbstractBuild.java:694)
13:10:54 at hudson.model.Build$RunnerImpl.build(Build.java:178)
13:10:54 at hudson.model.Build$RunnerImpl.doRun(Build.java:139)
13:10:54 at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:460)
13:10:54 at hudson.model.Run.run(Run.java:1404)
13:10:54 at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
13:10:54 at hudson.model.ResourceController.execute(ResourceController.java:88)
13:10:54 at hudson.model.Executor.run(Executor.java:230)
13:10:54 Caused by: java.io.IOException: Failed to set the timestamp of C:_JenkinsCI\workspace\ZZZ\YYY.ABCD.zip to 1320516545963
13:10:54 at hudson.FilePath$17.invoke(FilePath.java:1068)
13:10:54 at hudson.FilePath$17.invoke(FilePath.java:1063)
13:10:54 at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2022)
13:10:54 at hudson.remoting.UserRequest.perform(UserRequest.java:118)
13:10:54 at hudson.remoting.UserRequest.perform(UserRequest.java:48)
13:10:54 at hudson.remoting.Request$2.run(Request.java:287)
13:10:54 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
13:10:54 at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
13:10:54 at java.util.concurrent.FutureTask.run(FutureTask.java:138)
13:10:54 at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
13:10:54 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
13:10:54 at java.lang.Thread.run(Thread.java:619)
13:10:54 Build step 'Copy artifacts from another project' marked build as failure

I also rolled back to Copy Aritifact 1.16 to fix the problem. I'm running with 1.433 on a Win XP master with a Win XP slave.

Unfortunately I'm using copy artifact with matrix jobs and join plugin, so I'm unable to revert to 1.16 and stuck at jenkins 1.424

Yeah rolling back should only be a temporary solution. And I really hope this is getting fixed within the next month. Please vote for this bug to get fixed.

How are you connecting the windows slaves? Have you checked that the slaves have the latest version of the slave.jar?

According to the comments here http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=4243868 problems with setLastModified seems to be a widespread problem on Windows platforms

Code changed in jenkins
User: Christoph Kutzinski
Path:
core/src/main/java/hudson/FilePath.java
http://jenkins-ci.org/commit/jenkins/a7ce870c1ad1a7ff67962ecfc9830949d9e2861d
Log:
[FIXED JENKINS-11073] handle failure to set timestamp on Windows platforms more gracefully

Integrated in jenkins_main_trunk #1282
[FIXED JENKINS-11073] handle failure to set timestamp on Windows platforms more gracefully

Christoph Kutzinski : a7ce870c1ad1a7ff67962ecfc9830949d9e2861d
Files :

• core/src/main/java/hudson/FilePath.java

Code changed in jenkins
User: Christoph Kutzinski
Path:
changelog.html
http://jenkins-ci.org/commit/jenkins/4dc4678fd85c790fb619acb6e3c1cea7181863ce
Log:
Changelog for JENKINS-8383 and JENKINS-11073

Compare: https://github.com/jenkinsci/jenkins/compare/a7ce870...4dc4678

Still has a problem on Jenkins 1.440 with copy artifact 1.18

ERROR: Failed to copy artifacts from 3.8-distribution with filter: distribution-zip/target/distribution.zip
hudson.util.IOException2: remote file operation failed: c:\app\hudson\workspace\3.8-jelly-db\jdk/jdk1.6.0_21/label/sqlserver/profile/sqlserver\acceptance-tests\distribution.zip at hudson.remoting.Channel@1122fc6:tal-bri-tate-8
at hudson.FilePath.copyToWithPermission(FilePath.java:1435)
at hudson.plugins.copyartifact.FilePathCopyMethod.copyOne(FilePathCopyMethod.java:58)
at hudson.plugins.copyartifact.CopyArtifact.perform(CopyArtifact.java:231)
at hudson.plugins.copyartifact.CopyArtifact.perform(CopyArtifact.java:186)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:19)
at hudson.model.AbstractBuild$AbstractRunner.perform(AbstractBuild.java:692)
at hudson.model.Build$RunnerImpl.build(Build.java:178)
at hudson.model.Build$RunnerImpl.doRun(Build.java:139)
at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:462)
at hudson.model.Run.run(Run.java:1404)
at hudson.matrix.MatrixRun.run(MatrixRun.java:146)
at hudson.model.ResourceController.execute(ResourceController.java:88)
at hudson.model.Executor.run(Executor.java:230)
Caused by: hudson.util.IOException2: remote file operation failed: c:\app\hudson\workspace\3.8-jelly-db\jdk/jdk1.6.0_21/label/sqlserver/profile/sqlserver\acceptance-tests\distribution.zip at hudson.remoting.Channel@1122fc6:tal-bri-tate-8
at hudson.FilePath.act(FilePath.java:779)
at hudson.FilePath.act(FilePath.java:765)
at hudson.FilePath.touch(FilePath.java:1061)
at hudson.FilePath.copyToWithPermission(FilePath.java:1429)
... 12 more
Caused by: java.io.IOException: Failed to set the timestamp of c:\app\hudson\workspace\3.8-jelly-db\jdk\jdk1.6.0_21\label\sqlserver\profile\sqlserver\acceptance-tests\distribution.zip to 1321879253000
at hudson.FilePath$17.invoke(FilePath.java:1066)
at hudson.FilePath$17.invoke(FilePath.java:1061)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2030)
at hudson.remoting.UserRequest.perform(UserRequest.java:118)
at hudson.remoting.UserRequest.perform(UserRequest.java:48)
at hudson.remoting.Request$2.run(Request.java:287)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Build step 'Copy artifacts from another project' marked build as failure

Looks like you're indeed using the newest version (according to the stacktrace), but somehow 'c:\app\hudson\workspace\3.8-jelly-db\jdk\jdk1.6.0_21\label\sqlserver\profile\sqlserver\acceptance-tests\distribution.zip' isn't recognized to be a Windows path - which I don't quite understand, yet.

Background to our setup if it helps:
Our top level jobs are maven native jobs, followed by matrix test jobs.

When distribution completes a post join trigger on the top level job then starts a number of matrix test jobs. Each of which uses v1.18 copy artifact plugin with "upstream job that triggered this build" to obtain the distribution.zip.

With 1.424 in a successful run we get the following log messages, as we don't specify a module

Copied 1 artifact from 3.8-distribution #672
Unable to access workspace for artifact copy. Slave node offline?
Unable to access workspace for artifact copy. Slave node offline?
Unable to access workspace for artifact copy. Slave node offline?
Unable to access workspace for artifact copy. Slave node offline?
Unable to access workspace for artifact copy. Slave node offline?
Unable to access workspace for artifact copy. Slave node offline?
Unable to access workspace for artifact copy. Slave node offline?
Unable to access workspace for artifact copy. Slave node offline?
Unable to access workspace for artifact copy. Slave node offline?

Code changed in jenkins
User: Christoph Kutzinski
Path:
changelog.html
core/src/main/java/hudson/FilePath.java
core/src/test/java/hudson/FilePathTest.java
http://jenkins-ci.org/commit/jenkins/8755e59c9a48375cbe6b602e7553bd0508acfe87
Log:
[FIXED JENKINS-11073] handle failure to set timestamp on Windows platforms more gracefully - this time hopefully for real

D'oh, did a stupid mistake in the initial 'fix'. Should be fixed now.

Integrated in jenkins_main_trunk #1314
[FIXED JENKINS-11073] handle failure to set timestamp on Windows platforms more gracefully - this time hopefully for real

Christoph Kutzinski : 8755e59c9a48375cbe6b602e7553bd0508acfe87
Files :

• core/src/main/java/hudson/FilePath.java
• core/src/test/java/hudson/FilePathTest.java
• changelog.html

Looks like problem still exists:

Jenkins ver. 1.444
Copy Artifact Plugin ver. 1.19
OS Windows 2008 x64

[0mhudson.util.IOException2: remote file operation failed: ...
Caused by: java.io.IOException: Failed to set the timestamp of ...

Could you please reopen bug?

Looks like problem still exists:

Jenkins ver. 1.444
Copy Artifact Plugin ver. 1.19
OS Windows 2008 x64

[0mhudson.util.IOException2: remote file operation failed: ...
Caused by: java.io.IOException: Failed to set the timestamp of ...

Yauheni, please attach the complete stacktrace!

ERROR: Failed to copy artifacts from NightlyBuild with filter: artifacts/*/
ha:AAAAWB+LCAAAAAAAAABb85aBtbiIQSmjNKU4P08vOT+vOD8nVc8DzHWtSE4tKMnMz/PLL0ldFVf2c+b/lb5MDAwVRQxSaBqcITRIIQMEMIIUFgAAckCEiWAAAAA=hudson.util.IOException2: remote file operation failed: C:/Releases/PromotedNightlyBuilds/AppStore_139/news.zip at hudson.remoting.Channel@159ec47:DevApp
at hudson.FilePath.copyToWithPermission(FilePath.java:1435)
at hudson.plugins.copyartifact.FilePathCopyMethod.copyOne(FilePathCopyMethod.java:55)
at hudson.plugins.copyartifact.CopyArtifact.perform(CopyArtifact.java:233)
at hudson.plugins.copyartifact.CopyArtifact.perform(CopyArtifact.java:200)
at hudson.plugins.promoted_builds.Promotion$RunnerImpl.build(Promotion.java:152)
at hudson.plugins.promoted_builds.Promotion$RunnerImpl.doRun(Promotion.java:121)
at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:462)
at hudson.model.Run.run(Run.java:1404)
at hudson.plugins.promoted_builds.Promotion.run(Promotion.java:94)
at hudson.model.ResourceController.execute(ResourceController.java:88)
at hudson.model.Executor.run(Executor.java:238)
Caused by: hudson.util.IOException2: remote file operation failed: C:/Releases/PromotedNightlyBuilds/AppStore_139/news.zip at hudson.remoting.Channel@159ec47:DevApp
at hudson.FilePath.act(FilePath.java:779)
at hudson.FilePath.act(FilePath.java:765)
at hudson.FilePath.touch(FilePath.java:1061)
at hudson.FilePath.copyToWithPermission(FilePath.java:1429)
... 10 more
Caused by: java.io.IOException: Failed to set the timestamp of C:\Releases\PromotedNightlyBuilds\AppStore_139\news.zip to 1325067852000
at hudson.FilePath$17.invoke(FilePath.java:1066)
at hudson.FilePath$17.invoke(FilePath.java:1061)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2030)
at hudson.remoting.UserRequest.perform(UserRequest.java:118)
at hudson.remoting.UserRequest.perform(UserRequest.java:48)
at hudson.remoting.Request$2.run(Request.java:287)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
failed build hudson.plugins.copyartifact.CopyArtifact@144786d SUCCESS
Finished: FAILURE

Seems you've specified the artifact to copy using '/' slashes. Could you try with '\' ?
We're depending on this to determine if the remote host is Unix or not.

I'll think about a more reliable way to determine remote host OS.

I think that problem is not here, because such error (Failed to set the timestamp) appears from time to time. It's difficult to reproduce it. Even I setup path with '\', I won't make sure that there is no such problem anymore.

I don't know what you mean with 'I think that problem is not here ...'.
Have you actually tried it with '\' and still got the same error?

I meant that the problem is not the case.

So you mean that it doesn't matter if you use '/' or '\'? If so, could you please provide a stacktrace where you used '\' and it did still fail? (Note that you have to use \ in the beginning - i.e. write C:\...)

I use filter "filter: artifacts/*/" (with '/') and it works fine for me. But rarely Copy Artifacts plugin fails with error from this thread.

Alan, can you have a look? I think this might be related to how the Copy artifact plugin specifies path separators - I'm not familiar with the plugin itself

Don't know why the SCM/JIRA link daemon is not updating this issue, but I've implemented a core-side fix in https://github.com/jenkinsci/jenkins/commit/b4fe626f73acaa3d52453543752709261994635a
Alan, you still might want to add a plugin-side fix, so that it runs with previous Jenkins versions - see previous comment - but that would only affect a very small range of Jenkins versions.
So I'm closing this again.

Integrated in jenkins_main_trunk #1404

Seems that this issue is back with version 1.22.
I have just upgraded and faced the problem on a job.
Failed 4 times with this error.
Rolling back to 1.21 and the job is passed.

I can also confirm that the issue is back with version 1.22 of 'Copy Artifact plugin'. Rolling back to 1.21 fixes the problem
Please re-open

I can confirm this too. Rolling back to 1.21 fixes the problem.
Slave having the problem is Windows 7. Master is Windows 7 too.

StackTrace:
ERROR: Artefaktekopie aus xxxxxxxx mit Filter: ** fehlgeschlagen
hudson.util.IOException2: Failed to copy C:\Jenkins\jobs\xxxxxxxx\builds\2012-04-22_22-02-00\archive\Build\xxxxxxxx\File.xrs to c:\xxxxxxxx\Build\xxxxxxxx\File.xrs
at hudson.plugins.copyartifact.FingerprintingCopyMethod.copyOne(FingerprintingCopyMethod.java:91)
at hudson.plugins.copyartifact.FingerprintingCopyMethod.copyAll(FingerprintingCopyMethod.java:63)
at hudson.plugins.copyartifact.CopyArtifact.perform(CopyArtifact.java:243)
at hudson.plugins.copyartifact.CopyArtifact.perform(CopyArtifact.java:215)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:19)
at hudson.model.AbstractBuild$AbstractRunner.perform(AbstractBuild.java:705)
at hudson.model.Build$RunnerImpl.build(Build.java:178)
at hudson.model.Build$RunnerImpl.doRun(Build.java:139)
at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:475)
at hudson.model.Run.run(Run.java:1421)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
at hudson.model.ResourceController.execute(ResourceController.java:88)
at hudson.model.Executor.run(Executor.java:238)
Caused by: hudson.util.IOException2: remote file operation failed: c:\xxxxxxxx\Build\xxxxxxxx\File.xrs at hudson.remoting.Channel@d1faace:BuildSlaveWindows
at hudson.FilePath.act(FilePath.java:828)
at hudson.FilePath.act(FilePath.java:814)
at hudson.FilePath.touch(FilePath.java:1160)
at hudson.plugins.copyartifact.FingerprintingCopyMethod.copyOne(FingerprintingCopyMethod.java:79)
... 12 more
Caused by: java.io.IOException: Failed to set the timestamp of c:\xxxxxxxx\Build\xxxxxxxx\File.xrs to 1335126036000
at hudson.FilePath$19.invoke(FilePath.java:1166)
at hudson.FilePath$19.invoke(FilePath.java:1160)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2154)
at hudson.remoting.UserRequest.perform(UserRequest.java:118)
at hudson.remoting.UserRequest.perform(UserRequest.java:48)
at hudson.remoting.Request$2.run(Request.java:287)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Build step 'Artefakte aus einem anderen Projekt kopieren' marked build as failure

Same problem here with 1.22, not with 1.21. Master and slave both run on Windows Server 2008 R2. If you need additional info, just ask.

I found a workaround for this problem, by updating Java to version 1.7 in Windows XP Slave, as advised in the this java bug report

Problem resolved by installing Java JRE 7 (1.7)

Seems JDK indeed has some implementation issues with File.setLastModified, as explained on
http://stackoverflow.com/questions/1144635/setting-the-last-modified-time-of-a-directory-opened-for-readdirectorychangesw

Nicolas, yes there seems to be a bug in JDK with respect to setting the timestamp on Windows. However, that should be worked around in Jenkins core now.

Bertrand, Denis, Alexander, Marnix: which Jenkins version are you using?

@kutzi: I'm not exactly sure which version of Jenkins we were using at the time we tried Copy Artifact 1.22. Most likely it was Jenkins 1.447.1, if not it was likely 1.424.6.

Could you indicate in which versions of Jenkins core this has been worked around? Thanks!

It should be fixed in 1.447 and higher http://jenkins-ci.org/changelog

@kutzi in 1.22, hudson.plugins.copyartifact.FingerprintingCopyMethod#copyOne invoke chmod and touch, it should rely on setLastModifiedIfPossible to benefits the core fixes you listed on this ticket - But this method is private

@Nicolas: I don't understand, why you are not simply using FilePath.copyToWithPermission?

https://github.com/jenkinsci/jenkins/pull/509 to expose a public touch() method to optionally ignore windows failure on setLastModified

@kutzi FingerprintingCopyMethod#copyOne isn't just about copying file but about copying with fingerprint to avoid duplicating fingerprint computation.
javadoc excerpt :

• Performs fingerprinting during the copy.
  *
• This minimizes the cost of the fingerprinting as the I/O bound nature of the copy operation
• masks the cost of digest computation.

This uses copyTo(OutputStream) that has no equivalent for copyToWithPermission. Was introduced by 540a074e1b2209e0079334f93ce4266badc5e653 related to JENKINS-9741
Maybe just safer to revert.

I think this is a manifestation of the same issue that caues JENKINS-11251. I claim this change in remoting fixes this. This commit will be a part of 1.473.

Notice that all the problem reports in this bug is about remoting. Due to the asynchrony in the read/write operations in remoting vs closure calls, it was possible that the attempt to set the timestamp happens before the file is fully is written (or even before the write starts at all.)

In jenkins v1.474 this problem is still there. Overwriting existing files does not work, writing new files works fine.
So I use the following workaround: Use a Execute Windows batch command to delete all files before copying.

For the record: this duplicate of JENKINS-13515 has been resolved in Copy Artifact plugin 1.23/1.24; see the change log for details. And I can confirm that after switching from 1.21 to 1.28, this problem does not arise.