MissingProviderToken with TLS authentication

1,970 views
Skip to first unread message

Petar Petrov

unread,
May 5, 2017, 6:28:00 AM5/5/17
to pushy
Hi guys,

I'm stuck with a very weird issue a 2nd day now. 

I'm migrating our product APNs from java-apns to pushy. The previous library used Apple's legacy binary provider API and I'm trying to use the same authentication method (APNs Provider Certificates).
Unfortunately I'm alway getting the error MissingProviderToken from Apple's gateway when using pushy and the new HTTP/2 protocol. Here are the log details:


INFO  com.relayrides.pushy.apns.ApnsClientBuilder - Native SSL provider is available and supports ALPN; will use native provider.
TRACE io.netty.channel.nio.NioEventLoop - instrumented a special java.util.Set into: sun.nio.ch.EPollSelectorImpl@a83adf1c
[nioEventLoopGroup-12-1] DEBUG io.netty.handler.ssl.SslHandler - [id: 0xddd9cc29, L:/192.168.1.127:32556 - R:api.push.apple.com/17.188.144.174:443] HANDSHAKEN: TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384
TRACE com.relayrides.pushy.apns.ApnsClientHandler - Received settings from APNs gateway: {=4096, =1, =16384, =8000}
INFO  com.relayrides.pushy.apns.ApnsClient - Connected to api.push.apple.com/17.188.144.174:443.
DEBUG io.netty.handler.ssl.SslHandler - [id: 0xcd766e96, L:/192.168.1.127:32558 - R:api.push.apple.com/17.188.144.174:443] HANDSHAKEN: TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384
TRACE com.relayrides.pushy.apns.ApnsClientHandler - Received settings from APNs gateway: {=4096, =1, =16384, =8000}
INFO  com.relayrides.pushy.apns.ApnsClient - Connected to api.push.apple.com/17.188.144.174:443.
TRACE com.relayrides.pushy.apns.ApnsClientHandler - Wrote headers on stream 1: DefaultHttp2Headers[:method: POST, :authority: api.push.apple.com, :path: /3/device/b1173288362e8aeb181b1147cb52addeffb2db7678dd54afc802635e2b3a6c78, apns-expiration: 0, apns-priority: 10, apns-topic: com.example.myapp]
TRACE com.relayrides.pushy.apns.ApnsClientHandler - Wrote payload on stream 1: {"aps":{"badge":16,"alert":{"body":"test1"},"sound":"default","content-available":1}}
TRACE com.relayrides.pushy.apns.ApnsClientHandler - Received headers from APNs gateway on stream 1: DefaultHttp2Headers[:status: 403, apns-id: 055978B3-5C31-A783-73C9-271EB99AEB40]
TRACE com.relayrides.pushy.apns.ApnsClientHandler - Received data from APNs gateway on stream 1: {"reason":"MissingProviderToken"}
DEBUG com.relayrides.pushy.apns.ApnsClient - Received response from APNs gateway: SimplePushNotificationResponse [pushNotification=SimpleApnsPushNotification [token=b1173288362e8aeb181b1147cb52addeffb2db7678dd54afc802635e2b3a6c78, payload={"aps":{"badge":16,"alert":{"body":"test1"},"sound":"default","content-available":1}}, invalidationTime=null, priority=IMMEDIATE, topic=com.example.myapp, apns-collapse-id=null], success=false, rejectionReason=MissingProviderToken, tokenExpirationTimestamp=null]
INFO  com.relayrides.pushy.apns.ApnsClient - Disconnecting.




Here is a summary on what I'm doing:


ApnsClientBuilder builder = new ApnsClientBuilder().setClientCredentials(p12Stream, password);
ApnsClient apnsClient = builder.build();

final Future<Void> connectFuture = apnsClient.connect(ApnsClient.PRODUCTION_APNS_HOST);

connectFuture.await();


String token = "b1173288362e8aeb181b1147cb52addeffb2db7678dd54afc802635e2b3a6c78"; // token is a simple string of hex characters

final ApnsPayloadBuilder payloadBuilder = new ApnsPayloadBuilder();

payloadBuilder.setAlertBody(body);

payloadBuilder.setBadgeNumber(badges);

payloadBuilder.setSoundFileName(ApnsPayloadBuilder.DEFAULT_SOUND_FILENAME);

payloadBuilder.setContentAvailable(true);


Future<PushNotificationResponse<SimpleApnsPushNotification>> future = apnsClient.sendNotification(
    new SimpleApnsPushNotification(TokenUtil.sanitizeTokenString(token), "com.example.myapp"payloadBuilder.buildWithDefaultMaximumLength()));




