jenkinsci / pipeline-github-plugin

Pipeline: GitHub
https://plugins.jenkins.io/pipeline-github/
MIT License
159 stars 73 forks source link

Connection timed out Exception when accessing the pullRequest variable #101

Closed JFLarvoire closed 3 years ago

JFLarvoire commented 3 years ago

The pullRequest variable used in our Jenkinsfiles used to work fine until July 28th. Since July 29th, any attempt at using members or methods of that variable results in a "Connection timed out" Exception. That even when reading simple object members like pullRequest.id. Yet everything else works in our Jenkins builds. Jenkins successfully pulls code from our github server, which in turn successfully posts events to Jenkins.

I was on vacation that week, and nobody in our team remembers changing anything in the Jenkins or Jenkins host server configuration that could be related to this. And I can't find anything wrong there anyway. But there was a serious network issue that week, that forced shutting down and rebooting many servers. I've restarted Jenkins and rebooted its host server several times since then, with no effect on this bug.

I verified that the Jenkins host can access our github server API, thus eliminating possibilities like a firewall or network issue. Yet this does look like a DNS or authentication issue, but I don't know how to diagnose this any further.

Where does the pipeline: github plugin gets its github API URL and credentials from? (The plugin does not seem to have any setting in the global or project configuration.)

How can we get more information about what's going on under the hood, leading to that timeout?

Version report

Jenkins and plugins versions report:

Jenkins: 2.307
OS: Windows Server 2016 - 10.0
---
ace-editor:1.1
analysis-model-api:10.2.5
ant:1.11
antisamy-markup-formatter:2.1
apache-httpcomponents-client-4-api:4.5.13-1.0
authentication-tokens:1.4
bootstrap4-api:4.6.0-3
bootstrap5-api:5.0.1-2
bouncycastle-api:2.20
branch-api:2.6.5
caffeine-api:2.9.1-23.v51c4e2c879c8
checks-api:1.7.0
cloudbees-folder:6.15
clover:4.12.1
cobertura:1.16
code-coverage-api:1.4.0
command-launcher:1.6
credentials-binding:1.27
credentials:2.5
data-tables-api:1.10.25-1
display-url-api:2.3.5
docker-commons:1.17
docker-compose-build-step:1.0
docker-java-api:3.1.5.2
docker-plugin:1.2.2
docker-workflow:1.26
dtkit-api:3.0.0
durable-task:1.37
echarts-api:5.1.2-2
email-ext:2.83
emailext-template:1.2
font-awesome-api:5.15.3-3
forensics-api:1.2.0
git-client:3.8.0
git-server:1.10
git:4.7.2
github-api:1.123
github-autostatus:3.6.2
github-branch-pr-change-filter:1.2.4
github-branch-source:2.11.1
github-oauth:0.33
github-pr-coverage-status:2.1.1
github:1.33.1
handlebars:3.0.8
hashicorp-vault-pipeline:1.3
hashicorp-vault-plugin:3.8.0
jackson2-api:2.12.3
jacoco:3.3.0
jaxb:2.3.0.1
jdk-tool:1.5
jjwt-api:0.11.2-9.c8b45b8bb173
jquery-detached:1.2.1
jquery3-api:3.6.0-1
jsch:0.1.55.2
junit:1.51
ldap:2.7
lockable-resources:2.11
mailer:1.34
matrix-auth:2.6.7
matrix-project:1.19
momentjs:1.1.1
okhttp-api:3.14.9
pam-auth:1.6
pipeline-build-step:2.13
pipeline-github-lib:1.0
pipeline-github:2.7
pipeline-githubnotify-step:1.0.5
pipeline-graph-analysis:1.11
pipeline-input-step:2.12
pipeline-milestone-step:1.3.2
pipeline-model-api:1.8.5
pipeline-model-definition:1.8.5
pipeline-model-extensions:1.8.5
pipeline-rest-api:2.19
pipeline-stage-step:2.5
pipeline-stage-tags-metadata:1.8.5
pipeline-stage-view:2.19
pipeline-utility-steps:2.8.0
plain-credentials:1.7
plugin-util-api:2.3.0
popper-api:1.16.1-2
popper2-api:2.5.4-2
postbuild-task:1.9
powershell:1.5
resource-disposer:0.16
role-strategy:3.1.1
scm-api:2.6.4
script-security:1.77
snakeyaml-api:1.29.1
ssh-agent:1.23
ssh-credentials:1.19
ssh-slaves:1.32.0
ssh:2.6.1
sshd:3.0.4
structs:1.23
synopsys-coverity:3.0.1
timestamper:1.13
token-macro:2.15
trilead-api:1.0.13
warnings-ng:9.3.0
winrm-client:1.0
workflow-aggregator:2.6
workflow-api:2.46
workflow-basic-steps:2.23
workflow-cps-global-lib-http:1.13.0
workflow-cps-global-lib:2.21
workflow-cps:2.92
workflow-durable-task-step:2.39
workflow-job:2.41
workflow-multibranch:2.26
workflow-scm-step:2.13
workflow-step-api:2.24
workflow-support:3.8
ws-cleanup:0.39
xunit:3.0.2
Windows Server 2016 with all the latest Windows updates on the controller
Linux CentOS 7.9 x86_64 on two agent nodes

