Merge branch 'main' of https://github.com/EpicGames/zen

5 files changed, 189 insertions, 75 deletions

diff --git a/src/zenutil/include/zenutil/basicfile.h b/src/zenutil/include/zenutil/basicfile.h
index 7797258e8..f25d9f23c 100644
--- a/src/zenutil/include/zenutil/basicfile.h
+++ b/src/zenutil/include/zenutil/basicfile.h
@@ -44,7 +44,6 @@ public:
 		kModeMask	   = 0x0007,
 		kPreventDelete = 0x1000'0000,  // Do not open with delete sharing mode (prevent other processes from deleting file while open)
 		kPreventWrite  = 0x2000'0000,  // Do not open with write sharing mode (prevent other processes from writing to file while open)
-		kDeleteOnClose = 0x4000'0000,  // File should be deleted when the last handle is closed
 	};
 
 	void	 Open(const std::filesystem::path& FileName, Mode Mode);
@@ -138,6 +137,13 @@ public:
 	void	   Read(void* Data, uint64_t Size, uint64_t FileOffset);
 	MemoryView MakeView(uint64_t Size, uint64_t FileOffset);
 
+	template<typename T>
+	const T* MakeView(uint64_t FileOffset)
+	{
+		MemoryView View = MakeView(sizeof(T), FileOffset);
+		return reinterpret_cast<const T*>(View.GetData());
+	}
+
 private:
 	BasicFile&	   m_Base;
 	uint8_t*	   m_Buffer;
@@ -147,6 +153,29 @@ private:
 	uint64_t	   m_BufferEnd;
 };
 
+/** Adds a layer of buffered writing to a BasicFile
+
+This class is not intended for concurrent access, it is not thread safe.
+
+*/
+
+class BasicFileWriter
+{
+public:
+	BasicFileWriter(BasicFile& Base, uint64_t BufferSize);
+	~BasicFileWriter();
+
+	void Write(void* Data, uint64_t Size, uint64_t FileOffset);
+	void Flush();
+
+private:
+	BasicFile&	   m_Base;
+	uint8_t*	   m_Buffer;
+	const uint64_t m_BufferSize;
+	uint64_t	   m_BufferStart;
+	uint64_t	   m_BufferEnd;
+};
+
 ZENCORE_API void basicfile_forcelink();
 
 }  // namespace zen
diff --git a/src/zenutil/include/zenutil/logging/fullformatter.h b/src/zenutil/include/zenutil/logging/fullformatter.h
index 498ecd143..146fea7a0 100644
--- a/src/zenutil/include/zenutil/logging/fullformatter.h
+++ b/src/zenutil/include/zenutil/logging/fullformatter.h
@@ -16,136 +16,175 @@ namespace zen::logging {
 class full_formatter final : public spdlog::formatter
 {
 public:
-	full_formatter(std::string_view LogId, std::chrono::time_point<std::chrono::system_clock> Epoch) : m_Epoch(Epoch), m_LogId(LogId) {}
+	full_formatter(std::string_view LogId, std::chrono::time_point<std::chrono::system_clock> Epoch)
+	: m_Epoch(Epoch)
+	, m_LogId(LogId)
+	, m_LinePrefix(128, ' ')
+	, m_UseFullDate(false)
+	{
+	}
 
-	virtual std::unique_ptr<formatter> clone() const override { return std::make_unique<full_formatter>(m_LogId, m_Epoch); }
+	full_formatter(std::string_view LogId) : m_LogId(LogId), m_LinePrefix(128, ' '), m_UseFullDate(true) {}
 
-	static constexpr bool UseDate = false;
+	virtual std::unique_ptr<formatter> clone() const override { return std::make_unique<full_formatter>(m_LogId, m_Epoch); }
 
-	virtual void format(const spdlog::details::log_msg& msg, spdlog::memory_buf_t& dest) override
+	virtual void format(const spdlog::details::log_msg& msg, spdlog::memory_buf_t& OutBuffer) override
 	{
-		using namespace std::literals;
-
-		if constexpr (UseDate)
-		{
-			auto secs = std::chrono::duration_cast<std::chrono::seconds>(msg.time.time_since_epoch());
-			if (secs != m_LastLogSecs)
-			{
-				m_CachedTm	  = spdlog::details::os::localtime(spdlog::log_clock::to_time_t(msg.time));
-				m_LastLogSecs = secs;
-			}
-		}
+		// Note that the sink is responsible for ensuring there is only ever a
+		// single caller in here
 
-		const auto& tm_time = m_CachedTm;
+		using namespace std::literals;
 
-		// cache the date/time part for the next second.
-		auto duration = msg.time - m_Epoch;
-		auto secs	  = std::chrono::duration_cast<std::chrono::seconds>(duration);
+		std::chrono::seconds TimestampSeconds;
 
-		if (m_CacheTimestamp != secs || m_CachedDatetime.size() == 0)
+		if (m_UseFullDate)
 		{
-			m_CachedDatetime.clear();
-			m_CachedDatetime.push_back('[');
-
-			if constexpr (UseDate)
+			TimestampSeconds = std::chrono::duration_cast<std::chrono::seconds>(msg.time.time_since_epoch());
+			if (TimestampSeconds != m_LastLogSecs)
 			{
-				spdlog::details::fmt_helper::append_int(tm_time.tm_year + 1900, m_CachedDatetime);
-				m_CachedDatetime.push_back('-');
+				m_LastLogSecs = TimestampSeconds;
 
-				spdlog::details::fmt_helper::pad2(tm_time.tm_mon + 1, m_CachedDatetime);
+				m_CachedLocalTm = spdlog::details::os::localtime(spdlog::log_clock::to_time_t(msg.time));
+				m_CachedDatetime.clear();
+				m_CachedDatetime.push_back('[');
+				spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_year % 100, m_CachedDatetime);
 				m_CachedDatetime.push_back('-');
-
-				spdlog::details::fmt_helper::pad2(tm_time.tm_mday, m_CachedDatetime);
+				spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_mon + 1, m_CachedDatetime);
+				m_CachedDatetime.push_back('-');
+				spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_mday, m_CachedDatetime);
 				m_CachedDatetime.push_back(' ');
-
-				spdlog::details::fmt_helper::pad2(tm_time.tm_hour, m_CachedDatetime);
+				spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_hour, m_CachedDatetime);
 				m_CachedDatetime.push_back(':');
-
-				spdlog::details::fmt_helper::pad2(tm_time.tm_min, m_CachedDatetime);
+				spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_min, m_CachedDatetime);
 				m_CachedDatetime.push_back(':');