I'll greatly appreciate any help.






Petar Petrov

unread,
May 5, 2017, 7:02:12 AM5/5/17
to pushy
I just realised that I probably didn't add enough info.

Pushy:  v0.9.3
JVM: Java 8 using IBM J9

I noticed the following exception in logs when the ApnsClient is being created:


12:54:07.626 DEBUG io.netty.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
12:54:07.630 DEBUG io.netty.util.internal.NativeLibraryLoader - -Dio.netty.tmpdir: /tmp (java.io.tmpdir)
12:54:07.630 DEBUG io.netty.util.internal.NativeLibraryLoader - -Dio.netty.native.workdir: /tmp (io.netty.tmpdir)
12:54:07.647 DEBUG io.netty.util.internal.NativeLibraryLoader - Successfully loaded the library: netty-tcnative-linux-x86_64
12:54:07.648 DEBUG io.netty.handler.ssl.OpenSsl - netty-tcnative using native library: BoringSSL
12:54:07.661 DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.noUnsafe: false
12:54:07.663 DEBUG io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.theUnsafe: available
12:54:07.664 DEBUG io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.copyMemory: available
12:54:07.665 DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.Buffer.address: available
12:54:07.665 DEBUG io.netty.util.internal.PlatformDependent0 - direct buffer constructor: available
12:54:07.666 DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.Bits.unaligned: available, true
12:54:07.666 DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.DirectByteBuffer.<init>(long, int): available
12:54:07.667 DEBUG io.netty.util.internal.Cleaner0 - java.nio.ByteBuffer.cleaner(): available
12:54:07.669 DEBUG io.netty.util.internal.PlatformDependent - Java version: 8
12:54:07.669 DEBUG io.netty.util.internal.PlatformDependent - sun.misc.Unsafe: available
12:54:07.669 DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.tmpdir: /tmp (java.io.tmpdir)
12:54:07.670 DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.bitMode: 64 (sun.arch.data.model)
12:54:07.671 DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.noPreferDirect: false
12:54:07.671 DEBUG io.netty.util.internal.PlatformDependent - io.netty.maxDirectMemory: 67108864 bytes
12:54:08.236 DEBUG io.netty.handler.ssl.util.SelfSignedCertificate - Failed to generate a self-signed X.509 certificate using sun.security.x509:
java.lang.NoClassDefFoundError: sun.security.x509.X509CertImpl
at io.netty.handler.ssl.util.SelfSignedCertificate.<init>(SelfSignedCertificate.java:149) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.util.SelfSignedCertificate.<init>(SelfSignedCertificate.java:110) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.util.SelfSignedCertificate.<init>(SelfSignedCertificate.java:88) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.util.SelfSignedCertificate.<init>(SelfSignedCertificate.java:79) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.OpenSsl.<clinit>(OpenSsl.java:143) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at com.relayrides.pushy.apns.ApnsClientBuilder.build(ApnsClientBuilder.java:372) [pushy-0.9.3.jar:?]
at com.example.myapp.dots.common.notification.ApnsWrapper.create(ApnsWrapper.java:96) [com.example.myapp.dots_6.0.1.jar:6.0.1]
at com.example.myapp.dots.common.notification.ApnsWrapper.create(ApnsWrapper.java:121) [com.example.myapp.dots_6.0.1.jar:6.0.1]
at com.example.myapp.dots.common.notification.ApnsWrapper.create(ApnsWrapper.java:128) [com.example.myapp.dots_6.0.1.jar:6.0.1]
at com.example.myapp.dots.common.notification.NotificationManager.newApnsWrapper(NotificationManager.java:545) [com.example.myapp.dots_6.0.1.jar:6.0.1]
at com.example.myapp.dots.common.notification.NotificationManager.initializeMDMNotificationiOS(NotificationManager.java:582) [com.example.myapp.dots_6.0.1.jar:6.0.1]
at com.example.myapp.dots.common.notification.NotificationManager.initializeServices(NotificationManager.java:114) [com.example.myapp.dots_6.0.1.jar:6.0.1]
at com.example.myapp.dots.tasklets.NotificationTask.doRun(NotificationTask.java:36) [com.example.myapp.dots_6.0.1.jar:6.0.1]
at com.ibm.dots.task.AbstractServerTaskExt.run(AbstractServerTaskExt.java:47) [com.ibm.dots_9.0.0.20130309-0900.jar:?]
at com.ibm.dots.task.JobTaskService$ServiceTaskJob.doRun(JobTaskService.java:136) [com.ibm.dots_9.0.0.20130309-0900.jar:?]
at com.ibm.dots.task.JobTaskService$ServiceTaskJob.run(JobTaskService.java:99) [com.ibm.dots_9.0.0.20130309-0900.jar:?]
at org.eclipse.core.internal.jobs.Worker.run(Worker.java:54) [org.eclipse.core.jobs_3.5.1.R36x_v20100824.jar:?]
Caused by: java.lang.ClassNotFoundException: sun.security.x509.X509CertImpl
at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:506) ~[org.eclipse.osgi_3.6.2.R36x_v20110210.jar:?]
at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:422) ~[org.eclipse.osgi_3.6.2.R36x_v20110210.jar:?]
at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:410) ~[org.eclipse.osgi_3.6.2.R36x_v20110210.jar:?]
at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:107) ~[org.eclipse.osgi_3.6.2.R36x_v20110210.jar:?]
at java.lang.ClassLoader.loadClass(ClassLoader.java:809) ~[?:1.8.0]
... 17 more
12:54:08.368 DEBUG io.netty.buffer.AbstractByteBuf - -Dio.netty.buffer.bytebuf.checkAccessible: true
12:54:08.372 DEBUG io.netty.util.ResourceLeakDetector - -Dio.netty.leakDetection.level: simple
12:54:08.372 DEBUG io.netty.util.ResourceLeakDetector - -Dio.netty.leakDetection.maxRecords: 4
12:54:08.373 DEBUG io.netty.util.ResourceLeakDetectorFactory - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@ca38b886
12:54:08.388 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.numHeapArenas: 4
12:54:08.389 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.numDirectArenas: 0
12:54:08.389 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.pageSize: 8192
12:54:08.389 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.maxOrder: 11
12:54:08.389 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.chunkSize: 16777216
12:54:08.390 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.tinyCacheSize: 512
12:54:08.390 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.smallCacheSize: 256
12:54:08.390 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.normalCacheSize: 64
12:54:08.390 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.maxCachedBufferCapacity: 32768
12:54:08.390 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.cacheTrimInterval: 8192
12:54:08.391 DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.useCacheForAllThreads: true
12:54:08.396 DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.allocator.type: pooled
12:54:08.397 DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.threadLocalDirectBufferSize: 65536
12:54:08.397 DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.maxThreadLocalCharBufferSize: 16384
12:54:08.415 DEBUG io.netty.util.ResourceLeakDetectorFactory - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@24965260
12:54:08.416 DEBUG io.netty.handler.ssl.ReferenceCountedOpenSslContext - Default cipher suite (OpenSSL): [ECDHE-ECDSA-AES256-GCM-SHA384, ECDHE-ECDSA-AES128-GCM-SHA256, ECDHE-RSA-AES128-GCM-SHA256, ECDHE-RSA-AES128-SHA, ECDHE-RSA-AES256-SHA, AES128-GCM-SHA256, AES128-SHA, AES256-SHA]

 
Understandably the sun.security.x509.X509CertImpl cannot be found on a IBM J9 VM. Looking at Netty's SelfSignedCertificate code, I noticed the following:

         logger.debug("Failed to generate a self-signed X.509 certificate using sun.security.x509:", t);
            try {
                // Try Bouncy Castle if the current JVM didn't have sun.security.x509.
                paths = BouncyCastleSelfSignedCertGenerator.generate(fqdn, keypair, random, notBefore, notAfter);
            } catch (Throwable t2) {
                logger.debug("Failed to generate a self-signed X.509 certificate using Bouncy Castle:", t2);
                throw new CertificateException(
                        "No provider succeeded to generate a self-signed certificate. " +
                                "See debug log for the root cause.");
            }