Reproduction steps

Results

Expected result:

In the Jenkins build log file, we'd see a line like: pullRequest.id = 123

Actual result:

[Pipeline] // script
Error when executing success post condition:
java.net.ConnectException: Connection timed out: connect
    at java.base/java.net.PlainSocketImpl.connect0(Native Method)
    at java.base/java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:101)
    at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399)
    at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242)
    at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224)
    at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
    at java.base/java.net.Socket.connect(Socket.java:609)
    at java.base/sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:289)
    at java.base/sun.security.ssl.BaseSSLSocketImpl.connect(BaseSSLSocketImpl.java:173)
    at java.base/sun.net.NetworkClient.doConnect(NetworkClient.java:182)
    at java.base/sun.net.www.http.HttpClient.openServer(HttpClient.java:474)
    at java.base/sun.net.www.http.HttpClient.openServer(HttpClient.java:569)
    at java.base/sun.net.www.protocol.https.HttpsClient.<init>(HttpsClient.java:265)
    at java.base/sun.net.www.protocol.https.HttpsClient.New(HttpsClient.java:372)
    at java.base/sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.getNewHttpClient(AbstractDelegateHttpsURLConnection.java:203)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java:1187)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:1081)
    at java.base/sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(AbstractDelegateHttpsURLConnection.java:189)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1592)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1520)
    at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:527)
    at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:334)
    at org.eclipse.egit.github.core.client.GitHubClient.get(GitHubClient.java:771)
    at org.jenkinsci.plugins.pipeline.github.client.ExtendedGitHubClient.getUnchecked(ExtendedGitHubClient.java:79)
    at org.jenkinsci.plugins.pipeline.github.client.ExtendedPullRequestService.getPullRequest(ExtendedPullRequestService.java:80)
    at org.jenkinsci.plugins.pipeline.github.PullRequestGroovyObject.<init>(PullRequestGroovyObject.java:82)
    at org.jenkinsci.plugins.pipeline.github.PullRequestGlobalVariable.getValue(PullRequestGlobalVariable.java:30)
    at org.jenkinsci.plugins.workflow.cps.CpsScript.getProperty(CpsScript.java:135)
    at org.codehaus.groovy.runtime.InvokerHelper.getProperty(InvokerHelper.java:174)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.getProperty(ScriptBytecodeAdapter.java:456)
    at com.cloudbees.groovy.cps.sandbox.DefaultInvoker.getProperty(DefaultInvoker.java:39)
    at com.cloudbees.groovy.cps.impl.PropertyAccessBlock.rawGet(PropertyAccessBlock.java:20)
