Jira is unable to send webhooks to remote services with Web Fragment Finder Plugin installed

Summary

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:

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:

  1 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:

  1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 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.

Solution

Resolution

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