SDL_Log not working on Windows with debugger attached

[namandixit]

After this commit, SDL_Log doesn't print anything to the debugger if application is compiled with /subsystem:windows. If I use OutputDebugStringA or OutputDebugStringW manually, it works fine. Reverting to an older commit of SDL makes it work again. Setting the subsystem to console "works", by printing to the stderr of attached console instead of the debug stream.

I tested it with Epic's RAD Debugger and RemedyBG (don't have a Visual Studio install handy, let me know if it is required)

Compilation command was:

cl.exe main.c /nologo /Zi /FC /source-charset:utf-8 /execution-charset:utf-8 /GS- /std:c11 /DUNICODE=1 /D_UNICODE=1 /Feprogram.exe /link /NOLOGO "libvcruntime.lib" "kernel32.lib" "SDL3.lib" "ucrt.lib" /SUBSYSTEM:WINDOWS /fixed

I was using the callback based SDL_main, in case it matters. The commands used to build SDL are here.

[madebr]

On windows, let's ignore SDL_LIBC and always use WriteFile/WriteConsole + OutputDebugStream.

[madebr]

Btw, I can't reproduce with Visual Studio 2019. I built testspriteminimal.c (no callbacks) and testsprite.c (callbacks) using the windows and console subsystem, and added these lines:

    SDL_Log("Hello world");
    SDL_LogError(SDL_LOG_CATEGORY_APPLICATION, "An error (%s)", argv[0]);

cl /nologo ..\test\testspriteminimal.c /I../include /Fetestspriteminimal_console.exe /link /NOLOGO "libvcruntime.lib" "kernel32.lib" "SDL3.lib" "ucrt.lib" /SUBSYSTEM:CONSOLE /fixed
cl /nologo ..\test\testspriteminimal.c /I../include /Fetestspriteminimal_windows.exe /link /NOLOGO "libvcruntime.lib" "kernel32.lib" "SDL3.lib" "ucrt.lib" /SUBSYSTEM:WINDOWS /fixed


cl /nologo ..\test\testsprite.c ..\test\testutils.c /I../include /Fetestsprite_console.exe /link /NOLOGO /nodefaultlib:msvcrtd "libvcruntime.lib" "kernel32.lib" "SDL3_test.lib" "SDL3.lib" "ucrt.lib" /SUBSYSTEM:CONSOLE /fixed
cl /nologo ..\test\testsprite.c ..\test\testutils.c /I../include /Fetestsprite_windows.exe /link /NOLOGO /nodefaultlib:msvcrtd "libvcruntime.lib" "kernel32.lib" "SDL3_test.lib" "SDL3.lib" "ucrt.lib" /SUBSYSTEM:WINDOWS /fixed

When debugging the resulting executables in the Visual Studio IDE, in both cases I see the following in the debug view (with varying exe path):

Hello world
ERROR: An error (C:\projects\SDL\cmake-build-debug\testspriteminimal_console.exe)

[namandixit]

@madebr This is the minimal example, using an SDL compiled today at this commit:

#define SDL_MAIN_USE_CALLBACKS
#include "SDL3/SDL_main.h"
#include "SDL3/SDL.h"
#include <Windows.h>
int SDL_AppInit(void **appstate, int argc, char **argv) {
    OutputDebugStringA("OutputDebugString\n");
    SDL_Log("SDL_Log");
    return SDL_APP_CONTINUE;
}
int SDL_AppIterate(void *appstate) {
    return SDL_APP_SUCCESS;
}
int SDL_AppEvent(void *appstate, const SDL_Event *event) {
    return SDL_APP_CONTINUE;
}
void SDL_AppQuit(void *appstate) {
    // SDL3 will automatically call SDL_Quit()
}

Compiled with:

cl.exe test.c /nologo /Zi /FC /source-charset:utf-8 /execution-charset:utf-8 /GS- /std:c11 /DUNICODE=1 /D_UNICODE=1 /Fetest.exe /link /NOLOGO "libvcruntime.lib" "kernel32.lib" "SDL3.lib" "ucrt.lib" /SUBSYSTEM:WINDOWS /fixed

And I get the following output in the debug stream:

OutputDebugString

I don't have a VS installation set up, I'll put one to install overnight and test with it.

[namandixit]

@madebr Okay, so with Visual Studio 2022, the following program:

#define SDL_MAIN_USE_CALLBACKS
#include "SDL3/SDL_main.h"
#include "SDL3/SDL.h"
#include <Windows.h>
#include <stdio.h>
int SDL_AppInit(void **appstate, int argc, char **argv) {
    OutputDebugStringA("OutputDebugString\n");
    SDL_Log("SDL_Log");
    printf("stdout\n");
    fprintf(stderr, "stderr\n");
    return SDL_APP_CONTINUE;
}
int SDL_AppIterate(void *appstate) {
    return SDL_APP_SUCCESS;
}
int SDL_AppEvent(void *appstate, const SDL_Event *event) {
    return SDL_APP_CONTINUE;
}
void SDL_AppQuit(void *appstate) {
    // SDL3 will automatically call SDL_Quit()
}

compiled with:

cl.exe test.c /nologo /Zi /FC /source-charset:utf-8 /execution-charset:utf-8 /GS- /std:c11 /DUNICODE=1 /D_UNICODE=1 /Fetest.exe /link /NOLOGO "libvcruntime.lib" "kernel32.lib" "SDL3.lib" /SUBSYSTEM:WINDOWS /fixed

