marzent / XIV-on-Mac

Wine Wrapper, Setup tool and launcher for FFXIV on mac
GNU General Public License v3.0
338 stars 27 forks source link

"An error during game startup has occured" #127

Open jrowa2 opened 1 year ago

jrowa2 commented 1 year ago

Game does launch fine, been playing for days at this point with no issues.

Though keep getting an error when launching the game. The error can be seen in launcher.log:

2023-07-06 23:57:35.829 +01:00 [ERR] An error during game startup has occured
System.NullReferenceException: Object reference not set to an instance of an object.
   at NativeLibrary.Program.StartGame(IntPtr, Boolean) + 0x6c

dalamud.injector.log launcher.log wine.log

As mentioned, I can play the game fine. Just thought this may be worth posting here in case somebody needs to see it. Apologies if this is a duplicate.

jrowa2 commented 1 year ago

Unsure if related, though sometimes I will launch the game (click Login button) and the window opens to only a blank screen and spinning wheel - continues loading indefinitely until I force quit.

This seems to be very rare - or maybe even on first launch since boot, as after force quitting I can Login again with no issues besides the mentioned error message that appears every time.

Edit: Can confirm that the blank screen & spinning wheel thing doesn't happen on first launch since boot. Just launched first time after booting up and it's all fine.

renkejr commented 1 year ago

I am receiving the same "An error during game startup has occurred" on every launch but it plays fine. I'm not using Dalamud or Steam.

chipgeekjr commented 1 year ago

I am also receiving the 'An error during game startup has occurred' message upon closing the game, the game opens and runs fine, however, I have Dalamud enabled and it completely fails to load. The logs say something about being unable to allocate memory for its injection. dalamud.injector.log launcher.log wine.log

jrowa2 commented 1 year ago

I am also receiving the 'An error during game startup has occurred' message upon closing the game, the game opens and runs fine, however, I have Dalamud enabled and it completely fails to load. The logs say something about being unable to allocate memory for its injection. dalamud.injector.log launcher.log wine.log

I am now also experiencing this message popup only when exiting the game. No longer appears on launch. The error that is shown still appears to be the same though:

2023-08-08 20:18:10.746 +01:00 [INF] GameProcess was null...
2023-08-08 20:18:10.746 +01:00 [ERR] An error during game startup has occured
System.NullReferenceException: Object reference not set to an instance of an object.
   at NativeLibrary.Program.StartGame(IntPtr, Boolean) + 0x8c

I am not using Dalamud so unable to provide a whole lot here. However I am noticing an error before "An error during game startup has occured" which is related to Dalamud, unsure how relevant this is especially considering I'm not using it. Could not retrieve game Process information seems important.

