Merge pull request #10872 from shuffle2/timer

Timer improvements

Source/Core/Common/Image.cpp

@@ -116,7 +116,7 @@ bool SavePNG(const std::string& path, const u8* input, ImageByteFormat format, u
   size_t image_len = 0;
   spng_decoded_image_size(ctx.get(), SPNG_FMT_PNG, &image_len);
   INFO_LOG_FMT(FRAMEDUMP, "{} byte {} by {} image saved to {} at level {} in {}", image_len, width,
-               height, path, level, timer.GetTimeElapsedFormatted());
+               height, path, level, timer.ElapsedMs());
   return true;
 }
 

Source/Core/Common/Logging/LogManager.cpp

@@ -4,13 +4,15 @@
 #include "Common/Logging/LogManager.h"
 
 #include <algorithm>
+#include <chrono>
 #include <cstdarg>
 #include <cstring>
 #include <locale>
 #include <mutex>
 #include <ostream>
 #include <string>
 
+#include <fmt/chrono.h>
 #include <fmt/format.h>
 
 #include "Common/CommonPaths.h"
@@ -19,7 +21,6 @@
 #include "Common/Logging/ConsoleListener.h"
 #include "Common/Logging/Log.h"
 #include "Common/StringUtil.h"
-#include "Common/Timer.h"
 
 namespace Common::Log
 {
@@ -204,11 +205,23 @@ void LogManager::Log(LogLevel level, LogType type, const char* file, int line, c
   LogWithFullPath(level, type, file + m_path_cutoff_point, line, message);
 }
 
+std::string LogManager::GetTimestamp()
+{
+  // NOTE: the Qt LogWidget hardcodes the expected length of the timestamp portion of the log line,
+  // so ensure they stay in sync
+
+  // We want milliseconds *and not hours*, so can't directly use STL formatters
+  const auto now = std::chrono::system_clock::now();
+  const auto now_s = std::chrono::floor<std::chrono::seconds>(now);
+  const auto now_ms = std::chrono::floor<std::chrono::milliseconds>(now);
+  return fmt::format("{:%M:%S}:{:03}", now_s, (now_ms - now_s).count());
+}
+
 void LogManager::LogWithFullPath(LogLevel level, LogType type, const char* file, int line,
                                  const char* message)
 {
   const std::string msg =
-      fmt::format("{} {}:{} {}[{}]: {}\n", Common::Timer::GetTimeFormatted(), file, line,
+      fmt::format("{} {}:{} {}[{}]: {}\n", GetTimestamp(), file, line,
                   LOG_LEVEL_TO_CHAR[static_cast<int>(level)], GetShortName(type), message);
 
   for (const auto listener_id : m_listener_ids)

Source/Core/Common/Logging/LogManager.h

@@ -75,6 +75,8 @@ class LogManager
   LogManager(LogManager&&) = delete;
   LogManager& operator=(LogManager&&) = delete;
 
+  static std::string GetTimestamp();
+
   LogLevel m_level;
   EnumMap<LogContainer, LAST_LOG_TYPE> m_log{};
   std::array<LogListener*, LogListener::NUMBER_OF_LISTENERS> m_listeners{};

Source/Core/Common/Profiler.cpp

@@ -32,7 +32,7 @@ Profiler::Profiler(const std::string& name)
     : m_name(name), m_usecs(0), m_usecs_min(UINT64_MAX), m_usecs_max(0), m_usecs_quad(0),
       m_calls(0), m_depth(0)
 {
-  m_time = Common::Timer::GetTimeUs();
+  m_time = Common::Timer::NowUs();
   s_max_length = std::max<u32>(s_max_length, u32(m_name.length()));
 
   std::lock_guard<std::mutex> lk(s_mutex);
@@ -64,7 +64,7 @@ std::string Profiler::ToString()
   if (s_all_profilers.empty())
     return "";
 
-  u64 end = Common::Timer::GetTimeUs();
+  u64 end = Common::Timer::NowUs();
   s_usecs_frame = end - s_frame_time;
   s_frame_time = end;
 
@@ -101,15 +101,15 @@ void Profiler::Start()
 {
   if (!m_depth++)
   {
-    m_time = Common::Timer::GetTimeUs();
+    m_time = Common::Timer::NowUs();
   }
 }
 
 void Profiler::Stop()
 {
   if (!--m_depth)
   {
-    u64 end = Common::Timer::GetTimeUs();
+    u64 end = Common::Timer::NowUs();
 
     u64 diff = end - m_time;