gives the following output:

OutputDebugString
SDL_Log
stderr
stdout

As you can see, the "Output" panel on VS is actually slurping up all the output streams -- not just debug stream but also stdout and stderr. I am reasonably sure that this didn't used to be the case, and I can only assume that third party debuggers are replicating the older behaviour.

Regardless, I would say the the older behaviour was far more intuitive and SDL should revert back to it in order to maintain compatibility with non-VS IDEs, debuggers, etc.

[madebr]

Regardless, I would say the the older behaviour was far more intuitive and SDL should revert back to it in order to maintain compatibility with non-VS IDEs, debuggers, etc.

Yup, I can reproduce your issue with raddbg. MSVC forwards stdout/stderr to the debug stream, whereas other debuggers do not. I don't know how to detect this, so let's always log with the win32 api.

We want to keep the logging simple and reliable.

[namandixit]

Having thought about it, another thing that can be done is to put the debug-stream-only behaviour behind a hint. I know that many devs from *nix background get confused with debug streams ("I ran the game in terminal and there was no output"). This way, people who just use Visual Studio can keep using it (given the new behaviour of VS output panel), new developers get *nix-like behaviour in consoles, and those who want debug output can enable a hint and get debug output.

Ideally, for maximum flexibility, there can be two hints: "debug stream only", and "stdout/stderr and debug stream both".

Although I don't know if hints require SDL_Init() first. If they do, then this is no-go, since we need to log errors in init.

[namandixit]

So, VS2022 is just busted. If you load a project file, there is no stream redirection and it only prints the debug stream in the output panel. However, if you load an exe directly (devenv test.exe), then stdout and stderr start getting redirected to the output panel.

So, best thing to do would be to simply go back to the old behaviour and put logs in the debug stream. Otherwise, the behaviour of the program would change depending on how it was loaded in VS (thanks Microsoft, love you!).

[slouken]

@madebr I just ran into this tonight, loading the Visual Studio project in VS2022 yields no debug output and fprintf(stderr) doesn't output anywhere.

We need to fix this... how did it used to work?

[madebr]

The change was 125ce7137987ec91b931b4fb97d9c3c7af88c377

This patch undoes the failed attempt to detect a MS debugger

--- a/src/SDL_log.c
+++ b/src/SDL_log.c
@@ -515,7 +515,6 @@ enum {
     CONSOLE_UNATTACHED = 0,
     CONSOLE_ATTACHED_CONSOLE = 1,
     CONSOLE_ATTACHED_FILE = 2,
-    CONSOLE_ATTACHED_MSVC = 3,
     CONSOLE_ATTACHED_ERROR = -1,
 } consoleAttached = CONSOLE_UNATTACHED;
 
@@ -535,13 +534,11 @@ static void SDLCALL SDL_LogOutput(void *userdata, int category, SDL_LogPriority
         LPTSTR tstr;
         bool isstack;
 
-#if !defined(SDL_PLATFORM_WINRT) && !defined(SDL_PLATFORM_GDK)
+#if !defined(HAVE_STDIO_H) && !defined(SDL_PLATFORM_WINRT) && !defined(SDL_PLATFORM_GDK)
         BOOL attachResult;
         DWORD attachError;
         DWORD consoleMode;
-#if !defined(HAVE_STDIO_H)
         DWORD charsWritten;
-#endif
 
         // Maybe attach console and get stderr handle
         if (consoleAttached == CONSOLE_UNATTACHED) {
@@ -551,7 +548,7 @@ static void SDLCALL SDL_LogOutput(void *userdata, int category, SDL_LogPriority
                 if (attachError == ERROR_INVALID_HANDLE) {
                     // This is expected when running from Visual Studio
                     // OutputDebugString(TEXT("Parent process has no console\r\n"));
-                    consoleAttached = CONSOLE_ATTACHED_MSVC;
+                    consoleAttached = CONSOLE_ATTACHED_ERROR;
                 } else if (attachError == ERROR_GEN_FAILURE) {
                     OutputDebugString(TEXT("Could not attach to console of parent process\r\n"));
                     consoleAttached = CONSOLE_ATTACHED_ERROR;
@@ -582,17 +579,8 @@ static void SDLCALL SDL_LogOutput(void *userdata, int category, SDL_LogPriority
         (void)SDL_snprintf(output, length, "%s%s\r\n", SDL_GetLogPriorityPrefix(priority), message);
         tstr = WIN_UTF8ToString(output);
 
-
-#if defined(HAVE_STDIO_H) && !defined(SDL_PLATFORM_WINRT) && !defined(SDL_PLATFORM_GDK)
-        // When running in MSVC and using stdio, rely on forwarding of stderr to the debug stream
-        if (consoleAttached != CONSOLE_ATTACHED_MSVC) {
-            // Output to debugger
-            OutputDebugString(tstr);
-        }
-#else
         // Output to debugger
         OutputDebugString(tstr);
-#endif
 
 #if !defined(HAVE_STDIO_H) && !defined(SDL_PLATFORM_WINRT) && !defined(SDL_PLATFORM_GDK)
         // Screen output to stderr, if console was attached.

[madebr]

This should be fixed now by #10616

Thanks for the report!