"Trust anchor for certification path not found" exception on android

[SimonWoolf]

Customer (chat log) getting a W/System.err: io.ably.lib.types.AblyException: javax.net.ssl.SSLHandshakeException: java.security.cert.CertPathValidatorException: Trust anchor for certification path not found. exception for rest requests (specifically, a history request).

Full stacktrace:

W/System.err: io.ably.lib.types.AblyException: javax.net.ssl.SSLHandshakeException: java.security.cert.CertPathValidatorException: Trust anchor for certification path not found.
W/System.err: at io.ably.lib.http.Http.httpExecute(Http.java:437)
W/System.err: at io.ably.lib.http.Http.httpExecute(Http.java:379)
W/System.err: at io.ably.lib.http.Http.httpExecuteWithRetry(Http.java:458)
W/System.err: at io.ably.lib.http.Http.ablyHttpExecute(Http.java:335)
W/System.err: at io.ably.lib.http.Http.get(Http.java:243)
W/System.err: at io.ably.lib.http.PaginatedQuery.get(PaginatedQuery.java:49)
W/System.err: at io.ably.lib.realtime.Channel.history(Channel.java:633)
<customer app frames removed>
W/System.err: at android.app.IntentService$ServiceHandler.handleMessage(IntentService.java:65)
W/System.err: at android.os.Handler.dispatchMessage(Handler.java:110)
W/System.err: at android.os.Looper.loop(Looper.java:193)
W/System.err: at android.os.HandlerThread.run(HandlerThread.java:61)
W/System.err: Caused by: javax.net.ssl.SSLHandshakeException: java.security.cert.CertPathValidatorException: Trust anchor for certification path not found.
W/System.err: at com.android.org.conscrypt.OpenSSLSocketImpl.startHandshake(OpenSSLSocketImpl.java:410)
W/System.err: at com.android.okhttp.Connection.upgradeToTls(Connection.java:146)
W/System.err: at com.android.okhttp.Connection.connect(Connection.java:107)
W/System.err: at com.android.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:294)
W/System.err: at com.android.okhttp.internal.http.HttpEngine.sendSocketRequest(HttpEngine.java:255)
W/System.err: at com.android.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:206)
W/System.err: at com.android.okhttp.internal.http.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:355)
W/System.err: at com.android.okhttp.internal.http.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:306
...

Customer says they've gotten this error on every device they've tried ("moto e, infocus m2, samsung j5, asus zenfone"), which run versions of android from ranging 4.4 to 6.0. They're not behind a corporate network.

Client lib log leading up to the exception:

