Game doesn't start when clientsettings.json is present

[Corax]

Heya,

I'm having an issue with the game not starting properly in some instances.

With a freshly extracted copy, the game starts, prompts for the account info, and continues on to the main menu, just as expected. However, after that initial run, the game aborts before it reaches the menu (or the login screen for that matter).

Deleting/renaming the ~/.config/VintagestoryData/ directory made it start again, just like the initial run, with the login prompt first, then proceeding to the main menu. I've narrowed it down to just deleting ~/.config/VintagestoryData/clientsettings.json; none of the other files in that directory seem to make a difference. The file itself is generated correctly, as far as I can tell, and has read/write permissions, so there shouldn't be a problem there.

The issue happens with the latest 1.9.12, but it also happens with an old install I had for 1.7.8 which worked just fine before; I hadn't played in the meantime, so I suspect some system update might have changed some library (after all, it's been almost a year since). As such I don't want to report it as a bug with Vintage Story, but give you a heads up that there is a compatibility issue with my specific install. I can play the game if I delete the settings file and log in every time, which is annoying, but something I can live with if I don't find a solution.

 

If anybody has an idea as to what might cause it, I'm open for suggestions. In the meantime, I'll try and find a proper solution, and I'll keep you posted if anything changes.

 

Here's a console log of a failed run:

Spoiler

$ /usr/bin/mono Vintagestory.exe