It should fall back to using BouncyCastle, which I have, but it doesn't seem to do that. Any ideas?

Jon Chambers

unread,
May 5, 2017, 9:57:47 AM5/5/17
to Petar Petrov, pushy
It sounds to me like SOMETHING is going wrong with your certificate, and so the handshake with the APNs server fails. Because the handshake fails, TLS authentication doesn't happen, and so everything falls back to token-based authentication. Because you're not specifying tokens, we wind up with `MissingProviderToken` rejections.

My best guess is that you're trying to get your p12 input stream as a resource, and that resource isn't found. That can kick of a chain of silent failures; in that case, the input stream will be null, and setting null client credentials IS allowed in the ApnsClientBuilder (as a way of saying "I want to use token authentication"). That situation got better in https://github.com/relayrides/pushy/pull/451, where you'll need either a TLS certificate OR signing key at client build time, and so we should notice if something is missing.

Hope that helps!

-Jon

--
Pushy is an open-source Java library for sending APNs (iOS and OS X) push notifications. Pushy is brought to you by the engineers at RelayRides.
---
You received this message because you are subscribed to the Google Groups "pushy" group.
To unsubscribe from this group and stop receiving emails from it, send an email to pushy-apns+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Petar Petrov

unread,
May 5, 2017, 11:24:25 AM5/5/17
to pushy, petar.petr...@gmail.com
Jon, thanks a lot!!

