Network code changes

[BinDerDunDat]

I am having problems connecting to games which causes a bad hang on my system so I started troubleshooting.
I ran a sniffer and captured packets while trying to connect. I was able to connect during the sniff, but something became apparent.

FA is no longer using the configured UDP port or UPnP in FAF settings. Setting a UDP port forward or UPnP for FA in your router is pointless now.

FA is now using the FA ICE adapter as confirmed by Simple NAT Traversal for UDP and JSON RPC over UDP packets in the sniff.

I still see people telling others to port forward in aeolus. The word needs to get out that this (and UPnP) is no longer viable.

wiki:connections is no longer valid.

[Geosearchef]

I don't know how you catched some ICE packets. Which client version are you using? Are you sure those NAT traversal packets you did capture aren't just part of FA's own NAT traversal?

ICE is not yet deployed on the production server.

I can confirm from just testing that port forwarding still works perfectly fine:


Until ICE get's deployed, port forwarding is still a very good idea, but not totally necessary.
Without more information we can't tell you what's going wrong. (logs, official or java client, client version (maybe you launched a client that connects to the test server))

[BinDerDunDat]

I reran the sniff and connected to another game and I did see that people were sending and receiving on their faf configured port number. I apologize for the error. My system; however, is ignoring the configured port number and picking a random port. If I host I do not see UDP:6112 *.* in command-prompt>netstat -a output. When I join it is not using 6112 either. That's why my router port forward was not working and probably why I am getting the system hang. I see a lot of proxy connections in the game.log when I am able to connect.

The RPC packets were something else (to another IP address that I mistook for the faf server). I apologize again for the mistake. If you have a crow, I will eat it.

[BinDerDunDat]

The original problem that started the troubleshooting was that my system will hang when connecting to a game lobby. The abort button in the black connect screen goes unresponsive. Alt-Tab and Ctrl-Esc work, but I can not actually swap to another program. When I do try to swap, it just goes back to the FA connect screen. I have to press Ctrl-Alt-Del and do a restart. The restart closes everything but FAForever because it puts up a modal dialogue box saying fa stopped. I can answer no to that dialogue and stay in FAForever without doing the restart. I can try to connect to another game at this point, which will hang again most of the time (sometimes it connects properly). I will sometimes let the restart take place, but will get the same hang after the reboot most of the time.

Here are the relevant contents of my game.log on a failed connection attempt:

Code: Select all