2023-08-08 20:18:10.746 +01:00 [ERR] Could not retrieve game Process information
System.FormatException: The input string 'hellExec' was not in a correct format.
   at System.Number.ThrowOverflowOrFormatException[TInteger](Number.ParsingStatus, ReadOnlySpan`1) + 0x20
   at XIVLauncher.Common.Unix.Compatibility.CompatibilityTools.<>c__DisplayClass35_0.<GetUnixProcessId>b__0(String l) + 0x88
   at System.Linq.Enumerable.WhereSelectEnumerableIterator`2.ToArray() + 0x98
   at XIVLauncher.Common.Unix.Compatibility.CompatibilityTools.GetUnixProcessId(Int32) + 0x164
   at XIVLauncher.Common.Unix.UnixDalamudRunner.Run(FileInfo, Boolean, Boolean, Boolean, FileInfo, String, IDictionary`2, DalamudLoadMethod, DalamudStartInfo) + 0x9c0

Might be worth opening a separate issue for Dalamud failing if there isn't one open already.

dropbeardevs commented 9 months ago

I think I figured out the issue. The latest version of https://github.com/marzent/winecx/releases/tag/ff-wine-2.4.2 is missing winedbg.exe in the wineprefix/drive_c/system32 folder. There's a call to winedbg in XIVLauncher.NativeAOT, attempting to get the process ID and errors out when it can't find it. It'll only affect people who have clean installs with winecx 2.4.1 and 2.4.2.

A workaround is to download winecx 2.4 (https://github.com/marzent/winecx/releases/tag/ff-wine-2.4), grab lib/wine/x86_64-windows/winedbg.exe and put it in the ~/Library/Application Support/XIV on Mac/wineprefix/drive_c/windows/system32 folder (or wherever your wineprefix is - you can go to File->Open Install Folder to find it).

@marzent can you please re-include winedbg.exe in the next winecx release? Thanks!

marzent commented 9 months ago

Ah this does make a lot of sense, have been pondering the semi random nature of this issue for a while (there actually was a different issue a while back with the pid parsing code, which was also fixed). I didn't understand how people were still seeing the issue, but there was a bit of a build system migration which probably caused the flag to enable it to get lost.

HealsCodes commented 9 months ago

I think I figured out the issue. The latest version of https://github.com/marzent/winecx/releases/tag/ff-wine-2.4.2 is missing winedbg.exe in the wineprefix/drive_c/system32 folder. There's a call to winedbg in XIVLauncher.NativeAOT, attempting to get the process ID and errors out when it can't find it. It'll only affect people who have clean installs with winecx 2.4.1 and 2.4.2.

A workaround is to download winecx 2.4 (https://github.com/marzent/winecx/releases/tag/ff-wine-2.4), grab lib/wine/x86_64-windows/winedbg.exe and put it in the ~/Library/Application Support/XIV on Mac/wineprefix/drive_c/windows/system32 folder (or wherever your wineprefix is - you can go to File->Open Install Folder to find it).

@marzent can you please re-include winedbg.exe in the next winecx release? Thanks!

Let me point out that the issue isn't necessarily a missing winedbg.exe - if you look at the screenshots below I do already have the binary in my prefix but I get the error on every single launch of XIV (and hence made #137 ).

Replacing it with the winedbg.exe from winecx 2.4 fixed the issue though so it seems there was at least some point in the update history of XIV-on-Mac (likely around the 14th October) that shipped a broken winedbg.exe.

md5-sums for both:

Working version: MD5 (winedbg.exe) = 73680ff7b714b4bd4fc5cfdb084baa1a Version that gives the error: MD5 (winedbg.exe) = 46288ff04b57516e90bbb54475698280

Screenshot 2023-11-26 at 10 46 52@2x Screenshot 2023-11-26 at 10 47 27@2x

Waitsnake commented 9 months ago

Had the same issue with this error message popping up, but the game just running fine. According to timestamps of my FFXIV installation I might use XIV on Mac since around December 2022. I did all updates and still ended in this state with this error message (I use now 4.12.5 (143) ). According to the advice here i downloaded winedbg.exe from the winecx 2.4 version liked here (new file size 425.984 Byte) and replaced the renamed the same file I already had form winedbg.exe (old file size 438.286 Byte) and the error message is gone and game still works.

MD5 old not working version = c476423c257c0c7facc1ba5597b8f036 MD5 working version = 73680ff7b714b4bd4fc5cfdb084baa1a

I wonder if this could not be automatically fixed by XIC for Mac application to detect outdated winedbg.exe and replace them with a newer version?

dropbeardevs commented 9 months ago

I did a little bit more digging and it does seem like some later versions of wine broke winedbg.exe on Macs. I ran winedbg.exe using the XIV on Mac version of wine manually in the terminal:

WINEPREFIX="/Users//Library/Application Support/XIV on Mac/wineprefix" "/Applications/XIV on Mac.app/Contents/Resources/wine/bin/wine64" winedbg.exe --command "info procmap"

And got this result: winedbg 7_7

I then installed wine 8.0.1 (using homebrew), created a default prefix, ran this command to execute the default prefix-installed winedbg.exe:

WINEPREFIX="/Users//.wine" /usr/local/bin/wine64 ~/.wine/drive_c/windows/system32/winedbg.exe --command "info procmap"

and I got this error:

winedbg 8_0_1

@Shirk I have a feeling that what happened to you might have been the latter, where the version that had been installed might be a broken version of winedbg. I didn't spend too much time on it, so it might just be my 8.0.1 install, but I'll keep digging and see if there's a bug report submitted on the regular wine repo. This might not be a XIV on Mac specific bug, but Wine on Mac in general.

dropbeardevs commented 9 months ago

Ok, I apologize for being stupid. Winedbg isn't broken. It's just that winecx has an "info procmap" command that the mainline wine doesn't have. Can be found here: https://github.com/marzent/winecx/commit/a32eb437f44e341caa3a3796027b019b319e9931.

@Shirk just wondering, was your prefix built using XIV on Mac or was it built using a separate Wine install? Because "info procmap" doesn't exist in Wine. Another option is that your prefix was built in XIV on Mac with an older version of winedbg. I believe the info procmap functionality was only included with winecx 2.0-onwards.

Waitsnake commented 9 months ago

I did a little bit more digging and it does seem like some later versions of wine broke winedbg.exe on Macs. I ran winedbg.exe using the XIV on Mac version of wine manually in the terminal:

WINEPREFIX="/Users//Library/Application Support/XIV on Mac/wineprefix" "/Applications/XIV on Mac.app/Contents/Resources/wine/bin/wine64" winedbg.exe --command "info procmap"

What is curious when I do the same with my brocken winedbg and the working winedbg the output in the console looks the same for both versions!

With working winedbg (winedbg_fix.exe): WINEPREFIX="/Users//Library/Application Support/XIV on Mac/wineprefix" "/Applications/XIV on Mac.app/Contents/Resources/wine/bin/wine64" winedbg_fix.exe --command "info procmap"

...
00dc:fixme:thread:get_thread_times not implemented on this platform
 pid      unix_pid threads  executable (all id:s are in hex)
 00000030 0000612a 10       'services.exe'
 000000b0 00006134 4        \_ 'plugplay.exe'
 0000008c 00006132 7        \_ 'winedevice.exe'
 00000054 0000612e 6        \_ 'winedevice.exe'
 0000003c 0000612c 3        \_ 'svchost.exe'
 00000020 00006124 1        'start.exe'
 000000d0 00006136 1        \_ 'conhost.exe'

With brocken winedbg (winedbg_issue.exe): WINEPREFIX="/Users//Library/Application Support/XIV on Mac/wineprefix" "/Applications/XIV on Mac.app/Contents/Resources/wine/bin/wine64" winedbg_issue.exe --command "info procmap"

...
00dc:fixme:thread:get_thread_times not implemented on this platform
 pid      unix_pid threads  executable (all id:s are in hex)
 00000030 00000000 10       'services.exe'
 000000b0 00000000 4        \_ 'plugplay.exe'
 0000008c 00000000 7        \_ 'winedevice.exe'
 00000054 00000000 6        \_ 'winedevice.exe'
 0000003c 00000000 3        \_ 'svchost.exe'
 00000020 00000000 1        'start.exe'
 000000d0 00000000 1        \_ 'conhost.exe'

I can see the both can detect pid, threads and executable attribute. But only the working winedbg can detect unix_pid correctly. The broken winedbg shows always 00000000 for all processes!

Since your broken winedbg from wine 8.0.1 shows a completely different error it seams there are different broken versions of winedbg out there with different levels of brokenness.

dropbeardevs commented 9 months ago

@Waitsnake Ooohh that's interesting, great work!

I'm curious as to what version of winecx your prefix was created with. What's the date/timestamp of your winedbg_issue.exe? Or any of the other executables in your prefix folder?

HealsCodes commented 9 months ago

If it helps - and since i have the same issue - mine are all created on 31st of March this year, that would be ff-wine-2.4 I believe?

Waitsnake commented 9 months ago

@Waitsnake Ooohh that's interesting, great work!

I'm curious as to what version of winecx your prefix was created with. What's the date/timestamp of your winedbg_issue.exe? Or any of the other executables in your prefix folder?

The creation timestamp is 04.12.2022 13:01 like most of the files (only a few files have a timestamps some minutes earlier) in this system32 folder.

Since so many files have the same timestamps I assume this is the timestamp from installation or extraction of the files from a kind of ZIP archive(?). Or is it from the compiling time of all the files in this folder? At least packing and unpacking with MacOS internal compression app maintains the timestamp so it seams to be related to the compiling time.

I also find no useful version string within the binary itself other than this here (witch not helps much): <assemblyIdentity type="win32" name="Wine.Winedbg" version="0.0.0.0"/>

I also did run winedbg_issue.exe directly to see if this debugger has a version command in his own prompt: WINEPREFIX="/Users//Library/Application Support/XIV on Mac/wineprefix" "/Applications/XIV on Mac.app/Contents/Resources/wine/bin/wine64" winedbg_issue.exe There is a 'help' command that shows you all the debugger commands but there is no 'ver' or 'v' or 'version'.

I found winver.exe after some search in the folder and running it a version window opens, but without a version (only see a '%s' )? WINEPREFIX="/Users/koehmarc/Library/Application Support/XIV on Mac/wineprefix" "/Applications/XIV on Mac.app/Contents/Resources/wine/bin/wine64" winver.exe cut

I really start to wonder what is the official way to find out the used wine version ??

I think, it would help more if the developers would compile version strings into the binaries rather than relying only on the timestamps of the files.