Memory Leak in version 5.5.7

[shvo123]

Entries of closed connections in connections map of org.springframework.integration.ip.tcp.TcpSendingMessageHandler are not removed by removeDeadConnection when closed by client side.
Spring integ is listening on port on windows server 2019 standard.

I added some debug prints inside TcpSendingMessageHandler in addNewConnection and removeDead connections see attached log.

some explanation about the log.
I added to

public void addNewConnection(TcpConnection connection) {
		this.connections.put(connection.getConnectionId(), connection);
		**System.out.println(System.currentTimeMillis() + "," + LocalDateTime.now() + ",add," + connection.getConnectionId() + "," + this.connections.size() + "," +
				this.hashCode());
		logger.debug(System.currentTimeMillis() + "," + LocalDateTime.now() + ",add," + connection.getConnectionId() + "," + this.connections.size() + "," +
				this.hashCode());**
	}

That produces:
1640555438506,2021-12-26T23:50:38.506633400,add,10.64.34.156:64269:7006:9bbe89c3-b523-437c-bf3d-6c100d13e5fb,951,1463333127
And I added to:

public void removeDeadConnection(TcpConnection connection) {
		this.connections.remove(connection.getConnectionId());
		**System.out.println(System.currentTimeMillis() + "," + LocalDateTime.now() + ",remove," + connection.getConnectionId() + "," + this.connections.size() + "," +
				this.hashCode());
		logger.debug(System.currentTimeMillis() + "," + LocalDateTime.now() + ",remove," + connection.getConnectionId() + "," + this.connections.size() + "," +
				this.hashCode());**
	}

That produces:
1640556010630,2021-12-27T00:00:10.630973200,remove,10.64.34.156:64868:7006:77667a14-440c-4629-b698-d5f0b2a25e6b,984,1463333127

The problem manifested when host 10.64.34.156 connects to spring integration listener on port 7006.

I can not understand why, but it stopped removing inactive connections from connections map.

A link
agjstd_13600-2021-12-26.1.log

10x in advance, if you need further details please do not hasitate to contact me.

[shvo123]

Please close the issue, I found the bug in our code, redundant addNewConnection

[shvo123]

After additinal checks, there is memory leak issue as I described.
Atached new logs.
agjstd_728748-2021-12-28.2.log
agjstd_728748-2021-12-28.1.log

[shvo123]

Eventually, process crashed fatal error: OutOfMemory encountered: Java heap spac
hs_err_pid704812.log
e
let me know how can I pass to you full heap memory dump if you need it.

[garyrussell]

What version are you upgrading from?

Are you using connection interceptors?

I found the bug in our code, redundant addNewConnection

Why are you ever calling that method at all? It is an internal framework API.

There was a change earlier this year that fixed a similar memory leak but it is included in 5.5.7.

#3509

Perhaps that caused a regression in some circumstances.

Please show all of your TCP related bean definitions and any code that is calling the internal APIs.

[shvo123]

we are using latest version 5.5.7.
As you wrote no reason to use addnewConnection in any interceptor I removed it and we are no longer using it.
Even after this fix, still more and more dead connections are created until OutOfMemory of heap space.
I added simple check in addNewConnection (for debug purposes), and when the size of connections map is bigger than 300 (an arbitary number I picked up since in my case we are not using more than 50-100 connections), I scan the map and remove each connection that is not open or not connected see attached.
TcpSendingMessageHandler - Copy.txt

I think that source of the redundant connections is:
1229 19:40:12.512 ERROR istener_tcp_executor-2 o.s.i.ip.tcp.TcpSendingMessageHandler - [174171639675@] Error creating connection
java.io.UncheckedIOException: java.net.ConnectException: Connection refused: no further information

As you can see this error happened on 19:40:12.512, and the first leakage (more than 300 connections) found on 19:41
Line 1749: 1640799702877,2021-12-29T19:41:42.877124700,leakage,10.64.34.156:56624:7006:585f4fd7-d5af-47c7-a380-63bd749458ac,300,1610219311

Reasonable solution for us, can be an API you expose for us to check what is the size of the map associated with certain factory, and another API that would let us ask to scan this map and remove the deadConnection (I believe you have such anyway).

Finding all rare secanrios that dead connections are not removed may be painstaking while my quicky dirty approach would give us enough assurance, that or new version (that is using Spring Integration) is not going to explode when we would ship it to our customers.

If you need more log files just let me know.
I appriciate your efforts.
The issue is very important to us, and any assistant would be appriciated.
David

[shvo123]

Some definitions that you asked me to provide.
TransientModeConnectionInterceptor - Copy.txt
ListenerConnectionSupportFactory - Copy.txt
ctm_listener_tcp_factory is the factory involved.
CtmServerTcpConnectionFactoriesConfiguration - Copy.txt

[garyrussell]

1229 19:40:12.512 ERROR istener_tcp_executor-2 o.s.i.ip.tcp.TcpSendingMessageHandler - [174171639675@] Error creating connection
java.io.UncheckedIOException: java.net.ConnectException: Connection refused: no further information

Where do you see that? I don't see it in your logs.

In any case, Connection Refused is an error on the connect (before the connection is added).

[shvo123]

attached
ctmagj_891524-2021-12-29.0.log

I think you should concentrate on this log.

logs of add,remove,addchannel and leakage
it is a lot of stuff.
[agjstd_891524-2021-12-29.1
agjstd_891524-2021-12-29.1.log
agjstd_891524-2021-12-29.7.log
agjstd_891524-2021-12-29.6.log
agjstd_891524-2021-12-29.5.log
agjstd_891524-2021-12-29.4.log
agjstd_891524-2021-12-29.3.log
agjstd_891524-2021-12-29.2.log
agjstd_891524-2021-12-29.9.log
agjstd_891524-2021-12-29.8.log
.log](https://github.com/spring-projects/spring-integration/files/7790696/agjstd_891524-2021-12-29.1.log)

[garyrussell]

I can see that removeDeadConnections() is only called when a read or write error occurs (when a connection is intercepted). It is called from close() when there are no interceptors and closeConnection() when intercepted.

If there is no TcpListener we won't detect the socket is closed (since we don't read from it). It's hard to tell from your configuration if the client is send-only. If it is, then that might explain the problem.

If that is not the problem, it would be helpful if you could provide a minimal, complete example app that reproduces the behavior so we can investigate further.

Without understanding your code in more detail, it could be the close in your interceptor that might be part of the problem since you are closing it there.

You could try calling super.removeDeadConnection(this) in your closeConnection() method.