Network is unreachable: `api.push.apple.com/2620:149:208:4308:0:0:0:a:443`

[yong3269]

Whenever I try and send a push notification using Pushy 0.15.1 I get the following exception with low probability. Most likely to occur after a longer interval.

2023-11-13 03:23:40.283  WARN 26378 --- [ntLoopGroup-4-1] c.eatthepath.pushy.apns.ApnsChannelPool  : Failed to create channel

io.netty.channel.AbstractChannel$AnnotatedSocketException: Network is unreachable: api.push.apple.com/2620:149:208:4308:0:0:0:a:443
Caused by: java.net.SocketException: Network is unreachable
	at sun.nio.ch.Net.connect0(Native Method) ~[na:1.8.0_322]
	at sun.nio.ch.Net.connect(Net.java:482) ~[na:1.8.0_322]
	at sun.nio.ch.Net.connect(Net.java:474) ~[na:1.8.0_322]
	at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:647) ~[na:1.8.0_322]
	at io.netty.util.internal.SocketUtils$3.run(SocketUtils.java:91) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.util.internal.SocketUtils$3.run(SocketUtils.java:88) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
	at java.security.AccessController.doPrivileged(Native Method) ~[na:1.8.0_322]
	at io.netty.util.internal.SocketUtils.connect(SocketUtils.java:88) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.socket.nio.NioSocketChannel.doConnect(NioSocketChannel.java:315) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.connect(AbstractNioChannel.java:248) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.connect(DefaultChannelPipeline.java:1342) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:533) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.handler.ssl.SslHandler.connect(SslHandler.java:707) ~[netty-handler-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:533) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.handler.codec.http2.Http2ConnectionHandler.connect(Http2ConnectionHandler.java:449) ~[netty-codec-http2-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:533) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:517) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.DefaultChannelPipeline.connect(DefaultChannelPipeline.java:978) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.AbstractChannel.connect(AbstractChannel.java:253) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.bootstrap.Bootstrap$3.run(Bootstrap.java:250) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:497) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
	at java.lang.Thread.run(Thread.java:750) ~[na:1.8.0_322]

java.util.concurrent.ExecutionException: io.netty.channel.AbstractChannel$AnnotatedSocketException: Network is unreachable: api.push.apple.com/2620:149:208:4308:0:0:0:a:443
	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1908)
	...
	at sun.reflect.GeneratedMethodAccessor81.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:879)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793)
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
	at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:660)
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:109)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1594)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:750)
Caused by: io.netty.channel.AbstractChannel$AnnotatedSocketException: Network is unreachable: api.push.apple.com/2620:149:208:4308:0:0:0:a:443
Caused by: java.net.SocketException: Network is unreachable
	at sun.nio.ch.Net.connect0(Native Method)
	at sun.nio.ch.Net.connect(Net.java:482)
	at sun.nio.ch.Net.connect(Net.java:474)
	at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:647)
	at io.netty.util.internal.SocketUtils$3.run(SocketUtils.java:91)
	at io.netty.util.internal.SocketUtils$3.run(SocketUtils.java:88)
	at java.security.AccessController.doPrivileged(Native Method)
	at io.netty.util.internal.SocketUtils.connect(SocketUtils.java:88)
	at io.netty.channel.socket.nio.NioSocketChannel.doConnect(NioSocketChannel.java:315)
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.connect(AbstractNioChannel.java:248)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.connect(DefaultChannelPipeline.java:1342)
	at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548)
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:533)
	at io.netty.handler.ssl.SslHandler.connect(SslHandler.java:707)
	at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548)
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:533)
	at io.netty.handler.codec.http2.Http2ConnectionHandler.connect(Http2ConnectionHandler.java:449)
	at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548)
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:533)
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:517)
	at io.netty.channel.DefaultChannelPipeline.connect(DefaultChannelPipeline.java:978)
	at io.netty.channel.AbstractChannel.connect(AbstractChannel.java:253)
	at io.netty.bootstrap.Bootstrap$3.run(Bootstrap.java:250)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:497)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:750)

[ytakamura]

I've been experiencing the same issue with Pushy 0.13.9 for the past 10 days or so. I think this may be an issue on Apple's side, but I would appreciate any information you can give me.

[jchambers]

APNs does not have conventional load balancers (as near as I can tell). Instead, the expectation is that callers will query DNS for a list of active servers, then choose and connect to one of those servers directly. Please see the "best practices" section of "Sending notification requests to APNs" for details. Folks who are familiar with DNS might note that it is generally not considered an immediately-consistent system.

I think what's happening here is that, after some time, Apple retires an APNs server, but its address is still in the DNS record. When Pushy tries to reconnect to that old address, the connection fails. It's possible that there's a bug in Pushy where we're over-caching, but if there is, I haven't found it yet.