17:38:30 [Client Notification] Client logger started.
17:38:30 [Client Notification] Game Version: v1.9.12 (Stable)
17:38:30 [Client Debug] Creating game window with window mode Normal
gallium_hud: unknown driver query 'power'
17:38:31 [Client Notification] Graphics Card Vendor: X.Org
17:38:31 [Client Notification] Graphics Card Version: 4.5 (Core Profile) Mesa 19.1.1
17:38:31 [Client Notification] Graphics Card Renderer: Radeon RX 580 Series (POLARIS10, DRM 3.30.0, 5.1.15-gentoo, LLVM 7.1.0)
17:38:31 [Client Notification] Graphics Card ShadingLanguageVersion: 4.50
17:38:31 [Client Notification] Cairo Graphics Version: 1.16.0
17:38:31 [Client Notification] OpenAL Version: 1.1 ALSOFT 1.19.1
17:38:31 [Client Notification] C# Framework: Mono 5.20.1.19 (tarball Sat Jun 22 04:23:47 CEST 2019)
17:38:31 [Client Notification] OpenTK Version: 3.1.0 (A set of fast, low-level C# bindings for OpenGL, OpenGL ES and OpenAL. Unofficial fork by AnegoStudios.)
17:38:31 [Client Notification] Start discovering assets
17:38:31 [Client Notification] Found 0 base assets in category blocktypes
17:38:31 [Client Notification] Found 0 base assets in category itemtypes
17:38:31 [Client Notification] (Re-)loaded frame buffers
17:38:31 [Client Notification] Found 7 base assets in category lang
17:38:31 [Client Notification] Found 0 base assets in category journal
17:38:31 [Client Notification] Found 0 base assets in category patches
17:38:31 [Client Notification] Found 1 base assets in category config
17:38:31 [Client Notification] Found 0 base assets in category worldproperties
17:38:31 [Client Notification] Found 30 base assets in category sounds
17:38:31 [Client Notification] Found 2 base assets in category shapes
17:38:31 [Client Notification] Found 70 base assets in category shaders
17:38:31 [Client Notification] Found 11 base assets in category shaderincludes
17:38:31 [Client Notification] Found 58 base assets in category textures
17:38:31 [Client Notification] Found 5 base assets in category music
17:38:31 [Client Notification] Found 0 base assets in category dialog
17:38:31 [Client Notification] Found 184 base assets in total
17:38:31 [Client Notification] Loading sounds
17:38:31 [Client Notification] Loaded Shaderprogramm for render pass . 
17:38:31 [Client Notification] CPU Cores: 16
17:38:31 [Client Notification] Window was resized to 1280 850, rebuilding framebuffers...
17:38:31 [Client Notification] (Re-)loaded frame buffers
17:38:31 [Client Notification] Window was resized to 1280 850, rebuilding framebuffers...
17:38:31 [Client Notification] (Re-)loaded frame buffers
X Error of failed request:  BadAtom (invalid Atom parameter)
  Major opcode of failed request:  17 (X_GetAtomName)
  Atom id in failed request:  0x0
  Serial number of failed request:  23
  Current serial number in output stream:  23
AL lib: (EE) alc_cleanup: 1 device not closed

 

 

And here's one of a successful launch; note the same BadAtom error happens here, too, but the game continues after that:

Spoiler

$ /usr/bin/mono Vintagestory.exe

12:30:25 [Client Notification] Client logger started.
12:30:25 [Client Notification] Game Version: v1.9.12 (Stable)
12:30:25 [Client Debug] Creating game window with window mode Normal
gallium_hud: unknown driver query 'power'
12:30:26 [Client Notification] Graphics Card Vendor: X.Org
12:30:26 [Client Notification] Graphics Card Version: 4.5 (Core Profile) Mesa 19.1.1
12:30:26 [Client Notification] Graphics Card Renderer: Radeon RX 580 Series (POLARIS10, DRM 3.30.0, 5.1.15-gentoo, LLVM 7.1.0)
12:30:26 [Client Notification] Graphics Card ShadingLanguageVersion: 4.50
12:30:26 [Client Notification] Cairo Graphics Version: 1.16.0
12:30:26 [Client Notification] OpenAL Version: 1.1 ALSOFT 1.19.1
12:30:26 [Client Notification] C# Framework: Mono 5.20.1.19 (tarball Sat Jun 22 04:23:47 CEST 2019)
12:30:26 [Client Notification] OpenTK Version: 3.1.0 (A set of fast, low-level C# bindings for OpenGL, OpenGL ES and OpenAL. Unofficial fork by AnegoStudios.)
12:30:26 [Client Notification] Start discovering assets
12:30:26 [Client Notification] Found 0 base assets in category blocktypes
12:30:26 [Client Notification] Found 0 base assets in category itemtypes
12:30:26 [Client Notification] (Re-)loaded frame buffers
12:30:26 [Client Notification] Found 7 base assets in category lang
12:30:26 [Client Notification] Found 0 base assets in category journal
12:30:26 [Client Notification] Found 0 base assets in category patches
12:30:26 [Client Notification] Found 1 base assets in category config
12:30:26 [Client Notification] Found 0 base assets in category worldproperties
12:30:26 [Client Notification] Found 30 base assets in category sounds
12:30:26 [Client Notification] Found 2 base assets in category shapes
12:30:26 [Client Notification] Found 70 base assets in category shaders
12:30:26 [Client Notification] Found 11 base assets in category shaderincludes
12:30:26 [Client Notification] Found 58 base assets in category textures
12:30:26 [Client Notification] Found 5 base assets in category music
12:30:26 [Client Notification] Found 0 base assets in category dialog
12:30:26 [Client Notification] Found 184 base assets in total
12:30:26 [Client Notification] Loading sounds
12:30:26 [Client Notification] Loaded Shaderprogramm for render pass . 
12:30:26 [Client Notification] CPU Cores: 16
12:30:26 [Client Notification] Window was resized to 1280 850, rebuilding framebuffers...
12:30:26 [Client Notification] (Re-)loaded frame buffers
12:30:26 [Client Notification] Window was resized to 1280 850, rebuilding framebuffers...
12:30:26 [Client Notification] (Re-)loaded frame buffers
X11 Error encountered: 
  Error: BadAtom (invalid Atom parameter)
  Request:     17 (0)
  Resource ID: 0x0
  Serial:      23
  Hwnd:        <null>
  Control:     <null>  at System.Environment.get_StackTrace () [0x00000] in <ab4a534ed83547df8a5f88035772715b>:0 
  at System.Windows.Forms.XplatUIX11.HandleError (System.IntPtr display, System.Windows.Forms.XErrorEvent& error_event) [0x00000] in <b8705ebc4ff24f9aacb4536fc682dee5>:0 
  at OpenTK.Platform.X11.Functions.XGetAtomName (System.IntPtr , System.IntPtr ) [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.Platform.X11.XI2MouseKeyboard.UpdateDevices () [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.Platform.X11.XI2MouseKeyboard..ctor () [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.Platform.X11.XI2Input..ctor () [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.Platform.X11.X11Factory.get_InputDriver () [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.Platform.X11.X11Factory.CreateMouseDriver () [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.Input.Mouse..cctor () [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at _7M1yj4FQBTJEmfWvf7qNxqjmlto._R5QcbrHJytWHAq0n2UFgdxz1uit () [0x00000] in <4c2e6b6ed1db4ee89afd2df1fc0c2550>:0 
  at _7M1yj4FQBTJEmfWvf7qNxqjmlto._GqJojisQakCd6FNKy6lKacFO8co (System.Object , OpenTK.FrameEventArgs ) [0x00000] in <4c2e6b6ed1db4ee89afd2df1fc0c2550>:0 
  at OpenTK.GameWindow.OnRenderFrame (OpenTK.FrameEventArgs e) [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.GameWindow.OnRenderFrameInternal (OpenTK.FrameEventArgs e) [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.GameWindow.RaiseRenderFrame (System.Double elapsed, System.Double& timestamp) [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.GameWindow.DispatchRenderFrame () [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.GameWindow.Run (System.Double updates_per_second, System.Double frames_per_second) [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at OpenTK.GameWindow.Run () [0x00000] in <d2cd3fbe958341e98eff3ee31a301de2>:0 
  at _d3JBwM4eMb8W7G8DVNZYiP1na0q._cVCad1O9gFxfqkUkXdWAmvJte9x (_FgeJ0CzSGn1DY80XIagESHyrMlf , System.String[] ) [0x00000] in <b47ad26035194af3be47ad1e1edb32f8>:0 
  at _d3JBwM4eMb8W7G8DVNZYiP1na0q+_mbnEOCghqG8bQyh1Y801EcHTYch._AA71WP2jg1zHsHLOCWPQCA9aSom () [0x00000] in <b47ad26035194af3be47ad1e1edb32f8>:0 
  at _nbPUExoQOlKqsFEAyTfK5sdU31i._cVCad1O9gFxfqkUkXdWAmvJte9x (System.Threading.ThreadStart ) [0x00000] in <4c2e6b6ed1db4ee89afd2df1fc0c2550>:0 
  at _d3JBwM4eMb8W7G8DVNZYiP1na0q..ctor (System.String[] ) [0x00000] in <b47ad26035194af3be47ad1e1edb32f8>:0 
  at _d3JBwM4eMb8W7G8DVNZYiP1na0q._Q2SwdcKx0lcPchAt6mAzgEnRr5H (System.String[] ) [0x00000] in <b47ad26035194af3be47ad1e1edb32f8>:0 

12:30:26 [Client Notification] Loading shaders...
12:30:26 [Client Notification] Loaded Shaderprogramm for render pass standard. 
12:30:26 [Client Notification] Shader standard: Uniform locations for variables shadowMapFar, shadowIntensity, shadowMapWidthInv, shadowMapHeightInv, shadowMapNear, shadowZExtendFar, shadowRangeFar, toShadowMapSpaceMatrixFar, shadowZExtendNear, shadowRangeNear, toShadowMapSpaceMatrixNear not found (or not used).
12:30:26 [Client Notification] Loaded Shaderprogramm for render pass particlescube. 

... and so on, everything nominal

 

 

[Tyron]

Hm odd. First time I see such error. What OS are you on?

Looks like some other people had this issue before with other Projects using OpenTK but it was never found: https://github.com/opentk/opentk/issues/408

[Corax]

I'm on 64 bit Gentoo GNU/Linux, with a Ryzen 1800X CPU and a Radeon RX580 GPU, let me know if you need some more specific info.

If I were to guess, the BadAtom isn't the real issue here, since it also happens when I delete the config and the game runs fine after, interestingly with a lot more verbose output. I'd assume the issue to be somewhere *around* the code where this happens (sounds like something mouse driver related, but mouse doesn't appear to be impaired in any way). It's as if some part of reading the config file doesn't get called, the launcher works just fine. In other words, BadAtom might indicate the approximate location in the code, but not be the problem in and of itself.

I have tried removing sections of the config to see if anything specific causes the problem, but it appears it's a case of either–or, if there's a config file there, whatever (valid JSON syntax) is in it, the launcher crashes. If there is no config file, it still complains about the BadAtom but continues fine afterwards – and generates a default config, which makes the launcher crash on the next run...

 

 

On a side note, I have noticed there are a few control settings that can only be adjusted after the game has loaded into a world at least once, namely the keys for the journal and the in-game handbook (default keys "j" and "h"). There may be others, but those are the ones I always need to change since I use IJKL instead of WASD, and those are either conflicting or too close by for comfort.

Edited July 3, 2019 by Corax

[Tyron]

Fairly sure its somehow caused by the operating system or the environment. Do you happen to have any other linux distri available to test on?
I think with the clientsettings.json present it just crashes earlier, after all, in the logs we can see in both cases a BadAtom error.

Either way I reported the bug here: https://github.com/opentk/opentk/issues/937

[Corax]

4 hours ago, Tyron said:

with the clientsettings.json present it just crashes earlier

But the thing is, with no clientsettings.json, it doesn't crash at all. Yes, it throws that BadAtom error message, but then continues just fine.

I can play existing worlds migrated from 1.7, and create new ones, and don't have a single crash even if I play for hours at a time. I did have a crash or two, but those only happened when I pushed settings to the limit; while ideally that shouldn't result in crashes, they were at least not entirely unexpected.

Certainly a lot has changed in my system in the six or eight months since I last played, from the kernel I use, to various libraries; but that is really no different than a Windows or MacOs system receiving system updates.

I don't think testing with any other Linux distro is going to be helpful without at least some indication of what might be happening. If it were a more common issue, some of the other Linux users here would probably have said something already. I will certainly continue to try and test a few other things, first step will be reverting to an earlier version of Mono; good thing I posted my earlier setup in the Linux distros thread .)

[Tyron]

 

11 hours ago, Corax said:

But the thing is, with no clientsettings.json, it doesn't crash at all. Yes, it throws that BadAtom error message, but then continues just fine. 

Correct. There are certain code paths where a 3rd party error would crash the game and certain code paths that don't crash the game. There's not much I can do about that on the game engine side. I would need to add thousands upon thousands of error handlers to accommodate for every possible 3rd party error, from what I can see.
 

11 hours ago, Corax said:

I can play existing worlds migrated from 1.7, and create new ones, and don't have a single crash even if I play for hours at a time. I did have a crash or two, but those only happened when I pushed settings to the limit; while ideally that shouldn't result in crashes, they were at least not entirely unexpected.

And v1.8 and v1.9 crashes with the same error as above?

11 hours ago, Corax said:

I don't think testing with any other Linux distro is going to be helpful without at least some indication of what might be happening.

It would be helpful insofar as to figure out what part of the software chain is to blame.

 

[Corax]

1 hour ago, Tyron said:

 

13 hours ago, Corax said:

I can play existing worlds migrated from 1.7, and create new ones, and don't have a single crash even if I play for hours at a time. I did have a crash or two, but those only happened when I pushed settings to the limit; while ideally that shouldn't result in crashes, they were at least not entirely unexpected.

And v1.8 and v1.9 crashes with the same error as above?

The first time the problem appeared was when I installed 1.9.12, after I hadn't been playing for a while. The last time before that was with 1.7.8, which I have kept around since then. So naturally I tried running 1.7.8, which worked as expected back then, but now shows the same behaviour as 1.9.12. I have never installed 1.8.anything, but I'd be surprised if it would behave any different than 1.7 and 1.9.

I can only repeat, as I stated in my first post, that this isn't an issue that only started with  a new version of VintageStory, but after a long while not playing, and now happening on the old 1.7.8 install as well as the latest 1.9.12. I only didn't notice it in the meantime simply because I didn't try to run VS in between 1.7.8 and 1.9.12. So again, it's not something that has changed in VS, but in some system library, or possibly Mono which went from 5.16.0.179 to 5.20.1.19 over the course of that half year or so. I have just finished downgrading Mono back to 5.16.0.220 (.179 isn't available to me anymore), and will test and report back when I have results.

 

1 hour ago, Tyron said:

13 hours ago, Corax said:

I don't think testing with any other Linux distro is going to be helpful without at least some indication of what might be happening.

It would be helpful insofar as to figure out what part of the software chain is to blame.

I can't simply install all of the other Linux distros out there, to see if the error even happens on any of them. Without as much as a hint of what part of the software chain might be responsible, this sounds like an utterly futile attempt. It might make sense if it were a hardware related issue, just to see if the error happens no matter what, but I don't see that as a likely cause, since it is reliably reproducible on my end, and all hardware tests I ran indicate no faults.

Not trying to be a pain in the ass, but I'm fishing in the dark here.

OK, off to do some more testing...

[Corax]

Well, that was quick.

$ /usr/bin/mono Vintagestory.exe

12:09:38 [Client Notification] Client logger started.
12:09:38 [Client Notification] Game Version: v1.9.12 (Stable)
12:09:38 [Client Debug] Creating game window with window mode Fullscreen
12:09:38 [Client Notification] Graphics Card Vendor: X.Org
12:09:38 [Client Notification] Graphics Card Version: 4.5 (Core Profile) Mesa 19.1.1
12:09:38 [Client Notification] Graphics Card Renderer: Radeon RX 580 Series (POLARIS10, DRM 3.30.0, 5.1.16-gentoo, LLVM 7.1.0)
12:09:38 [Client Notification] Graphics Card ShadingLanguageVersion: 4.50
12:09:38 [Client Notification] Cairo Graphics Version: 1.16.0
12:09:38 [Client Notification] OpenAL Version: 1.1 ALSOFT 1.19.1
12:09:38 [Client Notification] C# Framework: Mono 5.16.0.220 (tarball Fri Jul  5 11:42:48 CEST 2019)
12:09:38 [Client Notification] OpenTK Version: 3.1.0 (A set of fast, low-level C# bindings for OpenGL, OpenGL ES and OpenAL. Unofficial fork by AnegoStudios.)
12:09:38 [Client Notification] Start discovering assets
12:09:38 [Client Notification] Found 0 base assets in category blocktypes
12:09:38 [Client Notification] Found 0 base assets in category itemtypes
12:09:38 [Client Notification] (Re-)loaded frame buffers
12:09:38 [Client Notification] Found 7 base assets in category lang
12:09:38 [Client Notification] Found 0 base assets in category journal
12:09:38 [Client Notification] Found 0 base assets in category patches
12:09:38 [Client Notification] Found 1 base assets in category config
12:09:38 [Client Notification] Found 0 base assets in category worldproperties
12:09:38 [Client Notification] Found 30 base assets in category sounds
12:09:38 [Client Notification] Found 2 base assets in category shapes
12:09:38 [Client Notification] Found 70 base assets in category shaders
12:09:38 [Client Notification] Found 11 base assets in category shaderincludes
12:09:38 [Client Notification] Found 58 base assets in category textures
12:09:38 [Client Notification] Found 5 base assets in category music
12:09:38 [Client Notification] Found 0 base assets in category dialog
12:09:38 [Client Notification] Found 184 base assets in total
12:09:38 [Client Notification] Loading sounds
12:09:38 [Client Notification] Loaded Shaderprogramm for render pass . 
12:09:38 [Client Notification] CPU Cores: 16
12:09:38 [Client Notification] Window was resized to 1280 850, rebuilding framebuffers...
12:09:38 [Client Notification] (Re-)loaded frame buffers
12:09:38 [Client Notification] Window was resized to 1920 1200, rebuilding framebuffers...
12:09:38 [Client Notification] (Re-)loaded frame buffers
X Error of failed request:  BadAtom (invalid Atom parameter)
  Major opcode of failed request:  17 (X_GetAtomName)
  Atom id in failed request:  0x0
  Serial number of failed request:  23
  Current serial number in output stream:  23

Mono version doesn't make a difference.

 

What I find interesting here, and didn't notice before (certainly was there before, just didn't pay attention), is this part:

12:09:38 [Client Notification] Window was resized to 1280 850, rebuilding framebuffers...
12:09:38 [Client Notification] (Re-)loaded frame buffers
12:09:38 [Client Notification] Window was resized to 1920 1200, rebuilding framebuffers...
12:09:38 [Client Notification] (Re-)loaded frame buffers

where it changes the screen resolution to the values in clientsettings.json; so it does read the config and applies at least part of the settings, but apparently struggles with something that doesn't happen when it has to generate a fresh default...

 

PS.: However, if I delete clientsettings, run VS, pass authentication, and immediately exit from the main menu without changing anything, it crashes again on the next start.

Edited July 5, 2019 by Corax

[Corax]

Would it help if I'd PM you strace runs of a failed and a successful launch for comparison?

I have reinstalled basically everything from the X server over Mesa, Xfce, Mono, down to gcc and glibc, and still haven't found any clue as to what might be causing it. I suspect it's not a library or other software dependency issue per se, but rather some silly configuration setting that has changed during some update, but again, I have no idea. I'll keep looking and reporting back if anything changes.

[Tyron]

Sure, go ahead. Perhaps we can find something in there. If anything we could post that to the X11 bug tracker?

I'm also clueless as to why this error occurs. I'd still suggest another or a newer/older version of the linux distro.

[Tyron]

A user on github suggests running it through xtrace: https://github.com/opentk/opentk/issues/937#issuecomment-518182006

[Corax]

PM sent. Personally I think it's interesting to have both crash and no-crash files side-by-side and see where they diverge, but that's about it from my part : )

[emlyn145]

go ahead