Caused: java.io.UncheckedIOException
    at org.jenkinsci.plugins.pipeline.github.client.ExtendedGitHubClient.getUnchecked(ExtendedGitHubClient.java:81)
    at org.jenkinsci.plugins.pipeline.github.client.ExtendedPullRequestService.getPullRequest(ExtendedPullRequestService.java:80)
    at org.jenkinsci.plugins.pipeline.github.PullRequestGroovyObject.<init>(PullRequestGroovyObject.java:82)
    at org.jenkinsci.plugins.pipeline.github.PullRequestGlobalVariable.getValue(PullRequestGlobalVariable.java:30)
    at org.jenkinsci.plugins.workflow.cps.CpsScript.getProperty(CpsScript.java:135)
    at org.codehaus.groovy.runtime.InvokerHelper.getProperty(InvokerHelper.java:174)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.getProperty(ScriptBytecodeAdapter.java:456)
    at com.cloudbees.groovy.cps.sandbox.DefaultInvoker.getProperty(DefaultInvoker.java:39)
    at com.cloudbees.groovy.cps.impl.PropertyAccessBlock.rawGet(PropertyAccessBlock.java:20)
    at cicd.onSuccess(cicd.groovy:413)
    at WorkflowScript.run(WorkflowScript:304)
    at ___cps.transform___(Native Method)
    at com.cloudbees.groovy.cps.impl.PropertyishBlock$ContinuationImpl.get(PropertyishBlock.java:74)
    at com.cloudbees.groovy.cps.LValueBlock$GetAdapter.receive(LValueBlock.java:30)
    at com.cloudbees.groovy.cps.impl.PropertyishBlock$ContinuationImpl.fixName(PropertyishBlock.java:66)
    at jdk.internal.reflect.GeneratedMethodAccessor190.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
    at com.cloudbees.groovy.cps.impl.ConstantBlock.eval(ConstantBlock.java:21)
    at com.cloudbees.groovy.cps.Next.step(Next.java:83)
    at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:174)
    at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:163)
    at org.codehaus.groovy.runtime.GroovyCategorySupport$ThreadCategoryInfo.use(GroovyCategorySupport.java:129)
    at org.codehaus.groovy.runtime.GroovyCategorySupport.use(GroovyCategorySupport.java:268)
    at com.cloudbees.groovy.cps.Continuable.run0(Continuable.java:163)
    at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.access$001(SandboxContinuable.java:18)
    at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.run0(SandboxContinuable.java:51)
    at org.jenkinsci.plugins.workflow.cps.CpsThread.runNextChunk(CpsThread.java:185)
    at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.run(CpsThreadGroup.java:400)
    at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.access$400(CpsThreadGroup.java:96)
    at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:312)
    at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:276)
    at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$2.call(CpsVmExecutorService.java:67)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:139)
    at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
    at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:68)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.base/java.lang.Thread.run(Thread.java:829)

Also in the Jenkins error log at "C:\Program Files\Jenkins\jenkins.err.log", I see other recurrent exceptions which I think are correlated to the above one:

2021-08-22 13:35:02.728+0000 [id=18454] SEVERE  o.j.p.g.c.GithubNotificationConfig#log
java.net.SocketTimeoutException: connect timed out
    at java.base/java.net.PlainSocketImpl.waitForConnect(Native Method)
    at java.base/java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:107)
    at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399)
    at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242)
    at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224)
    at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
    at java.base/java.net.Socket.connect(Socket.java:609)
    at java.base/sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:289)
    at java.base/sun.net.NetworkClient.doConnect(NetworkClient.java:177)
    at java.base/sun.net.www.http.HttpClient.openServer(HttpClient.java:474)
    at java.base/sun.net.www.http.HttpClient.openServer(HttpClient.java:569)
    at java.base/sun.net.www.protocol.https.HttpsClient.<init>(HttpsClient.java:265)
    at java.base/sun.net.www.protocol.https.HttpsClient.New(HttpsClient.java:372)
    at java.base/sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.getNewHttpClient(AbstractDelegateHttpsURLConnection.java:203)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java:1187)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:1081)
    at java.base/sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(AbstractDelegateHttpsURLConnection.java:189)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1592)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1520)
    at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:527)
    at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:334)
    at org.kohsuke.github.GitHubHttpUrlConnectionClient.getResponseInfo(GitHubHttpUrlConnectionClient.java:64)
    at org.kohsuke.github.GitHubClient.sendRequest(GitHubClient.java:394)
