search

jchambers / pushy

A Java library for sending APNs (iOS/macOS/Safari) push notifications
https://pushy-apns.org/
MIT License
1.81k stars 450 forks source link

Reconnect on InternalServerError and give PushMessage details with Exception #458

Closed kicktipp closed 7 years ago

kicktipp commented 7 years ago

We switched to Auth based authentication with pushy recently. Everything works fine for some days. Then we suddenly get many "InternalServerError":

2017-04-26 09:22:20,357 ERROR d.k.c.p.apns.ApnsResponseListener - Failed to send push notification
java.util.concurrent.ExecutionException: com.relayrides.pushy.apns.ApnsServerException: {"reason":"InternalServerError"}
    at io.netty.util.concurrent.AbstractFuture.get(AbstractFuture.java:41) ~[netty-common-4.1.9.Final.jar:4.1.9.Final]
    at de.kicktipp.core.push.apns.ApnsResponseListener.operationComplete(ApnsResponseListener.java:35) ~[kicktipp-core-17.139.jar:17.139]
    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.notifyListeners0(DefaultPromise.java:500) [netty-common-4.1.9.Final.jar:4.1.9.Final]
    at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:479) [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.tryFailure(DefaultPromise.java:122) [netty-common-4.1.9.Final.jar:4.1.9.Final]
    at com.relayrides.pushy.apns.ApnsClient.handleServerError(ApnsClient.java:964) [pushy-0.9.3.jar:na]
    at com.relayrides.pushy.apns.ApnsClientHandler$ApnsClientHandlerFrameAdapter.onDataRead(ApnsClientHandler.java:173) [pushy-0.9.3.jar:na]
    at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onDataRead(DefaultHttp2ConnectionDecoder.java:238) [netty-codec-http2-4.1.9.Final.jar:4.1.9.Final]
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readDataFrame(DefaultHttp2FrameReader.java:421) [netty-codec-http2-4.1.9.Final.jar:4.1.9.Final]
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:251) [netty-codec-http2-4.1.9.Final.jar:4.1.9.Final]
    at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:160) [netty-codec-http2-4.1.9.Final.jar:4.1.9.Final]
    at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:116) [netty-codec-http2-4.1.9.Final.jar:4.1.9.Final]
    at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:353) [netty-codec-http2-4.1.9.Final.jar:4.1.9.Final]
    at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:413) [netty-codec-http2-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.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:287) [netty-handler-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.handler.ssl.SslHandler.unwrap(SslHandler.java:1240) [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:745) [na:1.7.0_121]
Caused by: com.relayrides.pushy.apns.ApnsServerException: {"reason":"InternalServerError"}
    ... 37 common frames omitted

This seems to be an error on apples side as you already mentioned here: http://stackoverflow.com/questions/40429009/why-apple-push-notification-service-sometimes-gives-me-error-500

So far so good. But we didn't had these issues with Certificate based Authentication. Now we have these problems every two or three days. the node module has the same problems, so it really looks like an apple problem. Maybe there are some limits for using one connection.

The "InternalServerError" is then triggered for every message. If we restart the container and therefore reconnect to APNS everything works fine again.

  1. Even if it is still an Apple error, it would be a nice idea to reconnect automatically. But pushy does not.

  2. The ApnsServerException (and BTW the ClientNotConnectedException) you get inside a ResponseListener does not include any message ID, so we can't mark this message. I think these Exceptions should contain the original PushMessage if possible.

kicktipp commented 7 years ago

This seems to be related to https://github.com/relayrides/pushy/issues/435

I found this line in the log files hours before: java.util.concurrent.ExecutionException: com.relayrides.pushy.apns.ClientNotConnectedException: Client disconnected unexpectedly.

In the meantime there was no attempt to send any push Message but when we tried to send one after hours we got an InternalServerError. It looks like Pushy is not reconnecting and lost the state of connection.

kicktipp commented 7 years ago

Sorry, for commenting again. On a different server we didn't had any ClientNotConnectedException. The sending just stopped with InternalServerError.

jchambers commented 7 years ago

I think we're dealing with a few independent ideas here, and I'll try to separate them out.

First, there are the InernalServerError responses. It sounds like this is exactly the same thing that was reported in #408. I think the best path forward is to move discussion about InternalServerError responses to #408; any new details you can provide about when this starts to happen (after a new authentication token is generated?) would be helpful.

Second, you've made a feature request for including references to push notifications in exceptions. This is, I believe, the same thing that's being discussed in #439. Let's move this part of the discussion to #439.

Finally, you've mentioned that you think you're maybe also running into the issue described in #435, but I'm not entirely sure if that's accurate. As you wrote:

In the meantime there was no attempt to send any push Message but when we tried to send one after hours we got an InternalServerError.

I don't think that's reason to believe that Pushy failed to reconnect. In fact, I think it's quite the opposite; if you're getting an InternalServerError response, that means that we've sent a notification to the server, and the server responded. For that to be true, the client must have been connected.

I think all of the issues you've raised here are valid, but also covered in other tickets. Since these issues are already known, I'm going to close this specific ticket as a duplicate. Please do help us carry on the conversation in the other threads, though. Thanks for the report!

kicktipp commented 7 years ago

You are right, my issue report was confusing and stupid. I will try to resolve the problem on these individual tickets you mentioned.

Am 26.04.2017 um 15:54 schrieb Jon Chambers:

I think we're dealing with a few independent ideas here, and I'll try to separate them out.

First, there are the |InernalServerError| responses. It sounds like this is exactly the same thing that was reported in #408 https://github.com/relayrides/pushy/issues/408. I think the best path forward is to move discussion about |InternalServerError| responses to

408 https://github.com/relayrides/pushy/issues/408; any new details

you can provide about when this starts to happen (after a new authentication token is generated?) would be helpful.

Second, you've made a feature request for including references to push notifications in exceptions. This is, I believe, the same thing that's being discussed in #439 https://github.com/relayrides/pushy/issues/439. Let's move this part of the discussion to #439 https://github.com/relayrides/pushy/issues/439.

Finally, you've mentioned that you think you're maybe also running into the issue described in #435 https://github.com/relayrides/pushy/issues/435, but I'm not entirely sure if that's accurate. As you wrote:

In the meantime there was no attempt to send any push Message but
when we tried to send one after hours we got an InternalServerError.

I don't think that's reason to believe that Pushy failed to reconnect. In fact, I think it's quite the opposite; if you're getting an |InternalServerError| response, that means that we've sent a notification to the server, and the server responded. For that to be true, the client must have been connected.

I think all of the issues you've raised here are valid, but also covered in other tickets. Since these issues are already known, I'm going to close this specific ticket as a duplicate. Please do help us carry on the conversation in the other threads, though. Thanks for the report!

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/relayrides/pushy/issues/458#issuecomment-297415807, or mute the thread https://github.com/notifications/unsubscribe-auth/ACKQpSdjRZaDziFqIHioO2238jW2m3ILks5rz0yGgaJpZM4NIekw.

-- Kicktipp GmbH

Königstraße 9, 40212 Düsseldorf Sitz der Gesellschaft: Düsseldorf Geschäftsführung: Janning Vygen Handelsregister Düsseldorf: HRB 55639

http://www.kicktipp.de/

jchambers commented 7 years ago

Not at all! It was well-explained and helpful. It just so happened to be covered elsewhere. Thanks for sending it along!