diff --git a/audit/history.jsonl b/audit/history.jsonl index 473f757f..953192fb 100644 --- a/audit/history.jsonl +++ b/audit/history.jsonl @@ -606,3 +606,4 @@ {"date": "2026-09-30", "unit": "EterBase/CRC32.cpp", "action": "GetCaseCRC32 PORTED; GetHFILECRC32/GetFileCRC32/GetFileSize ADAPTED", "evidence": "port.utils CRC32/CFileBase/CMappedFile checks"} {"date": "2026-09-30", "unit": "EterBase/FileBase.cpp", "action": "all units mapped (FILE* over Win32 HANDLE); stale fstream note corrected", "evidence": "port.utils CRC32/CFileBase/CMappedFile checks"} {"date": "2026-09-30", "unit": "EterBase/MappedFile.cpp", "action": "Map/Unmap ADAPTED (mmap), rest PORTED verbatim; stale ifstream note corrected", "evidence": "port.utils CRC32/CFileBase/CMappedFile checks"} +{"date": "2026-09-30", "unit": "EterBase/Debug.cpp", "action": "Log*/Trace*/LogFile*/OpenLogFile PORTED (non-_DEBUG), OpenConsoleWindow N_A", "evidence": "port.debug_log"} diff --git a/audit/port-map/EterBase/Debug.cpp.json b/audit/port-map/EterBase/Debug.cpp.json index 2a79b89f..d71888e8 100644 --- a/audit/port-map/EterBase/Debug.cpp.json +++ b/audit/port-map/EterBase/Debug.cpp.json @@ -1,69 +1,165 @@ { - "reference": "EterBase/Debug.cpp", - "reference_sha256": "af7a6cba9e6d83511a40f596629f85f1b770b510fc0db1d9cbefcec88ecb15ec", - "priority": "P4", - "contracts": [], - "functions": { - "SetLogLevel": { - "status": "TODO" - }, - "Log": { - "status": "TODO" - }, - "Logn": { - "status": "TODO" - }, - "Logf": { - "status": "TODO" - }, - "Lognf": { - "status": "TODO" - }, - "Trace": { - "status": "TODO" - }, - "Tracen": { - "status": "TODO" - }, - "Tracenf": { - "status": "TODO" - }, - "Tracef": { - "status": "TODO" - }, - "TraceError": { - "status": "TODO" - }, - "TraceErrorWithoutEnter": { - "status": "TODO" - }, - "LogBoxf": { - "impl": [ - "src/platform/EterBase/Debug.cpp:LogBoxf" - ], - "status": "ADAPTED", - "note": "verbatim apart from two PORT fixes the 40250 build did not need: va_end (40250 leaks the va_list) and terminating szBuf, which _vsnprintf does not do on truncation.", - "test": "project/python_host_check.gd — system.py's ImportError reaches GDScript through it" - }, - "LogBox": { - "impl": [ - "src/platform/EterBase/Debug.cpp:LogBox" - ], - "status": "ADAPTED", - "note": "40250 pops a MessageBox on g_PopupHwnd and Tracen()s the text. No window here: the text goes to stderr and is kept in LastLogBoxMessage() (src/platform/EterBase/LogBox.h), because ScriptLib/PythonLauncher.cpp Traceback() reports every failed script line through LogBoxf after PyErr_Fetch has already cleared the exception — this is the only place a traceback survives.", - "test": "project/python_host_check.gd — system.py's ImportError reaches GDScript through it" - }, - "LogFile": { - "status": "TODO" - }, - "LogFilef": { - "status": "TODO" - }, - "OpenLogFile": { - "status": "TODO" - }, - "OpenConsoleWindow": { - "status": "TODO" + "reference": "EterBase/Debug.cpp", + "reference_sha256": "af7a6cba9e6d83511a40f596629f85f1b770b510fc0db1d9cbefcec88ecb15ec", + "priority": "P4", + "contracts": [], + "functions": { + "SetLogLevel": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:SetLogLevel" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too)." + }, + "Log": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:Log" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too)." + }, + "Logn": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:Logn" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too)." + }, + "Logf": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:Logf" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too). PORT: terminates szBuf after a truncating _vsnprintf (and va_end in LogFilef)." + }, + "Lognf": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:Lognf" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too)." + }, + "Trace": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:Trace" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too)." + }, + "Tracen": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:Tracen" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too)." + }, + "Tracenf": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:Tracenf" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too)." + }, + "Tracef": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:Tracef" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too). PORT: terminates szBuf after a truncating _vsnprintf (and va_end in LogFilef)." + }, + "TraceError": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:TraceError" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 (stderr without the SYSERR: prefix, log.txt with it). PORT: a -1 (truncated) _vsnprintf keeps the terminator inside the buffer; the TraceErrorObserver hook forwards the line (Android logcat, tests)." + }, + "TraceErrorWithoutEnter": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:TraceErrorWithoutEnter" + ], + "note": "Verbatim, including printing from szBuf + 8; no caller in 40250 (LC_ALL=C grep -a)." + }, + "LogBoxf": { + "impl": [ + "src/platform/EterBase/Debug.cpp:LogBoxf" + ], + "status": "ADAPTED", + "note": "verbatim apart from two PORT fixes the 40250 build did not need: va_end (40250 leaks the va_list) and terminating szBuf, which _vsnprintf does not do on truncation.", + "test": "project/python_host_check.gd — system.py's ImportError reaches GDScript through it" + }, + "LogBox": { + "impl": [ + "src/platform/EterBase/Debug.cpp:LogBox" + ], + "status": "ADAPTED", + "note": "40250 pops a MessageBox on g_PopupHwnd and Tracen()s the text. No window here: the text goes to stderr and is kept in LastLogBoxMessage() (src/platform/EterBase/LogBox.h), because ScriptLib/PythonLauncher.cpp Traceback() reports every failed script line through LogBoxf after PyErr_Fetch has already cleared the exception — this is the only place a traceback survives.", + "test": "project/python_host_check.gd — system.py's ImportError reaches GDScript through it" + }, + "LogFile": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:LogFile" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too)." + }, + "LogFilef": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:LogFilef" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim 40250 non-_DEBUG build (the _DEBUG OutputDebugString/stdout lines are compiled out there too). PORT: terminates szBuf after a truncating _vsnprintf (and va_end in LogFilef)." + }, + "OpenLogFile": { + "status": "PORTED", + "impl": [ + "src/platform/EterBase/Debug.cpp:OpenLogFile" + ], + "test": [ + "tests/port/port_debug_log_test.cpp" + ], + "note": "Verbatim (freopen syserr.txt over stderr; log.txt when true). 40250 Main calls OpenLogFile(false) in release; the SDL host does not call it yet (UserInterface.cpp Main is still TODO), so stderr stays on the terminal/logcat." + }, + "OpenConsoleWindow": { + "status": "N_A", + "note": "AllocConsole + CONOUT$/CONIN$ in the _DEBUG WinMain only; the shipped release build never calls it." + } } - } } diff --git a/src/platform/EterBase/Debug.cpp b/src/platform/EterBase/Debug.cpp index 3988d0e7..45db179e 100644 --- a/src/platform/EterBase/Debug.cpp +++ b/src/platform/EterBase/Debug.cpp @@ -1,11 +1,12 @@ -// Platform skeleton for EterBase/Debug.h (40250 EterBase/Debug.cpp), generated by platform_stub.py. -// Every MT_PLATFORM_STUB() body is unimplemented: replace it with the platform implementation. Implemented -// bodies follow the 40250 non-_DEBUG build (batch 2D: Trace*, TraceError to stderr). +// Platform implementation of EterBase/Debug.h (40250 EterBase/Debug.cpp), the non-_DEBUG build: Log*/Trace* +// reach log.txt only after OpenLogFile(true), TraceError goes to stderr (syserr.txt after OpenLogFile). The +// MT_PLATFORM_STUB() bodies left are the _DEBUG console and the Debug.h declarations 40250 never defines. #include "EterBase/StdAfx.h" #include "EterBase/Debug.h" #include "../PlatformStub.h" #include "EterBase/Timer.h" +#include "EterBase/Singleton.h" #include "LogBox.h" #include "TraceErrorObserver.h" @@ -26,51 +27,166 @@ void SetTraceErrorObserver(TraceErrorObserver observer) g_trace_error_observer = observer; } -auto SetLogLevel(UINT) -> void +// 40250 Debug.cpp:11 +static int isLogFile = false; +HWND g_PopupHwnd = NULL; + +// 40250 Debug.cpp:14 +class CLogFile : public CSingleton { - MT_PLATFORM_STUB(); + public: + CLogFile() : m_fp(NULL) + { + } + + virtual ~CLogFile() + { + if (m_fp) + fclose(m_fp); + + m_fp = NULL; + } + + void Initialize() + { + m_fp = fopen("log.txt", "w"); + } + + void Write(const char * c_pszMsg) + { + if (!m_fp) + return; + + time_t ct = time(0); + struct tm ctm = *localtime(&ct); + + fprintf(m_fp, "%02d%02d %02d:%02d:%05d :: %s", + ctm.tm_mon + 1, + ctm.tm_mday, + ctm.tm_hour, + ctm.tm_min, + ELTimer_GetMSec() % 60000, + c_pszMsg); + + fflush(m_fp); + } + + protected: + FILE * m_fp; +}; + +static CLogFile gs_logfile; + +static UINT gs_uLevel=0; + +// 40250 Debug.cpp:61. The Log*/Trace* bodies are the non-_DEBUG build: they only reach log.txt, which +// OpenLogFile(true) opens (40250 does that in _DEBUG builds only). +void SetLogLevel(UINT uLevel) +{ + gs_uLevel=uLevel; } -auto Log(UINT, const char *) -> void +void Log(UINT uLevel, const char* c_szMsg) { - MT_PLATFORM_STUB(); + if (uLevel>=gs_uLevel) + Trace(c_szMsg); } -auto Logn(UINT, const char *) -> void +void Logn(UINT uLevel, const char* c_szMsg) { - MT_PLATFORM_STUB(); + if (uLevel>=gs_uLevel) + Tracen(c_szMsg); } -auto Logf(UINT, const char *, ...) -> void +void Logf(UINT uLevel, const char* c_szFormat, ...) { - MT_PLATFORM_STUB(); + if (uLevel void +void Lognf(UINT uLevel, const char* c_szFormat, ...) { - MT_PLATFORM_STUB(); + if (uLevel 0) + { + szBuf[len] = '\n'; + szBuf[len + 1] = '\0'; + } + va_end(args); + + if (isLogFile) + LogFile(szBuf); } -void Trace(const char *) + +void Trace(const char * c_szMsg) { - // Non-_DEBUG 40250: written only to the log file (OpenLogFile, not implemented yet). + if (isLogFile) + LogFile(c_szMsg); } -void Tracen(const char *) +void Tracen(const char* c_szMsg) { - // Non-_DEBUG 40250: written only to the log file (OpenLogFile, not implemented yet). + if (isLogFile) + { + LogFile(c_szMsg); + LogFile("\n"); + } } -void Tracenf(const char *, ...) +void Tracenf(const char* c_szFormat, ...) { - // Non-_DEBUG 40250: written only to the log file (OpenLogFile, not implemented yet). + va_list args; + va_start(args, c_szFormat); + + char szBuf[DEBUG_STRING_MAX_LEN+2]; + int len = _vsnprintf(szBuf, sizeof(szBuf)-1, c_szFormat, args); + + if (len > 0) + { + szBuf[len] = '\n'; + szBuf[len + 1] = '\0'; + } + va_end(args); + + if (isLogFile) + LogFile(szBuf); } -void Tracef(const char *, ...) +void Tracef(const char* c_szFormat, ...) { - // Non-_DEBUG 40250: written only to the log file (OpenLogFile, not implemented yet). + char szBuf[DEBUG_STRING_MAX_LEN+1]; + + va_list args; + va_start(args, c_szFormat); + _vsnprintf(szBuf, sizeof(szBuf), c_szFormat, args); + va_end(args); + szBuf[DEBUG_STRING_MAX_LEN] = '\0'; // PORT: _vsnprintf does not terminate on truncation + + if (isLogFile) + LogFile(szBuf); } +// 40250 Debug.cpp:199 void TraceError(const char* c_szFormat, ...) { #ifndef _DISTRIBUTE @@ -104,12 +220,41 @@ void TraceError(const char* c_szFormat, ...) fflush(stderr); if (g_trace_error_observer) g_trace_error_observer(szBuf + 8); + + if (isLogFile) + LogFile(szBuf); #endif } -auto TraceErrorWithoutEnter(const char *, ...) -> void +// 40250 Debug.cpp:239. It prints from szBuf + 8 although nothing is prepended (TraceError's "SYSERR: " +// offset); there is no caller in 40250. +void TraceErrorWithoutEnter(const char* c_szFormat, ...) { - MT_PLATFORM_STUB(); +#ifndef _DISTRIBUTE + + char szBuf[DEBUG_STRING_MAX_LEN]; + + va_list args; + va_start(args, c_szFormat); + _vsnprintf(szBuf, sizeof(szBuf), c_szFormat, args); + va_end(args); + szBuf[DEBUG_STRING_MAX_LEN - 1] = '\0'; // PORT: _vsnprintf does not terminate on truncation + + time_t ct = time(0); + struct tm ctm = *localtime(&ct); + + fprintf(stderr, "%02d%02d %02d:%02d:%05d :: %s", + ctm.tm_mon + 1, + ctm.tm_mday, + ctm.tm_hour, + ctm.tm_min, + ELTimer_GetMSec() % 60000, + szBuf + 8); + fflush(stderr); + + if (isLogFile) + LogFile(szBuf); +#endif } namespace @@ -160,16 +305,26 @@ void LogBoxf(const char * c_szFormat, ...) LogBox(szBuf); } -auto LogFile(const char *) -> void +// 40250 Debug.cpp:292 +void LogFile(const char * c_szMsg) { - MT_PLATFORM_STUB(); + CLogFile::Instance().Write(c_szMsg); } -auto LogFilef(const char *, ...) -> void +void LogFilef(const char * c_szMessage, ...) { - MT_PLATFORM_STUB(); + va_list args; + va_start(args, c_szMessage); + char szBuf[DEBUG_STRING_MAX_LEN+1]; + _vsnprintf(szBuf, sizeof(szBuf), c_szMessage, args); + va_end(args); // PORT: 40250 leaks the va_list + szBuf[DEBUG_STRING_MAX_LEN] = '\0'; // PORT: _vsnprintf does not terminate on truncation + + CLogFile::Instance().Write(szBuf); } +// 40250 Debug.cpp:320: AllocConsole + CONOUT$/CONIN$, called by the _DEBUG WinMain only. The host +// process already has its terminal (or logcat). auto OpenConsoleWindow() -> void { MT_PLATFORM_STUB(); @@ -185,9 +340,18 @@ auto SetupLog() -> void MT_PLATFORM_STUB(); } -auto OpenLogFile(bool) -> void +// 40250 Debug.cpp:307 +void OpenLogFile(bool bUseLogFIle) { - MT_PLATFORM_STUB(); +#ifndef _DISTRIBUTE + freopen("syserr.txt", "w", stderr); + + if (bUseLogFIle) + { + isLogFile = true; + CLogFile::Instance().Initialize(); + } +#endif } auto CloseLogFile() -> void diff --git a/src/port/CMakeLists.txt b/src/port/CMakeLists.txt index 24eebe3d..076a4799 100644 --- a/src/port/CMakeLists.txt +++ b/src/port/CMakeLists.txt @@ -214,6 +214,11 @@ if(BUILD_TESTING AND CMAKE_SYSTEM_NAME STREQUAL CMAKE_HOST_SYSTEM_NAME) target_link_libraries(port_screenshot_test PRIVATE port_platform) add_test(NAME port.screenshot COMMAND $) + # EterBase/Debug.cpp: syserr.txt / log.txt (redirects its own stderr). + add_executable(port_debug_log_test ${PROJECT_SOURCE_DIR}/tests/port/port_debug_log_test.cpp) + target_link_libraries(port_debug_log_test PRIVATE port_platform) + add_test(NAME port.debug_log COMMAND $) + # 批次 2V1: Packet.h struct sizes against the classic wire layouts. add_executable(port_packet_test ${PROJECT_SOURCE_DIR}/tests/port/port_packet_test.cpp ${PROJECT_SOURCE_DIR}/tests/port/port_packet_test_wire.cpp) diff --git a/tests/port/port_debug_log_test.cpp b/tests/port/port_debug_log_test.cpp new file mode 100644 index 00000000..8325db41 --- /dev/null +++ b/tests/port/port_debug_log_test.cpp @@ -0,0 +1,73 @@ +// EterBase/Debug.cpp (the 40250 non-_DEBUG build): OpenLogFile sends stderr to syserr.txt and, with true, +// opens log.txt for Log*/Trace*; SetLogLevel filters Log*. Its own process because stderr is redirected, so +// failures go to stdout. +#include "EterBase/StdAfx.h" +#include "EterBase/Debug.h" + +#include +#include +#include +#include +#include + +static int g_failures = 0; +#define CHECK(cond) \ + do { \ + if (!(cond)) { \ + std::printf("%s:%d: CHECK(%s)\n", __FILE__, __LINE__, #cond); \ + ++g_failures; \ + } \ + } while (0) + +static std::string ReadAll(const char* path) +{ + std::ifstream in(path); + std::stringstream ss; + ss << in.rdbuf(); + return ss.str(); +} + +int main() +{ + char dir[] = "/tmp/mt_debuglog_XXXXXX"; + if (!mkdtemp(dir) || chdir(dir) != 0) + return 1; + + // Before OpenLogFile nothing reaches a log file. + Tracenf("before %d", 1); + + OpenLogFile(true); + SetLogLevel(1); + Logn(0, "level0"); + Logn(1, "level1"); + Lognf(2, "lognf %d", 2); + Logf(0, "logf-filtered"); + Tracen("tracen"); + Tracef("tracef %s\n", "x"); + TraceError("oops %d", 7); + LogFilef("filef %d\n", 3); + fflush(stderr); + + const std::string log = ReadAll("log.txt"); + const std::string syserr = ReadAll("syserr.txt"); + CHECK(log.find("before") == std::string::npos); + CHECK(log.find("level0") == std::string::npos); + CHECK(log.find(" :: level1") != std::string::npos); + CHECK(log.find(" :: lognf 2\n") != std::string::npos); + CHECK(log.find("logf-filtered") == std::string::npos); + CHECK(log.find(" :: tracen") != std::string::npos); + CHECK(log.find(" :: tracef x\n") != std::string::npos); + CHECK(log.find(" :: SYSERR: oops 7\n") != std::string::npos); + CHECK(log.find(" :: filef 3\n") != std::string::npos); + CHECK(syserr.find(" :: oops 7\n") != std::string::npos && syserr.find("SYSERR") == std::string::npos); + + unlink("log.txt"); + unlink("syserr.txt"); + chdir("/"); + rmdir(dir); + if (g_failures) + std::printf("port_debug_log_test: %d failure(s)\n", g_failures); + else + std::puts("port_debug_log_test: ok"); + return g_failures ? 1 : 0; +}