René's URL Explorer Experiment

{"@context":"https://schema.org","@type":"DiscussionForumPosting","headline":"Netty connection timed out","articleBody":"I wrote simple application using hap-java.\r\nEverything works fine with my iPad for few days and after that iPad cannot connect to accessories.\r\nWhen I restart application it works again for few days.\r\nI checked logs and it looks like netty doesn't close connections.\r\n\r\n```\r\n2016-11-22 13:36:42 [defaultEventExecutorGroup-4-1] [INFO ] [c.b.h.i.h.i.AccessoryHandler] - Terminated homekit connection from /192.168.10.6:50073\r\n2016-11-22 13:36:44 [nioEventLoopGroup-2-1] [INFO ] [i.n.h.l.LoggingHandler] - [id: 0xf1f723d8, /0:0:0:0:0:0:0:0:9123] RECEIVED: [id: 0x3ae20211, /192.168.10.6:50120 =\u003e /192.168.10.154:9123]\r\n2016-11-22 13:36:44 [defaultEventExecutorGroup-4-2] [INFO ] [c.b.h.i.h.i.AccessoryHandler] - New homekit connection from /192.168.10.6:50120\r\n2016-11-22 13:36:44 [defaultEventExecutorGroup-4-2] [DEBUG] [c.b.h.i.p.PairVerificationManager] - Starting pair verification for Dom\r\n2016-11-22 13:36:44 [defaultEventExecutorGroup-4-2] [INFO ] [c.b.h.i.h.HomekitClientConnection] - 200 /pair-verify\r\n2016-11-22 13:36:45 [defaultEventExecutorGroup-4-2] [DEBUG] [c.b.h.i.p.PairVerificationManager] - Completed pair verification for Dom\r\n2016-11-22 13:36:45 [defaultEventExecutorGroup-4-2] [INFO ] [c.b.h.i.h.HomekitClientConnection] - 200 /pair-verify\r\n2016-11-22 13:36:47 [defaultEventExecutorGroup-4-2] [INFO ] [c.b.h.i.h.HomekitClientConnection] - 200 /accessories\r\n2016-11-22 13:52:45 [JmDNS(pc220408-home.local.).Timer] [WARN ] [j.j.i.t.Responder] - Responder(pc220408-home.local.)run() exception \r\njava.io.IOException: Invalid argument\r\n\tat java.net.PlainDatagramSocketImpl.send(Native Method)\r\n\tat java.net.DatagramSocket.send(DatagramSocket.java:671)\r\n\tat javax.jmdns.impl.JmDNSImpl.send(JmDNSImpl.java:1536)\r\n\tat javax.jmdns.impl.tasks.Responder.run(Responder.java:148)\r\n\tat java.util.TimerThread.mainLoop(Timer.java:555)\r\n\tat java.util.TimerThread.run(Timer.java:505)\r\n2016-11-22 13:52:45 [JmDNS(pc220408-home.local.).State.Timer] [WARN ] [j.j.i.t.s.DNSStateTask] - Canceler(pc220408-home.local.).run() exception \r\njava.io.IOException: Invalid argument\r\n\tat java.net.PlainDatagramSocketImpl.send(Native Method)\r\n\tat java.net.DatagramSocket.send(DatagramSocket.java:671)\r\n\tat javax.jmdns.impl.JmDNSImpl.send(JmDNSImpl.java:1536)\r\n\tat javax.jmdns.impl.tasks.state.DNSStateTask.run(DNSStateTask.java:131)\r\n\tat java.util.TimerThread.mainLoop(Timer.java:555)\r\n\tat java.util.TimerThread.run(Timer.java:505)\r\n2016-11-22 13:52:50 [JmDNS(pc220408-home.local.).Timer] [WARN ] [j.j.i.DNSStatefulObject$DefaultImplementation] - Wait for canceled timed out: DNS: pc220408-home.local. state: canceling 1 task: null\r\n2016-11-22 14:02:50 [nioEventLoopGroup-3-4] [ERROR] [c.b.h.i.h.i.BinaryHandler] - Exception in binary handler\r\njava.io.IOException: Connection timed out\r\n\tat sun.nio.ch.FileDispatcherImpl.read0(Native Method)\r\n\tat sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)\r\n\tat sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)\r\n\tat sun.nio.ch.IOUtil.read(IOUtil.java:192)\r\n\tat sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:375)\r\n\tat io.netty.buffer.UnpooledUnsafeDirectByteBuf.setBytes(UnpooledUnsafeDirectByteBuf.java:447)\r\n\tat io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:880)\r\n\tat io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:242)\r\n\tat io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:119)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)\r\n\tat io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)\r\n\tat io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)\r\n\tat io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)\r\n\tat java.lang.Thread.run(Thread.java:744)\r\n2016-11-22 14:02:50 [defaultEventExecutorGroup-4-4] [ERROR] [c.b.h.i.h.i.AccessoryHandler] - Exception caught in web handler\r\njava.io.IOException: Connection timed out\r\n\tat sun.nio.ch.FileDispatcherImpl.read0(Native Method)\r\n\tat sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)\r\n\tat sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)\r\n\tat sun.nio.ch.IOUtil.read(IOUtil.java:192)\r\n\tat sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:375)\r\n\tat io.netty.buffer.UnpooledUnsafeDirectByteBuf.setBytes(UnpooledUnsafeDirectByteBuf.java:447)\r\n\tat io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:880)\r\n\tat io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:242)\r\n\tat io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:119)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)\r\n\tat io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)\r\n\tat io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)\r\n\tat io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)\r\n\tat java.lang.Thread.run(Thread.java:744)\r\n2016-11-22 14:02:50 [defaultEventExecutorGroup-4-4] [INFO ] [c.b.h.i.h.i.AccessoryHandler] - Terminated homekit connection from /192.168.10.6:50058\r\n2016-11-22 14:11:42 [nioEventLoopGroup-3-4] [ERROR] [c.b.h.i.h.i.BinaryHandler] - Exception in binary handler\r\njava.io.IOException: Connection timed out\r\n\tat sun.nio.ch.FileDispatcherImpl.read0(Native Method)\r\n\tat sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)\r\n\tat sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)\r\n\tat sun.nio.ch.IOUtil.read(IOUtil.java:192)\r\n\tat sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:375)\r\n\tat io.netty.buffer.UnpooledUnsafeDirectByteBuf.setBytes(UnpooledUnsafeDirectByteBuf.java:447)\r\n\tat io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:880)\r\n\tat io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:242)\r\n\tat io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:119)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)\r\n\tat io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)\r\n\tat io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)\r\n\tat io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)\r\n\tat java.lang.Thread.run(Thread.java:744)\r\n2016-11-22 14:11:42 [defaultEventExecutorGroup-4-4] [ERROR] [c.b.h.i.h.i.AccessoryHandler] - Exception caught in web handler\r\njava.io.IOException: Connection timed out\r\n\tat sun.nio.ch.FileDispatcherImpl.read0(Native Method)\r\n\tat sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)\r\n\tat sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)\r\n\tat sun.nio.ch.IOUtil.read(IOUtil.java:192)\r\n\tat sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:375)\r\n\tat io.netty.buffer.UnpooledUnsafeDirectByteBuf.setBytes(UnpooledUnsafeDirectByteBuf.java:447)\r\n\tat io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:880)\r\n\tat io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:242)\r\n\tat io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:119)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)\r\n\tat io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)\r\n\tat io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)\r\n\tat io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)\r\n\tat io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)\r\n\tat java.lang.Thread.run(Thread.java:744)\r\n```\r\n\r\nI also made thread dump and there are lot of threads are waiting.\r\nProbably netty connection pool reached limit and that's why I cannot connect to accessories.\r\n\r\n```\r\n\"defaultEventExecutorGroup-4-1\" #32 prio=5 os_prio=0 tid=0x62e4a800 nid=0x7b1a waiting on condition [0x5fcfe000]\r\n   java.lang.Thread.State: WAITING (parking)\r\n\tat sun.misc.Unsafe.park(Native Method)\r\n\t- parking to wait for  \u003c0x6a4d2598\u003e (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)\r\n\tat java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)\r\n\tat java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)\r\n\tat java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)\r\n\tat io.netty.util.concurrent.SingleThreadEventExecutor.takeTask(SingleThreadEventExecutor.java:218)\r\n\tat io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:34)\r\n\tat io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)\r\n\tat io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)\r\n\tat java.lang.Thread.run(Thread.java:744)\r\n```","author":{"url":"https://github.com/mariusz2108","@type":"Person","name":"mariusz2108"},"datePublished":"2016-11-27T08:38:55.000Z","interactionStatistic":{"@type":"InteractionCounter","interactionType":"https://schema.org/CommentAction","userInteractionCount":2},"url":"https://github.com/28/HAP-Java/issues/28"}