search

rfvgyhn / min-ed-launcher

Minimal Elite Dangerous Launcher
MIT License
271 stars 10 forks source link

Unhandled exception when getting remote time #124

Open einstine909 opened 7 months ago

einstine909 commented 7 months ago

Describe the bug/error

It seems like there is an issue when min-ed-launcher is getting the remote time.

Some notes:

Let me know if I can provide any other information that would be useful.

Thanks!

Debug log

2024-04-12 11:19:11.333 -06:00 [INF] Elite Dangerous: Minimal Launcher - v0.9.0+cebb41d8
2024-04-12 11:19:11.411 -06:00 [DBG] 
    Args: [|"/home/einstine909/.local/share/Steam/ubuntu12_32/reaper"; "SteamLaunch";
  "AppId=359320"; "--";
  "/home/einstine909/.local/share/Steam/ubuntu12_32/steam-launch-wrapper"; "--";
  "/home/einstine909/.local/share/Steam/steamapps/common/SteamLinuxRuntime_sniper/_v2-entry-point";
  "--verb=waitforexitandrun"; "--";
  "/home/einstine909/.local/share/Steam/steamapps/common/Proton - Experimental/proton";
  "waitforexitandrun";
  "/home/einstine909/.local/share/Steam/steamapps/common/Elite Dangerous/EDLaunch.exe";
  "/Steam"; "/novr"; "/autorun"; "/autoquit"; "/edh4"|]
    OS: Linux64
    Env: STEAM_COMPAT_DATA_PATH=/home/einstine909/.local/share/Steam/steamapps/compatdata/359320

2024-04-12 11:19:11.413 -06:00 [DBG] Reading settings from '/home/einstine909/.config/min-ed-launcher/settings.json'
2024-04-12 11:19:11.590 -06:00 [DBG] Settings: { Platform = Steam
  DisplayMode = Pancake
  AutoRun = true
  AutoQuit = true
  WatchForCrashes = false
  ProductWhitelist = seq ["edh4"]
  ForceLocal = true
  CompatTool =
   Some
     { EntryPoint = "/home/einstine909/.local/share/Steam/ubuntu12_32/reaper"
       Args =
        [|"SteamLaunch"; "AppId=359320"; "--";
          "/home/einstine909/.local/share/Steam/ubuntu12_32/steam-launch-wrapper";
          "--";
          "/home/einstine909/.local/share/Steam/steamapps/common/SteamLinuxRuntime_sniper/_v2-entry-point";
          "--verb=waitforexitandrun"; "--"; "python3";
          "/home/einstine909/.local/share/Steam/steamapps/common/Proton - Experimental/proton";
          "waitforexitandrun"|] }
  CbLauncherDir =
   "/home/einstine909/.local/share/Steam/steamapps/common/Elite Dangerous"
  PreferredLanguage = None
  ApiUri = https://api.zaonce.net/
  Restart = None
  AutoUpdate = true
  CheckForLauncherUpdates = true
  MaxConcurrentDownloads = 4
  ForceUpdate = set []
  Processes = []
  ShutdownProcesses = []
  FilterOverrides =
   seq [[FORC-FDEV-DO-1000, edo]; [FORC-FDEV-DO-38-IN-40, edh4]]
  AdditionalProducts = []
  DryRun = false
  ShutdownTimeout = 00:00:10
  CacheDir = "/home/einstine909/.cache/min-ed-launcher"
  GameStartDelay = 00:00:00
  ShutdownDelay = 00:00:00 }
2024-04-12 11:19:11.597 -06:00 [DBG] Unset LC_ALL. Using $LANG to determine correct UI culture
2024-04-12 11:19:11.624 -06:00 [INF] Elite Runtime
    Platform: Steam
    CobraBay Version: 1.7.6926.10
    Products Dir: /home/einstine909/.local/share/Steam/steamapps/common/Elite Dangerous/Products
