Loading...

Type: Bug
Resolution: Fixed
Priority: High
Fix Version/s: 9.3.2, 9.4.1, 8.20.16
Affects Version/s: 6.4-OD-13, 6.4.2, 6.4.11, 6.4.12, 7.2.4, 8.13.27, 8.20.14, 9.3.1
Component/s: Webhooks
Labels:

Introduced in Version:
6.04
Support reference count:
77
Symptom Severity:
Severity 2 - Major
UIS:
41
Bug Fix Policy:
View Atlassian Server bug fix policy

NOTE: This bug report is for JIRA Server. Using JIRA Cloud? See the corresponding bug report.

Summary

If the JIRA WebHook destination connection fails for any reason, such as the below, there will be no errors in the log, so no exceptions - essentially WebHooks fail silently:

The domain uses self signed certificate that's not in the Java trust store.
There's any other problem with verifying SSL connection (like certificate issued by an unknown CA, protocol/cipher mismatch and so on).
The host cannot be reached, due to network configuration.
The URL is invalid.

This makes it hard to understand why the connection failed, as nothing is written about the failure.

Steps to Reproduce

Setup a WebHook to send to a target that will fail (for example, it uses a self-signed certificate not in the JIRA's trust store, or SSL is configured in a way that will generate an exception, or the URL does not exist).
Attempt to send the WebHook by performing the JIRA action that triggers it.

Expected Results

The exception is written to the logs.

Actual Results

No exception is written to the logs or thrown.

Diagnose

Identify why the connection is failing - this can be tested outside of JIRA by using network tools such as cURL, telnet and/or ping. For example, if the target URL is www.example.com/webhook/test/ perform these tests from the JIRA server:

If using the -Dhttp.nonProxyHosts argument, the request may be failing due to ~~JRA-43143~~ (WebHooks are not respecting this argument).
ping www.example.com to see if the servers can establish a network connection.
telnet www.example.com 80 to see if the appropriate port is open.
curl -X POST www.example.com/webhook/test/ to see that you can submit a POST to the target server.

If these tests fail, it can indicate that network / firewall / DNS configurations may need to be addressed, depending upon the errors returned from the different tests.

If this is SSL related, ensure to import the self-signed certificate into the trust store as per Connecting to SSL services.

Workaround

Add the following startup options following the steps on Setting properties and options on startup:
- -Djavax.net.debug=ssl
- -Dssl.debug=true
Restart Jira.
Change logging level of packages com.atlassian.httpclient and com.atlassian.webhooks to DEBUG.

Here's an example of a webhook failing due to a non-existing hostname:

2018-08-10 14:51:07,060 Web-Hook-Publisher-1 DEBUG admin 888x149x1 1psle0s 192.168.11.106 /secure/WorkflowUIDispatcher.jspa [c.a.webhooks.plugin.PublishTaskFactoryImpl$PublishTaskImpl] Posting to web hook at 'https://123455555555webhook.site/cdf6ac3c-57c6-4d04-b212-8fca00ed7fc1?user_id=admin&user_key=admin', body is:


2018-08-10 14:51:07,061 Web-Hook-Publisher-1 DEBUG admin 888x149x1 1psle0s 192.168.11.106 /secure/WorkflowUIDispatcher.jspa [c.a.h.a.httpcomponents.cache.FlushableHttpCacheStorageImpl] Cache [7e644a31] is getting 'https://123455555555webhook.site:443/cdf6ac3c-57c6-4d04-b212-8fca00ed7fc1?user_id=admin&user_key=admin's response: null
2018-08-10 14:51:07,061 Web-Hook-Publisher-1 DEBUG admin 888x149x1 1psle0s 192.168.11.106 /secure/WorkflowUIDispatcher.jspa [c.a.h.apache.httpcomponents.ApacheAsyncHttpClient$2] Connection request: [route: {s}->https://123455555555webhook.site:443][total kept alive: 1; route allocated: 0 of 20; total allocated: 1 of 20]
2018-08-10 14:51:07,064 Web-Hook-Publisher-1 DEBUG admin 888x149x1 1psle0s 192.168.11.106 /secure/WorkflowUIDispatcher.jspa [c.a.h.apache.httpcomponents.ApacheAsyncHttpClient$2] Connection request failed
java.net.UnknownHostException: 123455555555webhook.site: nodename nor servname provided, or not known
	at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
	at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:928)
	at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1323)
	at java.net.InetAddress.getAllByName0(InetAddress.java:1276)
	at java.net.InetAddress.getAllByName(InetAddress.java:1192)
	at java.net.InetAddress.getAllByName(InetAddress.java:1126)
	at org.apache.http.impl.conn.SystemDefaultDnsResolver.resolve(SystemDefaultDnsResolver.java:45)
	at org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager$InternalAddressResolver.resolveRemoteAddress(PoolingNHttpClientConnectionManager.java:637)
	at org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager$InternalAddressResolver.resolveRemoteAddress(PoolingNHttpClientConnectionManager.java:608)
	at org.apache.http.nio.pool.AbstractNIOConnPool.processPendingRequest(AbstractNIOConnPool.java:474)
	at org.apache.http.nio.pool.AbstractNIOConnPool.lease(AbstractNIOConnPool.java:280)
	at org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager.requestConnection(PoolingNHttpClientConnectionManager.java:268)
	at org.apache.http.impl.nio.client.AbstractClientExchangeHandler.requestConnection(AbstractClientExchangeHandler.java:377)
	at org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl.start(DefaultClientExchangeHandlerImpl.java:129)
	at org.apache.http.impl.nio.client.InternalHttpAsyncClient.execute(InternalHttpAsyncClient.java:141)
	at com.atlassian.httpclient.apache.httpcomponents.BoundedHttpAsyncClient.execute(BoundedHttpAsyncClient.java:49)
	at org.apache.http.impl.client.cache.CachingHttpAsyncClient.callBackend(CachingHttpAsyncClient.java:691)
	at org.apache.http.impl.client.cache.CachingHttpAsyncClient.execute(CachingHttpAsyncClient.java:323)
	at org.apache.http.impl.client.cache.CachingHttpAsyncClient.execute(CachingHttpAsyncClient.java:281)
	at com.atlassian.httpclient.apache.httpcomponents.SettableFuturePromiseHttpPromiseAsyncClient.execute(SettableFuturePromiseHttpPromiseAsyncClient.java:33)
	at com.atlassian.httpclient.apache.httpcomponents.ApacheAsyncHttpClient.doExecute(ApacheAsyncHttpClient.java:344)
	at com.atlassian.httpclient.apache.httpcomponents.ApacheAsyncHttpClient.execute(ApacheAsyncHttpClient.java:297)
	at com.atlassian.httpclient.apache.httpcomponents.DefaultRequest$DefaultRequestBuilder.execute(DefaultRequest.java:258)
	at com.atlassian.httpclient.apache.httpcomponents.DefaultRequest$DefaultRequestBuilder.post(DefaultRequest.java:226)
	at com.atlassian.webhooks.plugin.PublishTaskFactoryImpl$PublishTaskImpl.run(PublishTaskFactoryImpl.java:119)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

