Files
MobileGL/MobileGL/MG_Util/Debug/Log.cpp
T
swung0x48 8b13d8a84c [MG_Remote, MG_Impl] (P6/dl): the device-lost latch, taken from a descriptor and never from a deadline
Before this, CONTRACT-P6 5.3's own sentence held: "a dead server leaves the
client silently DECLINE-ing every verb forever with glGetError clean".
FatalCode::DeviceLost had zero producers and zero consumers and
glGetGraphicsResetStatus returned GL_NO_ERROR unconditionally, so an
application had no way to learn that the process holding its GPU objects was
gone. Measured cost of that: a server killed on its first Clear left the
client waiting out the full 120 s barrier and reporting Fatal{BarrierTimeout}
- the wrong diagnosis, two minutes late. It now notices in 0.01 s.

THE MACHINERY WAS ALREADY THERE. Doorbell::Wait breaks out on Dead(),
SessionProducer::Park turns that into SessionWait::ShutDown, and ClientSession
already had the named DECLINED path. What did not exist was the death FACT:
D5c's finding is that the client parks on clientBell[0] and rings ITSELF
through clientBell[1], holding both ends, so EOF can never arrive on the one
descriptor it watches. A bell that can wake itself cannot hear a death.

SetDeathWitness(fd) fixes that with no new descriptor: the control socket's
far end is held only by the server. The subtlety is that the bell must watch a
socket it must NEVER read - the transport's reassembler owns those bytes and a
control reply is not a death. So the witness enters the poll set with
`events = POLLRDHUP` and nothing else: POLLHUP/POLLERR/POLLNVAL arrive in
revents unrequested, so the hangup is seen while POLLIN never is. Nothing is
recv'd from it and its ownership stays with SocketTransport.

Dead() AND PeerHungUp() ARE TWO FACTS. Park sets m_dead for POLLERR, POLLNVAL
and unrecognised revents too - each a fault in THIS process's descriptor - and
CondVarDoorbell::Kill() sets it on every orderly Stop(). A latch taken from
Dead() would report a lost GPU for a local fd bug and a context reset for
every clean exit, so only PeerHungUp() arms it.

GL_UNKNOWN_CONTEXT_RESET, not GUILTY or INNOCENT: those assign blame, and the
server died for a reason that never crossed the wire.

D5b, in the control-reply wait, which had the right comment and no code: EOF
on the control stream is device loss; a TIMEOUT with the socket still open is
"ALIVE BUT SILENT" and says so by name. 5.4 forbids calling a frozen or merely
slow peer dead, and under P5e run-ahead a server one frame behind is the
INTENDED steady state - a latch armed by a deadline would fire on a healthy
session under load.

MOBILEGL_IPC_RESPAWN is now a NAMED REFUSAL rather than a variable nothing
reads. The latch is one-way on purpose: every handle this client minted names
an object inside the server process, so recovery means re-pushing the world.

THREE TEST NAMES ADDED, none renamed (G14), and R-16 run both ways:
  * remove the witness -> AKilledServerLatchesDeviceLostFromTheHangupAndNot-
    ADeadline goes red, takes 2 s instead of 0.01 s, and names D5c.
  * collapse PeerHungUp() into Dead() -> ADeadBellIsNotAlwaysAHungUpPeer goes
    red naming the local-fd-bug consequence.
  * AnOrderlyStopIsNotADeviceLoss stays GREEN under that collapse, and its
    comment now says so. The first draft claimed it was the control for it;
    running the falsification proved otherwise - under spawn the self bell is a
    SocketDoorbell and Stop() never kills one. The comment was corrected rather
    than the claim quietly kept.

G1 RE-MEASURED, NOT ASSUMED: 0 symbol diff against the c6 baseline and .text
unchanged at 0xa52203. That measurement earned its keep - it caught a 16-byte
drift that had nothing to do with dl: P6's O_APPEND log-sink fix was compiling
into the PULL build, where a second process can never exist. Now guarded, and
.text is back to the baseline exactly.

Full unit suite: 2350 tests, the same two pre-existing environmental failures
and no others. All six OpenRA arms (2 backends x monolith/inproc/spawn) green.
2026-09-21 18:49:56 -04:00

180 lines
7.2 KiB
C++