2024-04-12 11:19:11.634 -06:00 [DBG] Getting machine id
2024-04-12 11:19:11.675 -06:00 [INF] Logging in
2024-04-12 11:19:11.675 -06:00 [DBG] Getting remote time
2024-04-12 11:20:51.718 -06:00 [ERR] Unhandled exception: System.Threading.Tasks.TaskCanceledException: net_http_request_timedout, 100
 ---> System.TimeoutException: TaskCanceledException_ctor_DefaultMessage
 ---> System.Threading.Tasks.TaskCanceledException: TaskCanceledException_ctor_DefaultMessage
   at System.Threading.Tasks.Tas...ion[36]`1.WaitWithCancellationAsync(CancellationToken)
   at System.Net.Http.HttpConnectionPool.HttpConnectionWaiter`1.WaitForConnectionAsync(Boolean, CancellationToken)
   at System.Net.Http.HttpConnectionPool.Sen...ync[37](HttpRequestMessage, Boolean, Boolean, CancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage, Boolean, CancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage, HttpCompletionOption, CancellationTokenSource, Boolean, CancellationTokenSource, CancellationToken)
   Exception_EndOfInnerExceptionStack
   Exception_EndOfInnerExceptionStack
   at System.Net.Http.HttpClient.HandleFailure(Exception, Boolean, HttpResponseMessage, CancellationTokenSource, CancellationToken, CancellationTokenSource)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage, HttpCompletionOption, CancellationTokenSource, Boolean, CancellationTokenSource, CancellationToken)
   at MinEdLauncher.Api.getTime@86.MoveNext()
   at MinEdLauncher.App.createGetRunningTime@256-1.MoveNext()
   at MinEdLauncher.App.createGetRunningTime@253.MoveNext()
   at MinEdLauncher.App.run@336-3.MoveNext()
   at MinEdLauncher.App.run@314.MoveNext()
   at MinEdLauncher.Program.run@64-23.MoveNext()
   at MinEdLauncher.Program.run@63-22.MoveNext()
   at MinEdLauncher.Program.run@63-21.MoveNext()
   at MinEdLauncher.Program.run@71-24.MoveNext()
   at MinEdLauncher.Program.run@74-25.MoveNext()
   at MinEdLauncher.Program.main(String[])
rfvgyhn commented 7 months ago

When did you use curl to test it compared to getting the exception? The launcher's request timed out so maybe you just had bad luck with your timing.

Do you have any issues with the default launcher?

einstine909 commented 7 months ago

Retested just now.

I had the same net_http_request_timedout at the same time I had a successful request with curl:

$ curl https://api.zaonce.net/1.1/server/time
{"unixTimestamp":1712965795}

The default launcher successfully launched the game just now.

rfvgyhn commented 7 months ago

I have no idea why it's timing out for you.

Does manually running it from a terminal change anything? STEAM_COMPAT_DATA_PATH=/home/einstine909/.local/share/Steam/steamapps/compatdata/359320 /path/to/MinEdLauncher /steam /dryrun

Just grasping at straws, does the latest CI build change anything? It's built with .net 8 instead of .net 7.

einstine909 commented 7 months ago

Running the 0.9 release manually from the terminal get the same result as when running under Steam:

$ STEAM_COMPAT_DATA_PATH=/home/einstine909/.local/share/Steam/steamapps/compatdata/359320 /home/einstine909/.local/share/Steam/steamapps/common/Elite\ Dangerous/MinEdLauncher /steam /dryrun
[14:14:49 INF] Elite Dangerous: Minimal Launcher - v0.9.0+cebb41d8
[14:14:49 INF] Elite Runtime
    Platform: Steam
    CobraBay Version: 1.7.6926.10
    Products Dir: /home/einstine909/.local/share/Steam/steamapps/common/Elite Dangerous/Products
[14:14:50 INF] Logging in
[14:16:30 ERR] Unhandled exception: System.Threading.Tasks.TaskCanceledException: net_http_request_timedout, 100
 ---> System.TimeoutException: TaskCanceledException_ctor_DefaultMessage
 ---> System.Threading.Tasks.TaskCanceledException: TaskCanceledException_ctor_DefaultMessage
   at System.Threading.Tasks.Tas...ion[36]`1.WaitWithCancellationAsync(CancellationToken)
   at System.Net.Http.HttpConnectionPool.HttpConnectionWaiter`1.WaitForConnectionAsync(Boolean, CancellationToken)
   at System.Net.Http.HttpConnectionPool.Sen...ync[37](HttpRequestMessage, Boolean, Boolean, CancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage, Boolean, CancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage, HttpCompletionOption, CancellationTokenSource, Boolean, CancellationTokenSource, CancellationToken)
   Exception_EndOfInnerExceptionStack
   Exception_EndOfInnerExceptionStack
   at System.Net.Http.HttpClient.HandleFailure(Exception, Boolean, HttpResponseMessage, CancellationTokenSource, CancellationToken, CancellationTokenSource)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage, HttpCompletionOption, CancellationTokenSource, Boolean, CancellationTokenSource, CancellationToken)
   at MinEdLauncher.Api.getTime@86.MoveNext()
   at MinEdLauncher.App.createGetRunningTime@256-1.MoveNext()
   at MinEdLauncher.App.createGetRunningTime@253.MoveNext()
   at MinEdLauncher.App.run@336-3.MoveNext()
   at MinEdLauncher.App.run@314.MoveNext()
   at MinEdLauncher.Program.run@64-23.MoveNext()
   at MinEdLauncher.Program.run@63-22.MoveNext()
   at MinEdLauncher.Program.run@63-21.MoveNext()
   at MinEdLauncher.Program.run@71-24.MoveNext()
   at MinEdLauncher.Program.run@74-25.MoveNext()
   at MinEdLauncher.Program.main(String[])
