From c6b02c4d0c94006407d77824bb3c5db3a81fbc51 Mon Sep 17 00:00:00 2001 From: baldurk Date: Thu, 2 Aug 2018 15:09:57 +0100 Subject: [PATCH] Pull adb logcat from renderdoc into log on host machine * This makes post-mortem debugging easier. It's only active while a remote server connection is running, so e.g. it will miss crashes of the remote server itself, this could be improved by adding a margin where it will still check for messages after the connection is dropped - perhaps on a separate thread. --- renderdoc/android/android.h | 4 + renderdoc/android/android_utils.cpp | 461 +++++++++++++++++- renderdoc/common/common.cpp | 14 +- renderdoc/common/common.h | 8 +- renderdoc/common/timing.h | 5 +- renderdoc/core/remote_server.cpp | 15 + renderdoc/os/os_specific.cpp | 5 + renderdoc/os/os_specific.h | 5 +- .../os/posix/android/android_stringio.cpp | 5 +- renderdoc/os/posix/posix_stringio.cpp | 7 +- renderdoc/os/posix/posix_threading.cpp | 5 + renderdoc/os/win32/win32_stringio.cpp | 7 +- renderdoc/os/win32/win32_threading.cpp | 5 + renderdoc/replay/entry_points.cpp | 6 +- 14 files changed, 525 insertions(+), 27 deletions(-) diff --git a/renderdoc/android/android.h b/renderdoc/android/android.h index 78524006c..4c44f22cb 100644 --- a/renderdoc/android/android.h +++ b/renderdoc/android/android.h @@ -40,4 +40,8 @@ Process::ProcessResult adbExecCommand(const std::string &deviceID, const std::st void initAdb(); void shutdownAdb(); bool InjectWithJDWP(const std::string &deviceID, uint16_t jdwpport); + +void ResetLogcat(); +void TickDeviceLogcat(); +void ProcessLogcat(std::string deviceID); }; diff --git a/renderdoc/android/android_utils.cpp b/renderdoc/android/android_utils.cpp index d66333bd3..d1b96d584 100644 --- a/renderdoc/android/android_utils.cpp +++ b/renderdoc/android/android_utils.cpp @@ -173,6 +173,356 @@ std::string GetFriendlyName(std::string deviceID) return combined; } + +static uint64_t getTimeMS() +{ + static uint64_t freq = (uint64_t)Timing::GetTickFrequency(); + + return uint64_t(Timing::GetTick() / freq); +} + +// the last time on the host that we processed android logcat, to avoid polling too often +uint64_t lastLogcatProcessTimeMS = 0; + +// the last log line we saw, so we start printing after that point. If we ever have a line here and +// we don't see it in the backlog. +std::string lastLogcatLine; + +void ResetLogcat() +{ + // reset last expected line so we restart from scratch next time + lastLogcatLine.clear(); +} + +// on android only when we hit this function we write a marker that isn't a standard log. The +// purpose is to always try and have a unique message in the last N lines so that we can detect if +// we ever lose messages. +void TickDeviceLogcat() +{ +#if ENABLED(RDOC_ANDROID) + OSUtility::WriteOutput( + OSUtility::Output_DebugMon, + StringFormat::Fmt("__rdoc_internal_android_logcat %llu", getTimeMS()).c_str()); +#endif +} + +struct LogLine +{ + time_t timestamp = 0; + uint32_t pid = 0; + LogType logtype = LogType::Comment; + std::string filename; + uint32_t line_number = 0; + std::string message; + + bool parse(const std::string &line) + { +#define EXPECT_CHAR(c) \ + if(idx >= line.length() || line[idx] != c) \ + return false; \ + idx++; + + // Parse out mostly our own log files, but also output that looks like crash callstacks + // + // Example lines: + // + // clang-format off + // + // 0 1 2 3 4 5 6 7 8 9 10 + // 1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456 + // I/renderdoc( 1234): @1234567812345678@ RDOC 001234: [01:02:03] filename.cpp( 123) - Log - Hello + // + // F/libc (11519): Fatal signal 11 (SIGSEGV), code 1, fault addr 0x4 in tid 11618 (FooBar), pid 11519 (blah) + // F/DEBUG (12061): backtrace: + // F/DEBUG (12061): #00 pc 000485ec /system/lib/libc.so (pthread_mutex_lock+1) + // F/DEBUG (12061): #01 pc 00137449 /data/app/org.renderdoc.renderdoccmd.arm32==/lib/arm/libVkLayer_GLES_RenderDoc.so + // F/DEBUG (12061): #02 pc 0013bbf1 /data/app/org.renderdoc.renderdoccmd.arm32==/lib/arm/libVkLayer_GLES_RenderDoc.so + // + // clang-format on + // + + size_t idx = 0; + + // too short - minimum is 22 for prefix. Could be longer if PID is over 5 digits + // saves on length checks below + if(line.length() <= 20) + return false; + + // skip past priority character + idx++; + + EXPECT_CHAR('/'); + + // we assume that the logcat filters have worked, so ignore the logcat tag here. Just check if + // it's ours or not + bool ownLog = !strncmp(&line[idx], "renderdoc", 9); + while(idx < line.length() && line[idx] != '(') + idx++; + + size_t tagEnd = idx; + + EXPECT_CHAR('('); + + // skip spaces + while(idx < line.length() && isspace(line[idx])) + idx++; + + // process this PID field - we'll override it with our own if this is one of our logs + pid = 0; + while(idx < line.length() && isdigit(line[idx])) + { + pid *= 10; + pid += int(line[idx] - '0'); + idx++; + } + + EXPECT_CHAR(')'); + EXPECT_CHAR(':'); + EXPECT_CHAR(' '); + + if(!ownLog) + { + // don't know anything more about the format, this whole thing is the message. + message = line.substr(idx); + + // use current host time, it's not accurate but it's close enough. + timestamp = Timing::GetUTCTime(); + + filename = line.substr(2, tagEnd - 2); + line_number = 0; + + logtype = LogType::Comment; + switch(line[0]) + { + case 'V': // VERBOSE + case 'D': // DEBUG + logtype = LogType::Debug; + break; + case 'I': // INFO + logtype = LogType::Comment; + break; + case 'W': // WARN + logtype = LogType::Warning; + break; + case 'E': // ERROR + logtype = LogType::Error; + break; + case 'F': // FATAL + logtype = LogType::Fatal; + break; + case 'S': // SILENT + default: logtype = LogType::Comment; break; + } + + // remove any padding spaces + while(!filename.empty() && isspace(filename.back())) + filename.pop_back(); + + // if adb gave us DOS newlines, remove the \r + if(message.back() == '\r') + message.pop_back(); + + return true; + } + + // skip past digits and '@', this field is only so that we don't ever get duplicates in the + // output even if the same message is printed + while(idx < line.length() && (line[idx] == '@' || isalnum(line[idx]))) + idx++; + + EXPECT_CHAR(' '); + + // should be at least 64 more characters + if(idx + 64 > line.length()) + return false; + + if(strncmp(&line[idx], "RDOC ", 5)) + return false; + + idx += 5; + + pid = 0; + while(idx < line.length() && isdigit(line[idx])) + { + pid *= 10; + pid += int(line[idx] - '0'); + idx++; + } + + EXPECT_CHAR(':'); + EXPECT_CHAR(' '); + EXPECT_CHAR('['); + + // expect HH:MM:SS + if(idx + 8 >= line.length()) + return false; + + // we only need the time part, so just take it from the epoch + uint32_t h = 0, m = 0, s = 0; + + h = int(line[idx + 0] - '0') * 10 + int(line[idx + 1] - '0'); + m = int(line[idx + 3] - '0') * 10 + int(line[idx + 4] - '0'); + s = int(line[idx + 6] - '0') * 10 + int(line[idx + 7] - '0'); + + if(line[idx + 2] != ':' || line[idx + 5] != ':') + return false; + + timestamp = (h * 60 + m) * 60 + s; + + idx += 8; + + EXPECT_CHAR(']'); + + while(idx < line.length() && line[idx] != '(') + { + filename.push_back(line[idx]); + idx++; + } + + // strip spaces + while(!filename.empty() && isspace(filename[0])) + filename.erase(0, 1); + + while(!filename.empty() && isspace(filename.back())) + filename.pop_back(); + + if(filename.empty()) + return false; + + EXPECT_CHAR('('); + + while(idx < line.length() && isspace(line[idx])) + idx++; + + line_number = 0; + while(idx < line.length() && isdigit(line[idx])) + { + line_number *= 10; + line_number += int(line[idx] - '0'); + idx++; + } + + EXPECT_CHAR(')'); + EXPECT_CHAR(' '); + EXPECT_CHAR('-'); + EXPECT_CHAR(' '); + + std::string logtype_str; + while(idx < line.length() && line[idx] != '-') + { + logtype_str.push_back(line[idx]); + idx++; + } + + // strip spaces + while(!logtype_str.empty() && isspace(logtype_str[0])) + logtype_str.erase(0); + + while(!logtype_str.empty() && isspace(logtype_str.back())) + logtype_str.pop_back(); + + if(logtype_str == "Debug") + logtype = LogType::Debug; + else if(logtype_str == "Log") + logtype = LogType::Comment; + else if(logtype_str == "Warning") + logtype = LogType::Warning; + else if(logtype_str == "Error") + logtype = LogType::Error; + else if(logtype_str == "Fatal") + logtype = LogType::Fatal; + else + return false; + + EXPECT_CHAR('-'); + EXPECT_CHAR(' '); + + if(idx >= line.length()) + return false; + + message = line.substr(idx); + + // if adb gave us DOS newlines, remove the \r + if(message.back() == '\r') + message.pop_back(); + +#undef EXPECT_CHAR + + return true; + } +}; + +void ProcessLogcat(std::string deviceID) +{ + uint64_t curTimeMS = getTimeMS(); + + // only check for logcat every 500ms, because adb can take ~250ms to run + if(lastLogcatProcessTimeMS + 400 > curTimeMS) + return; + + lastLogcatProcessTimeMS = curTimeMS; + + // adb is extremely unreliable, so although it supposedly contains functionality to filter for + // everything after a certain timestamp, this can actually drop messages. Instead we just always + // grab the last 750 lines and hope that the device doesn't ever peak over 1 line per millisecond + // such that we'd miss something. Note another joy of adb - the line count is applied *before* + // the filter, so if something else spams 1000 lines we won't see our own. + const uint32_t lineBacklog = 750; + + // logcat + // -t N // always the last N messages, and (implied -d) stop after doing so + // -v brief // print the 'brief' format + // -s // silence everything as a default + // renderdoc:* // print logcats from our tag. + // libc:* // or from libc (prints crash messages) + // DEBUG:* // or from DEBUG (prints crash messages) + // + // This gives us all messages from renderdoc since the last timestamp. + std::string command = + StringFormat::Fmt("logcat -t %u -v brief -s renderdoc:* libc:* DEBUG:*", lineBacklog); + + std::string logcat = trim(Android::adbExecCommand(deviceID, command, ".", true).strStdout); + + std::vector lines; + split(logcat, lines, '\n'); + + // remove \n from any lines right now to prevent it breaking further processing + for(std::string &line : lines) + if(!line.empty() && line.back() == '\r') + line.pop_back(); + + // only do any processing if we had a line last time that we know to start from. + if(!lastLogcatLine.empty()) + { + auto it = std::find(lines.begin(), lines.end(), lastLogcatLine); + + if(it != lines.end()) + { + // remove everything up to and including that line + lines.erase(lines.begin(), it + 1); + } + else + { + RDCWARN("Couldn't find last line. Potentially missed logcat messages."); + } + + for(const std::string &line : lines) + { + LogLine logline; + + if(logline.parse(line)) + { + rdclog_direct(logline.timestamp, logline.pid, logline.logtype, "ADRD", + logline.filename.c_str(), logline.line_number, "%s", logline.message.c_str()); + rdclog_flush(); + } + } + } + + // store the last line (if we have one) to search for and start from next time + if(!lines.empty()) + lastLogcatLine = lines.back(); +} }; template <> @@ -187,4 +537,113 @@ std::string DoStringise(const Android::ABI &el) STRINGISE_ENUM_CLASS(x86_64); } END_ENUM_STRINGISE(); -} \ No newline at end of file +} + +#if ENABLED(ENABLE_UNIT_TESTS) + +#undef None + +#include "3rdparty/catch/catch.hpp" + +TEST_CASE("Test that log line parsing is robust", "[android]") +{ + using namespace Android; + + SECTION("Empty string") + { + LogLine line; + + CHECK(line.parse("") == false); + }; + + SECTION("Invalid strings") + { + LogLine line1; + + CHECK(line1.parse("--------- beginning of main") == false); + + LogLine line2; + + CHECK( + line2.parse("Lorem ipsum dolor sit amet, consectetur adipiscing elit. Nullam lacus lacus, " + "egestas vitae elementum sit amet, venenatis ac nunc.") == false); + }; + + SECTION("Valid strings") + { + LogLine line; + + const char *valid_text = + R"(I/renderdoc( 1234): @1234567812345678@ RDOC 001234: [01:02:03] filename.cpp( 123) - Warning - Hello)"; + + CHECK(line.parse(valid_text) == true); + + CHECK(line.filename == "filename.cpp"); + CHECK(line.line_number == 123); + CHECK((line.logtype == LogType::Warning)); + CHECK(line.message == "Hello"); + CHECK(line.pid == 1234); + CHECK(line.timestamp == 3723); + + LogLine highpid; + + const char *highpid_text = + R"(I/renderdoc(12345678): @1234567812345678@ RDOC 12345678: [01:02:03] filename.cpp( 123) - Warning - Hello)"; + + CHECK(highpid.parse(highpid_text) == true); + + CHECK(highpid.filename == "filename.cpp"); + CHECK(highpid.line_number == 123); + CHECK((highpid.logtype == LogType::Warning)); + CHECK(highpid.message == "Hello"); + CHECK(highpid.pid == 12345678); + CHECK(highpid.timestamp == 3723); + + LogLine longname; + + const char *longname_text = + R"(I/renderdoc( 1234): @1234567812345678@ RDOC 001234: [01:02:03] a_very_long_source_filename.cpp( 123) - Warning - Hello)"; + + CHECK(longname.parse(longname_text) == true); + + CHECK(longname.filename == "a_very_long_source_filename.cpp"); + CHECK(longname.line_number == 123); + CHECK((longname.logtype == LogType::Warning)); + CHECK(longname.message == "Hello"); + CHECK(longname.pid == 1234); + CHECK(longname.timestamp == 3723); + + LogLine longlinenum; + + const char *longlinenum_text = + R"(I/renderdoc( 1234): @1234567812345678@ RDOC 001234: [01:02:03] filename.cpp(12345678) - Warning - Hello)"; + + CHECK(longlinenum.parse(longlinenum_text) == true); + + CHECK(longlinenum.filename == "filename.cpp"); + CHECK(longlinenum.line_number == 12345678); + CHECK((longlinenum.logtype == LogType::Warning)); + CHECK(longlinenum.message == "Hello"); + CHECK(longlinenum.pid == 1234); + CHECK(longlinenum.timestamp == 3723); + }; + + SECTION("Invalid strings - truncated") + { + std::string truncated = + R"(I/renderdoc( 1234): @1234567812345678@ RDOC 001234: [01:02:03] filename.cpp( 123) - Warning - H)"; + + LogLine working; + CHECK(working.parse(truncated) == true); + + while(!truncated.empty()) + { + truncated.pop_back(); + + LogLine broken; + CHECK(broken.parse(truncated) == false); + } + }; +} + +#endif \ No newline at end of file diff --git a/renderdoc/common/common.cpp b/renderdoc/common/common.cpp index 95aa0ceda..367799518 100644 --- a/renderdoc/common/common.cpp +++ b/renderdoc/common/common.cpp @@ -81,7 +81,8 @@ float SRGB8_lookuptable[256] = { void rdcassert(const char *msg, const char *file, unsigned int line, const char *func) { - rdclog_int(LogType::Error, RDCLOG_PROJECT, file, line, "Assertion failed: %s", msg); + rdclog_direct(Timing::GetUTCTime(), Process::GetCurrentPID(), LogType::Error, RDCLOG_PROJECT, + file, line, "Assertion failed: %s", msg); } #if 0 @@ -387,8 +388,8 @@ static void write_newline(char *output) *output = 0; } -void rdclog_int(LogType type, const char *project, const char *file, unsigned int line, - const char *fmt, ...) +void rdclog_direct(time_t utcTime, uint32_t pid, LogType type, const char *project, + const char *file, unsigned int line, const char *fmt, ...) { va_list args; va_start(args, fmt); @@ -399,7 +400,7 @@ void rdclog_int(LogType type, const char *project, const char *file, unsigned in char timestamp[64] = {0}; #if ENABLED(INCLUDE_TIMESTAMP_IN_LOG) - StringFormat::sntimef(timestamp, 63, "[%H:%M:%S] "); + StringFormat::sntimef(utcTime, timestamp, 63, "[%H:%M:%S] "); #endif char location[64] = {0}; @@ -424,9 +425,8 @@ void rdclog_int(LogType type, const char *project, const char *file, unsigned in char *base = output; - int numWritten = StringFormat::snprintf(output, available, "% 4s %06u: %s%s%s - ", project, - Process::GetCurrentPID(), timestamp, location, - typestr[(uint32_t)type]); + int numWritten = StringFormat::snprintf(output, available, "% 4s %06u: %s%s%s - ", project, pid, + timestamp, location, typestr[(uint32_t)type]); if(numWritten < 0) { diff --git a/renderdoc/common/common.h b/renderdoc/common/common.h index af645fccc..caf792e8e 100644 --- a/renderdoc/common/common.h +++ b/renderdoc/common/common.h @@ -296,10 +296,12 @@ void rdclogprint_int(LogType type, const char *fullMsg, const char *msg); #endif // printf() style main logger function -void rdclog_int(LogType type, const char *project, const char *file, unsigned int line, - const char *fmt, ...); +void rdclog_direct(time_t utcTime, uint32_t pid, LogType type, const char *project, + const char *file, unsigned int line, const char *fmt, ...); -#define rdclog(type, ...) rdclog_int(type, RDCLOG_PROJECT, __FILE__, __LINE__, __VA_ARGS__) +#define rdclog(type, ...) \ + rdclog_direct(Timing::GetUTCTime(), Process::GetCurrentPID(), type, RDCLOG_PROJECT, __FILE__, \ + __LINE__, __VA_ARGS__) const char *rdclog_getfilename(); void rdclog_filename(const char *filename); diff --git a/renderdoc/common/timing.h b/renderdoc/common/timing.h index 2140e2adf..fe8cc88fa 100644 --- a/renderdoc/common/timing.h +++ b/renderdoc/common/timing.h @@ -125,8 +125,9 @@ public: ~ScopedTimer() { - rdclog_int(LogType::Comment, RDCLOG_PROJECT, m_File, m_Line, "Timer %s - %.3lf ms", - m_Message.c_str(), m_Timer.GetMilliseconds()); + rdclog_direct(Timing::GetUTCTime(), Process::GetCurrentPID(), LogType::Comment, RDCLOG_PROJECT, + m_File, m_Line, "Timer %s - %.3lf ms", m_Message.c_str(), + m_Timer.GetMilliseconds()); } private: diff --git a/renderdoc/core/remote_server.cpp b/renderdoc/core/remote_server.cpp index 928d0c1b0..acbf94b19 100644 --- a/renderdoc/core/remote_server.cpp +++ b/renderdoc/core/remote_server.cpp @@ -236,6 +236,9 @@ static void ActiveRemoteClientThread(ClientThread *threadData, if(proxy) proxy->RefreshPreviewWindow(); + // insert a dummy line into our logcat so we can keep track of our progress + Android::TickDeviceLogcat(); + WRITE_DATA_SCOPE(); SCOPED_SERIALISE_CHUNK(eRemoteServer_Ping); } @@ -1061,6 +1064,16 @@ public: if(!Connected()) return false; + const char *host = hostname().c_str(); + if(Android::IsHostADB(host)) + { + int index = 0; + std::string deviceID; + Android::ExtractDeviceIDAndIndex(m_hostname, index, deviceID); + + Android::ProcessLogcat(deviceID); + } + { WRITE_DATA_SCOPE(); SCOPED_SERIALISE_CHUNK(eRemoteServer_Ping); @@ -1829,6 +1842,8 @@ RENDERDOC_CreateRemoteServerConnection(const char *host, uint32_t port, IRemoteS { s = "127.0.0.1"; + Android::ResetLogcat(); + int index = 0; std::string deviceID; Android::ExtractDeviceIDAndIndex(host, index, deviceID); diff --git a/renderdoc/os/os_specific.cpp b/renderdoc/os/os_specific.cpp index b3587a01a..cf2d4dced 100644 --- a/renderdoc/os/os_specific.cpp +++ b/renderdoc/os/os_specific.cpp @@ -45,6 +45,11 @@ int snprintf(char *str, size_t bufSize, const char *fmt, ...) return ret; } +void sntimef(char *str, size_t bufSize, const char *format) +{ + StringFormat::sntimef(Timing::GetUTCTime(), str, bufSize, format); +} + int vsnprintf(char *str, size_t bufSize, const char *format, va_list args) { return ::utf8printf(str, bufSize, format, args); diff --git a/renderdoc/os/os_specific.h b/renderdoc/os/os_specific.h index 309f5d41c..ed041fe62 100644 --- a/renderdoc/os/os_specific.h +++ b/renderdoc/os/os_specific.h @@ -88,6 +88,7 @@ namespace Timing double GetTickFrequency(); uint64_t GetTick(); uint64_t GetUnixTimestamp(); +time_t GetUTCTime(); }; namespace Threading @@ -365,7 +366,7 @@ bool PlatformHasKeyInput(); // implemented per-platform namespace StringFormat { -void sntimef(char *str, size_t bufSize, const char *format); +void sntimef(time_t utcTime, char *str, size_t bufSize, const char *format); string Wide2UTF8(const std::wstring &s); @@ -379,6 +380,8 @@ namespace StringFormat int vsnprintf(char *str, size_t bufSize, const char *format, va_list v); int snprintf(char *str, size_t bufSize, const char *format, ...); +void sntimef(char *str, size_t bufSize, const char *format); + string Fmt(const char *format, ...); int Wide2UTF8(wchar_t chr, char mbchr[4]); diff --git a/renderdoc/os/posix/android/android_stringio.cpp b/renderdoc/os/posix/android/android_stringio.cpp index 2c28b86c2..aee04b4c0 100644 --- a/renderdoc/os/posix/android/android_stringio.cpp +++ b/renderdoc/os/posix/android/android_stringio.cpp @@ -117,12 +117,15 @@ namespace OSUtility { void WriteOutput(int channel, const char *str) { + static uint32_t seq = 0; + seq++; if(channel == OSUtility::Output_StdOut) fprintf(stdout, "%s", str); else if(channel == OSUtility::Output_StdErr) fprintf(stderr, "%s", str); else if(channel == OSUtility::Output_DebugMon) - __android_log_print(ANDROID_LOG_INFO, LOGCAT_TAG, "%s", str); + __android_log_print(ANDROID_LOG_INFO, LOGCAT_TAG, "@%08x%08x@ %s", + uint32_t(Timing::GetUTCTime()), seq, str); } uint64_t GetMachineIdent() diff --git a/renderdoc/os/posix/posix_stringio.cpp b/renderdoc/os/posix/posix_stringio.cpp index 7404f361f..3c265add5 100644 --- a/renderdoc/os/posix/posix_stringio.cpp +++ b/renderdoc/os/posix/posix_stringio.cpp @@ -575,12 +575,9 @@ void logfile_close(const char *filename) namespace StringFormat { -void sntimef(char *str, size_t bufSize, const char *format) +void sntimef(time_t utcTime, char *str, size_t bufSize, const char *format) { - time_t tim; - time(&tim); - - tm *tmv = localtime(&tim); + tm *tmv = localtime(&utcTime); strftime(str, bufSize, format, tmv); } diff --git a/renderdoc/os/posix/posix_threading.cpp b/renderdoc/os/posix/posix_threading.cpp index 063d99392..9f9108336 100644 --- a/renderdoc/os/posix/posix_threading.cpp +++ b/renderdoc/os/posix/posix_threading.cpp @@ -33,6 +33,11 @@ uint64_t Timing::GetUnixTimestamp() return (uint64_t)time(NULL); } +time_t Timing::GetUTCTime() +{ + return time(NULL); +} + namespace Atomic { int32_t Inc32(volatile int32_t *i) diff --git a/renderdoc/os/win32/win32_stringio.cpp b/renderdoc/os/win32/win32_stringio.cpp index aff9a17c5..66f219647 100644 --- a/renderdoc/os/win32/win32_stringio.cpp +++ b/renderdoc/os/win32/win32_stringio.cpp @@ -776,13 +776,10 @@ void logfile_close(const char *filename) namespace StringFormat { -void sntimef(char *str, size_t bufSize, const char *format) +void sntimef(time_t utcTime, char *str, size_t bufSize, const char *format) { - time_t tim; - time(&tim); - tm tmv; - localtime_s(&tmv, &tim); + localtime_s(&tmv, &utcTime); wchar_t *buf = new wchar_t[bufSize + 1]; buf[bufSize] = 0; diff --git a/renderdoc/os/win32/win32_threading.cpp b/renderdoc/os/win32/win32_threading.cpp index 60bd5cdf5..4f7996e42 100644 --- a/renderdoc/os/win32/win32_threading.cpp +++ b/renderdoc/os/win32/win32_threading.cpp @@ -46,6 +46,11 @@ uint64_t Timing::GetUnixTimestamp() return (uint64_t)time(NULL); } +time_t Timing::GetUTCTime() +{ + return time(NULL); +} + namespace Atomic { int32_t Inc32(volatile int32_t *i) diff --git a/renderdoc/replay/entry_points.cpp b/renderdoc/replay/entry_points.cpp index e3be157c8..2cd5ecc0a 100644 --- a/renderdoc/replay/entry_points.cpp +++ b/renderdoc/replay/entry_points.cpp @@ -221,14 +221,16 @@ extern "C" RENDERDOC_API void RENDERDOC_CC RENDERDOC_SetDebugLogFile(const char extern "C" RENDERDOC_API void RENDERDOC_CC RENDERDOC_LogText(const char *text) { - rdclog_int(LogType::Comment, "EXT", "external", 0, "%s", text); + rdclog_direct(Timing::GetUTCTime(), Process::GetCurrentPID(), LogType::Comment, "EXT", "external", + 0, "%s", text); } extern "C" RENDERDOC_API void RENDERDOC_CC RENDERDOC_LogMessage(LogType type, const char *project, const char *file, unsigned int line, const char *text) { - rdclog_int(type, project ? project : "UNK?", file ? file : "unknown", line, "%s", text); + rdclog_direct(Timing::GetUTCTime(), Process::GetCurrentPID(), type, project ? project : "UNK?", + file ? file : "unknown", line, "%s", text); #if ENABLED(DEBUGBREAK_ON_ERROR_LOG) if(type == LogType::Error)