FAForever / server

The servercode for the Forged Alliance Forever lobby
http://www.faforever.com
GNU General Public License v3.0
66 stars 61 forks source link

Server not sending data to all connections from 1 ip #536

Open Brutus5000 opened 4 years ago

Brutus5000 commented 4 years ago

I am connecting with 3 tcp sessions from 1 computer to the test server.

Have a look at this log:

DEBUG    Feb 16  19:26:06 ServerContext                  ServerContext(LobbyServer): Client connected
DEBUG    Feb 16  19:26:06 LobbyConnection                LobbyConnection initialized
TRACE    Feb 16  19:26:06 LobbyConnection                <<: {'version': '1.0', 'user_agent': 'downlords-faf-client', 'command': 'ask_session'}
TRACE    Feb 16  19:26:06 LobbyConnection                >>: {'command': 'session', 'session': 2427045952}
DEBUG    Feb 16  19:26:07 ServerContext                  ServerContext(LobbyServer): Client connected
DEBUG    Feb 16  19:26:07 LobbyConnection                LobbyConnection initialized
TRACE    Feb 16  19:26:07 LobbyConnection                <<: {'version': '1.0', 'user_agent': 'downlords-faf-client', 'command': 'ask_session'}
TRACE    Feb 16  19:26:07 LobbyConnection                >>: {'command': 'session', 'session': 4036998942}
DEBUG    Feb 16  19:26:08 ServerContext                  ServerContext(LobbyServer): Client connected
DEBUG    Feb 16  19:26:08 LobbyConnection                LobbyConnection initialized
TRACE    Feb 16  19:26:08 LobbyConnection                <<: {'version': '1.0', 'user_agent': 'downlords-faf-client', 'command': 'ask_session'}
TRACE    Feb 16  19:26:08 LobbyConnection                >>: {'command': 'session', 'session': 683814683}
TRACE    Feb 16  19:26:08 LobbyConnection                <<: {'login': 'Ze_PilOt', 'password': '2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae', 'session': 2427045952, 'unique_id': 'xxxx', 'local_ip': '10.184.244.245)', 'command': 'hello'}
DEBUG    Feb 16  19:26:08 LobbyConnection                Login from: 5, Ze_PilOt, 2427045952
ERROR    Feb 16  19:26:08 LobbyConnection                Failure updating NickServ password for Ze_PilOt
TRACE    Feb 16  19:26:08 LobbyConnection                >>: {'command': 'welcome', 'me': {'id': 5, 'login': 'Ze_PilOt', 'global_rating': (1889.21, 51.4297), 'ladder_rating': (1649.81, 49.5031), 'number_of_games': 688, 'avatar': {'url': 'http://content.faforever.com/faf/avatars/GW_Aeon.png', 'tooltip': 'Cleanse !'}, 'country': ''}, 'id': 5, 'login': 'Ze_PilOt'}
TRACE    Feb 16  19:26:08 LobbyConnection                >>: {'command': 'player_info', 'players': [{'id': 5, 'login': 'Ze_PilOt', 'global_rating': (1889.21, 51.4297), 'ladder_rating': (1649.81, 49.5031), 'number_of_games': 688, 'avatar': {'url': 'http://content.faforever.com/faf/avatars/GW_Aeon.png', 'tooltip': 'Cleanse !'}, 'country': ''}]}
TRACE    Feb 16  19:26:08 LobbyConnection                >>: {'command': 'social', 'autojoin': [], 'channels': [], 'friends': [6, 7, 9, 22, 45, 86, 124, 153, 440, 636, 5268, 5440, 23708, 25237, 27092, 29149, 29832, 30046, 32563], 'foes': [], 'power': 0}
TRACE    Feb 16  19:26:08 LobbyConnection                >>: {'command': 'game_info', 'games': []}
TRACE    Feb 16  19:26:09 LobbyConnection                <<: {'login': 'Ephez', 'password': '2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae', 'session': 4036998942, 'unique_id': 'xxxx, 'local_ip': '10.145.67.173)', 'command': 'hello'}
DEBUG    Feb 16  19:26:09 LobbyConnection                Login from: 6, Ephez, 4036998942
ERROR    Feb 16  19:26:09 LobbyConnection                Failure updating NickServ password for Ephez
TRACE    Feb 16  19:26:09 LobbyConnection                >>: {'command': 'welcome', 'me': {'id': 6, 'login': 'Ephez', 'global_rating': (1415.12, 95.5099), 'ladder_rating': (1500.0, 385.434), 'number_of_games': 247, 'country': ''}, 'id': 6, 'login': 'Ephez'}
TRACE    Feb 16  19:26:09 LobbyConnection                >>: {'command': 'player_info', 'players': [{'id': 5, 'login': 'Ze_PilOt', 'global_rating': (1889.21, 51.4297), 'ladder_rating': (1649.81, 49.5031), 'number_of_games': 688, 'avatar': {'url': 'http://content.faforever.com/faf/avatars/GW_Aeon.png', 'tooltip': 'Cleanse !'}, 'country': ''}, {'id': 6, 'login': 'Ephez', 'global_rating': (1415.12, 95.5099), 'ladder_rating': (1500.0, 385.434), 'number_of_games': 247, 'country': ''}]}
TRACE    Feb 16  19:26:09 LobbyConnection                >>: {'command': 'social', 'autojoin': [], 'channels': [], 'friends': [5, 7, 9, 20, 22, 25, 36, 84, 93, 329, 1354, 25237, 25249, 29149, 30046, 30418, 35030, 118730], 'foes': [], 'power': 0}
TRACE    Feb 16  19:26:09 LobbyConnection                >>: {'command': 'game_info', 'games': []}
TRACE    Feb 16  19:26:10 LobbyConnection                <<: {'login': 'Kekouse', 'password': '2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae', 'session': 683814683, 'unique_id': 'xxxx', 'local_ip': '10.186.120.71)', 'command': 'hello'}
DEBUG    Feb 16  19:26:10 LobbyConnection                Login from: 7, Kekouse, 683814683
ERROR    Feb 16  19:26:10 LobbyConnection                Failure updating NickServ password for Kekouse
TRACE    Feb 16  19:26:10 LobbyConnection                >>: {'command': 'welcome', 'me': {'id': 7, 'login': 'Kekouse', 'global_rating': (2050.28, 338.244), 'ladder_rating': (1763.22, 393.528), 'number_of_games': 68, 'country': ''}, 'id': 7, 'login': 'Kekouse'}
TRACE    Feb 16  19:26:10 LobbyConnection                >>: {'command': 'player_info', 'players': [{'id': 5, 'login': 'Ze_PilOt', 'global_rating': (1889.21, 51.4297), 'ladder_rating': (1649.81, 49.5031), 'number_of_games': 688, 'avatar': {'url': 'http://content.faforever.com/faf/avatars/GW_Aeon.png', 'tooltip': 'Cleanse !'}, 'country': ''}, {'id': 6, 'login': 'Ephez', 'global_rating': (1415.12, 95.5099), 'ladder_rating': (1500.0, 385.434), 'number_of_games': 247, 'country': ''}, {'id': 7, 'login': 'Kekouse', 'global_rating': (2050.28, 338.244), 'ladder_rating': (1763.22, 393.528), 'number_of_games': 68, 'country': ''}]}
TRACE    Feb 16  19:26:10 LobbyConnection                >>: {'command': 'social', 'autojoin': [], 'channels': [], 'friends': [5, 6, 9, 20, 25, 30, 36, 57, 93, 329, 457, 1094, 1354, 14153, 30046], 'foes': [], 'power': 0}
TRACE    Feb 16  19:26:10 LobbyConnection                >>: {'command': 'game_info', 'games': []}
TRACE    Feb 16  19:26:48 LobbyConnection                <<: {'command': 'pong'}
INFO     Feb 16  19:26:49 MatchmakerQueue                Searching for matches: ladder1v1
DEBUG    Feb 16  19:26:49 Matchmaker                     Matching with stable marriage...
DEBUG    Feb 16  19:26:49 MatchmakingPolicy              Round 0 of stable marriage, currently 0 matches
DEBUG    Feb 16  19:26:49 Matchmaker                     Matching randomly for remaining newbies...
INFO     Feb 16  19:26:49 PopTimer                       Next ladder1v1 wave happening in 59s
TRACE    Feb 16  19:27:33 LobbyConnection                <<: {'command': 'pong'}
DEBUG    Feb 16  19:27:39 LobbyConnection                Lost lobby connection removing player 5
DEBUG    Feb 16  19:27:39 LobbyConnection                Lost lobby connection removing player 7
DEBUG    Feb 16  19:27:39 LobbyConnection                Lost lobby connection removing player 6

The last 3 log lines appear when I close my clients. So the connections are active all the time. Yet, the server only sends PINGs to one connection (and as such only one connection responds). This is reproducible with other messages as well (e.g. player_info on new logins etc.)

This might be an edge case. This behavior appears if no other users are on the server.

Askaholic commented 4 years ago

What server version were you testing this on? I cannot reproduce it in 1.3.4. I connect with 3 clients and all 3 of them get ping messages from the server.