-
-				spdlog::details::fmt_helper::pad2(tm_time.tm_sec, m_CachedDatetime);
+				spdlog::details::fmt_helper::pad2(m_CachedLocalTm.tm_sec, m_CachedDatetime);
+				m_CachedDatetime.push_back('.');
 			}
-			else
+		}
+		else
+		{
+			auto ElapsedTime = msg.time - m_Epoch;
+			TimestampSeconds = std::chrono::duration_cast<std::chrono::seconds>(ElapsedTime);
+
+			// cache the date/time part for the next second.
+
+			if (m_CacheTimestamp != TimestampSeconds || m_CachedDatetime.size() == 0)
 			{
-				int Count = int(secs.count());
+				m_CacheTimestamp = TimestampSeconds;
 
+				int		  Count	  = int(TimestampSeconds.count());
 				const int LogSecs = Count % 60;
 				Count /= 60;
-
 				const int LogMins = Count % 60;
 				Count /= 60;
-
 				const int LogHours = Count;
 
+				m_CachedDatetime.clear();
+				m_CachedDatetime.push_back('[');
 				spdlog::details::fmt_helper::pad2(LogHours, m_CachedDatetime);
 				m_CachedDatetime.push_back(':');
 				spdlog::details::fmt_helper::pad2(LogMins, m_CachedDatetime);
 				m_CachedDatetime.push_back(':');
 				spdlog::details::fmt_helper::pad2(LogSecs, m_CachedDatetime);
+				m_CachedDatetime.push_back('.');
 			}
-
-			m_CachedDatetime.push_back('.');
-
-			m_CacheTimestamp = secs;
 		}
 
-		dest.append(m_CachedDatetime.begin(), m_CachedDatetime.end());
+		OutBuffer.append(m_CachedDatetime.begin(), m_CachedDatetime.end());
 
 		auto millis = spdlog::details::fmt_helper::time_fraction<std::chrono::milliseconds>(msg.time);
-		spdlog::details::fmt_helper::pad3(static_cast<uint32_t>(millis.count()), dest);
-		dest.push_back(']');
-		dest.push_back(' ');
+		spdlog::details::fmt_helper::pad3(static_cast<uint32_t>(millis.count()), OutBuffer);
+		OutBuffer.push_back(']');
+		OutBuffer.push_back(' ');
 
 		if (!m_LogId.empty())
 		{
-			dest.push_back('[');
-			spdlog::details::fmt_helper::append_string_view(m_LogId, dest);
-			dest.push_back(']');
-			dest.push_back(' ');
+			OutBuffer.push_back('[');
+			spdlog::details::fmt_helper::append_string_view(m_LogId, OutBuffer);
+			OutBuffer.push_back(']');
+			OutBuffer.push_back(' ');
 		}
 
 		// append logger name if exists
 		if (msg.logger_name.size() > 0)
 		{
-			dest.push_back('[');
-			spdlog::details::fmt_helper::append_string_view(msg.logger_name, dest);
-			dest.push_back(']');
-			dest.push_back(' ');
+			OutBuffer.push_back('[');
+			spdlog::details::fmt_helper::append_string_view(msg.logger_name, OutBuffer);
+			OutBuffer.push_back(']');
+			OutBuffer.push_back(' ');
 		}
 