// MobileGL - MobileGL/MG_Util/Debug/Log.cpp
// Copyright (c) 2025-2026 MobileGL-Dev
// Licensed under the GNU Lesser General Public License v3.0:
// https://www.gnu.org/licenses/gpl-3.0.txt
// https://www.gnu.org/licenses/lgpl-3.0.txt
// SPDX-License-Identifier: LGPL-3.0-only
// End of Source File Header
#include "../../Includes.h"
#include <cstring> // std::strcmp, for the spawned-server role check in InitFile
namespace MobileGL {
namespace MG_Util::Debug {
static FILE* s_logFile = nullptr;
std::mutex& LogMutex() {
static auto* mutex = new std::mutex();
return *mutex;
}
constexpr char* GetOSName() {
#if defined(_WIN32)
return (char*)"Windows";
#elif defined(__ANDROID__)
return (char*)"Android";
#elif defined(__APPLE__)
return (char*)"macOS";
#elif defined(__linux__)
return (char*)"Linux";
#else
return (char*)"UnknownOS";
#endif
}
std::string GetThreadName() {
char buffer[64] = {0};
#if defined(_WIN32)
PWSTR desc = nullptr;
if (SUCCEEDED(GetThreadDescription(GetCurrentThread(), &desc))) {
WideCharToMultiByte(CP_UTF8, 0, desc, -1, buffer, sizeof(buffer), nullptr, nullptr);
LocalFree(desc);
}
#elif defined(__ANDROID__) || defined(__linux__) || defined(__APPLE__)
pthread_getname_np(pthread_self(), buffer, sizeof(buffer));
#endif
return buffer[0] ? buffer : "UnknownThread";
}
std::string GetCurrentTime() {
using namespace std::chrono;
auto now = system_clock::now();
std::time_t tt = system_clock::to_time_t(now);
struct tm tm{};
#if defined(_WIN32)
localtime_s(&tm, &tt);
#else
localtime_r(&tt, &tm);
#endif
char buf[16];
std::strftime(buf, sizeof(buf), "%H:%M:%S", &tm);
return buf;
}
void InitFile() {
#if MOBILEGL_LOG_ENABLE_FILE
if (!s_logFile) {
// MOBILEGL_LOG_FILE_PATH must stay a raw getenv (not MG_Config::Features):
// InitFile() runs before MG_ConfigLoader::Init() in MobileGL::Initialize().
const char* logPath = std::getenv("MOBILEGL_LOG_FILE_PATH");
if (!logPath || !*logPath) {
logPath = MOBILEGL_LOG_FILE_PATH;
}
if (logPath && *logPath) {
// "a", NOT "w", WHENEVER A SECOND PROCESS SHARES THIS PATH.
//
// Under transport=spawn the server is a separate process
// writing the same MOBILEGL_LOG_FILE_PATH, and two "w"
// handles each carry their OWN file offset: both start at 0
// and overwrite each other's bytes. The result is not
// interleaved, it is CORRUPT - observed as half-lines like
// `ote client: CapsMirror generation 1 adopted` while
// diagnosing the spawn retrace, and as the server's whole
// startup block vanishing under the client's later writes.
// O_APPEND makes each write atomic at the end of the file,
// which is what makes the log a usable census across both
// processes - and run_trace_case.cmake's Fatal{ count reads
// exactly this file.
//
// THE CLIENT STILL TRUNCATES ONCE, so a fresh run does not
// read as a growing pile of old ones. The server never does:
// it is always started by a client that has already opened
// this path, and a truncate from the far side would delete
// the very startup lines a failed session needs.
//
// GUARDED, BECAUSE G1 MEASURES BYTES AND NOT INTENT. Only a disaggregated
// build can ever have a second process on this path, so a pull build gains
// nothing from the append - and it would pay for it in .text, which G1
// requires to be unchanged. Measured: unguarded, the pull library's .text
// moved 16 bytes with its symbol set identical, which is exactly the kind of
// drift that is invisible unless somebody looks.
#if MOBILEGL_BUILD_DISAGGREGATED
const char* role = std::getenv("MOBILEGL_IPC_ROLE");
const bool isSpawnedServer = role != nullptr && std::strcmp(role, "server") == 0;
if (!isSpawnedServer) {
if (FILE* truncate = std::fopen(logPath, "w")) std::fclose(truncate);
}
s_logFile = std::fopen(logPath, "a");
#else
s_logFile = std::fopen(logPath, "w");
#endif
}
}
#endif
}
void WriteToFile(const char* msg) {
#if MOBILEGL_LOG_ENABLE_FILE
if (!s_logFile) InitFile();
if (s_logFile) {
std::fputs(msg, s_logFile);
std::fflush(s_logFile);
}
#endif
}
void Log(const char* levelTag, android_LogPriority androidLogLevel, const char* fmt, ...) {
std::lock_guard<std::mutex> lock(LogMutex());
#if MOBILEGL_LOG_ENABLE_STACKTRACE
auto trace = std::stacktrace::current();
std::string padding(4 * trace.size(), ' ');
#endif
std::string header =
"[" + GetCurrentTime() + "] [" + GetOSName() + " " + GetThreadName() + "/" + levelTag + "]: ";
static char buffer[1024000];
va_list args;
va_start(args, fmt);
int n = std::vsnprintf(buffer, sizeof(buffer), fmt, args);
const SizeT messageLength =
(n < 0) ? 0 : std::min(static_cast<SizeT>(n), sizeof(buffer) - static_cast<SizeT>(1));
std::string out = header +
#if MOBILEGL_LOG_ENABLE_STACKTRACE
padding +
#endif
std::string(buffer, messageLength) + "\n";
#if MOBILEGL_LOG_ENABLE_CONSOLE
std::fwrite(out.c_str(), 1, out.size(), stdout);
fflush(stdout);
#endif
#if MOBILEGL_LOG_ENABLE_ANDROID && defined(__ANDROID__)
// Without the trailing newline that the file sink needs: logcat terminates
// records itself, so handing it an already-newline-terminated string made
// every MobileGL log occupy TWO logcat records, the second one empty. That
// halved the useful depth of every `adb logcat -t N` window the CI
// diagnostics read (android-plugin/trace-replay-ci.sh).
__android_log_print(androidLogLevel, "MobileGL", "%.*s", static_cast<int>(out.size() - 1),
out.c_str());
#endif
WriteToFile(out.c_str());
va_end(args);
}
void Close() {
#if MOBILEGL_LOG_ENABLE_FILE
if (s_logFile) {
std::fclose(s_logFile);
s_logFile = nullptr;
}
#endif
}
} // namespace MG_Util::Debug
} // namespace MobileGL