I think you are definitely right that it has to do with the certificate. I don't know how I missed this but setClientCredentials does indeed throw an exception while loading the PKCS#12 container.

2017-05-05 15:03:41.958 ERROR - java.io.IOException: Keystore type is not PKCS12


        at com.ibm.crypto.provider.PKCS12KeyStoreOracle.engineLoad(Unknown Source)


        at java.security.KeyStore.load(KeyStore.java:1456)


        at com.relayrides.pushy.apns.P12Util.getFirstPrivateKeyEntryFromP12InputStream(P12Util.java:40)


        at com.relayrides.pushy.apns.ApnsClientBuilder.setClientCredentials(ApnsClientBuilder.java:137)



Now I'm baffled about why this happens, because PKCS#12 loading did work before that, and I can also open the file using the openssl cmd line tool. Even using the BC provider does not seem to work anymore.

Based on your experience, might this be related to the netty-tcnative-boringssl-static lib somehow?


Caused by: java.io.IOException: stream does not represent a PKCS12 key store


        at org.bouncycastle.jce.provider.JDKPKCS12KeyStore.engineLoad(Unknown Source)


        at java.security.KeyStore.load(KeyStore.java:1456)


        at com.myapp.security.x509.X509Utils.loadPKCS12KeyStore(X509Utils.java:91)


        ... 10 more



To unsubscribe from this group and stop receiving emails from it, send an email to pushy-apns+...@googlegroups.com.

Petar Petrov