-		dest.push_back('[');
+		OutBuffer.push_back('[');
 		// wrap the level name with color
-		msg.color_range_start = dest.size();
-		spdlog::details::fmt_helper::append_string_view(spdlog::level::to_string_view(msg.level), dest);
-		msg.color_range_end = dest.size();
-		dest.push_back(']');
-		dest.push_back(' ');
+		msg.color_range_start = OutBuffer.size();
+		spdlog::details::fmt_helper::append_string_view(spdlog::level::to_string_view(msg.level), OutBuffer);
+		msg.color_range_end = OutBuffer.size();
+		OutBuffer.push_back(']');
+		OutBuffer.push_back(' ');
 
 		// add source location if present
 		if (!msg.source.empty())
 		{
-			dest.push_back('[');
+			OutBuffer.push_back('[');
 			const char* filename =
 				spdlog::details::short_filename_formatter<spdlog::details::null_scoped_padder>::basename(msg.source.filename);
-			spdlog::details::fmt_helper::append_string_view(filename, dest);
-			dest.push_back(':');
-			spdlog::details::fmt_helper::append_int(msg.source.line, dest);
-			dest.push_back(']');
-			dest.push_back(' ');
+			spdlog::details::fmt_helper::append_string_view(filename, OutBuffer);
+			OutBuffer.push_back(':');
+			spdlog::details::fmt_helper::append_int(msg.source.line, OutBuffer);
+			OutBuffer.push_back(']');
+			OutBuffer.push_back(' ');
 		}
 
-		spdlog::details::fmt_helper::append_string_view(msg.payload, dest);
-		spdlog::details::fmt_helper::append_string_view("\n"sv, dest);
+		// Handle newlines in single log call by prefixing each additional line to make
+		// subsequent lines align with the first line in the message
+
+		const size_t LinePrefixCount = Min<size_t>(OutBuffer.size(), m_LinePrefix.size());
+
+		auto ItLineBegin  = msg.payload.begin();
+		auto ItMessageEnd = msg.payload.end();
+		bool IsFirstline  = true;
+
+		{
+			auto ItLineEnd = ItLineBegin;
+
+			auto EmitLine = [&] {
+				if (IsFirstline)
+				{
+					IsFirstline = false;
+				}
+				else
+				{
+					spdlog::details::fmt_helper::append_string_view(std::string_view(m_LinePrefix.data(), LinePrefixCount), OutBuffer);
+				}
+				spdlog::details::fmt_helper::append_string_view(spdlog::string_view_t(&*ItLineBegin, ItLineEnd - ItLineBegin), OutBuffer);
+			};
+
+			while (ItLineEnd != ItMessageEnd)
+			{
+				if (*ItLineEnd++ == '\n')
+				{
+					EmitLine();
+					ItLineBegin = ItLineEnd;
+				}
+			}
+
+			if (ItLineBegin != ItMessageEnd)
+			{
+				EmitLine();
+				spdlog::details::fmt_helper::append_string_view("\n"sv, OutBuffer);
+			}
+		}
 	}
 
 private:
 	std::chrono::time_point<std::chrono::system_clock> m_Epoch;
-	std::tm											   m_CachedTm;
+	std::tm											   m_CachedLocalTm;
 	std::chrono::seconds							   m_LastLogSecs;
 	std::chrono::seconds							   m_CacheTimestamp{0};
 	spdlog::memory_buf_t							   m_CachedDatetime;
 	std::string										   m_LogId;
+	std::string										   m_LinePrefix;
+	bool											   m_UseFullDate = true;
 };
 
 }  // namespace zen::logging
