Intermittent failures to trigger a Jenkins build when an MR first opened

[cotman]

Hi,

I've noticed comments in other issues, elsewhere, but they seem to suggest they've gone away?

I'm running:

Jenkins: 1.654
Gitlab Plugin: 1.1.32
Gitlab: 8.5.4

For the most part, everything works brilliantly. However...occasionally when opening an MR, a build isn't triggered and I see the following in the jenkins.log:

Mar 29, 2016 2:56:15 PM com.dabsquared.gitlabjenkins.GitLabWebHook getDynamic
INFO: WebHook called with url: 
Mar 29, 2016 2:56:15 PM org.eclipse.jetty.util.log.JavaUtilLog warn
WARNING: Error while serving https://-removed-url-/project/-removed-project-name
java.lang.reflect.InvocationTargetException
at sun.reflect.GeneratedMethodAccessor1121.invoke(Unknown Source)
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:324)
at org.kohsuke.stapler.Function.bindAndInvoke(Function.java:167)
at org.kohsuke.stapler.MetaClass$11.dispatch(MetaClass.java:378)
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:134)
at hudson.plugins.greenballs.GreenBallFilter.doFilter(GreenBallFilter.java:59)
at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:131)
at hudson.util.PluginServletFilter.doFilter(PluginServletFilter.java:125)
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)
Caused by: java.lang.NullPointerException
at com.dabsquared.gitlabjenkins.GitLabWebHook.getBuildBySHA1(GitLabWebHook.java:546)
at com.dabsquared.gitlabjenkins.GitLabWebHook.generateMergeRequestBuild(GitLabWebHook.java:475)
at com.dabsquared.gitlabjenkins.GitLabWebHook.generateBuild(GitLabWebHook.java:336)
at com.dabsquared.gitlabjenkins.GitLabWebHook.getDynamic(GitLabWebHook.java:146)
... 71 more

As above - it seems to work sometimes, but not others. When it doesn't work, providing another triggered event (MR related or pushing to the source branch in the MR) and the build gets triggered correctly.

I guess the empty INFO: WebHook called with url: is a little suspicious?
The Gitlab projects I've seen this on have (so far) got 2 webhooks associated with them - don't know if that's related?

The Gitlab webhooks are configured to be executed on MR events and push events, and I have the following Gitlab Plugin options selected on the job:

• Build on Merge Request Events
• Rebuild open Merge Requests: On push to the source branch
• Enable [ci-skip]
• Set build description to build cause (eg. Merge request or Git Push )
• Add note with build status on merge requests
• Use GitLab CI features (GitLab 8.1 required!)
• Vote added to note with build status on merge requests

Thanks.

[cotman]

Actually, seems a bit worse than what's above.

I've just opened an MR to find the exception thrown in the logs and no build triggered, but then closing/re-opening the MR doesn't trigger it either - the same exception is thrown.

I then trimmed down the webhooks on the Gitlab project so that there was just a single one left, but the same thing seems to happen.

[cotman]

Apologies for the stream of consciousness on this, but it seems to be happening across projects now - we're not getting any triggering.

The version of Gitlab hasn't changed since it was all working well, but we have upgraded Jenkins (and, perhaps, dependent, plugins). We're currently running Jenkins 1.655, so the issue definitely occurs with 1.654 and 1.655.

Again, don't know if it's related, but INFO: WebHook called with url: always seems to be empty in the logs, even if you just perform a test of the webhook from the Gitlab settings page.

[omehegan]

I looked into this and was about to comment to say I have no idea what is going on, but it looks like @pbendersky does :) We will review his PR.

[cotman]

Ah - interesting (and thanks for looking). Will keep an eye on the PR.

For the existing case, it seems to happen all the time for us now, but only with MR events - we always get the exception and no triggered build. This did all work previously, and work really well, so I'm suspecting a Jenkins/dependent Jenkins Plugin might be the cause?

When making a push to the source branch of an MR, after opening and the initial failure, a build does always seem to be triggered - in the logs INFO: WebHook called with url: is still empty, but shortly after INFO: -project-name- triggered for merge request is present and everything works. Closing/opening an MR doesn't do the same though (although, as above, this did work before) so if the PR addresses MR behaviour in a different way, I guess it does look likely there's a chance it'll address it.

[omehegan]

@cotman I would suggest you try upgrading to the latest version of the plugin, it has a substantial refactor of code and may resolve this issue on its own. Let me know if not.