info: GPGNET: setting nat handler to 0x11611004
info: LOBBY: Game port 6113[UDP] opened.
info: LOBBY: starting with local uid of 110218 [BinDerDunDat]
info: GPGNET: entering lobby state.
info: NET: using deflate compression for sends to I7-5960X:54015.
info: LOBBY: Connecting to host "Filosov" [I7-5960X:54015, uid=187739]
info: Can't add chat text -- no chat display
info: text="Connecting to game host..."
info: NET: using deflate compression for receives from I7-5960X:54015
info: LOBBY: connection to "Filosov" [I7-5960X:54015, uid=187739] made, status=Connecting.
info: NET: using deflate compression for sends to I7-5960X:54017.
info: DisconnectFromPeer (uid=234739)
info: LOBBY: deleting unknown peer uid 234739.
info: ConnectToPeer (name=Predeii, uid=234739, address=127.0.0.1:54016, USE PROXY)
info: NET: using deflate compression for sends to I7-5960X:54016.
info: LOBBY: Adding peer "Predeii" [I7-5960X:54016, uid=234739]
info: Can't add chat text -- no chat display
info: text="Connecting to Predeii..."
info: DisconnectFromPeer (uid=175912)
info: LOBBY: deleting unknown peer uid 175912.
info: ConnectToPeer (name=Hellpers, uid=175912, address=127.0.0.1:54017, USE PROXY)
info: LOBBY: Adding peer "Hellpers" [I7-5960X:54017, uid=175912]
info: Can't add chat text -- no chat display
info: text="Connecting to Hellpers..."
info: DisconnectFromPeer (uid=243395)
info: LOBBY: deleting unknown peer uid 243395.
info: ConnectToPeer (name=ARES47, uid=243395, address=127.0.0.1:54018, USE PROXY)
info: NET: using deflate compression for sends to I7-5960X:54018.
info: LOBBY: Adding peer "ARES47" [I7-5960X:54018, uid=243395]
info: Can't add chat text -- no chat display
info: text="Connecting to ARES47..."
info: DisconnectFromPeer (uid=236312)
info: LOBBY: deleting unknown peer uid 236312.
info: ConnectToPeer (name=Dreeedy, uid=236312, address=127.0.0.1:54019, USE PROXY)
info: NET: using deflate compression for sends to I7-5960X:54019.
info: LOBBY: Adding peer "Dreeedy" [I7-5960X:54019, uid=236312]
info: Can't add chat text -- no chat display
info: text="Connecting to Dreeedy..."
info: DisconnectFromPeer (uid=214131)
info: LOBBY: deleting unknown peer uid 214131.
info: ConnectToPeer (name=Finita, uid=214131, address=127.0.0.1:54020, USE PROXY)
info: NET: using deflate compression for sends to I7-5960X:54020.
info: LOBBY: Adding peer "Finita" [I7-5960X:54020, uid=214131]
info: Can't add chat text -- no chat display
info: text="Connecting to Finita..."
info: CONNECTED TO HOST
info:  {
info:     MEAN = 941.14300537109
info:     StartSpot = 1
info:     ArmyColor = 16
info:     PlayerClan = ""
info:     NG = 874
info:     Team = 1
info:     Ready = false
info:     PlayerColor = 16
info:     Country = "us"
info:     PlayerName = "BinDerDunDat"
info:     AIPersonality = ""
info:     ObserverListIndex = -1
info:     BadMap = false
info:     Civilian = false
info:     OwnerID = "110218"
info:     Faction = 3
info:     PL = 700
info:     DEV = 94.978103637695
info:     Human = true
info:  }
debug: Loading module '\000/lua/maui/effecthelpers.lua\000'
info: Supreme Commander: Forged Alliance version 3695
info: NET: using deflate compression for receives from I7-5960X:54016
info: NET: using deflate compression for receives from I7-5960X:54017
info: NET: using deflate compression for sends to I7-5960X:54022.
info: NET: using deflate compression for receives from I7-5960X:54018
debug: Loading module '\000/lua/ui/controls/combo.lua\000'
info: NET: using deflate compression for receives from I7-5960X:54019
debug: Loading module '\000/lua/maui/statusbar.lua\000'
debug: Loading module '\000/lua/ui/controls/columnlayout.lua\000'
info: NET: using deflate compression for sends to I7-5960X:54023.
info: NET: using deflate compression for receives from I7-5960X:54020
info: NET: using deflate compression for sends to I7-5960X:54021.
info: LOBBY: "Filosov" [I7-5960X:54015, uid=187739] has established connections to: 46667, 96333, 110218, 175912, 184538, 187968, 191398, 214131, 234739, 236312, 243395, 248592, 248787


I don't think my UDP port should be changing for each player I connect to. Shouldn't UDP port 2116 be used (that's what I have configured in FAForever) for both sending and receiving? Note that I have looked at game.log numerous times and every time the UDP ports used by my system are different. And in some of them the UDP port changes for some player connections without being sent to the proxy server.

I took a look in process explorer at the command line that FAForever is using to launch FA. I don't see a port being passed as a parameter there. Isn't there supposed the be a (something like) '/gameport 2116'?

Any insights and/or suggestions would be very helpful.

[PhilipJFry]

please post a complete game and client log

[BinDerDunDat]

Here is the full faforever.log. The is the same one as before. Its too big to paste here.
https://pastebin.com/Jwj63BJt

Here is the full game.log.
https://pastebin.com/bKPfcSxw

[BinDerDunDat]

Same game.log as before I mean.

[PhilipJFry]

you can attach files to your post
that way you can post big files without having to use external sources

you can also delete the log, then reproduce your issue and then post the log to have a fairly short log

Code: Select all

2018-05-03 06:09:51,288 INFO     client.connection              Outgoing JSON Message: {"command": "InitiateTest", "target": "connectivity", "args": [6112]}
2018-05-03 06:10:01,683 INFO     connectivity.helper.ConnectivityHelper Connectivity state is STUN, mapped address: xxx.xxx.xxx.xxx:54587

looks like you don't have port 6112 UDP mapped to your local ip and thus rely on the proxy which may or may not work properly