Caused: org.kohsuke.github.HttpException: Server returned HTTP response code: -1, message: 'null' for URL: https://github.hpe.com/api/v3/users/TME
    at org.kohsuke.github.GitHubClient.interpretApiError(GitHubClient.java:494)
    at org.kohsuke.github.GitHubClient.sendRequest(GitHubClient.java:414)
    at org.kohsuke.github.GitHubClient.sendRequest(GitHubClient.java:358)
    at org.kohsuke.github.Requester.fetch(Requester.java:76)
    at org.kohsuke.github.GitHub.getUser(GitHub.java:536)
    at org.jenkinsci.plugins.githubautostatus.config.GithubNotificationConfig.extractGHRepositoryInfo(GithubNotificationConfig.java:257)
    at org.jenkinsci.plugins.githubautostatus.config.GithubNotificationConfig.fromRun(GithubNotificationConfig.java:146)
    at org.jenkinsci.plugins.githubautostatus.config.GithubNotificationConfig.fromRun(GithubNotificationConfig.java:124)
    at org.jenkinsci.plugins.githubautostatus.BuildStatusAction.connectNotifiers(BuildStatusAction.java:132)
    at org.jenkinsci.plugins.githubautostatus.BuildStatusAction.<init>(BuildStatusAction.java:115)
    at org.jenkinsci.plugins.githubautostatus.BuildStatusAction.newAction(BuildStatusAction.java:101)
    at org.jenkinsci.plugins.githubautostatus.GithubBuildStatusGraphListener.checkEnableBuildStatus(GithubBuildStatusGraphListener.java:274)
    at org.jenkinsci.plugins.githubautostatus.GithubBuildStatusGraphListener.onNewHead(GithubBuildStatusGraphListener.java:70)
    at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.notifyListeners(CpsFlowExecution.java:1473)
    at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$3.run(CpsThreadGroup.java:489)
    at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$1.run(CpsVmExecutorService.java:38)
    at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:139)
    at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
    at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:68)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.base/java.lang.Thread.run(Thread.java:829)

Again, everything else works. Jenkins successfully pulls the code from the github server using the credentials configured in the Github Branch Source plugin, and every other plugin accessing our github server.

aaronwalker commented 3 years ago

@JFLarvoire did the you change the version of the plugin between that time? Also how are you authenticating against github. Are you using PAT or github oauth

JFLarvoire commented 3 years ago

did the you change the version of the plugin between that time?

No, it's not been changed.

Also how are you authenticating against github. Are you using PAT or github oauth

We're authenticating using a personal access token. It's not been changed recently, and the same token is used for pulling the code from github.

aaronwalker commented 3 years ago

@JFLarvoire are you using a hosted github enterprise or self hosted?

JFLarvoire commented 3 years ago

It's github enterprise. (github.hpe.com , accessible only internally within hpe.)

aaronwalker commented 3 years ago

@JFLarvoire I'm not able to reproduce the error as I don't have access to a self hosted Github Enterprise but I have tested it against managed Github Enterprise. You could try a pre-release of 2.8 which you can download from here https://repo.jenkins-ci.org/incrementals/org/jenkins-ci/plugins/pipeline-github/2.8-134.4da108752a5e/pipeline-github-2.8-134.4da108752a5e.hpi

aaronwalker commented 3 years ago

@JFLarvoire Release https://github.com/jenkinsci/pipeline-github-plugin/releases/tag/2.8-138.d766e30bb08b is now available are you able to confirm you still have the same issue?

JFLarvoire commented 3 years ago

I just upgraded Jenkins and the pipeline: github plugin, and the problem is still there. Please reopen the case.

JFLarvoire commented 3 years ago

And I still have the same questions as in the opening message:

Where does the pipeline: github plugin gets its github API URL and credentials from? (The plugin does not seem to have any setting in the global or project configuration.)

How can we get more information about what's going on under the hood, leading to that timeout?

Is there a way to enable logging, to get more information about what the plugin is doing, and why it fails?

aaronwalker commented 3 years ago

@JFLarvoire it gets the creds from the Jenkins job itself along with the github api endpoint as since it was working previously then it most likely an environmental issue. I would suggest doing a tcpdump from the jenkins agent and inspecting the traffic to confirm its trying to contact the correct api endpoint.