Skip navigation

This project is read only now. Read more.

8 Replies Latest reply on Nov 15, 2019 4:57 PM by bmaxwell

Too many intra-process localhost connections

luismcosta Mar 31, 2016 6:19 PM

Hi!

I'm observing many localhost connections. The number of connections keeps increasing leading wildfly to just log connection problems because Windows runs out of available ports:

Log entry example

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-6) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-3) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-6) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-3) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-6) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-3) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-6) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-3) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-6) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-3) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-6) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-3) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-6) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-3) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-6) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-3) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException

Using netstat (and filtering by PID) I see a lot of these connections:

TCP 127.0.0.1:61313 127.0.0.1:61314 ESTABLISHED 8592

TCP 127.0.0.1:61314 127.0.0.1:61313 ESTABLISHED 8592

TCP 127.0.0.1:61315 127.0.0.1:61316 ESTABLISHED 8592

TCP 127.0.0.1:61316 127.0.0.1:61315 ESTABLISHED 8592

TCP 127.0.0.1:61317 127.0.0.1:61318 ESTABLISHED 8592

TCP 127.0.0.1:61318 127.0.0.1:61317 ESTABLISHED 8592

TCP 127.0.0.1:61319 127.0.0.1:61320 ESTABLISHED 8592

TCP 127.0.0.1:61320 127.0.0.1:61319 ESTABLISHED 8592

TCP 127.0.0.1:61322 127.0.0.1:61323 ESTABLISHED 8592

TCP 127.0.0.1:61323 127.0.0.1:61322 ESTABLISHED 8592

TCP 127.0.0.1:61324 127.0.0.1:61325 ESTABLISHED 8592

TCP 127.0.0.1:61325 127.0.0.1:61324 ESTABLISHED 8592

TCP 127.0.0.1:61326 127.0.0.1:61327 ESTABLISHED 8592

TCP 127.0.0.1:61327 127.0.0.1:61326 ESTABLISHED 8592

TCP 127.0.0.1:61328 127.0.0.1:61329 ESTABLISHED 8592

TCP 127.0.0.1:61329 127.0.0.1:61328 ESTABLISHED 8592

TCP 127.0.0.1:61331 127.0.0.1:61332 ESTABLISHED 8592

TCP 127.0.0.1:61332 127.0.0.1:61331 ESTABLISHED 8592

TCP 127.0.0.1:61333 127.0.0.1:61334 ESTABLISHED 8592

TCP 127.0.0.1:61334 127.0.0.1:61333 ESTABLISHED 8592

TCP 127.0.0.1:61335 127.0.0.1:61336 ESTABLISHED 8592

TCP 127.0.0.1:61336 127.0.0.1:61335 ESTABLISHED 8592

TCP 127.0.0.1:61337 127.0.0.1:61338 ESTABLISHED 8592

TCP 127.0.0.1:61338 127.0.0.1:61337 ESTABLISHED 8592

TCP 127.0.0.1:61365 127.0.0.1:61366 ESTABLISHED 8592

TCP 127.0.0.1:61366 127.0.0.1:61365 ESTABLISHED 8592

TCP 127.0.0.1:61367 127.0.0.1:61368 ESTABLISHED 8592

TCP 127.0.0.1:61368 127.0.0.1:61367 ESTABLISHED 8592

TCP 127.0.0.1:61370 127.0.0.1:61371 ESTABLISHED 8592

TCP 127.0.0.1:61371 127.0.0.1:61370 ESTABLISHED 8592

TCP 127.0.0.1:61644 127.0.0.1:61645 ESTABLISHED 8592

TCP 127.0.0.1:61645 127.0.0.1:61644 ESTABLISHED 8592

TCP 127.0.0.1:61659 127.0.0.1:61660 ESTABLISHED 8592

TCP 127.0.0.1:61660 127.0.0.1:61659 ESTABLISHED 8592

TCP 127.0.0.1:61717 127.0.0.1:61718 ESTABLISHED 8592

TCP 127.0.0.1:61718 127.0.0.1:61717 ESTABLISHED 8592

As we can see these are local intra-process connections.

Setup:

I've tried/observed this in:

Windows Server 2012 and Windows 2007 Professional

JDK 8u20 and JDK 8u77

Wilfly 8.2.1-final

Some facts:

1)

Just by starting a fresh Wildfly (just downloaded), and without any application deployed I see some of the connections:

TCP 127.0.0.1:54808 127.0.0.1:54812 ESTABLISHED 11928

TCP 127.0.0.1:54809 127.0.0.1:54811 ESTABLISHED 11928

TCP 127.0.0.1:54810 127.0.0.1:54821 ESTABLISHED 11928

TCP 127.0.0.1:54811 127.0.0.1:54809 ESTABLISHED 11928

TCP 127.0.0.1:54812 127.0.0.1:54808 ESTABLISHED 11928

TCP 127.0.0.1:54813 127.0.0.1:54814 ESTABLISHED 11928

TCP 127.0.0.1:54814 127.0.0.1:54813 ESTABLISHED 11928

TCP 127.0.0.1:54815 127.0.0.1:54816 ESTABLISHED 11928

TCP 127.0.0.1:54816 127.0.0.1:54815 ESTABLISHED 11928

TCP 127.0.0.1:54817 127.0.0.1:54818 ESTABLISHED 11928

TCP 127.0.0.1:54818 127.0.0.1:54817 ESTABLISHED 11928

TCP 127.0.0.1:54819 127.0.0.1:54820 ESTABLISHED 11928

TCP 127.0.0.1:54820 127.0.0.1:54819 ESTABLISHED 11928