In fairness, Apple's best practices suggest:

Make an uncached DNS query to resolve the APNs server name, before each connection.

It may be that in honoring the 30-second TTL on their DNS records, we're violating the "uncached" part of the suggestion. Even so, though, expecting faster-than-30-second propagation of DNS changes seems unreasonable to me, and I'm not sure that would actually be helpful (or really good for the DNS ecosystem as a whole).

For now, I don't think there's anything to be done here; this is just a consequence of some upstream design decisions. At the same time, it sounds like more and more folks have been bumping into this lately. Let's leave this open and see if we can gather more information, I suppose.

[jchambers]

…though, @ytakamura, 0.13.9 is a truly ancient version of Pushy. I'd be curious if you get better results just by updating to a more recent version.

[dpenny-bravas]

I have been seeing similar issues in the past several weeks as well. It does seem like it has increased significantly in the past three or four weeks. Here is the output from the error I am seeing:

09:03:28.662 [nioEventLoopGroup-2-1] WARN  c.e.pushy.apns.ApnsChannelPool - Failed to create channel
io.netty.channel.AbstractChannel$AnnotatedNoRouteToHostException: No route to host: api.push.apple.com/[2620:149:f9:1021:0:0:0:9]:443
Caused by: java.net.NoRouteToHostException: No route to host
	at java.base/sun.nio.ch.Net.connect0(Native Method)
	at java.base/sun.nio.ch.Net.connect(Net.java:579)
Caused by: java.net.NoRouteToHostException: No route to host

	at java.base/sun.nio.ch.Net.connect(Net.java:586)
	at java.base/sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:853)
	at io.netty.util.internal.SocketUtils$3.run(SocketUtils.java:91)
	at io.netty.util.internal.SocketUtils$3.run(SocketUtils.java:88)
	at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)
	at io.netty.util.internal.SocketUtils.connect(SocketUtils.java:88)
	at io.netty.channel.socket.nio.NioSocketChannel.doConnect(NioSocketChannel.java:322)
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.connect(AbstractNioChannel.java:248)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.connect(DefaultChannelPipeline.java:1342)
	at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:653)
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:632)
	at io.netty.handler.ssl.SslHandler.connect(SslHandler.java:737)
	at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:657)
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:632)
	at io.netty.handler.codec.http2.Http2ConnectionHandler.connect(Http2ConnectionHandler.java:464)
	at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:657)
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:632)
	at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:616)
	at io.netty.channel.DefaultChannelPipeline.connect(DefaultChannelPipeline.java:978)
	at io.netty.channel.AbstractChannel.connect(AbstractChannel.java:265)
	at io.netty.bootstrap.Bootstrap$3.run(Bootstrap.java:264)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:566)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)
09:03:28.663 [nioEventLoopGroup-2-1] ERROR i.b.mdm.apple.apns.ApnsConnector - No route to host: api.push.apple.com/[2620:149:f9:1021:0:0:0:9]:443

@jchambers I can't tell from the logs, but will Pushy attempt to send the notification again? If not, it might be helpful to pass the error message up the chain so we can catch it and retry the notification.

[ytakamura]

I found this thread. https://developer.apple.com/forums/thread/741313
Looks like we have to deal with this change.

[yong3269]

I added the jvm parameter - Djava.net. preferIPv4Stack=true. domain name is no longer resolved ipv6, there is no problem for the time being. Thanks.

[jchambers]

Well, wait—this is still weird. @yong3269 did it ever work for you with IPv6? What happens if you, for example, curl -6 api.push.apple.com?

[jchambers]

And @dpenny-bravas and @ytakamura, I'd ask the same of you! Does this always fail with IPv6 for you? Is it possible that api.push.apple.com was sometimes resolving to IPv4 and sometimes to IPv6? What happens if you try the curl experiment?

[yong3269]

@jchambers What I see is really probabilistic error. api.push.apple.com resolution to ipv6 will definitely go wrong.

# curl -6 api.push.apple.com
curl: (7) Failed to connect to 2620:149:149:1030::1b: Network is unreachable
# curl -4 api.push.apple.com
curl: (7) Failed connect to api.push.apple.com:80; Connection refused

[jchambers]

@yong3269 I think that answers the question, but I should have offered a better set of curl invocations. Specifically:

curl -6 --http2 https://api.push.apple.com
curl -4 --http2 https://api.push.apple.com

[dpenny-bravas]

@jchambers Since enabling IPv6 on my local network I have not had a single failure.

[jchambers]

Okay; it sounds like this was, indeed, a network configuration issue and not something specific to Pushy. Let's consider this resolved for the moment.