Problem

Jira is unable to send webhooks to remote services.

There is no apparent errors being logged for the issue in the logs using Jira default logging settings, only the below exception is noticed to be abundant in the logs:

2019-06-13 08:26:42,995 LittleProxy-ClientToProxyWorker-6 WARN      [i.netty.channel.ChannelInitializer] Failed to initialize a channel. Closing: [id: 0xd7871135, /127.0.0.1:52724 => /127.0.0.1:8888]
java.lang.ClassCastException: org.slf4j.impl.Log4jLoggerAdapter cannot be cast to org.slf4j.spi.LocationAwareLogger
        at org.littleshoot.proxy.impl.ProxyConnectionLogger.<init>(ProxyConnectionLogger.java:26)
        at org.littleshoot.proxy.impl.ProxyConnection.<init>(ProxyConnection.java:75)
        at org.littleshoot.proxy.impl.ClientToProxyConnection.<init>(ClientToProxyConnection.java:127)
        at org.littleshoot.proxy.impl.DefaultHttpProxyServer$1.initChannel(DefaultHttpProxyServer.java:295)
        at io.netty.channel.ChannelInitializer.channelRegistered(ChannelInitializer.java:69)
        at io.netty.channel.DefaultChannelHandlerContext.invokeChannelRegistered(DefaultChannelHandlerContext.java:163)
        at io.netty.channel.DefaultChannelHandlerContext.fireChannelRegistered(DefaultChannelHandlerContext.java:149)
        at io.netty.channel.DefaultChannelPipeline.fireChannelRegistered(DefaultChannelPipeline.java:730)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:442)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.access$100(AbstractChannel.java:374)
        at io.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:418)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:354)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:353)
        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
        at java.lang.Thread.run(Thread.java:748)

Diagnosis

Environment

• Web Fragment Finder Plugin is installed on the Jira instance.

• No forward proxy configuration is added to Jira start up options

Diagnostic Steps

• enable Debug logging on the below Jira packages:

• • com.atlassian.webhooks

  • org.apache.http

  • Please check the KB: How to set logging level for a package in JIRA on how to enable debug logging on a package.