And here's an example of an SSL error:

2018-08-10 15:59:03,782 Web-Hook-Publisher-0 DEBUG admin 959x80x1 nsbpb3 192.168.11.106 /secure/WorkflowUIDispatcher.jspa [c.a.webhooks.plugin.PublishTaskFactoryImpl$PublishTaskImpl] Posting to web hook at 'https://self-signed.badssl.com/?user_id=admin&user_key=admin', body is:


2018-08-10 15:59:03,809 Web-Hook-Publisher-0 DEBUG admin 959x80x1 nsbpb3 192.168.11.106 /secure/WorkflowUIDispatcher.jspa [c.a.h.a.httpcomponents.cache.FlushableHttpCacheStorageImpl] Cache [59906666] is getting 'https://self-signed.badssl.com:443/?user_id=admin&user_key=admin's response: null
2018-08-10 15:59:03,824 Web-Hook-Publisher-0 DEBUG admin 959x80x1 nsbpb3 192.168.11.106 /secure/WorkflowUIDispatcher.jspa [c.a.h.apache.httpcomponents.ApacheAsyncHttpClient$2] Connection request: [route: {s}->https://self-signed.badssl.com:443][total kept alive: 0; route allocated: 0 of 20; total allocated: 0 of 20]
2018-08-10 15:59:04,236 I/O dispatcher 1 DEBUG      [c.a.h.apache.httpcomponents.ApacheAsyncHttpClient$2] Connection leased: [id: http-outgoing-0][route: {s}->https://self-signed.badssl.com:443][total kept alive: 0; route allocated: 1 of 20; total allocated: 0 of 20]
Using SSLEngineImpl.
Allow unsafe renegotiation: false
Allow legacy hello messages: true
Is initial handshake: true
Is secure renegotiation: false
Ignoring unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384 for TLSv1
Ignoring unsupported cipher suite: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384 for TLSv1
Ignoring unsupported cipher suite: TLS_RSA_WITH_AES_256_CBC_SHA256 for TLSv1
Ignoring unsupported cipher suite: TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384 for TLSv1
Ignoring unsupported cipher suite: TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384 for TLSv1
Ignoring unsupported cipher suite: TLS_DHE_RSA_WITH_AES_256_CBC_SHA256 for TLSv1
Ignoring unsupported cipher suite: TLS_DHE_DSS_WITH_AES_256_CBC_SHA256 for TLSv1
Ignoring unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384 for TLSv1.1
Ignoring unsupported cipher suite: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384 for TLSv1.1
Ignoring unsupported cipher suite: TLS_RSA_WITH_AES_256_CBC_SHA256 for TLSv1.1
Ignoring unsupported cipher suite: TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384 for TLSv1.1
Ignoring unsupported cipher suite: TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384 for TLSv1.1
Ignoring unsupported cipher suite: TLS_DHE_RSA_WITH_AES_256_CBC_SHA256 for TLSv1.1
Ignoring unsupported cipher suite: TLS_DHE_DSS_WITH_AES_256_CBC_SHA256 for TLSv1.1
%% No cached client session
*** ClientHello, TLSv1.2
RandomCookie:  GMT: 1533862008 bytes = { 209, 140, 137, 92, 18, 244, 221, 60, 165, 208, 92, 32, 159, 244, 73, 41, 214, 13, 82, 53, 223, 120, 242, 67, 154, 147, 185, 144 }
Session ID:  {}
Cipher Suites: [TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
Compression Methods:  { 0 }
Extension elliptic_curves, curve names: {secp256r1, secp384r1, secp521r1, sect283k1, sect283r1, sect409k1, sect409r1, sect571k1, sect571r1, secp256k1}
Extension ec_point_formats, formats: [uncompressed]
Extension signature_algorithms, signature_algorithms: SHA512withECDSA, SHA512withRSA, SHA384withECDSA, SHA384withRSA, SHA256withECDSA, SHA256withRSA, SHA256withDSA, SHA224withECDSA, SHA224withRSA, SHA224withDSA, SHA1withECDSA, SHA1withRSA, SHA1withDSA
Extension extended_master_secret
Extension server_name, server_name: [type=host_name (0), value=self-signed.badssl.com]
***
I/O dispatcher 1, WRITE: TLSv1.2 Handshake, length = 230
I/O dispatcher 1, READ: TLSv1.2 Handshake, length = 93
*** ServerHello, TLSv1.2
RandomCookie:  GMT: 1779871155 bytes = { 112, 235, 69, 55, 89, 157, 131, 71, 136, 113, 180, 235, 69, 30, 91, 123, 61, 79, 37, 254, 31, 230, 84, 234, 255, 86, 129, 84 }
Session ID:  {180, 234, 239, 132, 255, 45, 14, 230, 19, 99, 6, 124, 133, 71, 206, 244, 228, 232, 155, 102, 157, 23, 202, 204, 196, 205, 189, 7, 131, 130, 109, 38}
Cipher Suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
Compression Method: 0
Extension server_name, server_name:
Extension renegotiation_info, renegotiated_connection: <empty>
Extension ec_point_formats, formats: [uncompressed, ansiX962_compressed_prime, ansiX962_compressed_char2]
***
%% Initialized:  [Session-13, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256]
** TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
I/O dispatcher 1, READ: TLSv1.2 Handshake, length = 903
*** Certificate chain
chain [0] = [
[
  Version: V3
  Subject: CN=*.badssl.com, O=BadSSL, L=San Francisco, ST=California, C=US
  Signature Algorithm: SHA256withRSA, OID = 1.2.840.113549.1.1.11

  Key:  Sun RSA public key, 2048 bits
  modulus: 24492660100626679905549940109758101886765610555498019561237351076174546942126705991290366882656509310080501513812602706206351444964387935952263594274233370803388167168928622758093210777190425680103032107490380624850201721276806477615228126295940226807450889945207930835675033102934727992726436862717218438550009918736547634295262737442314962888280468639663924173291556081067280523421305313565638162799590985864930177996395295461079048360209103196860440439931811226709024172075892526400113878162488184158428982955287187952820072365979821268476491392572259766081582413144401029571982863046316691680331687828250550192773
  public exponent: 65537
  Validity: [From: Mon Aug 08 18:17:05 BRT 2016,
               To: Wed Aug 08 18:17:05 BRT 2018]
  Issuer: CN=*.badssl.com, O=BadSSL, L=San Francisco, ST=California, C=US
  SerialNumber: [    86fb4dc8 e5dd0f18]

Certificate Extensions: 2
[1]: ObjectId: 2.5.29.19 Criticality=false
BasicConstraints:[
  CA:false
  PathLen: undefined
]

[2]: ObjectId: 2.5.29.17 Criticality=false
SubjectAlternativeName [
  DNSName: *.badssl.com
  DNSName: badssl.com
]

]
  Algorithm: [SHA256withRSA]
  Signature:
0000: B5 B8 A5 A7 79 D9 3E D5   37 0D A7 14 C8 CF 1F DF  ....y.>.7.......
0010: 19 24 D0 10 42 05 B2 AF   71 F6 2A 56 4D E8 81 46  .$..B...q.*VM..F
0020: B2 89 CE 9C 20 BF 0E 8F   01 3F 1E 81 9C FD CF 17  .... ....?......
0030: 0A 2F 58 C6 AD D5 5B E7   45 1A 02 F2 5C 3F DF 47  ./X...[.E...\?.G
0040: 84 6B 35 AA 05 11 99 58   FC FA 2C 74 C4 DC 33 41  .k5....X..,t..3A
0050: 25 D7 3C C7 3E A6 87 CA   BD 44 95 FF 3C 08 FE 61  %.<.>....D..<..a
0060: 81 8D 12 54 EE EA A8 F8   F5 84 F4 04 48 4C 17 85  ...T........HL..
0070: 3E 75 34 34 1B CC B7 C7   85 8D 7E 2B BD A4 6A B2  >u44.......+..j.
0080: AE 9F 1D 03 37 A2 74 C7   D0 FE 95 34 D4 FA 68 3D  ....7.t....4..h=
0090: 30 CB BD 10 CD 92 63 2C   00 13 44 D5 F5 C1 7C 9C  0.....c,..D.....
00A0: 43 0C 6C 1F AB 5C 58 D6   3D B7 16 6E 81 A2 5C 19  C.l..\X.=..n..\.
00B0: 0B 6C BB 9F 5F 61 FA F3   18 55 66 C6 A2 8B EB 7F  .l.._a...Uf.....
00C0: 6F E2 6D 3B ED 71 3C 9F   0E 8A 7B 82 5E 58 CB 73  o.m;.q<.....^X.s
00D0: A7 71 9C 68 90 58 F6 D6   B5 19 A4 B8 31 F5 E6 B8  .q.h.X......1...
00E0: 6B DC F7 17 31 33 E6 E7   F2 9E AD 37 46 11 D3 13  k...13.....7F...
00F0: 57 AE FA 00 F3 30 41 74   18 D8 46 1A C2 AA 78 0E  W....0At..F...x.

]
***
I/O dispatcher 1, fatal error: 46: General SSLEngine problem
sun.security.validator.ValidatorException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target
%% Invalidated:  [Session-13, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256]
I/O dispatcher 1, SEND TLSv1.2 ALERT:  fatal, description = certificate_unknown
I/O dispatcher 1, WRITE: TLSv1.2 Alert, length = 2
I/O dispatcher 1, fatal: engine already closed.  Rethrowing javax.net.ssl.SSLHandshakeException: General SSLEngine problem
2018-08-10 15:59:04,433 I/O dispatcher 1 DEBUG anonymous     [c.a.h.apache.httpcomponents.ApacheAsyncHttpClient$2] Releasing connection: [id: http-outgoing-0][route: {s}->https://self-signed.badssl.com:443][total kept alive: 0; route allocated: 1 of 20; total allocated: 1 of 20]
2018-08-10 15:59:04,434 I/O dispatcher 1 DEBUG anonymous     [c.a.h.apache.httpcomponents.ApacheAsyncHttpClient$2] Connection released: [id: http-outgoing-0][route: {s}->https://self-signed.badssl.com:443][total kept alive: 0; route allocated: 0 of 20; total allocated: 0 of 20]
java-sdk-http-connection-reaper, called close()
java-sdk-http-connection-reaper, called closeInternal(true)
java-sdk-http-connection-reaper, SEND TLSv1.2 ALERT:  warning, description = close_notify
java-sdk-http-connection-reaper, WRITE: TLSv1.2 Alert, length = 26
java-sdk-http-connection-reaper, called closeSocket(true)
java-sdk-http-connection-reaper, called close()
java-sdk-http-connection-reaper, called closeInternal(true)
java-sdk-http-connection-reaper, SEND TLSv1.2 ALERT:  warning, description = close_notify
java-sdk-http-connection-reaper, WRITE: TLSv1.2 Alert, length = 26
java-sdk-http-connection-reaper, called closeSocket(true)

is related to

JRASERVER-61937 Atlassian HTTP client might stop working at high load

Closed

JRASERVER-41463 Webhook logging for JIRA

Gathering Interest

relates to

JRACLOUD-41388 WebHooks will not log any errors or throw an exception when there's a connection error

Closed

JRASERVER-43143 Webhooks failing to bypass proxy when receiving URL is configured as a nonProxyHost in JVM configuration

Closed

JRASERVER-39361 We should improve the Webhooks logging

Gathering Interest

RAID-89 Loading...

cloned by: CRANE-873 Loading...

mentioned in: Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...

(1 relates to, 1 cloned by, 15 mentioned in)

Details

Description

Summary

Steps to Reproduce

Expected Results

Actual Results

Diagnose

Workaround

Attachments

Issue Links

Forms

Activity

People

Dates