{"action":"created","issue":{"url":"https://api.github.com/repos/relayrides/pushy/issues/196","labels_url":"https://api.github.com/repos/relayrides/pushy/issues/196/labels{/name}","comments_url":"https://api.github.com/repos/relayrides/pushy/issues/196/comments","events_url":"https://api.github.com/repos/relayrides/pushy/issues/196/events","html_url":"https://github.com/relayrides/pushy/issues/196","id":108766290,"number":196,"title":"Pushy continues enqueueing onto closed connections","user":{"login":"omarkilani","id":78754,"avatar_url":"https://avatars.githubusercontent.com/u/78754?v=3","gravatar_id":"","url":"https://api.github.com/users/omarkilani","html_url":"https://github.com/omarkilani","followers_url":"https://api.github.com/users/omarkilani/followers","following_url":"https://api.github.com/users/omarkilani/following{/other_user}","gists_url":"https://api.github.com/users/omarkilani/gists{/gist_id}","starred_url":"https://api.github.com/users/omarkilani/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/omarkilani/subscriptions","organizations_url":"https://api.github.com/users/omarkilani/orgs","repos_url":"https://api.github.com/users/omarkilani/repos","events_url":"https://api.github.com/users/omarkilani/events{/privacy}","received_events_url":"https://api.github.com/users/omarkilani/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":1,"created_at":"2015-09-28T23:28:56Z","updated_at":"2015-09-29T00:33:56Z","closed_at":null,"body":"I had a situation where pushy (latest master) continued to write onto a closed connection forever.\r\n\r\nIt would 'failed to write notification' with a cause of 'java.nio.channels.ClosedChannelException', over and over on that failed channel. The channel received an INVALID_TOKEN rejection prior to this.\r\n\r\nI switched to using the new APNSConnectionGroup branch (encapsulate_connection_groups) but it still enqueues onto a closed channel:\r\n\r\n```\r\nTRACE [2015-09-28 23:02:29,807] [Thread-5] com.relayrides.pushy.apns.ApnsConnection - APNSPushManager-ConnectionGroup-3 sending SendableApnsPushNotification [sequenceNumber=1850, token=abc, payload={\"aps\":{\"content-available\":1}}, deliveryInvalidation=Tue Sep 29 23:02:29 UTC 2015]\r\nTRACE [2015-09-28 23:02:29,808] [nioEventLoopGroup-2-4] com.relayrides.pushy.apns.ApnsConnection - APNSPushManager-ConnectionGroup-3 successfully wrote notification 1850\r\nDEBUG [2015-09-28 23:02:29,904] [nioEventLoopGroup-2-4] com.relayrides.pushy.apns.ApnsConnection - APNs gateway rejected notification with sequence number 1850 from APNSPushManager-ConnectionGroup-3 (INVALID_TOKEN).\r\nTRACE [2015-09-28 23:02:29,922] [nioEventLoopGroup-2-4] com.relayrides.pushy.apns.ApnsConnectionGroup - ApnsConnection [name=APNSPushManager-ConnectionGroup-3] rejected SimpleApnsPushNotification [token=[1, 2, 3], payload={\"aps\":{\"content-available\":1}}, invalidationTime=Tue Sep 29 23:02:29 UTC 2015, priority=IMMEDIATE]: INVALID_TOKEN\r\nTRACE [2015-09-28 23:02:29,929] [nioEventLoopGroup-2-4] com.relayrides.pushy.apns.ApnsConnectionGroup - Connection closed: ApnsConnection [name=APNSPushManager-ConnectionGroup-3]\r\nTRACE [2015-09-28 23:02:29,932] [nioEventLoopGroup-2-4] com.relayrides.pushy.apns.ApnsConnectionGroup - ApnsConnectionGroup [name=APNSPushManager-ConnectionGroup] will remove connection ApnsConnection [name=APNSPushManager-ConnectionGroup-3].\r\nTRACE [2015-09-28 23:02:29,957] [Thread-5] com.relayrides.pushy.apns.ApnsConnection - APNSPushManager-ConnectionGroup-3 sending SendableApnsPushNotification [sequenceNumber=1851, token=abc, payload={\"aps\":{\"content-available\":1}}, deliveryInvalidation=Tue Sep 29 23:02:29 UTC 2015]\r\nTRACE [2015-09-28 23:02:30,078] [nioEventLoopGroup-2-4] com.relayrides.pushy.apns.ApnsConnection - APNSPushManager-ConnectionGroup-3 failed to write notification SendableApnsPushNotification [sequenceNumber=1851, token=abc, payload={\"aps\":{\"content-available\":1}}, deliveryInvalidation=Tue Sep 29 23:02:29 UTC 2015]\r\njava.nio.channels.ClosedChannelException\r\n```\r\n\r\nIt does recover and send it on a different channel after that (the master branch did this too, but only sometimes). But I don't really see the value in even attempting this if the connection group knows the channel is poisoned. It's a bit curious that 'Connection closed' has been printed:\r\n\r\n```\r\npublic void handleConnectionClosure(final ApnsConnection<T> connection) {\r\n    log.trace(\"Connection closed: {}\", connection);\r\n\r\n    this.writableConnections.remove(connection);\r\n```\r\n\r\nBut then getNextConnection is returning the removed channel:\r\n\r\n```\r\npublic ApnsConnection<T> getNextConnection(final long timeoutMillis) throws InterruptedException {\r\n    final ApnsConnection<T> connection = this.writableConnections.poll(timeoutMillis, TimeUnit.MILLISECONDS);\r\n```\r\n\r\nThe timestamp on the log is 20ms after 'Connection closed' so this is unlikely to be a timing issue with multiple-threads (unless something is adding the connection back onto the queue.)\r\n\r\nNote that getNextConnection says this:\r\n\r\n```\r\n* @return the next writable connection from this group, or {@code null} if no connection is available before the\r\n* given timeout elapses\r\n```\r\n\r\nBut actually returns any connection from writeableConnections, even if not isWritable. It just doesn't re-add the connection back onto the queue.\r\n\r\nIMHO getNextConnection should check for isWritable on the returned channel and either keep polling the queue waiting for a good channel or return null and handle it up the stack.\r\n\r\nNote also that createDispatchThread never checks the return value of getNextConnection for null:\r\n\r\n```\r\nprotected Thread createDispatchThread() {\r\n    return new Thread(new Runnable() {\r\n\r\n      @Override\r\n      public void run() {\r\n        while (PushManager.this.dispatchThreadShouldContinue) {\r\n          try {\r\n            final ApnsConnection<T> connection = PushManager.this.connectionGroup.getNextConnection();\r\n            final T notificationToRetry = PushManager.this.retryQueue.poll();\r\n\r\n            if (notificationToRetry != null) {\r\n              connection.sendNotification(notificationToRetry);\r\n            } else {\r\n              // We'll park here either until a new notification is available from the outside or until\r\n              // something shows up in the retry queue, at which point we'll be interrupted.\r\n              connection.sendNotification(PushManager.this.queue.take());\r\n            }\r\n          } catch (InterruptedException e) {\r\n            continue;\r\n          }\r\n        }\r\n      }\r\n    });\r\n  }\r\n```\r\n\r\nI may be missing something as I'm not 100% familiar with the code base just yet.\r\n\r\nOmar"},"comment":{"url":"https://api.github.com/repos/relayrides/pushy/issues/comments/143910816","html_url":"https://github.com/relayrides/pushy/issues/196#issuecomment-143910816","issue_url":"https://api.github.com/repos/relayrides/pushy/issues/196","id":143910816,"user":{"login":"omarkilani","id":78754,"avatar_url":"https://avatars.githubusercontent.com/u/78754?v=3","gravatar_id":"","url":"https://api.github.com/users/omarkilani","html_url":"https://github.com/omarkilani","followers_url":"https://api.github.com/users/omarkilani/followers","following_url":"https://api.github.com/users/omarkilani/following{/other_user}","gists_url":"https://api.github.com/users/omarkilani/gists{/gist_id}","starred_url":"https://api.github.com/users/omarkilani/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/omarkilani/subscriptions","organizations_url":"https://api.github.com/users/omarkilani/orgs","repos_url":"https://api.github.com/users/omarkilani/repos","events_url":"https://api.github.com/users/omarkilani/events{/privacy}","received_events_url":"https://api.github.com/users/omarkilani/received_events","type":"User","site_admin":false},"created_at":"2015-09-29T00:33:56Z","updated_at":"2015-09-29T00:33:56Z","body":"It's possible that this can be solved by removing the connection from writableConnections in ApnsConnectionGroup#removeConnection."}}