Forged Alliance Forever

Re: Issues with ICE

2019-07-28T12:56:21+02:00

/viewtopic.php?f=3&t=17847

Statistics: Posted by Bpamapb — 28 Jul 2019, 12:56

Re: Issues with ICE

2019-07-06T10:37:19+02:00

Please give me the ice adapter log.
Also, the client you're using is unsupported, please use the official client.

Statistics: Posted by Geosearchef — 06 Jul 2019, 10:37

Re: Issues with ICE

2019-07-06T10:05:09+02:00

Hello,

I'm facing an issue possibly related to ICE, game crashed after few second in game with a popup telling somthing about ICE 1073807364.

Here is debug message :

Traceback (most recent call last):
File "src\connectivity\JsonRpcTcpClient.py", line 40, in onSocketError
RuntimeError: Connection error to JSON RPC server: The remote host closed the connection (1)

Runtime info:

FAF Username: Tristaneo
FAF Version: 0.18.5+3134
FAF Environment: production
FAF Directory: C:\ProgramData\FAForever
FA Path: : D:/Program Files (x86)/Steam/steamapps/common/Supreme Commander Forged Alliance
Home Directory: D:/Users/***/Documents
Platform: Windows-10-10.0.18362
Uname: uname_result(system='Windows', node='***', release='10', version='10.0.18362', machine='AMD64', processor='Intel64 Family 6 Model 60 Stepping 3, GenuineIntel')

I could play normally yesterday, maybe it was specific to this game... I did'nt change anything on my side.

Thanks in advance for your investigations

Statistics: Posted by Tristaneo — 06 Jul 2019, 10:05

Re: Issues with ICE

2019-06-11T22:21:07+02:00

oh I flicked you the logs via pm
time stamp(well my timezone so might be the 4th for you) : 05 Jun 2019, 23:03

I'll see if he can confirm with his isp if he's cg nat'd as that does seem a likely reason for these symptoms given I don't have issues with other players.

Statistics: Posted by relent0r — 11 Jun 2019, 22:21

Re: Issues with ICE

2019-06-11T09:33:15+02:00

I've seen that and was ver confused aswell. First thing would be to make sure you're not behind CG NAT.

The IPv6 candidate failing is no problem and to be expected, the other candidates afterwards failing isn't normal. From that log I sadly can't twll what's going on. What you can try is disabling ipv6 (network adapters, rightlick, properties, disable the ipv6 stack).

Also, based on what logs?

Statistics: Posted by Geosearchef — 11 Jun 2019, 09:33

Re: Issues with ICE

2019-06-11T01:33:14+02:00

Did you have any more thoughts on this Geo based on the logs?
From what I can see my friends public IP isn't in the cg nat range that australia uses so I think he's good from that perspective.

From what I saw in the logs the only thing strange was that when the host machine attempting the binding request it used an ipv6 address and failed with 'Cannot assign requested address: Datagram send failed' then it attempted a binding response through the other addresses which failed with a 'has already seen a previous response' message. These errors continued until the relay peer was attempted.

Statistics: Posted by relent0r — 11 Jun 2019, 01:33

Re: Issues with ICE

2019-06-03T00:38:14+02:00

Ok cool will do.

Statistics: Posted by relent0r — 03 Jun 2019, 00:38

Re: Issues with ICE

2019-06-02T15:12:52+02:00

To say more I'd also need a downlords faf client log from both ends with a client version <= 0.10.5. (see github.com/FAForever/downlords-faf-client/releases)

Just install the 0.10.5 client and pm me both downlords-faf-client.log .

Statistics: Posted by Geosearchef — 02 Jun 2019, 15:12

Re: Issues with ICE

2019-06-02T11:16:48+02:00

Geosearchef wrote:
Port 6112 isn't going to do you any favor. The adapter randomly picks any port between 6112-7112 for each peer. (Not suggesting you forward the entire range though).

How long does your connection procedure take? 20+ secs?

To say more I'd also need a downlords faf client log from both ends with a client version <= 0.10.5. (see github.com/FAForever/downlords-faf-client/releases)