unread,
May 5, 2017, 2:00:37 PM5/5/17
to pushy, petar.petr...@gmail.com
Alright, just to clear out the confusion. The PKCS12 key store loading issue is resolved. I have debugged the ApnsClientBuilder and I can confirm that the clientCertificate and privateKey are correctly set and also useTlsAuthentication is set to true.
Just in case, I also added the Apple WWDC and GeoTrust CA certificates to the trustedServerCertificates array, so the sslContextBuilder looks good to me. Sadly, I still get the MissingProviderToken error :(. 

The strange part is that I tested the push notifications with cURL and that worked. I passed the same headers and parameters as the ones I used in pushy.  E.g.,

$CURL -v -d '{"aps":{"alert":"hi","sound":"default"}}' --cert cert.pem --key key.pem \
-H "apns-topic: de.midpoints.mobile.profiler" \
-H "apns-expiration: 0" \
-H "apns-priority: 10" \
        -H "authority: api.push.apple.com" \


Jon, if you got any ideas on what else I could be missing, I'd greatly appreciated. Thank you!

Jon Chambers

unread,
May 5, 2017, 2:35:07 PM5/5/17
to Petar Petrov, pushy
I still think something is going wrong with the TLS handshake, and that's the root of the problem.

The issue is that we're using "optional" client authentication, so if client authentication fails, we still wind up with a valid TLS connection. There is, unfortunately, no way I can find for us to know about that on the client side (I am VERY interested in suggestions here). The client knows that it TRIED to present a valid certificate, and so thinks it's in TLS mode while the server didn't get client authentication it liked, and so thinks it's in token authentication mode.

Depending on your JVM, there may be properties you can set to get more information about the handshake (see http://docs.oracle.com/javase/7/docs/technotes/guides/security/jsse/ReadDebug.html, for example).

I emphasize that I'd love to find a way to get at the outcome of an optional client authentication attempt so we can solve this problem for real, but right now, I don't have much to offer. Sorry :\

-Jon

To unsubscribe from this group and stop receiving emails from it, send an email to pushy-apns+unsubscribe@googlegroups.com.

Petar Petrov

unread,
May 5, 2017, 3:35:16 PM5/5/17
to pushy, petar.petr...@gmail.com
I understand and that makes perfect sense! I first thought the Apple push server's certificate chain could not be verified on client side and the handshake got broken from then on, hence I added the Apple G2 and GeoTrust to the trusted chain.
I'll take a look on how to debug the handshake. Thanks for the hint!


On Friday, May 5, 2017 at 8:35:07 PM UTC+2, Jon Chambers wrote:
I still think something is going wrong with the TLS handshake, and that's the root of the problem.

The issue is that we're using "optional" client authentication, so if client authentication fails, we still wind up with a valid TLS connection. There is, unfortunately, no way I can find for us to know about that on the client side (I am VERY interested in suggestions here). The client knows that it TRIED to present a valid certificate, and so thinks it's in TLS mode while the server didn't get client authentication it liked, and so thinks it's in token authentication mode.

Depending on your JVM, there may be properties you can set to get more information about the handshake (see http://docs.oracle.com/javase/7/docs/technotes/guides/security/jsse/ReadDebug.html, for example).

I emphasize that I'd love to find a way to get at the outcome of an optional client authentication attempt so we can solve this problem for real, but right now, I don't have much to offer. Sorry :\

-Jon
On Fri, May 5, 2017 at 11:00 AM, Petar Petrov <petar.petr...@gmail.com> wrote:
Alright, just to clear out the confusion. The PKCS12 key store loading issue is resolved. I have debugged the ApnsClientBuilder and I can confirm that the clientCertificate and privateKey are correctly set and also useTlsAuthentication is set to true.
Just in case, I also added the Apple WWDC and GeoTrust CA certificates to the trustedServerCertificates array, so the sslContextBuilder looks good to me. Sadly, I still get the MissingProviderToken error :(. 

The strange part is that I tested the push notifications with cURL and that worked. I passed the same headers and parameters as the ones I used in pushy.  E.g.,

Petar Petrov

unread,
May 7, 2017, 4:48:03 PM5/7/17
to pushy, petar.petr...@gmail.com
Jon, just to confirm that this doesn't seem to be a pushy issue at all. 

In my opinion, and from what I was able to debug, it seems like a general issue with the IBM JSSE / IBMJCE providers and the X509KeyManager implementation there. The VM spits a somewhat cryptic message that I wasn't able to resolve so far:

ssl: Ignoring alias key: signature does not conform to negotiated signature algorithms


Where key is the alias of the client certificate. The certificate itself is a SHA256WithRSA signed. 
This happens in Netty at point io.netty.handler.ssl.OpenSslKeyMaterialManager.chooseClientAlias, which basically calls X509KeyManager.chooseClientAlias().
When testing with an Oracle JDK, everything works fine, so I assume it is some sort of an IBM J9 specific issue.


Alas, something peculiar. Just for fun I setup a JDK SSL provider using jetty-alpn. I wanted to jump over boringssl in order to isolate any inconsistencies between the native code and the IBM J9 parts.
I used an older alpn-boot library (alpn-boot-7.1.3), so I don't know if that was the reason, but it seems the protocol doesn't get correctly reported to pushy and it closes the connection from there on.


***

JsseJCE:  Using KeyGenerator IbmTls12Prf from provider TBD via init

HandshakeMessage:  TLS Keygenerator IbmTlsPrf  from provider from init IBMJCE version 1.8

%% Cached client session: [Session-1, SSL_ECDHE_RSA_WITH_AES_256_GCM_SHA384]

[read] MD5 and SHA1 hashes:  len = 16

0000: 14 00 00 0c c9 0a 1e 16  da 24 70 06 9c 58 c8 f8  ..........p..X..

2017-07-05 18:51:22.082 [nioEventLoopGroup-2-1] DEBUG io.netty.handler.ssl.SslHandler - [id: 0x62b4d80b, L:/192.168.1.127:36940 - R:api.push.apple.com/17.188.164.208:443] HANDSHAKEN: SSL_ECDHE_RSA_WITH_AES_256_GCM_SHA384

2017-07-05 18:51:22.084 [nioEventLoopGroup-2-1] ERROR com.relayrides.pushy.apns.ApnsClient - Unexpected protocol:


nioEventLoopGroup-2-1, called closeOutbound()

nioEventLoopGroup-2-1, closeOutboundInternal()

nioEventLoopGroup-2-1, SEND TLSv1.2 ALERT:  warning, description = close_notify

CipherBox:  Using cipher AES/GCM/NoPadding from provider from init IBMJCE version 1.8


2017-07-05 19:10:08.287 [nioEventLoopGroup-7-1] INFO  com.relayrides.pushy.apns.ApnsClient - Failed to connect.
java.lang.IllegalStateException: Channel closed before HTTP/2 preface completed.
at com.relayrides.pushy.apns.ApnsClient$3.operationComplete(ApnsClient.java:467) [pushy-0.9.3.jar:?]
at com.relayrides.pushy.apns.ApnsClient$3.operationComplete(ApnsClient.java:459) [pushy-0.9.3.jar:?]
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:507) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:481) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:420) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:104) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:82) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannel$CloseFuture.setClosed(AbstractChannel.java:1058) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.doClose0(AbstractChannel.java:686) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:664) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:607) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.close(DefaultChannelPipeline.java:1276) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:624) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:608) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.ChannelOutboundHandlerAdapter.close(ChannelOutboundHandlerAdapter.java:71) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:624) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:608) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.SslHandler$8.operationComplete(SslHandler.java:1630) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.SslHandler$8.operationComplete(SslHandler.java:1619) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:507) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:481) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:420) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at io.netty.util.concurrent.DefaultPromise.addListener(DefaultPromise.java:163) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:93) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:28) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.SslHandler.safeClose(SslHandler.java:1619) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.SslHandler.closeOutboundAndChannel(SslHandler.java:1430) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.SslHandler.close(SslHandler.java:575) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:624) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:608) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:465) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at com.relayrides.pushy.apns.ApnsClient$1$1.configurePipeline(ApnsClient.java:273) [pushy-0.9.3.jar:?]
at io.netty.handler.ssl.ApplicationProtocolNegotiationHandler.userEventTriggered(ApplicationProtocolNegotiationHandler.java:92) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:329) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:315) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireUserEventTriggered(AbstractChannelHandlerContext.java:307) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.SslHandler.setHandshakeSuccess(SslHandler.java:1341) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1179) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1041) [netty-handler-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411) [netty-codec-4.1.9.Final.jar:4.1.9.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248) [netty-codec-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1334) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:926) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:624) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:559) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:476) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:438) [netty-transport-4.1.9.Final.jar:4.1.9.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144) [netty-common-4.1.9.Final.jar:4.1.9.Final]
at java.lang.Thread.run(Thread.java:785) [?:1.8.0]