Press any key to quit...

Here is the attempt with the latest CI build (same result as release):

$ STEAM_COMPAT_DATA_PATH=/home/einstine909/.local/share/Steam/steamapps/compatdata/359320 /home/einstine909/.local/share/Steam/steamapps/common/Elite\ Dangerous/MinEdLauncher /steam /dryrun
[14:20:46 INF] Elite Dangerous: Minimal Launcher - v0.9.0-ci8531602785+146367c1
[14:20:46 INF] Elite Runtime
    Platform: Steam
    CobraBay Version: 1.7.6926.10
    Products Dir: /home/einstine909/.local/share/Steam/steamapps/common/Elite Dangerous/Products
[14:20:46 INF] Logging in
[14:22:26 ERR] Unhandled exception: System.Threading.Tasks.TaskCanceledException: net_http_request_timedout, 100
 ---> System.TimeoutException: TaskCanceledException_ctor_DefaultMessage
 ---> System.Threading.Tasks.TaskCanceledException: TaskCanceledException_ctor_DefaultMessage
   at System.Threading.Tasks.Tas...ion[36]`1.WaitWithCancellationAsync(CancellationToken)
   at System.Net.Http.HttpConnectionPool.Sen...ync[37](HttpRequestMessage, Boolean, Boolean, CancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage, Boolean, CancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage, HttpCompletionOption, CancellationTokenSource, Boolean, CancellationTokenSource, CancellationToken)
   Exception_EndOfInnerExceptionStack
   Exception_EndOfInnerExceptionStack
   at System.Net.Http.HttpClient.HandleFailure(Exception, Boolean, HttpResponseMessage, CancellationTokenSource, CancellationToken, CancellationTokenSource)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage, HttpCompletionOption, CancellationTokenSource, Boolean, CancellationTokenSource, CancellationToken)
   at MinEdLauncher.Api.getTime@88.MoveNext()
   at MinEdLauncher.App.createGetRunningTime@273-1.MoveNext()
   at MinEdLauncher.App.createGetRunningTime@270.MoveNext()
   at MinEdLauncher.App.run@353-3.MoveNext()
   at MinEdLauncher.App.run@331.MoveNext()
   at MinEdLauncher.Program.run@64-23.MoveNext()
   at MinEdLauncher.Program.run@63-22.MoveNext()
   at MinEdLauncher.Program.run@63-21.MoveNext()
   at MinEdLauncher.Program.run@71-24.MoveNext()
   at MinEdLauncher.Program.run@74-25.MoveNext()
   at MinEdLauncher.Program.main(String[])
Press any key to quit...

I have a hunch on what might be happening, I will be back with more information shortly.

einstine909 commented 7 months ago

I found the problem: Unruly IPV6

I broke out wireshark to find out what the difference between curl and min-ed-launcher was. I found that curl was attempting to connect to api.zaonce.net's IPV6 address, and when that failed it retried with the IPV4 address. It seems that min-ed-launcher's http request lib does not do that. It attempts the IPV6 address which request gets lost somewhere along the way, and does not try to fall back to IPv4, causing the timeout error.

I have not yet compared the default launcher to min-ed-launcher with wireshark but I assume that it is also falling back to IPV4 when the IPV6 request fails, because I am able to login and launch the game.

Now knowing this I got E:D Horizon launching with min-ed-launcher by temporarily removing my machine's IPV6 address.

@rfvgyhn Its your call if you want to consider this closed or not. It would be nice if min-ed-launcher could also fallback to IPV4, but I can also make this work with the new knowledge that I have. Thank you for being so responsive!

rfvgyhn commented 7 months ago

I'm not certain, but you might be able to work around it by either specifying the env var DOTNET_SYSTEM_NET_DISABLEIPV6=true or disabling IPV6 by creating MinEdLauncher.runtimeconfig.json in the same directory as MinEdLauncher. I haven't tested either, so I'm not sure if the env var is a build time specific var or not. I'm also not sure if the json file will work with MinEdLauncher since it's a self-contained app.

{
  "runtimeOptions": {
    "configProperties": {
      "System.Net.DisableIPv6": true
    }
  }
}

I'll leave this open for now. I'm not sure how much effort it is to configure dotnet's HttpClient to fallback to IPV4 if IPV6 fails.

Thanks for the in-depth debugging. I doubt I'd have ever figured that out.

rfvgyhn commented 4 months ago

Looks like this is a known issue in .net. The API proposal to implement a happy eyeballs/fast fallback approach has been approved but the implementation hasn't been completed yet. It's possibly coming with .net 9.

Not sure what will come first, the .net team implementing it or me manually implementing it via ConnectCallback.