From f08579d201f393e814f5925824f573b30e419c99 Mon Sep 17 00:00:00 2001
From: Nekotekina <nekotekina@gmail.com>
Date: Wed, 22 Feb 2017 12:52:03 +0300
Subject: [PATCH] Log timestamp added

---
 Utilities/Log.cpp         | 55 ++++++++++++++++++++++++++++++++++++---
 Utilities/Log.h           |  2 +-
 rpcs3/Gui/ConLogFrame.cpp |  2 +-
 3 files changed, 53 insertions(+), 6 deletions(-)

diff --git a/Utilities/Log.cpp b/Utilities/Log.cpp
index 837a073a9a..74c218169a 100644
--- a/Utilities/Log.cpp
+++ b/Utilities/Log.cpp
@@ -5,6 +5,12 @@
 #include "rpcs3_version.h"
 #include <string>
 
+#ifdef _WIN32
+#include <Windows.h>
+#else
+#include <chrono>
+#endif
+
 // Thread-specific log prefix provider
 thread_local std::string(*g_tls_log_prefix)() = nullptr;
 
@@ -56,7 +62,7 @@ namespace logs
 		}
 
 		// Encode level, current thread name, channel name and write log message
-		virtual void log(const message& msg, const std::string& prefix, const std::string& text) override;
+		virtual void log(u64 stamp, const message& msg, const std::string& prefix, const std::string& text) override;
 	};
 
 	static file_listener* get_logger()
@@ -66,6 +72,39 @@ namespace logs
 		return &logger;
 	}
 
+	static u64 get_stamp()
+	{
+		static struct time_initializer
+		{
+#ifdef _WIN32
+			LARGE_INTEGER freq;
+			LARGE_INTEGER start;
+
+			time_initializer()
+			{
+				QueryPerformanceFrequency(&freq);
+				QueryPerformanceCounter(&start);
+			}
+#else
+			std::chrono::steady_clock::time_point start = std::chrono::steady_clock::now();
+#endif
+
+			u64 get() const
+			{
+#ifdef _WIN32
+				LARGE_INTEGER now;
+				QueryPerformanceCounter(&now);
+				const LONGLONG diff = now.QuadPart - start.QuadPart;
+				return diff / freq.QuadPart * 1'000'000 + diff % freq.QuadPart * 1'000'000 / freq.QuadPart;
+#else
+				return std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::steady_clock::now() - start).count();
+#endif
+			}
+		} timebase{};
+
+		return timebase.get();
+	}
+
 	channel GENERAL(nullptr, level::notice);
 	channel LOADER("LDR", level::notice);
 	channel MEMORY("MEM", level::notice);
@@ -94,6 +133,9 @@ void logs::listener::add(logs::listener* _new)
 
 void logs::message::broadcast(const char* fmt, const fmt_type_info* sup, const u64* args)
 {
+	// Get timestamp
+	const u64 stamp = get_stamp();
+
 	std::string text; fmt::raw_append(text, fmt, sup, args);
 	std::string prefix(g_tls_log_prefix ? g_tls_log_prefix() : "");
 
@@ -103,7 +145,7 @@ void logs::message::broadcast(const char* fmt, const fmt_type_info* sup, const u
 	// Send message to all listeners
 	while (lis)
 	{
-		lis->log(*this, prefix, text);
+		lis->log(stamp, *this, prefix, text);
 		lis = lis->m_next;
 	}
 }
@@ -130,7 +172,7 @@ void logs::file_writer::log(const char* text, std::size_t size)
 	m_file.write(text, size);
 }
 
-void logs::file_listener::log(const logs::message& msg, const std::string& prefix, const std::string& _text)
+void logs::file_listener::log(u64 stamp, const logs::message& msg, const std::string& prefix, const std::string& _text)
 {
 	std::string text; text.reserve(prefix.size() + _text.size() + 200);
 
@@ -147,7 +189,12 @@ void logs::file_listener::log(const logs::message& msg, const std::string& prefi
 	case level::trace:   text = u8"·T "; break;
 	}
 
-	// TODO: print time?
+	// Print miscosecond timestamp
+	const u64 hours = stamp / 3600'000'000;
+	const u64 mins = (stamp % 3600'000'000) / 60'000'000;
+	const u64 secs = (stamp % 60'000'000) / 1'000'000;
+	const u64 frac = (stamp % 1'000'000);
+	fmt::append(text, "%u:%02u:%02u.%06u ", hours, mins, secs, frac);
 
 	if (prefix.size() > 0)
 	{
diff --git a/Utilities/Log.h b/Utilities/Log.h
index d9a3129bca..d5f60cc175 100644
--- a/Utilities/Log.h
+++ b/Utilities/Log.h
@@ -43,7 +43,7 @@ namespace logs
 		virtual ~listener();
 
 		// Process log message
-		virtual void log(const message& msg, const std::string& prefix, const std::string& text) = 0;
+		virtual void log(u64 stamp, const message& msg, const std::string& prefix, const std::string& text) = 0;
 
 		// Add new listener
 		static void add(listener*);
diff --git a/rpcs3/Gui/ConLogFrame.cpp b/rpcs3/Gui/ConLogFrame.cpp
index ae144a249f..1310ceda06 100644
--- a/rpcs3/Gui/ConLogFrame.cpp
+++ b/rpcs3/Gui/ConLogFrame.cpp
@@ -46,7 +46,7 @@ struct gui_listener : logs::listener
 		delete read;
 	}
 
-	void log(const logs::message& msg, const std::string& prefix, const std::string& text)
+	void log(u64 stamp, const logs::message& msg, const std::string& prefix, const std::string& text)
 	{
 		if (msg.sev <= enabled)
 		{