Get "Unable to connect to GitHub anonymously" error when attempting to trigger build

[hardboiled]

Every time I try to trigger builds via pull request comments, I see the request going successfully out from github to my webhook. I even built a "curl" request myself to verify that the 200 OK status I was getting back was being reported right. I've tested the connectivity and successfully made a comment on a pull request by running the test from the jenkins UI.

However, even though I'm getting a 200 every time when I trigger the callback for pull request builder, I found that jenkins wasn't triggering the build. Upon further investigation, I looked in /var/log/jenkins/jenkins.log and found this error message:

SEVERE: Unable to connect to GitHub anonymously

I have configured jenkins with valid ssh keys to access my repos and also confirmed access to push/pull/comment via the API token. What am I missing?

[hardboiled]

This is the full error.

Jul 26, 2016 5:42:58 PM org.jenkinsci.plugins.ghprb.GhprbRootAction handleAction
SEVERE: Unable to connect to GitHub anonymously
com.fasterxml.jackson.databind.JsonMappingException: Can not instantiate value of type [simple type, class org.kohsuke.github.GHEventPayload$PullRequest] from String value; no single-String constructor/factory method
    at com.fasterxml.jackson.databind.deser.std.StdValueInstantiator._createFromStringFallbacks(StdValueInstantiator.java:428)
    at com.fasterxml.jackson.databind.deser.std.StdValueInstantiator.createFromString(StdValueInstantiator.java:299)
    at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.deserializeFromString(BeanDeserializerBase.java:1056)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer._deserializeOther(BeanDeserializer.java:136)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:123)
    at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:2888)
    at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2057)
    at org.kohsuke.github.GitHub.parseEventPayload(GitHub.java:408)
    at org.jenkinsci.plugins.ghprb.GhprbRootAction.getPullRequest(GhprbRootAction.java:267)
    at org.jenkinsci.plugins.ghprb.GhprbRootAction.handleAction(GhprbRootAction.java:160)
    at org.jenkinsci.plugins.ghprb.GhprbRootAction.doIndex(GhprbRootAction.java:118)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.kohsuke.stapler.Function$InstanceFunction.invoke(Function.java:320)
    at org.kohsuke.stapler.Function.bindAndInvoke(Function.java:163)
    at org.kohsuke.stapler.Function.bindAndInvokeAndServeResponse(Function.java:96)
    at org.kohsuke.stapler.IndexDispatcher.dispatch(IndexDispatcher.java:26)
    at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:746)
    at org.kohsuke.stapler.Stapler.invoke(Stapler.java:876)
    at org.kohsuke.stapler.MetaClass$11.dispatch(MetaClass.java:380)
    at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:746)
    at org.kohsuke.stapler.Stapler.invoke(Stapler.java:876)
    at org.kohsuke.stapler.Stapler.invoke(Stapler.java:649)
    at org.kohsuke.stapler.Stapler.service(Stapler.java:238)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:848)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:686)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1494)
    at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:135)
    at hudson.util.PluginServletFilter.doFilter(PluginServletFilter.java:126)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1482)
    at hudson.security.csrf.CrumbFilter.doFilter(CrumbFilter.java:49)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1482)
    at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:84)
    at hudson.security.UnwrapSecurityExceptionFilter.doFilter(UnwrapSecurityExceptionFilter.java:51)
    at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
    at jenkins.security.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:117)
    at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
    at org.acegisecurity.providers.anonymous.AnonymousProcessingFilter.doFilter(AnonymousProcessingFilter.java:125)
    at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
    at org.acegisecurity.ui.rememberme.RememberMeProcessingFilter.doFilter(RememberMeProcessingFilter.java:135)
    at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
    at org.acegisecurity.ui.AbstractProcessingFilter.doFilter(AbstractProcessingFilter.java:271)
    at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
    at jenkins.security.BasicHeaderProcessor.doFilter(BasicHeaderProcessor.java:93)
    at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
    at org.acegisecurity.context.HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:249)
    at hudson.security.HttpSessionContextIntegrationFilter2.doFilter(HttpSessionContextIntegrationFilter2.java:67)
    at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87)
    at hudson.security.ChainedServletFilter.doFilter(ChainedServletFilter.java:76)
    at hudson.security.HudsonFilter.doFilter(HudsonFilter.java:171)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1482)
    at org.kohsuke.stapler.compression.CompressionFilter.doFilter(CompressionFilter.java:49)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1482)
    at hudson.util.CharacterEncodingFilter.doFilter(CharacterEncodingFilter.java:81)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1482)
    at org.kohsuke.stapler.DiagnosticThreadNameFilter.doFilter(DiagnosticThreadNameFilter.java:30)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1474)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:499)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:533)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1086)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:428)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1020)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
    at org.eclipse.jetty.server.Server.handle(Server.java:370)
    at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489)
    at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:960)
    at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:1021)
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:865)
    at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
    at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:668)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
    at winstone.BoundedExecutorService$1.run(BoundedExecutorService.java:77)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

