feature-system-console (b02ad531 or later) build is crashing at game start (Windows-only)

[Conticop]

I just went to try out the latest updates here, b36efa4ef497454ab4ef9b9ab80120f7609dbb57 Built from sources (Windows 10, MSVC 19 - Win32), all successfully (also made sure I have copied Resources files.. etc). But, after starting the game (clicking on "Start" in the launch window), the following error message pops out:

A serious error caused OpenSpades to stop working: Caught an exception from the application @ [/Gui/MainScreen/MainScreenUI.as:145,13] void spades::MainScreenUI::RunFrame(float) See SystemMessages.log for more details.

[Conticop]

I been trying out which commits work and which ones does not; after some trial and error, I have came to the commit c37a0131 which compiles and runs; if you go a single commit ahead (b02ad531) and try to compile it (make sure to apply 33d920a5, otherwise it won't even compile with MSVC) - it will crash at game start.

My hypothesis is that "the console window" (feature-system-console branch) is still WIP and therefore the game is crashing.

[NotAFile]

@Conticop have a look at https://git-scm.com/docs/git-bisect to do this easier next time!

[Conticop]

@NotAFile I am not sure how that would exactly help in this case, because you still have to compile and run the game to see if it actually is playable (which is what I had wanted to figure out). I wasn't interested in finding source code differences nor something git version related. So, obviously to figure such thing out I had to go commit-by-commit. I started from 100 commits behind, and advanced by half each time until it started crashing, on the 3rd run/iteration I already had enough info. Anyways I have made up a local isolation branch which excludes "feature-system-console" related changes by using cherry-pick.

[NotAFile]

@Conticop have you read the link? It does exactly that. You tell it which commits work and which don't and it does the job of intelligently picking the next commit you should check.

[Conticop]

You tell it which commits work and which don't and it does the job of intelligently picking the next commit you should check.

Yes I have read it. I may be missing something but.. 🤔 And how do you tell it that in the first place when you still have to compile and run each commit in order to know that it is "bad" or "good"? 😕 Because obviously, initially you don't know what commits are "bad" (crash) or "good" (works) to begin with... 🤦‍♀ Only after a game launch you get to know those parameters and only then you could proceed onto next iteration. Bisecting is useless from my point of view in this case. It is only useful at the final iteration, when you want to make a "working" branch, which is what I have already made by using cherry pick tho, I find it easier :) Anyways thanks for your hint, it could be helpful in some cases, but I find bisecting not useful in this case.

[feikname]

So, obviously to figure such thing out I had to go commit-by-commit. I started from 100 commits behind, and advanced by half each time until it started crashing, on the 3rd run/iteration I already had enough info.

Git bisecet does exactly that, in a more automated way. You still have to compile and run, but switching the commit is easier.

[yvt]

I don't seem to be able to reproduce the crash...

Caught an exception from the application

is a catch-all error condition for all C++ exceptions unwound through a C++-AngelScript boundary, so it doesn't provide us with much information. Maybe try setting a breakpoint here: https://github.com/yvt/openspades/blob/c910bd48468850479d719af7a67d7bd9bc64c445/Sources/ScriptBindings/ScriptManager.cpp#L364-L366

[Conticop]

Weird... That place is never being hit...

[yvt]

How about this function?: https://github.com/yvt/openspades/blob/399e24090dbd8b686c31b57a4c0927730d61d97a/Sources/AngelScript/source/as_context.cpp#L4479-L4487

[Conticop]

I just started placing breakpoints on every reference to that text.

Will nail it down now..

The first breakpoint hit! It is on this line:

The second breakpoint being hit is there where you pointed at:

If i follow it onward, it just creates an error message we already know about: Caught an exception from the application @ [/Gui/MainScreen/MainScreenUI.as:145,13] void spades::MainScreenUI::RunFrame(float). Does this help?

[yvt]

We should be able to get the exception details if you modify this to something like catch (const std::exception &ex): https://github.com/yvt/openspades/blob/b36efa4ef497454ab4ef9b9ab80120f7609dbb57/Sources/AngelScript/source/as_callfunc.cpp#L714-L720

On second thought, MSVC has a functionality to break on C++ exceptions wherever it's thrown and whether it's handled (caught) or not, doesn't it? It should directly take us to the exception cause.

[Conticop]

Yes indeed. Here is the exception message:

GL error Invalid Operation in ?TexImage2D@SDLGLDevice@gui@spades@@UAEXW4Enum@IGLDevice@draw@3@H0IIH00PBX@Z at E:\Projects\openspades\Sources\Gui\SDLGLDevice.cpp:873

WARNING: r_ignoreGLErrors is enabled. Information contained in this message is inaccurate and non-informative.
at E:\Projects\openspades\Sources\Gui\SDLGLDevice.cpp:112
?CreateBufferHandle@GLFramebufferManager@draw@spades@@QAE?AVBufferHandle@123@HHW4Enum@IGLDevice@23@@Z at E:\Projects\openspades\Sources\Draw\GLFramebufferManager.cpp:583
?PrepareForWaterRendering@GLFramebufferManager@draw@spades@@QAE?AVBufferHandle@123@II@Z at E:\Projects\openspades\Sources\Draw\GLFramebufferManager.cpp:385
?Render@GLWaterRenderer@draw@spades@@QAEXXZ at E:\Projects\openspades\Sources\Draw\GLWaterRenderer.cpp:643
?EndScene@GLRenderer@draw@spades@@UAEXXZ at E:\Projects\openspades\Sources\Draw\GLRenderer.cpp:719
?ExecuteChecked@ScriptContextUtils@spades@@QAEXXZ at E:\Projects\openspades\Sources\ScriptBindings\ScriptManager.cpp:337
?ExecuteChecked@ScriptContextHandle@spades@@QAEXXZ at E:\Projects\openspades\Sources\ScriptBindings\ScriptManager.cpp:276
?RunFrame@MainScreen@gui@spades@@UAEXM@Z at E:\Projects\openspades\Sources\Gui\MainScreen.cpp:232
?RunFrame@ConsoleScreen@gui@spades@@UAEXM@Z at E:\Projects\openspades\Sources\Gui\ConsoleScreen.cpp:182
?Run@SDLRunner@gui@spades@@QAEXHH@Z at E:\Projects\openspades\Sources\Gui\SDLRunner.cpp:428
?Run@Runner@gui@spades@@QAEXXZ at E:\Projects\openspades\Sources\Gui\Runner.cpp:70
?RunProtected@Runner@gui@spades@@QAEXXZ at E:\Projects\openspades\Sources\Gui\Runner.cpp:42
_SDL_main at E:\Projects\openspades\Sources\Gui\Main.cpp:317

This leads me to think it might be something to do with OpenGL or graphics options, which is quite weird really. But, that's what we just got. ... Well this is interesting indeed. If i change from OpenGL to Software renderer, the game boots up (no error) ... It has to be something to do with OpenGL!

[Conticop]

Just in case you want to know: And here is the log, after changing r_ignoreGLErrors to 0:

GL error Invalid Operation in ?DepthMask@SDLGLDevice@gui@spades@@UAEX_N@Z at E:\Projects\openspades\Sources\Gui\SDLGLDevice.cpp:272
at E:\Projects\openspades\Sources\Gui\SDLGLDevice.cpp:114
?StartScene@GLRenderer@draw@spades@@UAEXABUSceneDefinition@client@3@@Z at E:\Projects\openspades\Sources\Draw\GLRenderer.cpp:459
?ExecuteChecked@ScriptContextUtils@spades@@QAEXXZ at E:\Projects\openspades\Sources\ScriptBindings\ScriptManager.cpp:337
?ExecuteChecked@ScriptContextHandle@spades@@QAEXXZ at E:\Projects\openspades\Sources\ScriptBindings\ScriptManager.cpp:276
?RunFrame@MainScreen@gui@spades@@UAEXM@Z at E:\Projects\openspades\Sources\Gui\MainScreen.cpp:232
?RunFrame@ConsoleScreen@gui@spades@@UAEXM@Z at E:\Projects\openspades\Sources\Gui\ConsoleScreen.cpp:182
?Run@SDLRunner@gui@spades@@QAEXHH@Z at E:\Projects\openspades\Sources\Gui\SDLRunner.cpp:428
?Run@Runner@gui@spades@@QAEXXZ at E:\Projects\openspades\Sources\Gui\Runner.cpp:70
?RunProtected@Runner@gui@spades@@QAEXXZ at E:\Projects\openspades\Sources\Gui\Runner.cpp:42
_SDL_main at E:\Projects\openspades\Sources\Gui\Main.cpp:317

hmmm.. void SDLGLDevice::DepthMask(bool b) is getting throw an invalid operation error?! (I can't find any references, nothing seems to be calling to it even.)

Could it be because of an outdated SDL2 ?

[yvt]

Could it be because of an outdated SDL2 ?

That's unlikely, it almost never intervenes in OpenGL rendering. SDLGLDevice is mostly a wrapper of the GL driver, and only coordinates with SDL for presentation.

I'm out of idea for now. The most curious thing is that the problem started occurring with b02ad53109f8783da143c9ca2475b0ad921f54e4, which was essentially a refactoring to make the codebase amenable to the main modification of feature-system-console. Maybe I accidentally changed the behavior (even changing the order of calls can be fatal because OpenGL and GLRenderer are both highly stateful) and caused a regression, or it could be a ramification of God knows how many of UBs that our codebase is plagued with and AngelScript deliberately makes use of...

[Conticop]

I'm out of idea for now.

Me too. I just tried placing a newer SDL2 over, and it doesn't seem to fix it either.

The most curious thing is that the problem started occurring with b02ad53

Yeah. There's either something wrong with that code, because that's the exact commit at which it starts crashing. Or there is an error elsewhere causing it to crash in a weird way (rabbit hole)...

[Conticop]

I have booted into Linux OS, and went through building from latest commit version (same, there were no updates in the last 2 weeks by looking at commit history). Interestingly, it runs fine! (Compiles and plays successfully.) Therefore I have changed the title to reflect the discovery. So, now we know it is Windows-only issue.

[Conticop]

There's definitely something really strange going on.

Log from the last week: Starting fresh. I cloned the repo, compiled MinSizeRel (Win32), copied resources.. Launched the openspades.exe, clicked on Start, and this particular error vanished. Awesome, and I could use the console!

Log from this morning: I launched the game, clicked on Start and got this exact error all over again. I'm like wtf?!? I think to myself, well I haven't recompiled it, didn't change any code, didn't update drivers...

So I decided to investigate this again... I tried recompiling and seeing if that would somehow fix it back -- no it didn't. I went over the MainScreenUI.as and started commenting out some code to hopefully find the cause, since it seems to be reporting that there is something wrong with that script. To our surprise, I found 1 particular line of code which seems to be causing this error!

Line 167 in MainScreenUI.as: renderer.Flip(); (in void RunFrameLate(float dt)) https://github.com/yvt/openspades/blob/8f2171055522a08dab9e7553e168ae33077c9bba/Resources/Scripts/Gui/MainScreen/MainScreenUI.as#L167

When I commented out that particular call, and started the game, it launched fine into the main screen. However, the main screen has become black, but I do hear the 'feedback sound' when I move the mouse over the area of where the server-list is, I am able to join some server (blindly), and play the game fine as well. The console itself seems to work as well at that point.

Next, I tried to look into what renderer.Flip exactly does, but I couldn't find the Angelscript code for it. I suppose it is a binding from C++?

I assume the code is trying to do something with GL in the current state, but fails because such operation is invalid at that particular point on Windows.

Since you can't seem to reproduce this, I can do screen share (and/or live share with VSCode), so if you want to go over this together, what's your Discord id?