Specific pipeline using github.pr plugin fails requesting for 'checkout'

[wlsf82]

At appear.in we use GoCD with the github.pr plugin for almost a year, and in one of our projects we started to face the following issue when trying to run its pipeline:

Interaction with plugin with id 'github.pr' implementing 'scm' extension failed while requesting for 'checkout'. Reason: [The plugin sent a response that could not be understood by Go. Plugin returned with code '500' and the following response: '"Exception Occurred: [git, clean, -dff] - /var/lib/go-agent/pipelines/appearin-pwa-pr/workspace/node_modules-dev/appearin-jslib-commons"']

Below is the log from the agent:

2017-08-25 12:12:30,864 [loopThread] INFO  thoughtworks.go.work.DefaultGoPublisher:94 - Agent [ip-xxx-xx-x-xx, xxx.xx.x.xx, 6ad1b88a-7e6d-441a-9b0a-54fc7f78e050] is reporting status [Preparing] to Go Server for Build [appearin-pwa-pr/213/lint-and-unit-test/1/lint-and-unit-test/10606]
2017-08-25 12:12:32,224 [loopThread] ERROR thoughtworks.go.work.DefaultGoPublisher:145 - Interaction with plugin with id 'github.pr' implementing 'scm' extension failed while requesting for 'checkout'. Reason: [The plugin sent a response that could not be understood by Go. Plugin returned with code '500' and the following response: '"Exception Occurred: [git, clean, -dff] - /var/lib/go-agent/pipelines/appearin-pwa-pr/workspace/node_modules-dev/appearin-jslib-commons"']
java.lang.RuntimeException: Interaction with plugin with id 'github.pr' implementing 'scm' extension failed while requesting for 'checkout'. Reason: [The plugin sent a response that could not be understood by Go. Plugin returned with code '500' and the following response: '"Exception Occurred: [git, clean, -dff] - /var/lib/go-agent/pipelines/appearin-pwa-pr/workspace/node_modules-dev/appearin-jslib-commons"']
    at com.thoughtworks.go.plugin.access.PluginRequestHelper.submitRequest(PluginRequestHelper.java:41)
    at com.thoughtworks.go.plugin.access.scm.SCMExtension.checkout(SCMExtension.java:137)
    at com.thoughtworks.go.domain.materials.scm.PluggableSCMMaterialAgent.prepare(PluggableSCMMaterialAgent.java:51)
    at com.thoughtworks.go.remote.work.BuildWork.prepareJob(BuildWork.java:187)
    at com.thoughtworks.go.remote.work.BuildWork.build(BuildWork.java:137)
    at com.thoughtworks.go.remote.work.BuildWork.doWork(BuildWork.java:93)
    at com.thoughtworks.go.agent.JobRunner.run(JobRunner.java:60)
    at com.thoughtworks.go.agent.AgentHTTPClientController.retrieveWork(AgentHTTPClientController.java:123)
    at com.thoughtworks.go.agent.AgentHTTPClientController.work(AgentHTTPClientController.java:99)
    at com.thoughtworks.go.agent.AgentController.loop(AgentController.java:78)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)
    at org.springframework.scheduling.support.MethodInvokingRunnable.run(MethodInvokingRunnable.java:65)
    at org.springframework.scheduling.timer.DelegatingTimerTask.run(DelegatingTimerTask.java:70)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)
Caused by: java.lang.RuntimeException: The plugin sent a response that could not be understood by Go. Plugin returned with code '500' and the following response: '"Exception Occurred: [git, clean, -dff] - /var/lib/go-agent/pipelines/appearin-pwa-pr/workspace/node_modules-dev/appearin-jslib-commons"'
    at com.thoughtworks.go.plugin.access.PluginRequestHelper.submitRequest(PluginRequestHelper.java:39)
    ... 18 more
2017-08-25 12:12:32,229 [loopThread] INFO  thoughtworks.go.work.DefaultGoPublisher:106 - Agent [ip-xxx-xx-x-xx, xxx.xx.x.xx, 6ad1b88a-7e6d-441a-9b0a-54fc7f78e050] is reporting build result [Failed] to Go Server for Build [appearin-pwa-pr/213/lint-and-unit-test/1/lint-and-unit-test/10606]
2017-08-25 12:12:32,239 [loopThread] INFO  thoughtworks.go.work.DefaultGoPublisher:89 - Stopping Transmission for Build [appearin-pwa-pr/213/lint-and-unit-test/1/lint-and-unit-test/10606]
2017-08-25 12:12:32,253 [loopThread] INFO  thoughtworks.go.util.HttpService:136 - Got back 200 from server

It's worth mentioning that other projects/pipelines use the same git submodule referenced in the error, and they simply work.

Also, we noticed that deleting the workspace manually from the agent fixed the issue once, but we haven't done it again, but we tried setting cleanup_workspace: true in the stage of the pipeline, and this has not solved the issue.

GoCD version: 17.7.0 Github Pull Requests Builder version: 1.3.3

[ashwanthkumar]

@wlsf82 Thank you so much for using this plugin for so long 😄

For the issue, can you please check and let me know if the go user has the permissions to delete that directory? I have seen that happen when the permissions of some files in the working directory gets changed. That explains the fact why it started working once you clean the directory manually. Having said that cleanup_workspace: true should have done the same thing else it should have failed.

Can you please check / share the pipeline stage run logs? It should have something like

[go] Cleaning working directory ... since stage is configured to clean working directory

[wlsf82]

@ashwanthkumar, this has been displayed, yes:

[go] Job Started: 2017-08-25 11:43:27 UTC
[go] Start to prepare appearin-pwa-pr/212/lint-and-unit-test/1/lint-and-unit-test on ip-xxx-xx-xx-xx [/var/lib/go-agent]
[go] Cleaning working directory "/var/lib/go-agent/pipelines/appearin-pwa-pr" since stage is configured to clean working directory
[go] Start to update materials.
Interaction with plugin with id 'github.pr' implementing 'scm' extension failed while requesting for 'checkout'. Reason: [The plugin sent a response that could not be understood by Go. Plugin returned with code '500' and the following response: '"Exception Occurred: [git, submodule, update] - /var/lib/go-agent/pipelines/appearin-pwa-pr/workspace"']
[go] Job completed appearin-pwa-pr/212/lint-and-unit-test/1/lint-and-unit-test on ip-xxx-xx-xx-xx [/var/lib/go-agent]

[wlsf82]

I'm not sure if it could be a permission issue since the go user can run all the other pipelines.

[ashwanthkumar]

The error seems to be a little different this time. First time it was failing on git clean now it's failing on git submodule update. If it's not too much trouble, can you please try running those command manually as go user on the same folder? The output from the git command would help me understand what's the error that's happening.

[wlsf82]

hrm, when running git submodule update in the workspace manually I'm getting this: Username for 'https://github.com': So, seems that this is the issue, right?

[wlsf82]

I may need to add some AWS policy on the agents to be able to fetch the submodule, right?

[ashwanthkumar]

Ah! Yes, can you please check if you've configured the username / password for the material or if it's possible please consider moving to git's SSH URL.

[wlsf82]

Yeah, we use SSH URLs. I'll check that and will keep you posted.

[wlsf82]

The issue was that we were using the https URL for the submodule instead of the git@github.com:...