• The above would show logs that looks like below basically from debug logging on com.atlassian.webhooks:

  2019-01-01 08:00:01,874 Web-Hook-Publisher-0 DEBUG aaaaa 111x11111x1 1utxvol 198.51.100.10 /secure/CommentAssignIssue.jspa [c.a.webhooks.plugin.PublishTaskFactoryImpl$PublishTaskImpl] Posting to web hook at 'http://test_example.url/test?user_id=aaaaa&user_key=aaaaa', body is:{"timestamp":1560921111111,"webhookEvent":"jira:issue_updated","issue_event_type_name":"issue_generic","user":{"self":"https://myjira.hostname/rest/api/2/user?username=aaaaa","name":"aaaaa","key":"aaaaa","emailAddress":"user@localdomain","avatarUrls":{"48x48":"https://myjira.hostname/secure/useravatar?ownerId=aaaaa&avatarId=10000","24x24":"https://myjira.hostname/secure/useravatar?size=small&ownerId=aaaaa&avatarId=10000","16x16":"https://myjira.hostname/secure/useravatar?size=xsmall&ownerId=aaaaa&avatarId=10000","32x32":"https://myjira.hostname/secure/useravatar?size=medium&ownerId=aaaaa&avatarId=10000"},"displayName":"user1","active":true,"timeZone":"Europe/Amsterdam"},"issue":{"id":"10000","self":"https://myjira.hostname/rest/api/2/issue/10000","key":"TEST-1","fields":{"issuetype":{"self":"https://myjira.hostname/rest/api/2/issuetype/3"

  As could be seen Jira is actually able to generate the webhook body, so the webhook core functionality is working fine.

• The org.apache.http shows below logs:

  2019-01-01 08:00:01,876 LittleProxy-ClientToProxyWorker-7 WARN      [i.netty.channel.ChannelInitializer] Failed to initialize a channel. Closing: [id: 0x162adda6, /127.0.0.1:56636 => /127.0.0.1:8888]
  java.lang.ClassCastException: org.slf4j.impl.Log4jLoggerAdapter cannot be cast to org.slf4j.spi.LocationAwareLogger
          at org.littleshoot.proxy.impl.ProxyConnectionLogger.<init>(ProxyConnectionLogger.java:26)
          at org.littleshoot.proxy.impl.ProxyConnection.<init>(ProxyConnection.java:75)
          at org.littleshoot.proxy.impl.ClientToProxyConnection.<init>(ClientToProxyConnection.java:127)
          at org.littleshoot.proxy.impl.DefaultHttpProxyServer$1.initChannel(DefaultHttpProxyServer.java:295)
          at io.netty.channel.ChannelInitializer.channelRegistered(ChannelInitializer.java:69)
          at io.netty.channel.DefaultChannelHandlerContext.invokeChannelRegistered(DefaultChannelHandlerContext.java:163)
          at io.netty.channel.DefaultChannelHandlerContext.fireChannelRegistered(DefaultChannelHandlerContext.java:149)
          at io.netty.channel.DefaultChannelPipeline.fireChannelRegistered(DefaultChannelPipeline.java:730)
          at io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:442)
          at io.netty.channel.AbstractChannel$AbstractUnsafe.access$100(AbstractChannel.java:374)
          at io.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:418)
          at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:354)
          at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:353)
          at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
          at java.lang.Thread.run(Thread.java:748)
  2019-01-01 08:00:01,876 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.client.InternalHttpAsyncClient] [exchange: 661] route completed
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.client.MainClientExec] [exchange: 661] Connection route established
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.client.MainClientExec] [exchange: 661] Attempt 1 to execute request
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.client.MainClientExec] [exchange: 661] Target auth state: UNCHALLENGED
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.client.MainClientExec] [exchange: 661] Proxy auth state: UNCHALLENGED
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.conn.ManagedNHttpClientConnectionImpl] http-outgoing-657 127.0.0.1:56636<->127.0.0.1:8888[ACTIVE][rw:]: Set timeout 20000
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.apache.http.headers] http-outgoing-657 >> POST http://test_example.url/qjukjsqj?user_id=aaaaa&user_key=aaaaa HTTP/1.1
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.apache.http.headers] http-outgoing-657 >> Accept: */*
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.apache.http.headers] http-outgoing-657 >> Content-Type: application/json; charset=UTF-8
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.apache.http.headers] http-outgoing-657 >> Via: 1.1 localhost (Apache-HttpClient/4.5.5 (cache))
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.apache.http.headers] http-outgoing-657 >> Content-Length: 7777
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.apache.http.headers] http-outgoing-657 >> Host: test_example.url
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.apache.http.headers] http-outgoing-657 >> Proxy-Connection: Keep-Alive
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.apache.http.headers] http-outgoing-657 >> User-Agent: Atlassian HttpClient 2.0.0 / JIRA-8.1.0 (801000) / Default
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.conn.ManagedNHttpClientConnectionImpl] http-outgoing-657 127.0.0.1:56636<->127.0.0.1:8888[ACTIVE][rw:]: Event set [w]
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.conn.ManagedNHttpClientConnectionImpl] http-outgoing-657 127.0.0.1:56636<->127.0.0.1:8888[ACTIVE][rw:rw]: -1 bytes read
  2019-01-01 08:00:01,877 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.conn.ManagedNHttpClientConnectionImpl] http-outgoing-657 127.0.0.1:56636<->127.0.0.1:8888[ACTIVE][rw:rw]: Shutdown
  2019-01-01 08:00:01,878 I/O dispatcher 8 DEBUG anonymous     [o.a.h.i.nio.client.InternalHttpAsyncClient] [exchange: 661] connection aborted
  2019-01-01 08:00:02,463 java-sdk-http-connection-reaper DEBUG      [o.a.h.impl.conn.PoolingHttpClientConnectionManager] Closing connections idle longer

  The above logs show that Jira tried to open a connection using the an HTTP forward proxy running at: 127.0.0.1:8888, even though Jira doesn’t have proxy settings in its start up options.

  The connection fails and is aborted and thus the webhook failed to be sent.

• And as could be seen, the org.littleshoot.proxy log4j exception now makes more sense as it is actually coming from the proxy that Jira is trying to used above, the little shoot proxy is actually introduced by the Web Fragment Finder plugin and is injected into Jira though Jira properties added by the plugin pragmatically.

Cause

The Web Fragment Finder plugin is the root cause of this issue.

The plugin should not be installed on a production instance as per the plugin Atlassian marketplace page.

Resolution

Disable or uninstall the Web Fragment Finder plugin to avoid running into those problems.

Jira Core