[bwarfield-amplify]

@hardboiled if you remember and don't mind saying, what was the issue here? I have a similar problem, and if it's because I have a silly configuration issue I'd really appreciate a pointer.

[hardboiled]

@bwarfield-amplify I ended up using the ghprb polling option instead of webhooks as a workaround to this. However, on my newest jenkins setup, I installed SSH keys into the user directory in jenkins and added the path of the keys into the system settings in the Jenkins UI. This caused the webhooks to work, so I think this most likely would have solved the problem I was seeing here too.

[bwarfield-amplify]

I'm not sure about that—I'm now seeing a somewhat similar error (Jackson failure during response parsing) on some pull request builds but not others on the same jenkins installation. It's driving me mildly crazy, but polling does at least work around the problem.

[hardboiled]

I had issues on my AWS setup where the outbound TCP dynamic port range for my instances wasn't set properly. Do you have any restrictions on TCP ports, or is your jenkins box completely open?

[bwarfield-amplify]

As far as I know there aren't such restrictions (and I checked with the network guru and he agrees).

[hardboiled]

Hmm... Are your ssh keys stored in the jenkins home directory?

$ sudo su -s /bin/bash jenkins
$ cd ~/
$ pwd
> /var/lib/jenkins
$ ls ~/.ssh
> authorized_keys  id_rsa  id_rsa.pub  known_hosts

[bwarfield-amplify]

I have this on two different jenkinses right now, I think one of them has that setup and the other is using jenkins-managed credentials. (The one that has both working and non-working webhooks uses jenkins-managed credentials.)

[hardboiled]

Have you added the path to your id_rsa.pub file to the global jenkins credentials?

In the UI, I had to go to:

Jenkins -> Credentials -> System -> Global credentials

Then add a github username with a path to the file:

[bwarfield-amplify]

I should clarify that with polling everything works: the thing that's breaking is the API call back to github, which appears to be getting an invalid response of some kind. I appreciate the help, but I don't want to waste your time with general-purpose Jenkins debugging—I was just hoping there was a known answer for the "github suddenly hates my PRB API calls" problem. I'll try dialing up logging and see if more specific information emerges.

[bwarfield-amplify]

I successfully resolved my issue, after exploiting my reverse-proxy setup to get apache to dump out its input using mod_dumpio. I doubt it will be relevant to anybody else, but for the record: I had added a query string to my POST URL to debug an unrelated infrastructure issue. This caused the POST body to be (as far as I can tell) application/x-www-form-urlencoded instead of application/json, with my query string as one of the "form" parameters and the original payload as another (called "payload"). When it reached org.kohsuke.github.GitHub.parseEventPayload, though, it was being parsed as JSON instead of having the payload field extracted and parsed: understandably, this led to JSON parsing errors.

Unable to connect to GitHub anonymously
com.fasterxml.jackson.core.JsonParseException: Unexpected character ('a' (code 97)): expected a valid value (number, String, array, object, 'true', 'false' or 'null')
 at [Source: java.io.StringReader@557b6aba; line: 1, column: 2]
    at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1369)
    at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:532)
    at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:453)
    at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._handleUnexpectedValue(ReaderBasedJsonParser.java:1386)
    at com.fasterxml.jackson.core.json.ReaderBasedJsonParser.nextToken(ReaderBasedJsonParser.java:669)
    at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:2926)
    at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:2873)
    at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2057)
    at org.kohsuke.github.GitHub.parseEventPayload(GitHub.java:547)
    at org.jenkinsci.plugins.ghprb.GhprbRootAction.getIssueComment(GhprbRootAction.java:273)
    at org.jenkinsci.plugins.ghprb.GhprbRootAction.handleAction(GhprbRootAction.java:139)
    at org.jenkinsci.plugins.ghprb.GhprbRootAction.doIndex(GhprbRootAction.java:118)
    at sun.reflect.GeneratedMethodAccessor471.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[... etc, etc. ].