TCP 127.0.0.1:54821 127.0.0.1:54810 ESTABLISHED 11928

TCP 127.0.0.1:54822 127.0.0.1:54824 ESTABLISHED 11928

TCP 127.0.0.1:54823 127.0.0.1:54825 ESTABLISHED 11928

TCP 127.0.0.1:54824 127.0.0.1:54822 ESTABLISHED 11928

TCP 127.0.0.1:54825 127.0.0.1:54823 ESTABLISHED 11928

TCP 127.0.0.1:54826 127.0.0.1:54827 ESTABLISHED 11928

TCP 127.0.0.1:54827 127.0.0.1:54826 ESTABLISHED 11928

TCP 127.0.0.1:54828 127.0.0.1:54829 ESTABLISHED 11928

TCP 127.0.0.1:54829 127.0.0.1:54828 ESTABLISHED 11928

This value does not seem to increase when there are no deployed applications.

2)

When I deploy an application that creates some HTTP connections and also WebSockets the number of connections starts to grow.

3)

Using the debugger I has not able to catch how are the connections (sockets - I assume that server socket is being binded to port 0) being created .

4)

Using WinCap to capture 127.0.0.1 traffic I've found the following pattern:

Client Connects [SYN]

Server Ack [SYN, ACK]

Client Ack [ACK]

Client Push [PSH] - It pushes 8 bytes (e.g., in hex, e6202552f2b95f6f)

Optionally the server pushes some data periodically (always the same)

Server Push [PSH] - It pushes 1 bytes (in hex, 1)

Does someone has any idea on what the problem may be? Or give any additional troubleshooting tip?

Thanks,

Luís M. Costa

1. Re: Too many intra-process localhost connections

dmlloyd Mar 31, 2016 6:36 PM (in response to luismcosta)

When you see the "2016-03-30 10:44:26,222 ERROR [org.xnio.listener] (default I/O-3) XNIO001007: A channel event listener threw an exception: java.lang.NullPointerException" message, I assume there is a stack trace? Could you share it?
Actions
2. Re: Too many intra-process localhost connections

luismcosta Mar 31, 2016 6:46 PM (in response to dmlloyd)

Hi David!

Unfortunately, there is not. The log files rapidly (in minutes, or less) fill up with the the messages I've posted.

Please note that, although the logs are coincidentally from the same millisecond, this is not a copy-paste gone bad. This is the actual log!

A 50Mb log is filled in 10s.
Actions
3. Re: Too many intra-process localhost connections

luismcosta Mar 31, 2016 7:02 PM (in response to luismcosta)

Just a quick note to add that, using a just downloaded version of wildfly 10.0.0.Final, and without any applications deployed I also observed some (12 actually) localhost intra-process connections.
Actions
4. Re: Too many intra-process localhost connections

dmlloyd Apr 1, 2016 9:02 AM (in response to luismcosta)

I can only assume that stack traces must be disabled in your log formatter configuration (a "%e" instead of a "%E"). The NPE is a bug in whatever library is currently using XNIO (it could be Undertow or it could be JBoss Remoting). It's impossible to tell which without the stack trace.

The NPE is likely occurring because something is connecting internally and then sending unparseable garbage, and the garbage is such that the code doesn't understand what to do with it, resulting in NPE. The odd thing is that the source _and_ destination port numbers appear to be ephemeral. I'm not sure what we have that would use XNIO and also bind ephemeral ports - HornetQ maybe?
Actions
5. Re: Too many intra-process localhost connections

luismcosta Apr 1, 2016 10:37 AM (in response to dmlloyd)

I David,

I also find the source _and_ destination port numbers intriguing...

I think I have the formatter correctly configured:
<pattern-formatter pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c] (%t) %s%E%n"/>

The wildfly instance that I'm using does not have the messaging extension configured, and there is reference to HornetQ (standalone.xml).

I've set "org.xnio" to trace, but there is no reference to these ephemeral ports, only to the expected one (8180 in my case).

Can you give any troubleshooting tips?
I've tried to debug the server, setting breakpoints in Socket and ServerSockets constructors, but I didn't get any of the ephemeral ports. Again, just 8180 related connections.
Actions
6. Re: Too many intra-process localhost connections

rcd Apr 11, 2016 5:25 PM (in response to luismcosta)

Does your application use java.io.PipedInput/OutputStream? If memory serves, those are implemented using loopback sockets on Windows. Most likely something in WildFly is also using them, which leads to a bunch of loopback sockets being created when the server starts up.
Actions
7. Re: Too many intra-process localhost connections

jaikiran Apr 12, 2016 12:47 AM (in response to luismcosta)

Luís M. Costa wrote:

Can you give any troubleshooting tips?

Byteman maybe? Byteman Homepage · JBoss Community
Actions
8. Re: Too many intra-process localhost connections

bmaxwell Nov 15, 2019 4:57 PM (in response to luismcosta)

> I'm observing many localhost connections. The number of connections keeps increasing leading wildfly to just log connection problems because Windows runs out of available ports:

Windows Java NIO implementation uses TCP for intra-process signaling. It opens a pair of self-connected sockets for every Selector.
So seeing the connections is normal when nio is used as the default dynamic port range for TCP/IP is 49152 to 65535.
You would want to make sure you do not try to bind JBoss or any service to a port that is in this ephemeral port rage else you would get port conflicts.
I would try the latest Wildfly and see if the NPE is fixed.

https://support.microsoft.com/en-us/help/929851/the-default-dynamic-port-range-for-tcp-ip-has-changed-in-windows-vista
Troubleshoot port exhaustion issues | Microsoft Docs
Actions

Go to original post