{"action":"created","issue":{"url":"https://api.github.com/repos/gocd/gocd/issues/1428","labels_url":"https://api.github.com/repos/gocd/gocd/issues/1428/labels{/name}","comments_url":"https://api.github.com/repos/gocd/gocd/issues/1428/comments","events_url":"https://api.github.com/repos/gocd/gocd/issues/1428/events","html_url":"https://github.com/gocd/gocd/issues/1428","id":100038730,"number":1428,"title":"Access is denied when fetching artifacts","user":{"login":"reidca","id":7325010,"avatar_url":"https://avatars.githubusercontent.com/u/7325010?v=3","gravatar_id":"","url":"https://api.github.com/users/reidca","html_url":"https://github.com/reidca","followers_url":"https://api.github.com/users/reidca/followers","following_url":"https://api.github.com/users/reidca/following{/other_user}","gists_url":"https://api.github.com/users/reidca/gists{/gist_id}","starred_url":"https://api.github.com/users/reidca/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/reidca/subscriptions","organizations_url":"https://api.github.com/users/reidca/orgs","repos_url":"https://api.github.com/users/reidca/repos","events_url":"https://api.github.com/users/reidca/events{/privacy}","received_events_url":"https://api.github.com/users/reidca/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":7,"created_at":"2015-08-10T11:14:15Z","updated_at":"2015-08-11T10:37:11Z","closed_at":null,"body":"When fetching artifacts in some pipelines we see \"Access is denied\" messages.\r\n\r\nThese failures appear in certain pipelines repeatedly however the exact same pipelines/stage/job can also execute OK.\r\n\r\nI have tried the usual combination of re-running the pipeline and its dependences from start, restarting the GO Server, the GO Agent in question however the problem persists.\r\n\r\n\r\nHere is an example:\r\n```\r\n0:18:50.632 [go] Start to execute task: <fetchartifact pipeline=\"MyPipeline\" stage=\"stage_package\" job=\"job_package\" srcdir=\"Scripts\" />.\r\n10:18:50.632 [go] Fetching artifact [Scripts] from [MyPipeline/334/stage_package/1/job_package]\r\n10:18:55.694 [go] Could not fetch artifact https://MyServer:443/go/remoting/files/MyPipeline/334/stage_package/1/job_package/Scripts.zip. Pausing 20 seconds to retry. Error was : Caught an exception 'pipelines\\WHSLE_Web_Assurance_Deploy_Testing\\Scripts\\DeployTools\\Deploy-Modules.ps1 (Access is denied)'\r\n10:19:15.726 [go] Could not fetch artifact https://MyServer:443/go/remoting/files/MyPipeline/334/stage_package/1/job_package/Scripts.zip. Pausing 29 seconds to retry. Error was : Caught an exception 'pipelines\\WHSLE_Web_Assurance_Deploy_Testing\\Scripts\\DeployTools\\Deploy-Modules.ps1 (Access is denied)'\r\n10:19:44.742 [go] Could not fetch artifact https://MyServer:443/go/remoting/files/MyPipeline/334/stage_package/1/job_package/Scripts.zip. Pausing 39 seconds to retry. Error was : Caught an exception 'pipelines\\WHSLE_Web_Assurance_Deploy_Testing\\Scripts\\DeployTools\\Deploy-Modules.ps1 (Access is denied)'\r\n10:20:23.758 [go] Failed to save artifact [Scripts] to []\r\n10:20:23.789 [go] Current job status: failed.\r\n```\r\n\r\nThe corresponding error in on the agent is:\r\n```\r\n2015-08-10 11:43:56,643 [loopThread] INFO  thoughtworks.go.work.DefaultGoPublisher:95 - Agent [sd-wh-web1-dev, 10.129.10.150, 4e94fe64-6264-4337-9e0e-faccbdd043b7] is reporting status [Building] to Go Server for Build [WHSLE_Web_Assurance_Deploy_Testing/173/Deploy_API/2/Deploy_API/95271]\r\n2015-08-10 11:43:56,706 [loopThread] INFO  thoughtworks.go.util.HttpService:129 - Got back 200 from server\r\n2015-08-10 11:43:56,706 [loopThread] INFO  thoughtworks.go.util.PerfTimer:53 - Performance: Downloading from url [https://MyServer:443/go/remoting/files/WHSLE_PubFacing_AssuranceAPI_Commit/334/stage_package/1/job_package/cruise-output/md5.checksum] took 47ms\r\n2015-08-10 11:43:56,722 [loopThread] INFO  thoughtworks.go.domain.ChecksumFileHandler:58 - [Agent Fetch Artifact] Saved checksum property file [pipelines\\WHSLE_Web_Assurance_Deploy_Testing\\Packages\\Testing\\WHSLE_PubFacing_AssuranceAPI_Commit_stage_package_job_package_md5.checksum]\r\n2015-08-10 11:43:57,378 [loopThread] INFO  thoughtworks.go.util.HttpService:129 - Got back 304 from server\r\n2015-08-10 11:43:57,378 [loopThread] INFO  thoughtworks.go.util.PerfTimer:53 - Performance: Downloading from url [https://MyServer:443/go/remoting/files/WHSLE_PubFacing_AssuranceAPI_Commit/334/stage_package/1/job_package/Packages/Testing/WholesaleAssuranceAPI.zip?sha1=Ny2bEREzkmJh7rqTXudQGIAs9%2Bk%3D] took 125ms\r\n2015-08-10 11:43:57,393 [loopThread] INFO  thoughtworks.go.util.HttpService:129 - Got back 200 from server\r\n2015-08-10 11:43:57,393 [loopThread] INFO  thoughtworks.go.util.PerfTimer:53 - Performance: Downloading from url [https://MyServer:443/go/remoting/files/WHSLE_PubFacing_AssuranceAPI_Commit/334/stage_package/1/job_package/cruise-output/md5.checksum] took 15ms\r\n2015-08-10 11:43:57,393 [loopThread] INFO  thoughtworks.go.domain.ChecksumFileHandler:58 - [Agent Fetch Artifact] Saved checksum property file [pipelines\\WHSLE_Web_Assurance_Deploy_Testing\\WHSLE_PubFacing_AssuranceAPI_Commit_stage_package_job_package_md5.checksum]\r\n2015-08-10 11:43:57,425 [loopThread] INFO  thoughtworks.go.util.HttpService:129 - Got back 200 from server\r\n2015-08-10 11:43:57,425 [loopThread] INFO  thoughtworks.go.util.PerfTimer:53 - Performance: Downloading from url [https://MyServer:443/go/remoting/files/WHSLE_PubFacing_AssuranceAPI_Commit/334/stage_package/1/job_package/Scripts.zip] took 32ms\r\n2015-08-10 11:43:57,425 [loopThread] INFO  thoughtworks.go.domain.DirHandler:53 - [Agent Fetch Artifact] Downloading from 'Scripts' to 'C:\\Program Files (x86)\\Go Agent\\pipelines\\WHSLE_Web_Assurance_Deploy_Testing'. Will read from Socket stream to compute MD5 and write to file\r\n2015-08-10 11:43:57,425 [loopThread] ERROR thoughtworks.go.util.ZipUtil:158 - Failed to unzip file [Scripts/DeployTools/Deploy-Modules.ps1] to directory [C:\\Program Files (x86)\\Go Agent\\pipelines\\WHSLE_Web_Assurance_Deploy_Testing]\r\njava.io.FileNotFoundException: pipelines\\WHSLE_Web_Assurance_Deploy_Testing\\Scripts\\DeployTools\\Deploy-Modules.ps1 (Access is denied)\r\n\tat java.io.FileOutputStream.open(Native Method)\r\n\tat java.io.FileOutputStream.<init>(Unknown Source)\r\n\tat java.io.FileOutputStream.<init>(Unknown Source)\r\n\tat com.thoughtworks.go.util.ZipUtil.extractTo(ZipUtil.java:140)\r\n\tat com.thoughtworks.go.util.ZipUtil.unzip(ZipUtil.java:119)\r\n\tat com.thoughtworks.go.domain.DirHandler.handle(DirHandler.java:56)\r\n\tat com.thoughtworks.go.util.HttpService.download(HttpService.java:101)\r\n\tat com.thoughtworks.go.domain.DownloadAction.download(DownloadAction.java:73)\r\n\tat com.thoughtworks.go.domain.DownloadAction.perform(DownloadAction.java:47)\r\n\tat com.thoughtworks.go.domain.builder.FetchArtifactBuilder.pullArtifact(FetchArtifactBuilder.java:73)\r\n\tat com.thoughtworks.go.domain.builder.FetchArtifactBuilder.downloadArtifact(FetchArtifactBuilder.java:64)\r\n\tat com.thoughtworks.go.domain.builder.FetchArtifactBuilder.fetch(FetchArtifactBuilder.java:59)\r\n\tat com.thoughtworks.go.publishers.GoArtifactsManipulator.fetch(GoArtifactsManipulator.java:183)\r\n\tat com.thoughtworks.go.work.DefaultGoPublisher.fetch(DefaultGoPublisher.java:77)\r\n\tat com.thoughtworks.go.domain.builder.FetchArtifactBuilder.build(FetchArtifactBuilder.java:54)\r\n\tat com.thoughtworks.go.domain.builder.Builder.build(Builder.java:51)\r\n\tat com.thoughtworks.go.remote.work.Builders.build(Builders.java:63)\r\n\tat com.thoughtworks.go.remote.work.BuildWork.execute(BuildWork.java:208)\r\n\tat com.thoughtworks.go.remote.work.BuildWork.buildJob(BuildWork.java:183)\r\n\tat com.thoughtworks.go.remote.work.BuildWork.build(BuildWork.java:145)\r\n\tat com.thoughtworks.go.remote.work.BuildWork.doWork(BuildWork.java:91)\r\n\tat com.thoughtworks.go.agent.JobRunner.run(JobRunner.java:53)\r\n\tat com.thoughtworks.go.agent.AgentController.retrieveWork(AgentController.java:186)\r\n\tat com.thoughtworks.go.agent.AgentController.loop(AgentController.java:132)\r\n\tat sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)\r\n\tat sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)\r\n\tat java.lang.reflect.Method.invoke(Unknown Source)\r\n\tat org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)\r\n\tat org.springframework.scheduling.support.MethodInvokingRunnable.run(MethodInvokingRunnable.java:65)\r\n\tat org.springframework.scheduling.timer.DelegatingTimerTask.run(DelegatingTimerTask.java:70)\r\n\tat java.util.TimerThread.mainLoop(Unknown Source)\r\n\tat java.util.TimerThread.run(Unknown Source)\r\n```\r\n\r\nIf I look into the directory I can see that the files have all be fetched successfully however they are all read-only.\r\n\r\nLooking at other pipelines and jobs that fetch the same files they are not read-only and those jobs work OK. I have checked the files on the job where they are uploaded, the same files in the artifact directory and they are not read-only anywhere.\r\n\r\nUsing Process Monitor I can see that the files get set to be read-only and then a call to overwrite the files occurs however fails with ACCESS IS DENIED resulting in this error. This is failing even though the files are actually there. I have no idea why it is trying to overwrite the files when they have already been written.\r\nSee screen shots\r\n![go access denied 1](https://cloud.githubusercontent.com/assets/7325010/9170256/2b8343d4-3f59-11e5-8e8e-33009f0b509a.png)\r\n![go access denied 2](https://cloud.githubusercontent.com/assets/7325010/9170262/34dae996-3f59-11e5-849d-1cb5bcc59dc0.png)\r\n\r\n\r\nLooking at the [source code](https://github.com/gocd/gocd/blob/master/base/src/com/thoughtworks/go/util/ZipUtil.java) it appears that this problem occurs in the \"extractTo\" function when calling [IOUtils.copyLarge(entryInputStream, os);](https://commons.apache.org/proper/commons-io/apidocs/src-html/org/apache/commons/io/IOUtils.html) however the source code for this does not reveal anything to me.\r\n\r\nThis problem is causing a serious issue for us. People in our organisation are starting to lose confidence in the platform and I would appreciate anyone being able to provide assistance, work-around or possible fixes.\r\n\r\n\r\n\r\n\r\n"},"comment":{"url":"https://api.github.com/repos/gocd/gocd/issues/comments/129828955","html_url":"https://github.com/gocd/gocd/issues/1428#issuecomment-129828955","issue_url":"https://api.github.com/repos/gocd/gocd/issues/1428","id":129828955,"user":{"login":"reidca","id":7325010,"avatar_url":"https://avatars.githubusercontent.com/u/7325010?v=3","gravatar_id":"","url":"https://api.github.com/users/reidca","html_url":"https://github.com/reidca","followers_url":"https://api.github.com/users/reidca/followers","following_url":"https://api.github.com/users/reidca/following{/other_user}","gists_url":"https://api.github.com/users/reidca/gists{/gist_id}","starred_url":"https://api.github.com/users/reidca/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/reidca/subscriptions","organizations_url":"https://api.github.com/users/reidca/orgs","repos_url":"https://api.github.com/users/reidca/repos","events_url":"https://api.github.com/users/reidca/events{/privacy}","received_events_url":"https://api.github.com/users/reidca/received_events","type":"User","site_admin":false},"created_at":"2015-08-11T10:37:11Z","updated_at":"2015-08-11T10:37:11Z","body":"@ketan Thanks for the suggestion however we use these Powershell scripts in ALL our pipelines and this problem does not happen elsewhere. In fact the very same directory \"scripts\" fetches without any problem on all the other pipelines at the moment. Although in the past I have seen similar errors on other agents that happen at random."}}