libsdl-org / SDL

Simple Directmedia Layer
https://libsdl.org
zlib License
9.75k stars 1.81k forks source link

[Question][SDL3] 'SDL_Log' shows duplicated message. #10049

Closed jskimn closed 2 months ago

jskimn commented 4 months ago

C# winform --> CLR --> CPP(SDL) I made simple c++ class and I called 'SDL_Log' function. Strangely, I got the duplicated log message like following screen shot. image

And in console mode, it has no problem. I don't know if the cause is in WinForms or in the C++ code or in CLR.

[c++ class]

include "PlayerCore.h"

include <SDL3/SDL.h>

CPlayerCore::CPlayerCore(HWND parentHwnd) { } CPlayerCore::~CPlayerCore() { } int CPlayerCore::PlayVideo(std::string filepath) { SDL_Log("DDDDDDDDDDDDDDDDDDDDD \n"); return 0; }

madebr commented 4 months ago

Before delving deeper, what is the behavior when logging using fprintf, std::cout, std::cerr and OutputDebugStringA?

jskimn commented 4 months ago

Before delving deeper, what is the behavior when logging using fprintf, std::cout, std::cerr and OutputDebugStringA?

I can't understand your comment or question. Do you mean that showing duplicated message is related with those IO functions?

madebr commented 4 months ago

Replace SDL_Log("DDDDDDDDDDDDDDDDDDDDD \n"); with

std::cerr << "output using std::cerr\n";
std::cout << "output using std::cout\n";
fprintf(stdout, "output using fprintf(stdout)\n");
SDL_Log("output using SDL_Log");
fprintf(stderr, "output using fprintf(stderr)\n");
OutputDebugStringA("output using OutputDebugStringA");

and add

#include <cstdio>
#include <iostream>
#include <windows.h>

at the top

I want to know the behavior of the stl/libc/win32 functions. If those print once and SDL_Log twice, it's something to do with SDL. If all print twice, then it's a logic bug in your application.

jskimn commented 4 months ago

Replace SDL_Log("DDDDDDDDDDDDDDDDDDDDD \n"); with

std::cerr << "output using std::cerr\n";
std::cout << "output using std::cout\n";
fprintf(stdout, "output using fprintf(stdout)\n");
SDL_Log("output using SDL_Log");
fprintf(stderr, "output using fprintf(stderr)\n");
OutputDebugStringA("output using OutputDebugStringA");

and add

#include <cstdio>
#include <iostream>
#include <windows.h>

at the top

I want to know the behavior of the stl/libc/win32 functions. If those print once and SDL_Log twice, it's something to do with SDL. If all print twice, then it's a logic bug in your application.

Because it is not console application, std::cout and fprintf(stdout) do not shows any message. So, I changed like below codes by your advice.

std::cerr << "output using std::cerr\n";
SDL_Log("output using SDL_Log");
fprintf(stderr, "output using fprintf(stderr)\n");
OutputDebugStringA("output using OutputDebugStringA\n");

And I can see below output: image

madebr commented 4 months ago

Can you share a minimal Visual Studio solution that reproduces the issue? Most of use are no C# specialists, so it would help us a lot.

jskimn commented 4 months ago

Can you share a minimal Visual Studio solution that reproduces the issue? Most of use are no C# specialists, so it would help us a lot.

Hi, Madebr, I attached whole solution files and I am working on VS2019. You can see simple form application, and then if you click 'start button', you can see log in VS output window. 'PlayerCore.cpp' file has codes that is related with log and SDL.

SDL3 library is pulled from main branch a few days ago. Thanks a lot! FFMpegPlayer.zip

madebr commented 4 months ago

I cannot reproduce your issue. When pressing the "Start" button, the following appears in the "Output" window:

output using std::cerr
INFO: output using SDL_Log
output using fprintf(stderr)
output using OutputDebugStringA