10-27 15:50:08.423 I/System.out: (INFO): io.ably.lib.realtime.AblyRealtime: started
10-27 15:50:08.423 I/System.out: (INFO): Auth(): anonymous, using basic auth
10-27 15:50:08.424 D/dalvikvm: create interp thread : stack size=128KB
10-27 15:50:08.424 D/dalvikvm: create new thread
10-27 15:50:08.444 D/dalvikvm: new thread created
10-27 15:50:08.444 D/dalvikvm: update thread list
10-27 15:50:08.444 D/dalvikvm: threadid=20: interp stack at 0x64049000
10-27 15:50:08.444 D/dalvikvm: threadid=20: created from interp
10-27 15:50:08.445 D/dalvikvm: start new thread
10-27 15:50:08.445 D/dalvikvm: threadid=20: notify debugger
10-27 15:50:08.445 D/dalvikvm: threadid=20 (Thread-27218): calling run()
10-27 15:50:08.445 I/System.out: (VERBOSE): io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null
10-27 15:50:08.445 I/System.out: (VERBOSE): (VERBOSE): io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null
10-27 15:50:08.445 I/System.out: (DEBUG): io.ably.lib.transport.ITransport: getConnectParams: params = [key:<redacted>, format:msgpack, heartbeats:false]
10-27 15:50:08.446 I/System.out: io.ably.lib.realtime.Channel: RealtimeChannel(); channel = inbox:628
10-27 15:50:08.449 D/dalvikvm: create interp thread : stack size=128KB
10-27 15:50:08.449 D/dalvikvm: create new thread
10-27 15:50:08.449 D/dalvikvm: new thread created
10-27 15:50:08.450 D/dalvikvm: update thread list
10-27 15:50:08.450 D/dalvikvm: threadid=21: interp stack at 0x64069000
10-27 15:50:08.450 D/dalvikvm: threadid=21: created from interp
10-27 15:50:08.450 D/dalvikvm: start new thread
10-27 15:50:08.450 D/dalvikvm: threadid=21: notify debugger
10-27 15:50:08.450 D/dalvikvm: threadid=21 (Thread-27219): calling run()
10-27 15:50:08.450 I/System.out: (VERBOSE): io.ably.lib.transport.ConnectionManager: setState(): setting connecting
10-27 15:50:08.713 D/libc-netbsd: getaddrinfo: realtime.ably.io get result from proxy >>
10-27 15:50:08.714 I/System.out: propertyValue:true
10-27 15:50:08.714 I/System.out: [socket][3] connection realtime.ably.io/23.22.39.159:443;LocalPort=56303(0)
10-27 15:50:08.714 I/System.out: [CDS]connect[realtime.ably.io/23.22.39.159:443] tm:90
10-27 15:50:08.715 D/libc-netbsd: getaddrinfo: rest.ably.io get result from proxy >>
10-27 15:50:08.715 D/Posix: [Posix_connect Debug]Process <redacted> :443 
10-27 15:50:08.715 I/System.out: propertyValue:true
10-27 15:50:08.715 I/System.out: [socket][4] connection rest.ably.io/54.164.145.244:443;LocalPort=58148(4000)
10-27 15:50:08.715 I/System.out: [CDS]connect[rest.ably.io/54.164.145.244:443] tm:4
10-27 15:50:08.716 D/Posix: [Posix_connect Debug]Process <redacted> :443 
10-27 15:50:08.982 I/System.out: [socket][/192.168.1.2:56303] connected
10-27 15:50:08.983 D/NativeCrypto: ssl=0x63ac0398 NativeCrypto_SSL_do_handshake fd=0x1e900005 shc=0x20800009 timeout_millis=0 client_mode=1 npn=0x0
10-27 15:50:08.983 D/NativeCrypto: doing handshake ++
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x10 ret=1
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 handshake start in UNKWN  before/connect initialization
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:UNKWN  before/connect initialization
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:23WCHA SSLv2/v3 write client hello A
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1002 ret=-1
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:error exit in 23RSHA SSLv2/v3 read server hello A
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:08.984 D/NativeCrypto: doing handshake -- ret=-1
10-27 15:50:08.984 D/NativeCrypto: ssl=0x63ac0398 NativeCrypto_SSL_do_handshake ret=-1 errno=11 sslError=2 timeout_millis=0
10-27 15:50:08.987 I/System.out: [socket][/192.168.1.2:58148] connected
10-27 15:50:08.987 I/System.out: [CDS]rx timeout:15000
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 NativeCrypto_SSL_do_handshake fd=0xe1200005 shc=0xb9600009 timeout_millis=15000 client_mode=1 npn=0x0
10-27 15:50:08.989 D/NativeCrypto: doing handshake ++
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x10 ret=1
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 handshake start in UNKWN  before/connect initialization
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 SSL_connect:UNKWN  before/connect initialization
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 SSL_connect:23WCHA SSLv2/v3 write client hello A
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1002 ret=-1
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 SSL_connect:error exit in 23RSHA SSLv2/v3 read server hello A
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:08.989 D/NativeCrypto: doing handshake -- ret=-1
10-27 15:50:08.989 D/NativeCrypto: ssl=0x63eca278 NativeCrypto_SSL_do_handshake ret=-1 errno=11 sslError=2 timeout_millis=15000
10-27 15:50:09.248 D/NativeCrypto: doing handshake ++
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:3RSH_A SSLv3 read server hello A
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1002 ret=-1
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:error exit in 3RSC_A SSLv3 read server certificate A
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1002 ret=-1
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:error exit in 3RSC_A SSLv3 read server certificate A
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.248 D/NativeCrypto: doing handshake -- ret=-1
10-27 15:50:09.248 D/NativeCrypto: ssl=0x63ac0398 NativeCrypto_SSL_do_handshake ret=-1 errno=11 sslError=2 timeout_millis=0
10-27 15:50:09.249 D/NativeCrypto: doing handshake ++
10-27 15:50:09.250 E/NativeCrypto: ssl=0x63ac0398 cert_verify_callback x509_store_ctx=0x643d2940 arg=0x0
10-27 15:50:09.250 E/NativeCrypto: ssl=0x63ac0398 cert_verify_callback calling verifyCertificateChain authMethod=ECDHE_RSA
10-27 15:50:09.263 D/NativeCrypto: doing handshake ++
10-27 15:50:09.263 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:09.263 D/NativeCrypto: ssl=0x63eca278 SSL_connect:3RSH_A SSLv3 read server hello A
10-27 15:50:09.263 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.264 E/NativeCrypto: ssl=0x63eca278 cert_verify_callback x509_store_ctx=0x6399d8c0 arg=0x0
10-27 15:50:09.265 E/NativeCrypto: ssl=0x63eca278 cert_verify_callback calling verifyCertificateChain authMethod=ECDHE_RSA
10-27 15:50:09.271 D/NativeCrypto: ssl=0x63ac0398 cert_verify_callback => 1
10-27 15:50:09.271 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:09.271 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:3RSC_A SSLv3 read server certificate A
10-27 15:50:09.271 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63eca278 cert_verify_callback => 0
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:3RSKEA SSLv3 read server key exchange A
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63eca278 SSL_connect:3RSC_A SSLv3 read server certificate A
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:3RSD_A SSLv3 read server done A
10-27 15:50:09.273 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.274 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:09.274 D/NativeCrypto: ssl=0x63eca278 SSL_connect:3RSKEA SSLv3 read server key exchange A
10-27 15:50:09.274 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.274 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:09.274 D/NativeCrypto: ssl=0x63eca278 SSL_connect:3RSD_A SSLv3 read server done A
10-27 15:50:09.274 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.283 D/OpenSSLLib:  User Build
10-27 15:50:09.283 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:09.283 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:3WCKEA SSLv3 write client key exchange A
10-27 15:50:09.283 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.284 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:09.284 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:3WCCSA SSLv3 write change cipher spec A
10-27 15:50:09.284 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.284 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:09.284 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:3WFINA SSLv3 write finished A
10-27 15:50:09.284 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.285 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1001 ret=1
10-27 15:50:09.285 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:3FLUSH SSLv3 flush data
10-27 15:50:09.285 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.285 D/NativeCrypto: ssl=0x63ac0398 info_callback where=0x1002 ret=-1
10-27 15:50:09.285 D/NativeCrypto: ssl=0x63ac0398 SSL_connect:error exit in 3RFINA SSLv3 read finished A
10-27 15:50:09.285 D/NativeCrypto: ssl=0x63ac0398 info_callback ignored
10-27 15:50:09.285 D/NativeCrypto: doing handshake -- ret=-1
10-27 15:50:09.285 D/NativeCrypto: ssl=0x63ac0398 NativeCrypto_SSL_do_handshake ret=-1 errno=11 sslError=2 timeout_millis=0
10-27 15:50:09.286 D/OpenSSLLib:  User Build
10-27 15:50:09.286 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:09.286 D/NativeCrypto: ssl=0x63eca278 SSL_connect:3WCKEA SSLv3 write client key exchange A
10-27 15:50:09.286 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.287 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:09.287 D/NativeCrypto: ssl=0x63eca278 SSL_connect:3WCCSA SSLv3 write change cipher spec A
10-27 15:50:09.287 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.287 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:09.287 D/NativeCrypto: ssl=0x63eca278 SSL_connect:3WFINA SSLv3 write finished A
10-27 15:50:09.287 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.287 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1001 ret=1
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 SSL_connect:3FLUSH SSLv3 flush data
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1002 ret=-1
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 SSL_connect:error exit in UNKWN  SSLv3 read server session ticket A
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 info_callback where=0x1002 ret=-1
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 SSL_connect:error exit in UNKWN  SSLv3 read server session ticket A
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 info_callback ignored
10-27 15:50:09.288 D/NativeCrypto: doing handshake -- ret=-1
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 NativeCrypto_SSL_do_handshake exception => 0
10-27 15:50:09.288 D/NativeCrypto: ssl=0x63eca278 NativeCrypto_SSL_interrupt
10-27 15:50:09.288 D/NativeCrypto:  sslNotify, appData=0x63ac12c8 ret=1
10-27 15:50:09.288 D/NativeCrypto:  sslNotify, appData=0x63ac12c8 ret=1
10-27 15:50:09.288 I/System.out: [CDS]close[58148]
10-27 15:50:09.289 I/System.out: close [socket][/0.0.0.0:58148]
10-27 15:50:09.289 D/NativeCrypto: ssl=0x0 NativeCrypto_SSL_interrupt
10-27 15:50:09.290 W/System.err: io.ably.lib.types.AblyException: javax.net.ssl.SSLHandshakeException: java.security.cert.CertPathValidatorException: Trust anchor for certification path not found.

