If tried and true connections to 3rd party systems all of a sudden stop working, it is usually the work of either a system update on either side, or a certification and thus communication problem.
Typical Error Scenarios
We had certificate problems with an external service. The external service provider assured us that they had no problems in their logs at all, while we got three retries and then a "give up" message in the ivy.log:
2020-06-03 09:54:37.854-[SERVICE INFO] Invoking REST service call to GET https://testservices.ourservice.ch/api/address/v2/validate?zip=...&town=...&countryCode=CH&street=...&live=true
2020-06-03 09:54:38.179-[SERVICE ERROR] [ch.axonivy.fintech.crdhway.property.OurServiceCallbackListener]
Run ourService calculation failed:
javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid
certification path to requested target
javax.ws.rs.ProcessingException: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException:
PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid
certification path to requested target
at org.glassfish.jersey.client.internal.HttpUrlConnector.apply(HttpUrlConnector.java:287)
Caused by: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException:
PKIX path building failed:
sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path
to requested target
at sun.security.ssl.Alerts.getSSLException(Alerts.java:192)
...
Caused by: sun.security.validator.ValidatorException: PKIX path building failed:
sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path
to requested target
...
Caused by: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification
path to requested target
at sun.security.provider.certpath.SunCertPathBuilder.build(SunCertPathBuilder.java:141)
unable to find valid certification path to requested target is a typical error message for the scenario.
But, the error image changed without a change on our side in the ivy.log:
2020-06-03 10:37:56.475-[SERVICE INFO] Invoking REST service call to POST https://testservices.ourService.ch/api/auth/v2/login
2020-06-03 10:37:56.544-[SERVICE INFO] Invoking REST service call to POST https://testservices.ourService.ch/api/auth/v2/login
2020-06-03 10:37:56.613-[SERVICE INFO] Invoking REST service call to POST https://testservices.ourService.ch/api/auth/v2/login
2020-06-03 10:37:56.657-[SERVICE ERROR] Cannot retry calling authentication web service with error: java.lang.RuntimeException: Command failed on all of 3 retries
How To Debug Certificate Problems
Record Interaction Session
We start to debug by adding the following parameters to
- jvm.options (Ivy 8 or newer engine)
- AxonIvyEngine.conf (Ivy 7 or older engine)
- Axon.ivy Designer.ini (Designer up to 8.0.x)
- AxonIvyDesigner.ini (Designer 9+)
-Djavax.net.debug=all
You need to restart the engine or designer for this logging to start.
A good reference of the settings possible for javax.net.debug, see IBM's debugging and troubleshooting page.
File Axon.ivy engine.console (up to Ivy engine 7), console.log (from ivy engine 8) is created and contains all messages from the javax.net debug requested.
Once you have made your application contact the non-working service,
for Ivy 7 and earlier:
- stop the engine
- rename Axon.ivy engine.console to Axon.ivy engine.console_ssl (or whatever you like)
- remove the debug setting from jvm.options or AxonIvyEngine.conf
- start the engine
For Ivy 8 and newer:
- open the Engine Cockpit, go to Monitor, Logs
- open the console.log
Now, analyze what messages have been issued during the contact.
Analyze Problems
- Open the log file created above.
- Search for the URL of the service you have problems with.
In our case, it's testapi.ourservice.ch.
Search backwards for the last start of a TLS/SSL handshake session, which starts with trustStore is:
Session Initiation Block:
trustStore is: configuration/truststore.jks
trustStore type is : jks
trustStore provider is :
init truststore
adding as trusted cert:
Subject: ...
Issuer: ...
Algorithm: ...
Valid from Mon Mar 30 02:00:00 CEST 2020 until Sat Jul 02 02:00:00 CEST 2022
adding as trusted cert:
...
trigger seeding of SecureRandom
done seeding SecureRandom
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_ECDSA_WITH_AES_256_CBC_SHA384 for TLSv1.1
Ignoring unsupported cipher suite: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384 for TLSv1.1
%% No cached client session
The service is likely in a ClientHello block; below, it is in the third-to-last line.
ClientHello Block:
*** ClientHello, TLSv1.2
RandomCookie: GMT: 1574503919 bytes = { 1, 35, ... }
Session ID: {}
Cipher Suites: [TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, ...]
Compression Methods: { 0 }
Extension elliptic_curves, curve names: {secp256r1, secp384r1, secp521r1}
Extension ec_point_formats, formats: [uncompressed]
Extension signature_algorithms, signature_algorithms: SHA512withECDSA, ...
Extension server_name, server_name: [type=host_name (0), value=testapi.ourservice.ch]
***
https-jsse-nio-8443-exec-3, WRITE: TLSv1.2 Handshake, length = 219
In response to the ClientHello, we get a ServerHello from the counterparty, i.e. the service:
ServerHello Block:
https-jsse-nio-8443-exec-3, READ: TLSv1.2 Handshake, length = 87
*** ServerHello, TLSv1.2
RandomCookie: GMT: 1574503916 bytes = { 98, ... }
Session ID: {204, ... }
Cipher Suite: TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA
Compression Method: 0
Extension renegotiation_info, renegotiated_connection: <empty>
Extension ec_point_formats, formats: [uncompressed]
***
%% Initialized: [Session-36, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA]
** TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA
Now, the certificate chain is displayed:
Certificate Chain Block:
https-jsse-nio-8443-exec-3, READ: TLSv1.2 Handshake, length = 5065
*** Certificate chain
chain [0] = [
[
Version: V3
Subject: CN=*.ourservice.ch, OU=OURSERVICE, O="OURSERVICE, Our ...", STREET=..., L=..., ST=..., C=CH
Signature Algorithm: SHA256withRSA, OID = 1.2.840.113549.1.1.11
Key: Sun RSA public key, 4096 bits
modulus: ...
public exponent: 65537
Validity: [From: Tue Jun 02 02:00:00 CEST 2020,
To: Tue Feb 02 00:59:59 CET 2021]
Issuer: CN=...
SerialNumber: [ ... ]
...
]
chain [1] = [
...
chain [2] = [
...
at the end of the interaction, we get the following block:
Outcome Block:
***
%% Invalidated: [Session-36, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA]
https-jsse-nio-8443-exec-3, SEND TLSv1.2 ALERT: fatal, description = certificate_unknown
https-jsse-nio-8443-exec-3, WRITE: TLSv1.2 Alert, length = 2
https-jsse-nio-8443-exec-3, called closeSocket()
https-jsse-nio-8443-exec-3, handling exception: javax.net.ssl.SSLHandshakeException:
sun.security.validator.ValidatorException: PKIX path building failed:
sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path
to requested target
As you see here, the session has been invalidated, and a fatal ALERT has been issued because of certificate_unknown, along with an exception
handling exception: javax.net.ssl.SSLHandshakeException:
sun.security.validator.ValidatorException: PKIX path building failed:
sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path
to requested target
This implies that the client has been unable to find a trusted certificate that matched one of the three in the chain. As the last in the chain is the most general certificate, start checking if the subject of the third certificate is in your truststore, i.e. list the trust store and search that listing for the subject string.
As these are machines at work, there is no room for slight differences, either the subject matches or there will be no common ground and thus no connection.
A successful handshake and certificate match would have led to:
Successful ServerHello:
*** ServerHelloDone
and finally, after the selection of the cipher suite:
Final Entry
*** Finished