{"action":"opened","issue":{"url":"https://api.github.com/repos/logstash-plugins/logstash-input-tcp/issues/16","labels_url":"https://api.github.com/repos/logstash-plugins/logstash-input-tcp/issues/16/labels{/name}","comments_url":"https://api.github.com/repos/logstash-plugins/logstash-input-tcp/issues/16/comments","events_url":"https://api.github.com/repos/logstash-plugins/logstash-input-tcp/issues/16/events","html_url":"https://github.com/logstash-plugins/logstash-input-tcp/issues/16","id":104638130,"number":16,"title":"New incoming connections not `accept()`-ed ","user":{"login":"jstangroome","id":148754,"avatar_url":"https://avatars.githubusercontent.com/u/148754?v=3","gravatar_id":"","url":"https://api.github.com/users/jstangroome","html_url":"https://github.com/jstangroome","followers_url":"https://api.github.com/users/jstangroome/followers","following_url":"https://api.github.com/users/jstangroome/following{/other_user}","gists_url":"https://api.github.com/users/jstangroome/gists{/gist_id}","starred_url":"https://api.github.com/users/jstangroome/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jstangroome/subscriptions","organizations_url":"https://api.github.com/users/jstangroome/orgs","repos_url":"https://api.github.com/users/jstangroome/repos","events_url":"https://api.github.com/users/jstangroome/events{/privacy}","received_events_url":"https://api.github.com/users/jstangroome/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":0,"created_at":"2015-09-03T07:34:25Z","updated_at":"2015-09-03T07:34:25Z","closed_at":null,"body":"I am running logstash 1.4.5 (-1-a2bacae) on Ubuntu 14.04.1 LTS, kernel 3.13.0-36-generic x86_64 and Java from  openjdk-7-jre-headless=7u75-2.5.4-1~trusty1.\r\n\r\nI have the following TCP+TLS input configured:\r\n\r\n```\r\ntcp {\r\n  port => 6514\r\n  codec => line\r\n  data_timeout => 120\r\n  ssl_enable => true\r\n  ssl_cert => \"/etc/logstash/tls/ourcert.pem\"\r\n  ssl_key => \"/etc/logstash/tls/ourkey.pem\"\r\n  type => \"syslog-over-tls\"\r\n}\r\n```\r\n\r\nWhen logstash starts it begins accepting incoming connections from about 20 remote hosts, geographically distributed. Logstash also processes the incoming data on these connections and sends to our outputs (statsd, elasticsearch).\r\n\r\nAfter a few minutes, new incoming connections arrive. The kernel performs the SYN/SYN+ACK/ACK handshake, puts these connections in the `ESTABLISHED` state and into logstash's listen backlog. Logstash continues processing data on the incoming connections and sending to our outputs but does not `accept` the new connections on the listen backlog. Over time the backlog grows.\r\n\r\nBecause the kernel has established the connection, the remote end thinks everything is good.\r\n\r\nRunning `watch 'ss -anpt sport = :6514'` shows this in action, here is a sample output with IP addresses removed:\r\n\r\n```\r\nState      Recv-Q Send-Q   :Port\r\nLISTEN     4      50       :6514   users:((\"java\",1851,28))\r\nESTAB      0      0        :52301  users:((\"java\",1851,35))\r\nESTAB      0      0        :38714  users:((\"java\",1851,64))\r\nESTAB      0      0        :35478  users:((\"java\",1851,59))\r\nESTAB      305    0        :53403\r\nESTAB      305    0        :60525\r\nESTAB      0      0        :36547  users:((\"java\",1851,63))\r\nESTAB      305    0        :49315\r\nESTAB      0      0        :45487  users:((\"java\",1851,43))\r\nESTAB      0      0        :39752  users:((\"java\",1851,42))\r\nESTAB      0      0        :56869  users:((\"java\",1851,34))\r\nESTAB      0      0        :44424  users:((\"java\",1851,37))\r\nESTAB      0      0        :40604  users:((\"java\",1851,74))\r\nESTAB      0      0        :40573  users:((\"java\",1851,17))\r\nESTAB      0      0        :53410\r\nESTAB      0      0        :41848  users:((\"java\",1851,38))\r\n```\r\n\r\nThe `ESTAB` connections without the owner process details (ie `users:((...)))`) are the un-`accept()`-ed connections. Most of these have a ~300 Recv-Q which I presume is the TLS client hello. The number of these `ESTAB` connections corresponds with the Recv-Q value of the `LISTEN` entry - `4` in this example.\r\n\r\nSending `SIGQUIT` to the logstash Java process to dump the all the thread call stacks shows the following for the tcp input thread:\r\n\r\n```\r\n\"<tcp\" daemon prio=10 tid=0x0000000000888800 nid=0x76a runnable [0x00007f0ff3efb000]\r\n   java.lang.Thread.State: RUNNABLE\r\n        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)\r\n        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)\r\n        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)\r\n        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)\r\n        - locked <0x00000000e4e93a40> (a sun.nio.ch.Util$2)\r\n        - locked <0x00000000e4e93a28> (a java.util.Collections$UnmodifiableSet)\r\n        - locked <0x00000000e60c8f38> (a sun.nio.ch.EPollSelectorImpl)\r\n        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)\r\n        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:102)\r\n        at org.jruby.ext.openssl.SSLSocket$2.run(SSLSocket.java:342)\r\n        at org.jruby.RubyThread.executeBlockingTask(RubyThread.java:1065)\r\n        at org.jruby.ext.openssl.SSLSocket.waitSelect(SSLSocket.java:319)\r\n        at org.jruby.ext.openssl.SSLSocket.doHandshake(SSLSocket.java:437)\r\n        at org.jruby.ext.openssl.SSLSocket.acceptCommon(SSLSocket.java:270)\r\n        at org.jruby.ext.openssl.SSLSocket.accept(SSLSocket.java:232)\r\n        at org.jruby.ext.openssl.SSLSocket$INVOKER$i$0$0$accept.call(SSLSocket$INVOKER$i$0$0$accept.gen)\r\n        at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:134)\r\n        at org.jruby.ast.CallNoArgNode.interpret(CallNoArgNode.java:60)\r\n```\r\n\r\nIf you need more information, I'm happy to provide it. I'm keen to diagnose and fix this problem but I'm not sure where to look next."}}