(I'm using SDL3 from current main)

jskimn commented 4 months ago

I cannot reproduce your issue. When pressing the "Start" button, the following appears in the "Output" window:

output using std::cerr
INFO: output using SDL_Log
output using fprintf(stderr)
output using OutputDebugStringA

(I'm using SDL3 from current main)

I will check again with latest SDL3 and so on.... It's very strange.

jskimn commented 4 months ago

I cannot reproduce your issue. When pressing the "Start" button, the following appears in the "Output" window:

output using std::cerr
INFO: output using SDL_Log
output using fprintf(stderr)
output using OutputDebugStringA

(I'm using SDL3 from current main)

I will check again with latest SDL3 and so on.... It's very strange.

I think that I have some problem in 'SDL3.dll', but I can't find why. I built using VisualC\SDL.sln and copied header files in 'include\SDL3' directory. Is it something wrong?

madebr commented 4 months ago

I can reproduce it when I use a prebuilt SDL3 binary from CI. It prints twice when configuring SDL with -DSDL_LIBC=ON, printing once with OutputDebugString and once with fprintf(stderr).

The current behavior is as follows: -DSDL_LIBC=OFF => OutputDebugString; if (attached_to_console) { WriteFile(GetStdHandle(STD_ERROR_HANDLE)) }. -DSDL_LIBC=ON => OutputDebugString; fprintf(stderr)

The behavior of fprintf(stderr) (of MS libc) is to print to the debug stream when no console is attached. When a console is attached, then it prints to the terminal and everything happens as expected.

slouken commented 2 months ago

Maybe what we want here is just do fprintf(stderr) if -DSDL_LIBC=ON?

slouken commented 2 months ago

Actually, we still want the debug output. Maybe we should check to see if the console is attached (the first time?) before calling fprintf(stderr)?

madebr commented 2 months ago

This patch makes it behave as expected when building with SDL_LIBC=ON and OFF. But I don't feel 100% comfortable applying, so can you please have a look at it? The function feels way too complicated.

Don't do DebugOutputStream when attached under MSVC and using libc ```diff diff --git a/src/SDL_log.c b/src/SDL_log.c index 2b2680f5f..3126ffe4f 100644 --- a/src/SDL_log.c +++ b/src/SDL_log.c @@ -510,9 +510,14 @@ void SDL_LogMessageV(int category, SDL_LogPriority priority, SDL_PRINTF_FORMAT_S } } -#if defined(SDL_PLATFORM_WIN32) && !defined(HAVE_STDIO_H) && !defined(SDL_PLATFORM_WINRT) && !defined(SDL_PLATFORM_GDK) -/* Flag tracking the attachment of the console: 0=unattached, 1=attached to a console, 2=attached to a file, -1=error */ -static int consoleAttached = 0; +#if defined(SDL_PLATFORM_WIN32) && !defined(SDL_PLATFORM_WINRT) && !defined(SDL_PLATFORM_GDK) +enum { + CONSOLE_UNATTACHED = 0, + CONSOLE_ATTACHED_CONSOLE = 1, + CONSOLE_ATTACHED_FILE = 2, + CONSOLE_ATTACHED_MSVC = 3, + CONSOLE_ATTACHED_ERROR = -1, +} consoleAttached = CONSOLE_UNATTACHED; /* Handle to stderr output of console. */ static HANDLE stderrHandle = NULL; @@ -530,58 +535,66 @@ static void SDLCALL SDL_LogOutput(void *userdata, int category, SDL_LogPriority LPTSTR tstr; SDL_bool isstack; -#if !defined(HAVE_STDIO_H) && !defined(SDL_PLATFORM_WINRT) && !defined(SDL_PLATFORM_GDK) +#if !defined(SDL_PLATFORM_WINRT) && !defined(SDL_PLATFORM_GDK) BOOL attachResult; DWORD attachError; DWORD charsWritten; DWORD consoleMode; /* Maybe attach console and get stderr handle */ - if (consoleAttached == 0) { + if (consoleAttached == CONSOLE_UNATTACHED) { attachResult = AttachConsole(ATTACH_PARENT_PROCESS); if (!attachResult) { attachError = GetLastError(); if (attachError == ERROR_INVALID_HANDLE) { /* This is expected when running from Visual Studio */ /*OutputDebugString(TEXT("Parent process has no console\r\n"));*/ - consoleAttached = -1; + consoleAttached = CONSOLE_ATTACHED_MSVC; } else if (attachError == ERROR_GEN_FAILURE) { OutputDebugString(TEXT("Could not attach to console of parent process\r\n")); - consoleAttached = -1; + consoleAttached = CONSOLE_ATTACHED_ERROR; } else if (attachError == ERROR_ACCESS_DENIED) { /* Already attached */ - consoleAttached = 1; + consoleAttached = CONSOLE_ATTACHED_CONSOLE; } else { OutputDebugString(TEXT("Error attaching console\r\n")); - consoleAttached = -1; + consoleAttached = CONSOLE_ATTACHED_ERROR; } } else { /* Newly attached */ - consoleAttached = 1; + consoleAttached = CONSOLE_ATTACHED_CONSOLE; } - if (consoleAttached == 1) { + if (consoleAttached == CONSOLE_ATTACHED_CONSOLE) { stderrHandle = GetStdHandle(STD_ERROR_HANDLE); if (GetConsoleMode(stderrHandle, &consoleMode) == 0) { /* WriteConsole fails if the output is redirected to a file. Must use WriteFile instead. */ - consoleAttached = 2; + consoleAttached = CONSOLE_ATTACHED_FILE; } } } #endif /* !defined(HAVE_STDIO_H) && !defined(SDL_PLATFORM_WINRT) && !defined(SDL_PLATFORM_GDK) */ - length = SDL_strlen(SDL_GetLogPriorityPrefix(priority)) + SDL_strlen(message) + 1 + 1 + 1; output = SDL_small_alloc(char, length, &isstack); (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 strem */ + 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. */ - if (consoleAttached == 1) { + if (consoleAttached == CONSOLE_ATTACHED_CONSOLE) { if (!WriteConsole(stderrHandle, tstr, (DWORD)SDL_tcslen(tstr), &charsWritten, NULL)) { OutputDebugString(TEXT("Error calling WriteConsole\r\n")); if (GetLastError() == ERROR_NOT_ENOUGH_MEMORY) { @@ -589,7 +602,7 @@ static void SDLCALL SDL_LogOutput(void *userdata, int category, SDL_LogPriority } } - } else if (consoleAttached == 2) { + } else if (consoleAttached == CONSOLE_ATTACHED_FILE) { if (!WriteFile(stderrHandle, output, (DWORD)SDL_strlen(output), &charsWritten, NULL)) { OutputDebugString(TEXT("Error calling WriteFile\r\n")); } ```
slouken commented 2 months ago

This patch makes it behave as expected when building with SDL_LIBC=ON and OFF. But I don't feel 100% comfortable applying, so can you please have a look at it? The function feels way too complicated.

Don't do DebugOutputStream when attached under MSVC and using libc

This looks good to me, thanks!