It takes about 6-8 seconds for the connection, doesn't feel very long. We are both running 0.10.6 client.
When we look at the debug we can see that the remote is relay. (though I didn't know that ice picks a random port for each peer).

The log from his side is as follows when the connection was being made. Or are you looking for a different log file?

Code:: 2019-06-01 17:39:12.677 INFO Version: SNAPSHOT (com.faforever.iceadapter.IceAdapter:52) 2019-06-01 17:39:12.681 INFO Using GPGNET_PORT: 15202 (c.f.iceadapter.gpgnet.GPGNetServer:38) 2019-06-01 17:39:12.684 INFO Generated LOBBY_PORT: 59099 (c.f.iceadapter.gpgnet.GPGNetServer:43) 2019-06-01 17:39:12.686 INFO GPGNetServer started (c.f.iceadapter.gpgnet.GPGNetServer:56) 2019-06-01 17:39:12.707 INFO Creating RPC server on port 20532 (c.f.iceadapter.rpc.RPCService:32) 2019-06-01 17:39:12.880 DEBUG LobbyInitMode set to normal (c.f.iceadapter.rpc.RPCHandler:53) 2019-06-01 17:39:13.180 INFO Ice Servers set, total addresses: 3 (c.f.iceadapter.ice.GameSession:122) 2019-06-01 17:39:14.500 INFO Created debug window. (c.f.iceadapter.debug.DebugWindow:78) 2019-06-01 17:39:20.344 DEBUG Listening for GPG messages (c.f.iceadapter.gpgnet.GPGNetServer:144) 2019-06-01 17:39:20.345 INFO GPGNetClient has connected (c.f.iceadapter.gpgnet.GPGNetServer:85) 2019-06-01 17:39:20.349 DEBUG New GameState: Idle (c.f.iceadapter.gpgnet.GPGNetServer:96) 2019-06-01 17:39:20.350 INFO Sent GPGNet message: CreateLobby 0 59099 Sarge420 266006 1 (c.f.iceadapter.gpgnet.GPGNetServer:133) 2019-06-01 17:39:20.350 INFO Received GPGNet message: GameState Idle (c.f.iceadapter.gpgnet.GPGNetServer:123) 2019-06-01 17:39:20.539 DEBUG New GameState: Lobby (c.f.iceadapter.gpgnet.GPGNetServer:96) 2019-06-01 17:39:20.539 INFO Received GPGNet message: GameState Lobby (c.f.iceadapter.gpgnet.GPGNetServer:123) 2019-06-01 17:39:21.015 INFO onJoinGame 3149 relentless (com.faforever.iceadapter.IceAdapter:72) 2019-06-01 17:39:21.017 DEBUG Peer created: 3149, relentless, localOffer: false (com.faforever.iceadapter.ice.Peer:32) 2019-06-01 17:39:21.018 DEBUG Now forwarding data to peer relentless(3149) (com.faforever.iceadapter.ice.Peer:53) 2019-06-01 17:39:21.020 INFO Sent GPGNet message: JoinGame 127.0.0.1:63095 relentless 3149 (c.f.iceadapter.gpgnet.GPGNetServer:133) 2019-06-01 17:39:22.430 INFO IceMsg received %s (c.f.iceadapter.rpc.RPCHandler:72) 2019-06-01 17:39:22.430 DEBUG ICE relentless(3149): Got IceMsg for peer (c.f.iceadapter.ice.PeerIceModule:167) 2019-06-01 17:39:22.431 INFO ICE relentless(3149): Initiating ICE for peer (c.f.iceadapter.ice.PeerIceModule:76) 2019-06-01 17:39:22.952 INFO ICE relentless(3149): Gathering ice candidates (c.f.iceadapter.ice.PeerIceModule:96) 2019-06-01 17:39:23.663 DEBUG ICE relentless(3149): Sending own candidates to 3149 (c.f.iceadapter.ice.PeerIceModule:134) 2019-06-01 17:39:23.669 DEBUG ICE relentless(3149): Starting ICE for peer 3149 (c.f.iceadapter.ice.PeerIceModule:202) 2019-06-01 17:39:25.069 DEBUG ICE relentless(3149): ICE terminated (c.f.iceadapter.ice.PeerIceModule:227) 2019-06-01 17:39:25.070 INFO Started turn refresh module for peer relentless (c.f.i.ice.PeerTurnRefreshModule:60) 2019-06-01 17:39:25.071 INFO Sent turn refresh request. (c.f.i.ice.PeerTurnRefreshModule:72) 2019-06-01 17:39:25.071 DEBUG ICE relentless(3149): Now forwarding data from ICE to FA for peer (c.f.iceadapter.ice.PeerIceModule:351) 2019-06-01 17:39:25.874 INFO Created info window. (c.f.iceadapter.debug.InfoWindow:55)

Statistics: Posted by relent0r — 02 Jun 2019, 11:16

Re: Issues with ICE

2019-06-02T10:30:25+02:00

Port 6112 isn't going to do you any favor. The adapter randomly picks any port between 6112-7112 for each peer. (Not suggesting you forward the entire range though).

How long does your connection procedure take? 20+ secs?

To say more I'd also need a downlords faf client log from both ends with a client version <= 0.10.5. (see github.com/FAForever/downlords-faf-client/releases)

Statistics: Posted by Geosearchef — 02 Jun 2019, 10:30

Re: Issues with ICE

2019-06-01T22:57:50+02:00

Anyone got advice on how to better troubleshoot an issue where the game connection keeps going through relay. (I'm in nz, he's in aus so relay for us = 600ping)
I'm fine with games to others but with my friend its just not doing its thing. It was fine prior to the ice implementation.
We both have the same routers and we've both setup a nat for port 6112 on TCP/UDP to our local lan ip(upnp is also enabled on). I'm really not understanding where its going wrong. I don't see anything obvious in the logs either. So given that we have the same routers and I'm fine with others. He doesn't have any other 3rd party firewall software or anything. Any other tips that would help us figure out where its going wrong.

On my side the ice logs look like this(i can can get his side as well if it might shed more light).
2019-06-01 19:39:31.210 INFO onConnectToPeer 266006 Sarge420, offer: true (com.faforever.iceadapter.IceAdapter:89)
2019-06-01 19:39:31.213 DEBUG Peer created: 266006, Sarge420, localOffer: true (com.faforever.iceadapter.ice.Peer:32)
2019-06-01 19:39:31.214 DEBUG Now forwarding data to peer Sarge420(266006) (com.faforever.iceadapter.ice.Peer:53)
2019-06-01 19:39:31.218 INFO ICE Sarge420(266006): Initiating ICE for peer (c.f.iceadapter.ice.PeerIceModule:76)
2019-06-01 19:39:31.220 INFO Sent GPGNet message: ConnectToPeer 127.0.0.1:49267 Sarge420 266006 (c.f.iceadapter.gpgnet.GPGNetServer:133)
2019-06-01 19:39:31.220 INFO Received GPGNet message: Disconnected 266006 (c.f.iceadapter.gpgnet.GPGNetServer:123)
2019-06-01 19:39:31.298 INFO ICE Sarge420(266006): Gathering ice candidates (c.f.iceadapter.ice.PeerIceModule:96)
2019-06-01 19:39:32.322 DEBUG ICE Sarge420(266006): Sending own candidates to 266006 (c.f.iceadapter.ice.PeerIceModule:134)
2019-06-01 19:39:34.181 INFO IceMsg received %s (c.f.iceadapter.rpc.RPCHandler:72)
2019-06-01 19:39:34.181 DEBUG ICE Sarge420(266006): Got IceMsg for peer (c.f.iceadapter.ice.PeerIceModule:167)
2019-06-01 19:39:34.184 DEBUG ICE Sarge420(266006): Starting ICE for peer 266006 (c.f.iceadapter.ice.PeerIceModule:202)
2019-06-01 19:39:35.568 DEBUG ICE Sarge420(266006): ICE terminated (c.f.iceadapter.ice.PeerIceModule:227)
2019-06-01 19:39:35.570 DEBUG Starting connectivity checker for peer 266006 (c.f.i.i.PeerConnectivityCheckerModule:37)
2019-06-01 19:39:35.571 DEBUG ICE Sarge420(266006): Now forwarding data from ICE to FA for peer (c.f.iceadapter.ice.PeerIceModule:351)

Statistics: Posted by relent0r — 01 Jun 2019, 22:57

Re: Issues with ICE

2019-05-14T14:52:59+02:00

Nearly all firewalls will not block any outgoing connections based on the target port on server side.

It's also fascinating, except for the complaint about the close adapter button, NO ONE here has so far posted any issue about ice.

Statistics: Posted by Geosearchef — 14 May 2019, 14:52

Re: Issues with ICE

2019-05-14T13:04:17+02:00

Bernie_Sanders wrote:
The new FAF client is not recognizing my login (Bernie_Sanders). When I attempt to reset the password it still is not working. Not sure what the problem is.

If it hangs for a while when you try to log in, you might be having the same problem as in my office which I think is that the login uses port 8001, which might be blocked on your firewall?

Statistics: Posted by dananski — 14 May 2019, 13:04

Re: Issues with ICE

2019-05-13T23:40:40+02:00

Yeah, the kill adapter button in the debugger window is probably overkill, it is focused and does trigger on the first click. The debug window is not supposed to be open all the time . The info window button is not selected by default and needs multiple presses to stop the adapter.

Statistics: Posted by Geosearchef — 13 May 2019, 23:40

Re: Issues with ICE

2019-05-13T21:05:30+02:00

I discovered a new ICE "feature"....

If the debug window is open (and possibly "active"?), one single "enter" will kill/close both the ICE and ICE debug window and thus all your connections with them. Happened to me twice, took me the second time to figure it out.

It is reproducible, at least in the lobby: open debug window, pres enter, windows close. Lobby stays, but i'm guessing no-one will be able to connect.

Very annoying feature, especially since "enter", which is the default key one to open chat, for instance when another player is having connection issues, at which time you might wanna look at said debug window . . .

Statistics: Posted by rkrempel — 13 May 2019, 21:05