[SimonWoolf]

Customer says:

• the GlobalSign nv-sa cert is present, has the correct id, and enabled on the phones
• they can't run openssl s_client -debug -connect rest.ably.io:443 etc. as they're on windows

[paddybyers]

they can't run openssl s_client -debug -connect rest.ably.io:443 etc. as they're on windows

Hmm.

Is there a simple online check (ie an Ably demo that runs in the browser) so he can point his phone browser at it, and see what the browser thinks of the cert/network combination?

I realise the browser has different root certs from the platform, but if there was a MITM or some other network issue we'd find out.

[SimonWoolf]

Good idea. I've asked them to just go to https://rest.ably.io (it'll be a 404, but that doesn't matter) on one of the phones, and click the padlock and tell us what it says, hopefully that'll rule out / confirm a MITM

[mattheworiordan]

He has confirmed that rest.ably.io via the browser is accessible fine (i.e. valid cert), although I've now asked him to check with the Android lib as I suspect Chrome includes its own trusted cert chain. That arguably though does rule out MITM.

@paddybyers any further suggestions here? If this issue is indeed affecting others, we should do everything we can to reproduce and resolve for everyone.

[mattheworiordan]

Even after our certificate changes to remove the root cert from the chain, the customer is still experiencing this issue both on a physical device and emulator. He also confirmed he is not using MDM.

The device that he can reproduce this on is is a nexus 5, with marshmallow, 4.95", java lib 0.8.4

[paddybyers]

So the problem was that he has setting a custom SSLSocketFactory with a custom set of root certs:

KeyStore trustStore = KeyStore.getInstance("BKS");
            InputStream in = context.getResources().openRawResource(R.raw.ts);
            trustStore.load(in, pwd.toCharArray());
            TrustManagerFactory trustManagerFactory = 
                TrustManagerFactory.getInstance(TrustManagerFactory.getDefaultAlgorithm());
            trustManagerFactory.init(trustStore);

            SSLContext context = SSLContext.getInstance("SSL");
            context.init(null, trustManagerFactory.getTrustManagers(), new SecureRandom());
            HostnameVerifier allHostsValid = new HostnameVerifier() {
                public boolean verify(String hostname, SSLSession session) {
                    //...
                    return true;
                }
            };
            HttpsURLConnection.setDefaultHostnameVerifier(allHostsValid);
            HttpsURLConnection.setDefaultSSLSocketFactory(context.getSocketFactory());