diff --git a/src/zenutil/include/zenutil/workerpools.h b/src/zenutil/include/zenutil/workerpools.h
new file mode 100644
index 000000000..339120ece
--- /dev/null
+++ b/src/zenutil/include/zenutil/workerpools.h
@@ -0,0 +1,21 @@
+// Copyright Epic Games, Inc. All Rights Reserved.
+
+#pragma once
+
+#include <zencore/workthreadpool.h>
+
+namespace zen {
+
+// Worker pool with std::thread::hardware_concurrency() worker threads
+WorkerThreadPool& GetLargeWorkerPool();
+
+// Worker pool with std::thread::hardware_concurrency() / 4 worker threads
+WorkerThreadPool& GetSmallWorkerPool();
+
+// Special worker pool that does not use worker thread but issues all scheduled work on the calling thread
+// This is useful for debugging when multiple async thread can make stepping in debugger complicated
+WorkerThreadPool& GetSyncWorkerPool();
+
+void ShutdownWorkerPools();
+
+}  // namespace zen
diff --git a/src/zenutil/include/zenutil/zenserverprocess.h b/src/zenutil/include/zenutil/zenserverprocess.h
index 60adfba54..15138341c 100644
--- a/src/zenutil/include/zenutil/zenserverprocess.h
+++ b/src/zenutil/include/zenutil/zenserverprocess.h
@@ -4,6 +4,7 @@
 
 #include <zencore/enumflags.h>
 #include <zencore/logging.h>
+#include <zencore/process.h>
 #include <zencore/thread.h>
 #include <zencore/uid.h>
 
@@ -38,6 +39,7 @@ public:
 	inline bool				IsInitialized() const { return m_IsInitialized; }
 	inline bool				IsTestEnvironment() const { return m_IsTestInstance; }
 	inline std::string_view GetServerClass() const { return m_ServerClass; }
+	inline uint16_t			GetNewPortNumber() { return m_NextPortNumber.fetch_add(1); }
 
 private:
 	std::filesystem::path m_ProgramBaseDir;
@@ -45,6 +47,7 @@ private:
 	bool				  m_IsInitialized  = false;
 	bool				  m_IsTestInstance = false;
 	std::string			  m_ServerClass;
+	std::atomic_uint16_t  m_NextPortNumber{20000};
 };
 
 /** Zen Server Instance management
@@ -63,16 +66,29 @@ struct ZenServerInstance
 
 	void			   Shutdown();
 	void			   SignalShutdown();
-	void			   WaitUntilReady();
+	uint16_t		   WaitUntilReady();
 	[[nodiscard]] bool WaitUntilReady(int Timeout);
 	void			   EnableTermination() { m_Terminate = true; }
 	void			   DisableShutdownOnDestroy() { m_ShutdownOnDestroy = false; }
 	void			   Detach();
 	inline int		   GetPid() { return m_Process.Pid(); }
 	inline void		   SetOwnerPid(int Pid) { m_OwnerPid = Pid; }
+	bool			   IsRunning();
 
-	void		SetTestDir(std::filesystem::path TestDir);
-	inline void SpawnServer(int BasePort = 0, std::string_view AdditionalServerArgs = std::string_view())
+	void SetTestDir(std::filesystem::path TestDir);
+
+	inline void SpawnServer(std::string_view AdditionalServerArgs = std::string_view())
+	{
+		SpawnServer(m_Env.GetNewPortNumber(), AdditionalServerArgs, /* WaitTimeoutMs */ 0);
+	}
+
+	inline uint16_t SpawnServerAndWaitUntilReady(std::string_view AdditionalServerArgs = std::string_view())
+	{
+		SpawnServer(m_Env.GetNewPortNumber(), AdditionalServerArgs, /* WaitTimeoutMs */ 100'000);
+		return GetBasePort();
+	}
+
+	inline void SpawnServer(int BasePort, std::string_view AdditionalServerArgs = std::string_view())
 	{
 		SpawnServer(BasePort, AdditionalServerArgs, /* WaitTimeoutMs */ 0);
 	}
@@ -84,6 +100,7 @@ struct ZenServerInstance
 
 	void		AttachToRunningServer(int BasePort = 0);
 	std::string GetBaseUri() const;
+	uint16_t	GetBasePort() const { return m_BasePort; }
 
 private:
 	ZenServerEnvironment& m_Env;
@@ -93,11 +110,13 @@ private:
 	bool				  m_Terminate		  = false;
 	bool				  m_ShutdownOnDestroy = true;
 	std::filesystem::path m_TestDir;
-	int					  m_BasePort = 0;
+	uint16_t			  m_BasePort = 0;
 	std::optional<int>	  m_OwnerPid;
+	std::string			  m_Name;
 
 	void CreateShutdownEvent(int BasePort);
 	void SpawnServer(int BasePort, std::string_view AdditionalServerArgs, int WaitTimeoutMs);
+	void OnServerReady();
 };
 
 /** Shared system state
diff --git a/src/zenutil/include/zenutil/zenutil.h b/src/zenutil/include/zenutil/zenutil.h
index 14d21ea0d..662743de8 100644
--- a/src/zenutil/include/zenutil/zenutil.h
+++ b/src/zenutil/include/zenutil/zenutil.h
@@ -1,3 +1,9 @@
 // Copyright Epic Games, Inc. All Rights Reserved.
 
 #pragma once
+
+namespace zen {
+
+void zenutil_forcelinktests();
+
+}