Open
Description
Closing the socket on probing timeout (code) may not take any effect on the thread handling the incoming messages (as it is supposed) and, as result, the connection gets stuck in an endless loop of trying to be established without any success:
ssu1: May 08 16:04:27 ssu1 p[8909]: Network.Socket.ByteString.sendMany: total=407552 sent=325800
ssu1: May 08 16:04:28 ssu1 p[8909]: Network.Socket.ByteString.sendMany: total=506136 sent=76374
ssu1: May 08 16:04:28 ssu1 p[8909]: Network.Socket.ByteString.sendMany: total=506072 sent=65036
ssu1: May 08 16:04:28 ssu1 p[8909]: runScheduledAction: exception=ProcessLinkException pid://172.28.128.18:9070:0:544484 DiedNormal remote=172.28.128.14:9070:0 stack=["Network.Transport.TCP.runScheduledAction (src/Network/Transport/TCP.hs:(1950,1)-(1981,38))","Network.Transport.TCP.withScheduledAction.\\ (src/Network/Transport/TCP.hs:1989:34-71)","Network.Transport.TCP.withScheduledAction (src/Network/Transport/TCP.hs:(1987,1)-(1990,94))","Network.Transport.TCP.apiSend (src/Network/Transport/TCP.hs:(820,1)-(850,49))","Network.Transport.TCP.apiConnect (src/Network/Transport/TCP.hs:(766,1)-(780,11))"]
ssu1: May 08 16:04:28 ssu1 p[8909]: Network.Socket.ByteString.sendMany: total=441036 sent=325800
ssu1: May 08 16:04:28 ssu1 p[8909]: Network.Socket.ByteString.sendMany: total=63244 sent=41662
ssu1: May 08 16:04:29 ssu1 p[8909]: Network.Socket.ByteString.sendMany: total=63308 sent=52878
ssu1: May 08 16:04:29 ssu1 p[8909]: runScheduledAction: exception=ProcessLinkException pid://172.28.128.18:9070:0:544701 DiedNormal remote=172.28.128.14:9070:0 stack=["Network.Transport.TCP.runScheduledAction (src/Network/Transport/TCP.hs:(1950,1)-(1981,38))","Network.Transport.TCP.withScheduledAction.\\ (src/Network/Transport/TCP.hs:1989:34-71)","Network.Transport.TCP.withScheduledAction (src/Network/Transport/TCP.hs:(1987,1)-(1990,94))","Network.Transport.TCP.apiSend (src/Network/Transport/TCP.hs:(820,1)-(850,49))","Network.Transport.TCP.apiConnect (src/Network/Transport/TCP.hs:(766,1)-(780,11))"]
ssu1: May 08 16:04:29 ssu1 p[8909]: Network.Socket.ByteString.sendMany: total=63387 sent=1494
ssu1: May 08 16:04:29 ssu1 p[8909]: runScheduledAction: exception=ProcessLinkException pid://172.28.128.18:9070:0:544732 DiedNormal remote=172.28.128.14:9070:0 stack=["Network.Transport.TCP.runScheduledAction (src/Network/Transport/TCP.hs:(1950,1)-(1981,38))","Network.Transport.TCP.withScheduledAction.\\ (src/Network/Transport/TCP.hs:1989:34-71)","Network.Transport.TCP.withScheduledAction (src/Network/Transport/TCP.hs:(1987,1)-(1990,94))","Network.Transport.TCP.apiSend (src/Network/Transport/TCP.hs:(820,1)-(850,49))","Network.Transport.TCP.apiConnect (src/Network/Transport/TCP.hs:(766,1)-(780,11))"]
ssu1: May 08 16:04:29 ssu1 p[8909]: Network.Socket.ByteString.sendMany: total=63384 sent=24181
ssu1: May 08 16:04:29 ssu1 p[8909]: runScheduledAction: exception=ProcessLinkException pid://172.28.128.18:9070:0:544983 DiedNormal remote=172.28.128.14:9070:0 stack=["Network.Transport.TCP.runScheduledAction (src/Network/Transport/TCP.hs:(1950,1)-(1981,38))","Network.Transport.TCP.withScheduledAction.\\ (src/Network/Transport/TCP.hs:1989:34-71)","Network.Transport.TCP.withScheduledAction (src/Network/Transport/TCP.hs:(1987,1)-(1990,94))","Network.Transport.TCP.apiSend (src/Network/Transport/TCP.hs:(820,1)-(850,49))","Network.Transport.TCP.apiConnect (src/Network/Transport/TCP.hs:(766,1)-(780,11))"]
ssu1: May 08 16:04:29 ssu1 p[8909]: handleIncomingMessages.prematureExit: err=Network.Socket.recvBuf: resource vanished (Connection reset by peer) st=RemoteEndPointValid
ssu1: May 08 16:04:29 ssu1 p[8909]: resetIfBroken: remoteEP failed
ssu1: May 08 16:04:29 ssu1 p[8909]: removeRemoteEndPoint: 172.28.128.14:9070:0
ssu1: May 08 16:04:29 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:29 ssu1 p[8909]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.14:9070:0,True,35)
ssu1: May 08 16:04:29 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:29 ssu1 p[8909]: socketToEndPoint: AddrInfo {addrFlags = [AI_ADDRCONFIG,AI_V4MAPPED], addrFamily = AF_INET, addrSocketType = Stream, addrProtocol = 6, addrAddress = 172.28.128.14:9070, addrCanonName = Nothing}
ssu1: May 08 16:04:29 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:29 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:29 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53624
---------------------- send ProbeSocket 👇which should timeout after 2 seconds (transportConnectTimeout) if there is no reply (and there was not)
ssu4: May 08 16:04:29 ssu4 p[8904]: ProbeSocket: 172.28.128.18:9070:0
ssu1: May 08 16:04:30 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:31 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:31 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53626
ssu1: May 08 16:04:31 ssu1 p[8909]: createConnectionTo.go: remove crossed RemoteEndPoint 172.28.128.14:9070:0
ssu1: May 08 16:04:31 ssu1 p[8909]: removeRemoteEndPoint: 172.28.128.14:9070:0
ssu1: May 08 16:04:31 ssu1 p[8909]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.14:9070:0,True,36)
ssu1: May 08 16:04:31 ssu1 p[8909]: socketToEndPoint: AddrInfo {addrFlags = [AI_ADDRCONFIG,AI_V4MAPPED], addrFamily = AF_INET, addrSocketType = Stream, addrProtocol = 6, addrAddress = 172.28.128.14:9070, addrCanonName = Nothing}
ssu1: May 08 16:04:31 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:31 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:32 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:32 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53628
ssu1: May 08 16:04:32 ssu1 p[8909]: createConnectionTo.go: remove crossed RemoteEndPoint 172.28.128.14:9070:0
ssu1: May 08 16:04:32 ssu1 p[8909]: removeRemoteEndPoint: 172.28.128.14:9070:0
ssu1: May 08 16:04:32 ssu1 p[8909]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.14:9070:0,True,37)
ssu1: May 08 16:04:32 ssu1 p[8909]: socketToEndPoint: AddrInfo {addrFlags = [AI_ADDRCONFIG,AI_V4MAPPED], addrFamily = AF_INET, addrSocketType = Stream, addrProtocol = 6, addrAddress = 172.28.128.14:9070, addrCanonName = Nothing}
ssu1: May 08 16:04:32 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:33 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:33 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53630
ssu1: May 08 16:04:33 ssu1 p[8909]: createConnectionTo.go: remove crossed RemoteEndPoint 172.28.128.14:9070:0
ssu1: May 08 16:04:33 ssu1 p[8909]: removeRemoteEndPoint: 172.28.128.14:9070:0
ssu1: May 08 16:04:33 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:33 ssu1 p[8909]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.14:9070:0,True,38)
ssu1: May 08 16:04:33 ssu1 p[8909]: socketToEndPoint: AddrInfo {addrFlags = [AI_ADDRCONFIG,AI_V4MAPPED], addrFamily = AF_INET, addrSocketType = Stream, addrProtocol = 6, addrAddress = 172.28.128.14:9070, addrCanonName = Nothing}
ssu1: May 08 16:04:33 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:34 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:35 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:35 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53632
ssu1: May 08 16:04:35 ssu1 p[8909]: createConnectionTo.go: remove crossed RemoteEndPoint 172.28.128.14:9070:0
ssu1: May 08 16:04:35 ssu1 p[8909]: removeRemoteEndPoint: 172.28.128.14:9070:0
ssu1: May 08 16:04:35 ssu1 p[8909]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.14:9070:0,True,39)
ssu1: May 08 16:04:35 ssu1 p[8909]: socketToEndPoint: AddrInfo {addrFlags = [AI_ADDRCONFIG,AI_V4MAPPED], addrFamily = AF_INET, addrSocketType = Stream, addrProtocol = 6, addrAddress = 172.28.128.14:9070, addrCanonName = Nothing}
ssu1: May 08 16:04:35 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:35 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:36 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:36 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53634
ssu1: May 08 16:04:36 ssu1 p[8909]: createConnectionTo.go: remove crossed RemoteEndPoint 172.28.128.14:9070:0
ssu1: May 08 16:04:36 ssu1 p[8909]: removeRemoteEndPoint: 172.28.128.14:9070:0
ssu1: May 08 16:04:36 ssu1 p[8909]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.14:9070:0,True,40)
ssu1: May 08 16:04:36 ssu1 p[8909]: socketToEndPoint: AddrInfo {addrFlags = [AI_ADDRCONFIG,AI_V4MAPPED], addrFamily = AF_INET, addrSocketType = Stream, addrProtocol = 6, addrAddress = 172.28.128.14:9070, addrCanonName = Nothing}
ssu1: May 08 16:04:36 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:37 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:37 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53636
ssu1: May 08 16:04:37 ssu1 p[8909]: createConnectionTo.go: remove crossed RemoteEndPoint 172.28.128.14:9070:0
ssu1: May 08 16:04:37 ssu1 p[8909]: removeRemoteEndPoint: 172.28.128.14:9070:0
ssu1: May 08 16:04:37 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:37 ssu1 p[8909]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.14:9070:0,True,41)
ssu1: May 08 16:04:37 ssu1 p[8909]: socketToEndPoint: AddrInfo {addrFlags = [AI_ADDRCONFIG,AI_V4MAPPED], addrFamily = AF_INET, addrSocketType = Stream, addrProtocol = 6, addrAddress = 172.28.128.14:9070, addrCanonName = Nothing}
ssu1: May 08 16:04:37 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:37 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:37 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:37 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:37 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:37 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:38 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:39 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:39 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53638
ssu1: May 08 16:04:39 ssu1 p[8909]: createConnectionTo.go: remove crossed RemoteEndPoint 172.28.128.14:9070:0
ssu1: May 08 16:04:39 ssu1 p[8909]: removeRemoteEndPoint: 172.28.128.14:9070:0
ssu1: May 08 16:04:39 ssu1 p[8909]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.14:9070:0,True,42)
ssu1: May 08 16:04:39 ssu1 p[8909]: socketToEndPoint: AddrInfo {addrFlags = [AI_ADDRCONFIG,AI_V4MAPPED], addrFamily = AF_INET, addrSocketType = Stream, addrProtocol = 6, addrAddress = 172.28.128.14:9070, addrCanonName = Nothing}
ssu1: May 08 16:04:39 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:39 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:39 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu1: May 08 16:04:39 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:40 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:40 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53640
ssu1: May 08 16:04:40 ssu1 p[8909]: createConnectionTo.go: remove crossed RemoteEndPoint 172.28.128.14:9070:0
ssu1: May 08 16:04:40 ssu1 p[8909]: removeRemoteEndPoint: 172.28.128.14:9070:0
ssu1: May 08 16:04:40 ssu1 p[8909]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.14:9070:0,True,43)
ssu1: May 08 16:04:40 ssu1 p[8909]: socketToEndPoint: AddrInfo {addrFlags = [AI_ADDRCONFIG,AI_V4MAPPED], addrFamily = AF_INET, addrSocketType = Stream, addrProtocol = 6, addrAddress = 172.28.128.14:9070, addrCanonName = Nothing}
ssu1: May 08 16:04:40 ssu1 p[8909]: createConnectionTo.go: ourAddr=172.28.128.18:9070:0 theirAddr=172.28.128.14:9070:0
ssu4: May 08 16:04:41 ssu4 p[8904]: findRemoteEndPoint: (addr, new?, id)=(172.28.128.18:9070:0,False,16)
ssu4: May 08 16:04:41 ssu4 p[8904]: handleConnectionRequest.go: ConnectionRequestCrossed: 172.28.128.18:53642
...
Originally posted by @andriytk in haskell-distributed/network-transport-tcp#74 (comment)