Unable to host custom games - any advice?

KZ0

I tried again with simulation mods turned off -- but the result seems to be the same:

2021-12-24 00:21:42.937 DEBUG 14828 --- [PrefTimer] c.f.c.preferences.PreferencesService     : Writing preferences file %USER_PROFILE%\AppData\Roaming\Forged Alliance Forever\client.prefs
2021-12-24 00:21:44.263 DEBUG 14828 --- [PrefTimer] c.f.c.preferences.PreferencesService     : Writing preferences file %USER_PROFILE%\AppData\Roaming\Forged Alliance Forever\client.prefs
2021-12-24 00:21:51.415 DEBUG 14828 --- [JavaFX Application Thread] c.f.commons.api.elide.ElideNavigator     : Route built: /data/map?include=latestVersion,author,versions,versions.reviews,versions.reviews.player,reviewsSummary&filter=latestVersion.hidden=="false";versions.folderName=="hilly_plateau.v0002"&page[size]=1
2021-12-24 00:21:51.416 DEBUG 14828 --- [JavaFX Application Thread] com.faforever.client.api.TokenService    : Retrieving OAuth token
2021-12-24 00:21:51.621 DEBUG 14828 --- [reactor-http-nio-12] com.faforever.client.api.TokenService    : Token still valid for 3599 seconds
2021-12-24 00:21:51.745 DEBUG 14828 --- [reactor-http-nio-12] com.faforever.client.api.FafApiAccessor  : Retrieved Map(super=AbstractEntity(id=77), displayName=hilly_plateau, author=Player(super=AbstractEntity(id=59493), login=Hawkei)) from /data/map?include=latestVersion,author,versions,versions.reviews,versions.reviews.player,reviewsSummary&filter=latestVersion.hidden=="false";versions.folderName=="hilly_plateau.v0002"&page[size]=1
2021-12-24 00:21:51.758 DEBUG 14828 --- [reactor-http-nio-12] c.f.c.preferences.PreferencesService     : Hash of Supreme Commander.exe in selected User directory: C6783580C0B7A408EC2AD3BFE5EB1FDBEF31A60D92C1007FF9B90C33BB960AA0
2021-12-24 00:21:51.794 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1593, version=3730, name=ForgedAlliance.exe, md5=0ba3b4274c2e0e1b866297d9b928b47c, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/ForgedAlliance.3730.exe)
2021-12-24 00:21:51.794 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1591, version=3730, name=init_faf.lua, md5=3616a5664ee717b84367eb39839ab1a2, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/init_faf_3730.lua)
2021-12-24 00:21:51.819 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=179, version=3634, name=faforever.faf, md5=51c196294638c22071dc8ee01e55771e, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/faforever.3634.faf)
2021-12-24 00:21:51.820 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1330, version=3709, name=init_ladder1v1.lua, md5=88ee8e210112031bff137ae327683b41, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/init_ladder1v1.3709.lua)
2021-12-24 00:21:51.821 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=99, version=1, name=GDFBinary.dll, md5=6f57f59c2e705d7a5a02d49e3915cb26, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/GDFBinary3603.dll)
2021-12-24 00:21:51.821 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1592, version=3730, name=SupComDataPath.lua, md5=88e26f5a8336094acee87e541f12bba2, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/SupComDataPath_3730.lua)
2021-12-24 00:21:51.821 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=101, version=1, name=SupComDataPathFAF.lua, md5=962c9d1327657d77184adcf358c628f1, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/SupComDataPathFAF.lua)
2021-12-24 00:21:51.821 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=102, version=1, name=init_nonxt.lua, md5=16da7063ae3309c154a2c544f559b3a9, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/init_nonxt.lua)
2021-12-24 00:21:51.823 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1583, version=3730, name=effects.nx2, md5=ee37a25c1dc9b04a450f32b148821d91, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/effects.3730.nx2)
2021-12-24 00:21:52.070 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1587, version=3730, name=env.nx2, md5=b2ef743d4219c6f1015dfdeb3a7ac18e, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/env.3730.nx2)
2021-12-24 00:21:52.074 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1582, version=3730, name=loc.nx2, md5=2fe0348bea487e4f61e16370117b2b3c, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/loc.3730.nx2)
2021-12-24 00:21:52.078 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1584, version=3730, name=lua.nx2, md5=80355161e8fc5a11bd152bb60907e79f, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/lua.3730.nx2)
2021-12-24 00:21:52.085 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1586, version=3730, name=meshes.nx2, md5=b58ace40f51d98f03395b0b26c79c875, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/meshes.3730.nx2)
2021-12-24 00:21:52.085 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=999, version=3677, name=modules.nx2, md5=8eaeb838a8a6f2585351d50e4a20d5d9, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/modules.3677.nxt)
2021-12-24 00:21:52.086 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1581, version=3730, name=projectiles.nx2, md5=2028a383ecde01af6c43d5d5eff67c6f, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/projectiles.3730.nx2)
2021-12-24 00:21:52.086 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1589, version=3730, name=schook.nx2, md5=bdba276944d4b000f33769e8a0fab252, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/schook.3730.nx2)
2021-12-24 00:21:52.136 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1585, version=3730, name=textures.nx2, md5=e8bb05eac9dd50392d1202240d54e3ae, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/textures.3730.nx2)
2021-12-24 00:21:52.247 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1588, version=3730, name=units.nx2, md5=315cca82492869a0fd93118f1c6db020, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/units.3730.nx2)
2021-12-24 00:21:52.247 DEBUG 14828 --- [pool-3-thread-13] c.f.c.p.SimpleHttpFeaturedModUpdaterTask : Featured mod file already prepared: FeaturedModFile(id=1590, version=3730, name=etc.nx2, md5=7bcccb8ed3f8a391aca3a81fa9874e51, url=https://content.faforever.com/legacy-featured-mod-files/updates_faf_files/etc.3730.nx2)
2021-12-24 00:21:52.248  INFO 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Updating binaries to 3730
2021-12-24 00:21:52.248 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying Forged Alliance binaries FAF folder
2021-12-24 00:21:52.248 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\BsSndRpt.exe' to 'C:\ProgramData\FAForever\bin\BsSndRpt.exe'
2021-12-24 00:21:52.248 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\BugSplat.dll' to 'C:\ProgramData\FAForever\bin\BugSplat.dll'
2021-12-24 00:21:52.249 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\BugSplatRc.dll' to 'C:\ProgramData\FAForever\bin\BugSplatRc.dll'
2021-12-24 00:21:52.249 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\DbgHelp.dll' to 'C:\ProgramData\FAForever\bin\DbgHelp.dll'
2021-12-24 00:21:52.249 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\GDFBinary.dll' to 'C:\ProgramData\FAForever\bin\GDFBinary.dll'
2021-12-24 00:21:52.249 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\msvcm80.dll' to 'C:\ProgramData\FAForever\bin\msvcm80.dll'
2021-12-24 00:21:52.249 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\msvcp80.dll' to 'C:\ProgramData\FAForever\bin\msvcp80.dll'
2021-12-24 00:21:52.249 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\msvcr80.dll' to 'C:\ProgramData\FAForever\bin\msvcr80.dll'
2021-12-24 00:21:52.250 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\SHSMP.DLL' to 'C:\ProgramData\FAForever\bin\SHSMP.DLL'
2021-12-24 00:21:52.250 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\sx32w.dll' to 'C:\ProgramData\FAForever\bin\sx32w.dll'
2021-12-24 00:21:52.250 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\wxmsw24u-vs80.dll' to 'C:\ProgramData\FAForever\bin\wxmsw24u-vs80.dll'
2021-12-24 00:21:52.250 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Copying file 'C:\Program Files (x86)\Steam\steamapps\common\Supreme Commander Forged Alliance\bin\zlibwapi.dll' to 'C:\ProgramData\FAForever\bin\zlibwapi.dll'
2021-12-24 00:21:52.250 DEBUG 14828 --- [pool-3-thread-13] c.f.commons.fa.ForgedAllianceExePatcher  : Updating version in C:\ProgramData\FAForever\bin\ForgedAlliance.exe to 3730
2021-12-24 00:21:52.250 DEBUG 14828 --- [pool-3-thread-13] c.f.c.patch.GameBinariesUpdateTaskImpl   : Binaries have been updated successfully
2021-12-24 00:21:52.621 DEBUG 14828 --- [PrefTimer] c.f.c.preferences.PreferencesService     : Writing preferences file %USER_PROFILE%\AppData\Roaming\Forged Alliance Forever\client.prefs

Sheikah

Are these the full logs? There is no communication with the server in here which I would expect. Can you try restarting the client and trying again?

KZ0

No - I just added the new lines I saw added from the end of the client.log file. I'll restart and upload.

Edit: here's the complete log: https://subcons.teod.eu/static/2021-12-24-client.log (1740 lines). Hosting on my own domain so that I can take it down if it contains something it shouldn't.

Sheikah

Something is killing your connection to the server and the api before the game can launch.

See the error message below. I would think it is anti virus or something about your network connections

2021-12-24 02:02:21.848  INFO 11796 --- [JavaFX Application Thread] c.f.client.remote.FafServerAccessor      : Closing lobby server connection
2021-12-24 02:02:21.849  INFO 11796 --- [JavaFX Application Thread] com.faforever.commons.lobby.FafLobbyApi  : Disconnecting from server
2021-12-24 02:02:21.849  INFO 11796 --- [JavaFX Application Thread] com.faforever.commons.lobby.FafLobbyApi  : Outbound channel closed
2021-12-24 02:02:21.853  INFO 11796 --- [reactor-tcp-nio-2] com.faforever.commons.lobby.FafLobbyApi  : Disconnected from server
2021-12-24 02:02:21.853 DEBUG 11796 --- [pool-3-thread-1] com.faforever.client.theme.UiService     : Watcher service terminated
2021-12-24 02:02:21.862  WARN 11796 --- [reactor-http-nio-12] r.netty.http.client.HttpClientConnect    : [id:99bd53de-1, L:/192.168.1.11:61749 ! R:api.faforever.com/116.202.155.226:443] The connection observed an error

reactor.netty.http.client.PrematureCloseException: Connection prematurely closed BEFORE response

2021-12-24 02:02:21.866 ERROR 11796 --- [reactor-http-nio-12] c.f.client.game.CreateGameController     : Error when updating the map

java.util.concurrent.CompletionException: org.springframework.web.reactive.function.client.WebClientRequestException: Connection prematurely closed BEFORE response; nested exception is reactor.netty.http.client.PrematureCloseException: Connection prematurely closed BEFORE response

Sheikah

To me it looks like you are closing your client while it is trying to start the game which is odd. But that is why I think it is some anti virus or something shutting down the client

KZ0

Hmm. I'm using Windows defender, default rules.

Any ideas about why this is an issue now, and was not an issue on 1.5.0 and before?

KZ0

I tried a few things:

Reset windows defender firewall settings to defaults
Turn off firewall
Run the FAF client from master (89bcab)
Turn off anti-virus real-time protection

Same results as before - no custom game launched.

Happy to provide more logs. Now that I'm on master, I can easily test specific commits.

Sheikah

Hmm if you are running from source you should be able see the logs more clearly. Also the updated branch is develop not master. So checkout that one. Also the only thing that changed between 1.5.0 and later is we changed the backed library we use for the tcp connections

KZ0

OK - thanks for the info. It seems I was on develop all along, I guess I typed "master" out of habit.

if you are running from source you should be able see the logs more clearly

Should I just copy stdout? Loglevel debug? From what I could see last time, stdout looked similar to what I found in client.log. Any other information we need to understand what's going on?

(Sorry for the fragmented process. I have a Windows computer for playing FAF - and I don't use Windows for other things than FAF. So there is a bit of time between each time I'm on the FAF computer ...).

Sheikah

When running from source the stdout is the log. And you can set it to debug level and you will also see all the messages that are being sent between the server and you.

KZ0

Full logs, loglevel debug. I pressed "Create game" a few times, with not result.

http://subcons.teod.eu/static/2021-12-30-debug.log

I'm also getting some file not found errors:

java.io.FileNotFoundException: META-INF/native/netty_tcnative_windows_x86_64.dll
java.io.FileNotFoundException: META-INF/native/netty_tcnative_x86_64.dll
java.io.FileNotFoundException: META-INF/native/netty_tcnative.dll

KZ0

@Sheikah - I was able to narrow down the issue. Are you able to reproduce?

I'm allways getting the failure when the password contains "ø".

Using only english letters in the password does not trigger the error.

I created a github issue: https://github.com/FAForever/downlords-faf-client/issues/2517

Sheikah

Okay that makes sense then. Generally things like these game properties are limited to ASCII. I am surprised it didn't give a more informative error but will make sure to restrict it properly