Anyway, it's an interesting issue and I'll definitely come back to this again as I'm really interested in pushy. Thanks again Jon!

Petar Petrov

unread,
Jun 19, 2018, 8:31:17 AM6/19/18
to pushy
I've been playing with pushy again this year. Nicely surprised to see that it has really evolved since v0.9. Great job!

I was having some issues with a IBM J9 JVM and to anyone that might come to this a a problem, I believe I got this solved. The issue itself has nothing to do with pushy, but with a seemingly complex arrangement of underlying dependencies.

It seems to involve the following 3 components:
  1. The IBM J9 JVM and from what it seems its IBMJSSE2 provider.
  2. The netty-tcnative-boringssl-static dependency.
  3. BouncyCastle

Based on my testing, the IBM J9 fails to provide the client certificate for the TLS handshake in the following cases:

  1. pushy 0.13.1 + BouncyCastle v1.46 + netty-tcnative-boringssl-static:2.0.8.Final
  2. pushy 0.13.1 + BouncyCastle v1.46 (no static ssl libs)
  3. pushy 0.13.1 + BouncyCastle v1.47 + netty-tcnative-boringssl-static:2.0.8.Final
  4. pushy 0.13.1 + BouncyCastle v1.59 + netty-tcnative-boringssl-static:2.0.8.Final

In the following cases the client certificate is successfully retrieved and the TLS handshake proceeds without any issues:
  1. pushy 0.13.1 + BouncyCastle v1.47
  2. pushy 0.13.1 + BouncyCastle v1.59
  3. pushy 0.13.1 + BouncyCastle v1.47 + io.netty:netty-tcnative:2.0.8.Final linux-x86_64-fedora (OpenSSL 1.0.1e-fips)
  4. pushy 0.13.1 + BouncyCastle v1.59 + io.netty:netty-tcnative:2.0.8.Final linux-x86_64-fedora (OpenSSL 1.0.1e-fips)

So in the end, it seems if you are running pushy on an IBM J9, you need to make sure you use a BC version > 1.46 and no tcnative-boringssl-static dependency. I don't really have an explanation for the tcnative-boringssl results at this point.

Jon Chambers

unread,
Jun 19, 2018, 8:57:40 AM6/19/18
to Petar Petrov, pushy
Thanks kindly for following up!

-Jon
Reply all
Reply to author
Forward
0 new messages