From ccfd90a68dce51a931e6e89fa9ebbf9c2c8332ab Mon Sep 17 00:00:00 2001 From: Jelle Foks Date: Fri, 16 Aug 2024 12:35:58 -0700 Subject: [PATCH] Log thread and process CPU time --- base/logging.cc | 28 +++++++++++++++++++++++++++- 1 file changed, 27 insertions(+), 1 deletion(-) diff --git a/base/logging.cc b/base/logging.cc index 5a159ff4f3a0..0d451285f6c6 100644 --- a/base/logging.cc +++ b/base/logging.cc @@ -5,6 +5,7 @@ #include "base/logging.h" #include +#include #include "base/macros.h" #include "base/trace_event/trace_event.h" @@ -125,6 +126,30 @@ typedef pthread_mutex_t* MutexHandle; namespace logging { +namespace { +std::string print_rusage(int who, + const char* prefix = "", + const char* postfix = "") { + struct rusage usage; + if (getrusage(who, &usage) != -1) { + return starboard::FormatString( + "%s(CPU:u%ld.%03ld+s%ld=%ld.%03ld,FLT:%ld+%ld,CTX:%ld+%ld)%s", prefix, + usage.ru_utime.tv_sec, usage.ru_utime.tv_usec / 1000, + usage.ru_stime.tv_sec, usage.ru_stime.tv_usec / 1000, + ((usage.ru_utime.tv_sec + usage.ru_stime.tv_sec) * 1000000 + + (usage.ru_utime.tv_usec + usage.ru_stime.tv_usec)) / 1000, + usage.ru_minflt, usage.ru_majflt, usage.ru_nvcsw, usage.ru_nivcsw, + postfix); + } + return std::string(strerror(errno)); +} + +std::string print_stats() { + return print_rusage(RUSAGE_THREAD, "(", "/") + + print_rusage(RUSAGE_SELF, "", ")"); +} +} // namespace + namespace { VlogInfo* g_vlog_info = nullptr; @@ -1040,7 +1065,8 @@ void LogMessage::Init(const char* file, int line) { stream_ << CurrentProcessId() << ':'; #endif if (g_log_thread_id) - stream_ << base::PlatformThread::GetName() << '/' << base::PlatformThread::CurrentId() << ":"; + stream_ << base::PlatformThread::GetName() << '/' + << base::PlatformThread::CurrentId() << "/" << print_stats() << ":"; if (g_log_timestamp) { #if defined(STARBOARD) EzTimeValue time_value;